Couchbase Server

indexer crash on add_replicas call

Details

  • Type: Bug Bug
  • Status: Resolved Resolved
  • Priority: Blocker Blocker
  • Resolution: Fixed
  • Affects Version/s: 2.0-beta
  • Fix Version/s: 2.0-beta
  • Component/s: ns_server, view-engine
  • Security Level: Public
  • Labels:
    None
  • Environment:
    See MB-6058 (second thing)

Description

After one of nodes was rebooted during rebalance and rebalance failed twice there's now some problem on that rebooted node.

[couchdb:info] [2012-08-13 12:19:19] [ns_1@10.3.121.25:<0.710.0>:couch_log:info:39] Restarting compaction for replica group `_design/dev_view3`, set view `default`. Reason: partition states were updated
[couchdb:info] [2012-08-13 12:19:19] [ns_1@10.3.121.25:<0.1200.0>:couch_log:info:39] Restarting compaction for replica group `_design/dev_view2`, set view `default`. Reason: partition states were updated
[couchdb:info] [2012-08-13 12:19:19] [ns_1@10.3.121.25:<0.710.0>:couch_log:info:39] Set view `default`, replica group `_design/dev_view3`, compaction starting
[couchdb:info] [2012-08-13 12:19:19] [ns_1@10.3.121.25:<0.1200.0>:couch_log:info:39] Set view `default`, replica group `_design/dev_view2`, compaction starting
[couchdb:info] [2012-08-13 12:19:19] [ns_1@10.3.121.25:<0.705.0>:couch_log:info:39] Set view `default`, main group `_design/dev_view3`, defined new replica partitions: [47,48,49,50,51,52,150,151,152,153,154,155,156,157,187,188,189,190,205,254,255,256,277,278,279,280,308,356,357,358,359,401,403,457,458,459,460,461,462,463,487,488,489,672,673,674,675,712,713,714,740,741,742,792,793,794,795,796,797,798,799]
New full set of replica partitions is: [47,48,49,50,51,52,150,151,152,153,154,155,156,157,187,188,189,190,205,254,255,256,277,278,279,280,308,356,357,358,359,401,403,457,458,459,460,461,462,463,487,488,489,672,673,674,675,712,713,714,740,741,742,792,793,794,795,796,797,798,799]

[couchdb:info] [2012-08-13 12:19:19] [ns_1@10.3.121.25:<0.705.0>:couch_log:info:39] Set view `default`, main group `_design/dev_view3`, terminating with reason: {{badmatch,
                                                                               {not_found,
                                                                                no_db_file}},
                                                                              [{couch_set_view_group,
                                                                                monitor_partitions,
                                                                                3},
                                                                               {couch_set_view_group,
                                                                                monitor_partitions,
                                                                                2},
                                                                               {couch_set_view_group,
                                                                                handle_call,
                                                                                3},
                                                                               {gen_server,
                                                                                handle_msg,
                                                                                5},
                                                                               {proc_lib,
                                                                                init_p_do_apply,
                                                                                3}]}
[couchdb:info] [2012-08-13 12:19:19] [ns_1@10.3.121.25:<0.710.0>:couch_log:info:39] Set view `default`, replica group `_design/dev_view3`, terminating with reason: shutdown
[views:info] [2012-08-13 12:19:19] [ns_1@10.3.121.25:'capi_set_view_manager-default':capi_set_view_manager:apply_index_states:367]
couch_set_view:add_replica_partitions([<<"default">>,<<"_design/dev_view3">>,
                                       [47,48,49,50,51,52,150,151,152,153,154,
                                        155,156,157,187,188,189,190,205,254,
                                        255,256,277,278,279,280,308,356,357,
                                        358,359,401,403,457,458,459,460,461,
                                        462,463,487,488,489,672,673,674,675,
                                        712,713,714,740,741,742,792,793,794,
                                        795,796,797,798,799]]) raised exit:{{{badmatch,
                                                                              {not_found,
                                                                               no_db_file}},
                                                                             [{couch_set_view_group,
                                                                               monitor_partitions,
                                                                               3},
                                                                              {couch_set_view_group,
                                                                               monitor_partitions,
                                                                               2},
                                                                              {couch_set_view_group,
                                                                               handle_call,
                                                                               3},
                                                                              {gen_server,
                                                                               handle_msg,
                                                                               5},
                                                                              {proc_lib,
                                                                               init_p_do_apply,
                                                                               3}]},
                                                                            {gen_server,
                                                                             call,
                                                                             [<0.705.0>,
                                                                              {add_replicas,
                                                                               6641967501501417383806791632523375489625984170218009161305639732734490564036031833581652368858531824236549515887750274907866037489577590312730316390889342644699189815496146066239026917192134394144920743793928168199194568457626425643944116224},
                                                                              infinity]}}
[error_logger:error] [2012-08-13 12:19:19] [ns_1@10.3.121.25:error_logger:ale_error_logger_handler:log_msg:76] ** Generic server <0.705.0> terminating
** Last message in was {add_replicas,6641967501501417383806791632523375489625984170218009161305639732734490564036031833581652368858531824236549515887750274907866037489577590312730316390889342644699189815496146066239026917192134394144920743793928168199194568457626425643944116224}
** When Server state == {state,
                         {"/data",<<"default">>,
                          {set_view_group,
                           <<101,48,96,72,5,6,250,227,107,51,35,214,124,13,132,
                             179>>,
                           nil,<<"default">>,<<"_design/dev_view3">>,[],
                           [{set_view,0,
                             [<<"view3">>],
                             <<"function (doc) {\n emit(doc['name'], [doc['achievements'], {location:{city: doc['city']}}]);\n}\n\n">>,
                             nil,[],[],undefined}],
                           nil,nil,
                           {set_view_index_header,1,0,0,0,0,[],nil,[],false,
                            [],nil,[]},
                           nil,main,nil,nil,nil,[]}},
                         <0.710.0>,
                         {set_view_group,
                          <<101,48,96,72,5,6,250,227,107,51,35,214,124,13,132,
                            179>>,
                          <0.5401.0>,<<"default">>,<<"_design/dev_view3">>,[],
                          [{set_view,0,
                            [<<"view3">>],
                            <<"function (doc) {\n emit(doc['name'], [doc['achievements'], {location:{city: doc['city']}}]);\n}\n\n">>,
                            {btree,<0.5401.0>,nil,
                             #Fun<couch_btree.3.59827385>,
                             #Fun<couch_btree.4.7841881>,
                             #Fun<couch_set_view_group.27.133282011>,
                             #Fun<couch_set_view_group.26.3863607>,5120,true},
                            [],[],#Ref<0.0.10.20933>}],
                          {btree,<0.5401.0>,nil,#Fun<couch_btree.3.59827385>,
                           #Fun<couch_btree.4.7841881>,
                           #Fun<couch_btree.5.72034400>,
                           #Fun<couch_set_view_group.11.83913258>,5120,true},
                          <0.5406.0>,
                          {set_view_index_header,1,1024,
                           225460087946287989877899396285904440311899765536343703386406136522124206147773051676300150243028163086763687936,
                           0,0,
                           [{74,0},
                            {92,0},
                            {93,0},
                            {263,0},
                            {264,0},
                            {298,0},
                            {365,0},
                            {366,0}],
                           nil,


Full logs below. Could be some issue in ns_server but since it's becoming late here I'm filing this in hope Filipe can find something obvious in view engine's log messages.

Activity

Ascending order - Click to sort in descending order
Hide
Permalink
Filipe Manana added a comment -
Not sure what I can do here.

One of the new replica partitions/databases could not be open, as apparently it doesn't exist (according to couch_db:open_int result).
Looking at the logs, it doesn't seem the database was deleted at the same or shortly before the add_replicas call.
I don't see what can be done other than crashing, or returning an explicit error to ns_server so that it can react to it (probably no idea what do there as well). Once a new partition/database/vbucket is added, it must be open for monitoring.

Submitted a change that will raise a more explicit error, mentioning the name of the database, when this happens: http://review.couchbase.org/#change,19598
Show
Filipe Manana added a comment - Not sure what I can do here. One of the new replica partitions/databases could not be open, as apparently it doesn't exist (according to couch_db:open_int result). Looking at the logs, it doesn't seem the database was deleted at the same or shortly before the add_replicas call. I don't see what can be done other than crashing, or returning an explicit error to ns_server so that it can react to it (probably no idea what do there as well). Once a new partition/database/vbucket is added, it must be open for monitoring. Submitted a change that will raise a more explicit error, mentioning the name of the database, when this happens: http://review.couchbase.org/#change,19598
Hide
Permalink
Filipe Manana added a comment -
Please try to reproduce with latest master to help diagnose where the problem comes from.
Show
Filipe Manana added a comment - Please try to reproduce with latest master to help diagnose where the problem comes from.
Hide
Permalink
Thuan Nguyen added a comment -
Integrated in github-couchdb-preview #477 (See [http://qa.hq.northscale.net/job/github-couchdb-preview/477/])
    MB-6218 More explicit error on database open failure (Revision eae73702a2d7b0b58ac53dcda2eb6fd02649cb76)

     Result = SUCCESS
Filipe David Borba Manana :
Files :
* src/couch_set_view/src/couch_set_view_group.erl
Show
Thuan Nguyen added a comment - Integrated in github-couchdb-preview #477 (See [ http://qa.hq.northscale.net/job/github-couchdb-preview/477/ ])      MB-6218 More explicit error on database open failure (Revision eae73702a2d7b0b58ac53dcda2eb6fd02649cb76)      Result = SUCCESS Filipe David Borba Manana : Files : * src/couch_set_view/src/couch_set_view_group.erl
Hide
Permalink
Farshid Ghods added a comment -
Tony,

please retry with the latest build that has Filipe changes
Show
Farshid Ghods added a comment - Tony, please retry with the latest build that has Filipe changes
Hide
Permalink
Thuan Nguyen added a comment - - edited
I may reproduce this issue.
I rerun on build 1584 on 10 nodes cluster with swap enable in 4 nodes. I just try to remove node 14 and rebalance failed all the times. Memcached crashed on 5 out of 10 nodes.
10.3.121.13
10.3.121.14
10.3.121.15 memcached crashed
10.3.121.16 memcached crashed
10.3.121.17 memcached crashed
10.3.121.20 memcached crashed
10.3.121.22 memcached crashed
10.3.121.24
10.3.121.25
10.3.121.23
I will upload diags of all nodes later and may have new issue
Here is the link to all diags
https://s3.amazonaws.com/packages.couchbase/diag-logs/large_cluster_2_0/10nodes-1584-rebalance-failed-memcached-crashed-20120815.tgz
Show
Thuan Nguyen added a comment - - edited I may reproduce this issue. I rerun on build 1584 on 10 nodes cluster with swap enable in 4 nodes. I just try to remove node 14 and rebalance failed all the times. Memcached crashed on 5 out of 10 nodes. 10.3.121.13 10.3.121.14 10.3.121.15 memcached crashed 10.3.121.16 memcached crashed 10.3.121.17 memcached crashed 10.3.121.20 memcached crashed 10.3.121.22 memcached crashed 10.3.121.24 10.3.121.25 10.3.121.23 I will upload diags of all nodes later and may have new issue Here is the link to all diags https://s3.amazonaws.com/packages.couchbase/diag-logs/large_cluster_2_0/10nodes-1584-rebalance-failed-memcached-crashed-20120815.tgz
Hide
Permalink
Thuan Nguyen added a comment -
Here is the atop of all nodes
https://s3.amazonaws.com/packages.couchbase/atop-files/2.0.0/atop-10nodes-1584-reb-failed-memcached-crashed-20120815.tgz
Show
Thuan Nguyen added a comment - Here is the atop of all nodes https://s3.amazonaws.com/packages.couchbase/atop-files/2.0.0/atop-10nodes-1584-reb-failed-memcached-crashed-20120815.tgz
Hide
Permalink
Aleksey Kondratenko added a comment -
That's different bug. Please file separately. Please try to do exactly same thing as before with rebooting node in order to reproduce this exact problem.
Show
Aleksey Kondratenko added a comment - That's different bug. Please file separately. Please try to do exactly same thing as before with rebooting node in order to reproduce this exact problem.
Hide
Permalink
Aleksey Kondratenko added a comment -
See above
Show
Aleksey Kondratenko added a comment - See above
Hide
Permalink
Thuan Nguyen added a comment - - edited
I can repro this bug 2 more times in build 2.0.0-1584 with swap rebalance and reboot in 9 nodes clusters (27+ million items, total resident ratio 60%).
Keep load running about 10K ops
10.3.121.13
10.3.121.14
10.3.121.15
10.3.121.16
10.3.121.17
10.3.121.20
10.3.121.22
10.3.121.25
10.3.121.23
I add node 14 to cluster and remove node 22
When rebalance starts in few minutes, reboot node 14 using command reboot
Check UI. See rebalance failed as expected.
Then node 14 up in up. Verify in cbstats that warmup is completed
ep_failpartialwarmup: 0
 ep_waitforwarmup: 0
 ep_warmup: 1
 ep_warmup_batch_size: 1000
 ep_warmup_dups: 0
 ep_warmup_min_items_threshold: 100
 ep_warmup_min_memory_threshold: 100
 ep_warmup_oom: 0
 ep_warmup_thread: complete
 ep_warmup_time: 23023396

Try swap rebalance again and it failed in few seconds.
Try 3 more rebalance and all failed with errors

Rebalance exited with reason {mover_failed,{badmatch,{error,ehostunreach}}}
<0.2092.53> exited with {mover_failed,{badmatch,{error,ehostunreach}}}
I will upload all diags files later

In swap rebalance reboot add node 25 and remove node 15, I got error below:

Rebalance exited with reason {bulk_set_vbucket_state_failed,
[{'ns_1@10.3.121.25',
{'EXIT',
{{{{{{badmatch,{not_found,no_db_file}},
[{couch_db_set,'-handle_call/3-fun-1-',
3},
{lists,foldl,3},
{couch_db_set,handle_call,3},
{gen_server,handle_msg,5},
{proc_lib,init_p_do_apply,3}]},
{gen_server,call,
[<15350.795.0>,
{add_partitions,"stuv"},
infinity]}},
{gen_server,call,
[<15350.616.0>,
{set_state,"stu","v",
[0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,
16,17,18,19,20,21,22,23,24,25,26,27,
28,29,30,31,32,33,34,35,36,37,38,39,
40,41,42,43,44,45,46,47,48,49,50,51,
52,53,54,55,56,57,58,59,60,61,62,63,
64,65,66,67,68,69,70,71,72,73,74,75,
76,77,78,79,80,81,82,83,84,85,86,87,
88,89,90,91,92,93,94,95,96,97,98,99,
100,101,102,103,104,105,106,107,108,
109,110,111,112,113,114,119,120,121,
122,123,124,125,126,127,128,129,130,
131,132,133,134,135,136,137,138,139,
140,141,142,143,144,145,146,147,148,
149,150,151,152,153,154,155,156,157,
158,159,160,161,162,163,164,165,166,
167,168,169,170,171,172,173,174,175,
176,177,178,179,180,181,182,183,184,
185,186,187,188,189,190,191,192,193,
194,195,196,197,198,199,200,201,202,
203,204,205,206,207,208,209,210,211,

Here is the link to diags
https://s3.amazonaws.com/packages.couchbase/diag-logs/large_cluster_2_0/10nodes-1584-swap-reb-failed-after-reboot-add-node-20120816.tgz
Show
Thuan Nguyen added a comment - - edited I can repro this bug 2 more times in build 2.0.0-1584 with swap rebalance and reboot in 9 nodes clusters (27+ million items, total resident ratio 60%). Keep load running about 10K ops 10.3.121.13 10.3.121.14 10.3.121.15 10.3.121.16 10.3.121.17 10.3.121.20 10.3.121.22 10.3.121.25 10.3.121.23 I add node 14 to cluster and remove node 22 When rebalance starts in few minutes, reboot node 14 using command reboot Check UI. See rebalance failed as expected. Then node 14 up in up. Verify in cbstats that warmup is completed ep_failpartialwarmup: 0  ep_waitforwarmup: 0  ep_warmup: 1  ep_warmup_batch_size: 1000  ep_warmup_dups: 0  ep_warmup_min_items_threshold: 100  ep_warmup_min_memory_threshold: 100  ep_warmup_oom: 0  ep_warmup_thread: complete  ep_warmup_time: 23023396 Try swap rebalance again and it failed in few seconds. Try 3 more rebalance and all failed with errors Rebalance exited with reason {mover_failed,{badmatch,{error,ehostunreach}}} <0.2092.53> exited with {mover_failed,{badmatch,{error,ehostunreach}}} I will upload all diags files later In swap rebalance reboot add node 25 and remove node 15, I got error below: Rebalance exited with reason {bulk_set_vbucket_state_failed, [{' ns_1@10.3.121.25 ', {'EXIT', {{{{{{badmatch,{not_found,no_db_file}}, [{couch_db_set,'-handle_call/3-fun-1-', 3}, {lists,foldl,3}, {couch_db_set,handle_call,3}, {gen_server,handle_msg,5}, {proc_lib,init_p_do_apply,3}]}, {gen_server,call, [<15350.795.0>, {add_partitions,"stuv"}, infinity]}}, {gen_server,call, [<15350.616.0>, {set_state,"stu","v", [0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15, 16,17,18,19,20,21,22,23,24,25,26,27, 28,29,30,31,32,33,34,35,36,37,38,39, 40,41,42,43,44,45,46,47,48,49,50,51, 52,53,54,55,56,57,58,59,60,61,62,63, 64,65,66,67,68,69,70,71,72,73,74,75, 76,77,78,79,80,81,82,83,84,85,86,87, 88,89,90,91,92,93,94,95,96,97,98,99, 100,101,102,103,104,105,106,107,108, 109,110,111,112,113,114,119,120,121, 122,123,124,125,126,127,128,129,130, 131,132,133,134,135,136,137,138,139, 140,141,142,143,144,145,146,147,148, 149,150,151,152,153,154,155,156,157, 158,159,160,161,162,163,164,165,166, 167,168,169,170,171,172,173,174,175, 176,177,178,179,180,181,182,183,184, 185,186,187,188,189,190,191,192,193, 194,195,196,197,198,199,200,201,202, 203,204,205,206,207,208,209,210,211, Here is the link to diags https://s3.amazonaws.com/packages.couchbase/diag-logs/large_cluster_2_0/10nodes-1584-swap-reb-failed-after-reboot-add-node-20120816.tgz
Hide
Permalink
Aleksey Kondratenko added a comment -
May I ask you guys to re-run it with latest fixes ?

I'm unable to reproduce this condition myself
Show
Aleksey Kondratenko added a comment - May I ask you guys to re-run it with latest fixes ? I'm unable to reproduce this condition myself
Hide
Permalink
Farshid Ghods added a comment -
the steps mentioned by tony are a dupe of http://www.couchbase.com/issues/browse/MB-6292 ?

moving this out of c-block since we are working on basic issues right now and this one seems like a more sophisticated test with too many items
Show
Farshid Ghods added a comment - the steps mentioned by tony are a dupe of http://www.couchbase.com/issues/browse/MB-6292 ? moving this out of c-block since we are working on basic issues right now and this one seems like a more sophisticated test with too many items
Hide
Permalink
Farshid Ghods added a comment -
please reproduce with the latest 2.0 build
Show
Farshid Ghods added a comment - please reproduce with the latest 2.0 build
Hide
Permalink
Karan Kumar added a comment -
To update the bug,
we tried to repro this on 1613.

Saw the following message on the UI:
Rebalance exited with reason bad_replicas_due_to_bad_results
Failed to get active replicas for following nodes:['ns_1@10.3.121.17']

From Alk:
The rebalance here failed in verifying replications, and the following message gets printed out on UI to indicate that
ns_server timed out verifying replications to that node.

Show
Karan Kumar added a comment - To update the bug, we tried to repro this on 1613. Saw the following message on the UI: Rebalance exited with reason bad_replicas_due_to_bad_results Failed to get active replicas for following nodes:[' ns_1@10.3.121.17 '] From Alk: The rebalance here failed in verifying replications, and the following message gets printed out on UI to indicate that ns_server timed out verifying replications to that node.
Hide
Permalink
Karan Kumar added a comment -
Will keep the bug open, as we are trying it more.
Show
Karan Kumar added a comment - Will keep the bug open, as we are trying it more.
Hide
Permalink
Farshid Ghods added a comment -
closing this bug for now if we see this issue again let's re-open the bug
Show
Farshid Ghods added a comment - closing this bug for now if we see this issue again let's re-open the bug

People

  • Assignee:
    Thuan Nguyen
    Reporter:
    Aleksey Kondratenko
Vote (0)
Watch (3)

Dates

  • Created:
    Updated:
    Resolved: