[#MB-7115] Rebalance operation failed repetitively while trying to rebalance in 5 nodes and rebalance out 3 nodes on a 5 node cluster, reason possibly because: "Unable to listen" to one of the nodes that was being rebalanced out. - Couchbase

Abhinav Dangeti made changes - 06/Nov/12 10:21 PM

Field	Original Value	New Value
Description	Scenario: - 10 node cluster with build 1942 - Rebalance out 5 nodes (completed successfully) - Cluster right now: 5 nodes - Add 5 nodes (with build 1944) and remove 3 nodes. - Hit rebalance. - Rebalance failed with reason: Rebalance exited with reason {badmatch, [{<0.26283.119>, {{badmatch,{error,emfile}}, [{ns_replicas_builder_utils, kill_a_bunch_of_tap_names,3}, {misc,try_with_maybe_ignorant_after,2}, {gen_server,terminate,6}, {proc_lib,init_p_do_apply,3}]}}]} - Tried rebalance again, but failed repetitively: Rebalance exited with reason {{{badmatch,[{<18058.14511.0>,noproc}]}, [{misc,sync_shutdown_many_i_am_trapping_exits, 1}, {misc,try_with_maybe_ignorant_after,2}, {gen_server,terminate,6}, {proc_lib,init_p_do_apply,3}]}, {gen_server,call, [<0.11023.120>, {shutdown_replicator, 'ns_1@ec2-54-251-5-97.ap-southeast-1.compute.amazonaws.com'}, infinity]}} Will upload logs from one of the nodes in the cluster during the time of the rebalance failures shortly.	Scenario: - 10 node cluster with build 1942 - Rebalance out 5 nodes (completed successfully) - Cluster right now: 5 nodes - Add 5 nodes (with build 1944) and remove 3 nodes. - Hit rebalance. - Rebalance failed with reason: Rebalance exited with reason {badmatch, [{<0.26283.119>, {{badmatch,{error,emfile}}, [{ns_replicas_builder_utils, kill_a_bunch_of_tap_names,3}, {misc,try_with_maybe_ignorant_after,2}, {gen_server,terminate,6}, {proc_lib,init_p_do_apply,3}]}}]} - Tried rebalance again, but failed repetitively: Rebalance exited with reason {{{badmatch,[{<18058.14511.0>,noproc}]}, [{misc,sync_shutdown_many_i_am_trapping_exits, 1}, {misc,try_with_maybe_ignorant_after,2}, {gen_server,terminate,6}, {proc_lib,init_p_do_apply,3}]}, {gen_server,call, [<0.11023.120>, {shutdown_replicator, 'ns_1@ec2-54-251-5-97.ap-southeast-1.compute.amazonaws.com'}, infinity]}} Will upload logs from one of the nodes in the cluster during the time of the rebalance failures shortly. _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ Noticed this on one of the nodes being rebalanced out: Unable to listen on 'ns_1@ec2-122-248-217-156.ap-southeast-1.compute.amazonaws.com'. So failed over the node and tried rebalancing, rebalancing still failed. So added that node back, and did not involve that particular node in the rebalance operation, rebalance succeeded.

Abhinav Dangeti made changes - 06/Nov/12 10:24 PM

Summary

Rebalance operation failed repetitively while trying to rebalance in 5 nodes and rebalance out 3 nodes on a 5 node cluster

Rebalance operation failed repetitively while trying to rebalance in 5 nodes and rebalance out 3 nodes on a 5 node cluster, reason possibly because: "Unable to listen" to one of the nodes that was being rebalanced out.

Abhinav Dangeti made changes - 06/Nov/12 10:29 PM

Description

Scenario:
- 10 node cluster with build 1942
- Rebalance out 5 nodes (completed successfully)
- Cluster right now: 5 nodes
- Add 5 nodes (with build 1944) and remove 3 nodes.
- Hit rebalance.
- Rebalance failed with reason:

Rebalance exited with reason {badmatch,
[{<0.26283.119>,
{{badmatch,{error,emfile}},
[{ns_replicas_builder_utils,
kill_a_bunch_of_tap_names,3},
{misc,try_with_maybe_ignorant_after,2},
{gen_server,terminate,6},
{proc_lib,init_p_do_apply,3}]}}]}

- Tried rebalance again, but failed repetitively:

Rebalance exited with reason {{{badmatch,[{<18058.14511.0>,noproc}]},
[{misc,sync_shutdown_many_i_am_trapping_exits,
1},
{misc,try_with_maybe_ignorant_after,2},
{gen_server,terminate,6},
{proc_lib,init_p_do_apply,3}]},
{gen_server,call,
[<0.11023.120>,
{shutdown_replicator,
'ns_1@ec2-54-251-5-97.ap-southeast-1.compute.amazonaws.com'},
infinity]}}

Will upload logs from one of the nodes in the cluster during the time of the rebalance failures shortly.

_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

Noticed this on one of the nodes being rebalanced out:
Unable to listen on 'ns_1@ec2-122-248-217-156.ap-southeast-1.compute.amazonaws.com'.

So failed over the node and tried rebalancing, rebalancing still failed.

So added that node back, and did not involve that particular node in the rebalance operation, rebalance succeeded.

Scenario:
- 10 node cluster with build 1942
- Rebalance out 5 nodes (completed successfully)
- Cluster right now: 5 nodes
- Add 5 nodes (with build 1944) and remove 3 nodes.
- Hit rebalance.
- Rebalance failed with reason:

Rebalance exited with reason {badmatch,
[{<0.26283.119>,
{{badmatch,{error,emfile}},
[{ns_replicas_builder_utils,
kill_a_bunch_of_tap_names,3},
{misc,try_with_maybe_ignorant_after,2},
{gen_server,terminate,6},
{proc_lib,init_p_do_apply,3}]}}]}

- Tried rebalance again, but failed repetitively:

Rebalance exited with reason {{{badmatch,[{<18058.14511.0>,noproc}]},
[{misc,sync_shutdown_many_i_am_trapping_exits,
1},
{misc,try_with_maybe_ignorant_after,2},
{gen_server,terminate,6},
{proc_lib,init_p_do_apply,3}]},
{gen_server,call,
[<0.11023.120>,
{shutdown_replicator,
'ns_1@ec2-54-251-5-97.ap-southeast-1.compute.amazonaws.com'},
infinity]}}

Will upload logs from one of the nodes in the cluster present in the cluster during the time of the rebalance failures, shortly.

_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

Noticed this on one of the nodes being rebalanced out:
Unable to listen on 'ns_1@ec2-122-248-217-156.ap-southeast-1.compute.amazonaws.com'.

So failed over the node and tried rebalancing, rebalancing still failed.

So added that node back, and did not involve that particular node in the rebalance operation, rebalance succeeded.

Hide

Permalink

Abhinav Dangeti added a comment - 06/Nov/12 10:46 PM

Grabbed diags: https://s3.amazonaws.com/bugdb/MB-7115/C_rebalance_fails_ns-diag-20121107040344.txt.zip

Show

Abhinav Dangeti added a comment - 06/Nov/12 10:46 PM Grabbed diags: https://s3.amazonaws.com/bugdb/MB-7115/C_rebalance_fails_ns-diag-20121107040344.txt.zip

Abhinav Dangeti made changes - 06/Nov/12 10:50 PM

Assignee

Abhinav Dangeti [ abhinav ]

Ketaki Gangal made changes - 06/Nov/12 10:53 PM

Assignee	Abhinav Dangeti [ abhinav ]	Aleksey Kondratenko [ alkondratenko ]
Priority	Major [ 3 ]	Critical [ 2 ]
Component/s		cross-datacenter-replication [ 10136 ]
Component/s		ns_server [ 10019 ]

Hide

Permalink

Aliaksey Artamonau added a comment - 07/Nov/12 11:58 AM

Diags from ec2-122-248-217-156.ap-southeast-1.compute.amazonaws.com are needed here.

Show

Aliaksey Artamonau added a comment - 07/Nov/12 11:58 AM Diags from ec2-122-248-217-156.ap-southeast-1.compute.amazonaws.com are needed here.

Aliaksey Artamonau made changes - 07/Nov/12 11:59 AM

Assignee

Aleksey Kondratenko [ alkondratenko ]

Abhinav Dangeti [ abhinav ]

Hide

Permalink

Junyi Xie added a comment - 07/Nov/12 6:25 PM

Looks a rebalance issue with no direct connection to XDCR

Show

Junyi Xie added a comment - 07/Nov/12 6:25 PM Looks a rebalance issue with no direct connection to XDCR

Junyi Xie made changes - 07/Nov/12 6:25 PM

Component/s

cross-datacenter-replication [ 10136 ]

Hide

Permalink

Thuan Nguyen added a comment - 07/Nov/12 8:30 PM

Hit this bug again in build 2.0.0-1941. Bin creates a 4 nodes windows cluster with 5 million items. Then Bin creates xdcr to one ubuntu 10.04 64bit (ec2-50-16-18-63.compute-1.amazonaws.com). At destination, add another ubuntu node to node ec2-50 and rebalance. Rebalance failed with error:
Rebalance exited with reason {mover_failed,{badmatch,{error,emfile}}}

Look at diags, I see ebucketmigrator crashed

[rebalance:info,2012-11-07T22:36:53.434,ns_1@10.108.30.25:<0.11871.3>:janitor_agent:wait_index_updated:459]default: Doing wait_index_updated call for ns_1@10.46.215.52 (vbucket 677)
[ns_server:info,2012-11-07T22:36:53.445,ns_1@10.108.30.25:<0.11709.3>:ns_replicas_builder_utils:kill_a_bunch_of_tap_names:59]Killed the following tap names on 'ns_1@10.108.30.25': [<<"replication_building_677_'ns_1@10.46.215.52'">>]
[ns_server:debug,2012-11-07T22:36:53.458,ns_1@10.108.30.25:<0.11706.3>:ns_single_vbucket_mover:spawn_ebucketmigrator_mover:283]Spawned mover "default" 677 'ns_1@10.108.30.25' -> 'ns_1@10.46.215.52': <0.11874.3>
[ns_server:info,2012-11-07T22:36:53.461,ns_1@10.108.30.25:<0.11874.3>:ebucketmigrator_srv:init:490]Setting {"10.46.215.52",11209} vbucket 677 to state replica
[ns_server:error,2012-11-07T22:36:53.621,ns_1@10.108.30.25:<0.11876.3>:menelaus_web_alerts_srv:can_listen:349]gen_udp:open failed due to emfile
[user:info,2012-11-07T22:36:53.621,ns_1@10.108.30.25:<0.11876.3>:menelaus_web_alerts_srv:global_alert:87]IP address seems to have changed. Unable to listen on 'ns_1@10.108.30.25'.
[ns_server:info,2012-11-07T22:36:53.621,ns_1@10.108.30.25:ns_log<0.785.0>:ns_log:handle_cast:125]suppressing duplicate log menelaus_web_alerts_srv:1("IP address seems to have changed. Unable to listen on 'ns_1@10.108.30.25'.") because it's been seen 1 times in the past 9.049832 secs (last seen 9.049832 secs ago
[ns_server:info,2012-11-07T22:36:53.638,ns_1@10.108.30.25:ns_port_memcached<0.864.0>:ns_port_server:log:171]memcached<0.864.0>: Wed Nov 7 22:36:53.446940 UTC 3: TAP (Producer) eq_tapq:replication_building_677_'ns_1@10.46.215.52' - disconnected, keep alive for 300 seconds
memcached<0.864.0>: Wed Nov 7 22:36:53.454932 UTC 3: TAP (Producer) eq_tapq:replication_building_677_'ns_1@10.46.215.52' - Connection is closed by force.

[ns_server:debug,2012-11-07T22:36:53.659,ns_1@10.108.30.25:<0.11874.3>:ebucketmigrator_srv:kill_tapname:966]killing tap named: rebalance_677
[ns_server:info,2012-11-07T22:36:53.663,ns_1@10.108.30.25:<0.30736.0>:ns_orchestrator:handle_info:282]Skipping janitor in state rebalancing: {rebalancing_state,<0.31142.0>,
                                        {dict,2,16,16,8,80,48,
                                         {[],[],[],[],[],[],[],[],[],[],[],[],
                                          [],[],[],[]},
                                         {{[],[],
                                           [['ns_1@10.46.215.52'|0.322265625]],
                                           [],[],
                                           [['ns_1@10.108.30.25'|
                                             0.7740885416666666]],
                                           [],[],[],[],[],[],[],[],[],[]}}},
                                        ['ns_1@10.108.30.25',
                                         'ns_1@10.46.215.52'],
                                        [],[]}
[error_logger:error,2012-11-07T22:36:53.663,ns_1@10.108.30.25:error_logger<0.5.0>:ale_error_logger_handler:log_report:72]
=========================CRASH REPORT=========================
  crasher:
    initial call: ebucketmigrator_srv:init/1
    pid: <0.11874.3>
    registered_name: []
    exception error: no match of right hand side value {error,emfile}
      in function ebucketmigrator_srv:connect/4
      in call from ebucketmigrator_srv:init/1
    ancestors: [<0.11706.3>,<0.31209.0>,<0.31142.0>]
    messages: []
    links: [#Port<0.142811>,<0.11706.3>,#Port<0.142808>]
    dictionary: []
    trap_exit: false
    status: running
    heap_size: 987
    stack_size: 24
    reductions: 123486
  neighbours:

[ns_server:info,2012-11-07T22:36:53.665,ns_1@10.108.30.25:<0.11709.3>:ns_replicas_builder_utils:kill_a_bunch_of_tap_names:59]Killed the following tap names on 'ns_1@10.108.30.25': []
[rebalance:error,2012-11-07T22:36:53.666,ns_1@10.108.30.25:<0.31209.0>:ns_vbucket_mover:handle_info:252]<0.11706.3> exited with {mover_failed,{badmatch,{error,emfile}}}
[error_logger:error,2012-11-07T22:36:53.666,ns_1@10.108.30.25:error_logger<0.5.0>:ale_error_logger_handler:log_report:72]
=========================CRASH REPORT=========================
  crasher:
    initial call: ns_single_vbucket_mover:mover/6
    pid: <0.11706.3>
    registered_name: []
    exception exit: {mover_failed,{badmatch,{error,emfile}}}
      in function ns_single_vbucket_mover:wait_for_mover/5
      in call from ns_single_vbucket_mover:mover_inner/6
      in call from misc:try_with_maybe_ignorant_after/2
      in call from ns_single_vbucket_mover:mover/6
    ancestors: [<0.31209.0>,<0.31142.0>]
    messages: []
    links: [<0.31209.0>]
    dictionary: [{cleanup_list,[<0.11709.3>]}]
    trap_exit: true
    status: running
    heap_size: 75025
    stack_size: 24
    reductions: 13260
  neighbours:

[ns_server:info,2012-11-07T22:36:53.684,ns_1@10.108.30.25:janitor_agent-default<0.1056.0>:janitor_agent:handle_info:676]Undoing temporary vbucket states caused by rebalance
[ns_server:debug,2012-11-07T22:36:53.685,ns_1@10.108.30.25:<0.31219.0>:ns_pubsub:do_subscribe_link:132]Parent process of subscription {ns_node_disco_events,<0.31209.0>} exited with reason {mover_failed,
                                                                                      {badmatch,
                                                                                       {error,
                                                                                        emfile}}}
[user:info,2012-11-07T22:36:53.685,ns_1@10.108.30.25:<0.30736.0>:ns_orchestrator:handle_info:319]Rebalance exited with reason {mover_failed,{badmatch,{error,emfile}}}

[ns_server:debug,2012-11-07T22:36:53.774,ns_1@10.108.30.25:capi_set_view_manager-default<0.1035.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs
[ns_server:info,2012-11-07T22:36:53.778,ns_1@10.108.30.25:<0.12564.3>:diag_handler:log_all_tap_and_checkpoint_stats:127]logging tap & checkpoint stats
[ns_server:debug,2012-11-07T22:36:53.778,ns_1@10.108.30.25:ns_config_rep<0.797.0>:ns_config_rep:do_push_keys:317]Replicating some config keys ([counters,rebalance_status,rebalancer_pid]..)
[ns_server:debug,2012-11-07T22:36:53.797,ns_1@10.108.30.25:capi_set_view_manager-default<0.1035.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs
[ns_server:debug,2012-11-07T22:36:53.798,ns_1@10.108.30.25:ns_config_log<0.779.0>:ns_config_log:log_common:111]config change:
counters ->
[{rebalance_fail,1},{rebalance_start,1}]
[ns_server:debug,2012-11-07T22:36:53.804,ns_1@10.108.30.25:capi_set_view_manager-default<0.1035.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs
[ns_server:debug,2012-11-07T22:36:53.818,ns_1@10.108.30.25:capi_set_view_manager-default<0.1035.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs
[ns_server:debug,2012-11-07T22:36:53.818,ns_1@10.108.30.25:ns_config_log<0.779.0>:ns_config_log:log_common:111]config change:
rebalancer_pid ->
undefined
[ns_server:debug,2012-11-07T22:36:53.831,ns_1@10.108.30.25:ns_config_log<0.779.0>:ns_config_log:log_common:111]config change:
rebalance_status ->
{none,<<"Rebalance failed. See logs for detailed reason. You can try rebalance again.">>}
[ns_server:debug,2012-11-07T22:36:53.830,ns_1@10.108.30.25:capi_set_view_manager-default<0.1035.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs
[error_logger:error,2012-11-07T22:36:53.669,ns_1@10.108.30.25:error_logger<0.5.0>:ale_error_logger_handler:log_msg:76]** Generic server <0.31209.0> terminating
** Last message in was {'EXIT',<0.11706.3>,
                               {mover_failed,{badmatch,{error,emfile}}}}
** When Server state == {state,"default",<0.31219.0>,
                               {dict,2,16,16,8,80,48,
                                     {[],[],[],[],[],[],[],[],[],[],[],[],[],
                                      [],[],[]},
                                     {{[],[],
                                       [['ns_1@

Link to collect info of all nodes of destination cluster https://s3.amazonaws.com/packages.couchbase/collect_info/orange/2_0_0/201211/2-ec2-1941reb-failed-no-match-right-hand-20121107.tgz

Show

Thuan Nguyen added a comment - 07/Nov/12 8:30 PM Hit this bug again in build 2.0.0-1941. Bin creates a 4 nodes windows cluster with 5 million items. Then Bin creates xdcr to one ubuntu 10.04 64bit (ec2-50-16-18-63.compute-1.amazonaws.com). At destination, add another ubuntu node to node ec2-50 and rebalance. Rebalance failed with error: Rebalance exited with reason {mover_failed,{badmatch,{error,emfile}}} Look at diags, I see ebucketmigrator crashed [rebalance:info,2012-11-07T22:36:53.434, ns_1@10.108.30.25 :<0.11871.3>:janitor_agent:wait_index_updated:459]default: Doing wait_index_updated call for ns_1@10.46.215.52 (vbucket 677) [ns_server:info,2012-11-07T22:36:53.445, ns_1@10.108.30.25 :<0.11709.3>:ns_replicas_builder_utils:kill_a_bunch_of_tap_names:59]Killed the following tap names on ' ns_1@10.108.30.25 ': [<<"replication_building_677_' ns_1@10.46.215.52 '">>] [ns_server:debug,2012-11-07T22:36:53.458, ns_1@10.108.30.25 :<0.11706.3>:ns_single_vbucket_mover:spawn_ebucketmigrator_mover:283]Spawned mover "default" 677 ' ns_1@10.108.30.25 ' -> ' ns_1@10.46.215.52 ': <0.11874.3> [ns_server:info,2012-11-07T22:36:53.461, ns_1@10.108.30.25 :<0.11874.3>:ebucketmigrator_srv:init:490]Setting {"10.46.215.52",11209} vbucket 677 to state replica [ns_server:error,2012-11-07T22:36:53.621, ns_1@10.108.30.25 :<0.11876.3>:menelaus_web_alerts_srv:can_listen:349]gen_udp:open failed due to emfile [user:info,2012-11-07T22:36:53.621, ns_1@10.108.30.25 :<0.11876.3>:menelaus_web_alerts_srv:global_alert:87]IP address seems to have changed. Unable to listen on ' ns_1@10.108.30.25 '. [ns_server:info,2012-11-07T22:36:53.621, ns_1@10.108.30.25 :ns_log<0.785.0>:ns_log:handle_cast:125]suppressing duplicate log menelaus_web_alerts_srv:1("IP address seems to have changed. Unable to listen on ' ns_1@10.108.30.25 '.") because it's been seen 1 times in the past 9.049832 secs (last seen 9.049832 secs ago [ns_server:info,2012-11-07T22:36:53.638, ns_1@10.108.30.25 :ns_port_memcached<0.864.0>:ns_port_server:log:171]memcached<0.864.0>: Wed Nov 7 22:36:53.446940 UTC 3: TAP (Producer) eq_tapq:replication_building_677_' ns_1@10.46.215.52 ' - disconnected, keep alive for 300 seconds memcached<0.864.0>: Wed Nov 7 22:36:53.454932 UTC 3: TAP (Producer) eq_tapq:replication_building_677_' ns_1@10.46.215.52 ' - Connection is closed by force. [ns_server:debug,2012-11-07T22:36:53.659, ns_1@10.108.30.25 :<0.11874.3>:ebucketmigrator_srv:kill_tapname:966]killing tap named: rebalance_677 [ns_server:info,2012-11-07T22:36:53.663, ns_1@10.108.30.25 :<0.30736.0>:ns_orchestrator:handle_info:282]Skipping janitor in state rebalancing: {rebalancing_state,<0.31142.0>, {dict,2,16,16,8,80,48, {[],[],[],[],[],[],[],[],[],[],[],[], [],[],[],[]}, {{[],[], [[' ns_1@10.46.215.52 '|0.322265625]], [],[], [[' ns_1@10.108.30.25 '| 0.7740885416666666]], [],[],[],[],[],[],[],[],[],[]}}}, [' ns_1@10.108.30.25 ', ' ns_1@10.46.215.52 '], [],[]} [error_logger:error,2012-11-07T22:36:53.663, ns_1@10.108.30.25 :error_logger<0.5.0>:ale_error_logger_handler:log_report:72] =========================CRASH REPORT========================= crasher: initial call: ebucketmigrator_srv:init/1 pid: <0.11874.3> registered_name: [] exception error: no match of right hand side value {error,emfile} in function ebucketmigrator_srv:connect/4 in call from ebucketmigrator_srv:init/1 ancestors: [<0.11706.3>,<0.31209.0>,<0.31142.0>] messages: [] links: [#Port<0.142811>,<0.11706.3>,#Port<0.142808>] dictionary: [] trap_exit: false status: running heap_size: 987 stack_size: 24 reductions: 123486 neighbours: [ns_server:info,2012-11-07T22:36:53.665, ns_1@10.108.30.25 :<0.11709.3>:ns_replicas_builder_utils:kill_a_bunch_of_tap_names:59]Killed the following tap names on ' ns_1@10.108.30.25 ': [] [rebalance:error,2012-11-07T22:36:53.666, ns_1@10.108.30.25 :<0.31209.0>:ns_vbucket_mover:handle_info:252]<0.11706.3> exited with {mover_failed,{badmatch,{error,emfile}}} [error_logger:error,2012-11-07T22:36:53.666, ns_1@10.108.30.25 :error_logger<0.5.0>:ale_error_logger_handler:log_report:72] =========================CRASH REPORT========================= crasher: initial call: ns_single_vbucket_mover:mover/6 pid: <0.11706.3> registered_name: [] exception exit: {mover_failed,{badmatch,{error,emfile}}} in function ns_single_vbucket_mover:wait_for_mover/5 in call from ns_single_vbucket_mover:mover_inner/6 in call from misc:try_with_maybe_ignorant_after/2 in call from ns_single_vbucket_mover:mover/6 ancestors: [<0.31209.0>,<0.31142.0>] messages: [] links: [<0.31209.0>] dictionary: [{cleanup_list,[<0.11709.3>]}] trap_exit: true status: running heap_size: 75025 stack_size: 24 reductions: 13260 neighbours: [ns_server:info,2012-11-07T22:36:53.684, ns_1@10.108.30.25 :janitor_agent-default<0.1056.0>:janitor_agent:handle_info:676]Undoing temporary vbucket states caused by rebalance [ns_server:debug,2012-11-07T22:36:53.685, ns_1@10.108.30.25 :<0.31219.0>:ns_pubsub:do_subscribe_link:132]Parent process of subscription {ns_node_disco_events,<0.31209.0>} exited with reason {mover_failed, {badmatch, {error, emfile}}} [user:info,2012-11-07T22:36:53.685, ns_1@10.108.30.25 :<0.30736.0>:ns_orchestrator:handle_info:319]Rebalance exited with reason {mover_failed,{badmatch,{error,emfile}}} [ns_server:debug,2012-11-07T22:36:53.774, ns_1@10.108.30.25 :capi_set_view_manager-default<0.1035.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs [ns_server:info,2012-11-07T22:36:53.778, ns_1@10.108.30.25 :<0.12564.3>:diag_handler:log_all_tap_and_checkpoint_stats:127]logging tap & checkpoint stats [ns_server:debug,2012-11-07T22:36:53.778, ns_1@10.108.30.25 :ns_config_rep<0.797.0>:ns_config_rep:do_push_keys:317]Replicating some config keys ([counters,rebalance_status,rebalancer_pid]..) [ns_server:debug,2012-11-07T22:36:53.797, ns_1@10.108.30.25 :capi_set_view_manager-default<0.1035.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs [ns_server:debug,2012-11-07T22:36:53.798, ns_1@10.108.30.25 :ns_config_log<0.779.0>:ns_config_log:log_common:111]config change: counters -> [{rebalance_fail,1},{rebalance_start,1}] [ns_server:debug,2012-11-07T22:36:53.804, ns_1@10.108.30.25 :capi_set_view_manager-default<0.1035.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs [ns_server:debug,2012-11-07T22:36:53.818, ns_1@10.108.30.25 :capi_set_view_manager-default<0.1035.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs [ns_server:debug,2012-11-07T22:36:53.818, ns_1@10.108.30.25 :ns_config_log<0.779.0>:ns_config_log:log_common:111]config change: rebalancer_pid -> undefined [ns_server:debug,2012-11-07T22:36:53.831, ns_1@10.108.30.25 :ns_config_log<0.779.0>:ns_config_log:log_common:111]config change: rebalance_status -> {none,<<"Rebalance failed. See logs for detailed reason. You can try rebalance again.">>} [ns_server:debug,2012-11-07T22:36:53.830, ns_1@10.108.30.25 :capi_set_view_manager-default<0.1035.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs [error_logger:error,2012-11-07T22:36:53.669, ns_1@10.108.30.25 :error_logger<0.5.0>:ale_error_logger_handler:log_msg:76]** Generic server <0.31209.0> terminating ** Last message in was {'EXIT',<0.11706.3>, {mover_failed,{badmatch,{error,emfile}}}} ** When Server state == {state,"default",<0.31219.0>, {dict,2,16,16,8,80,48, {[],[],[],[],[],[],[],[],[],[],[],[],[], [],[],[]}, {{[],[], [['ns_1@ Link to collect info of all nodes of destination cluster https://s3.amazonaws.com/packages.couchbase/collect_info/orange/2_0_0/201211/2-ec2-1941reb-failed-no-match-right-hand-20121107.tgz

Hide

Permalink

Steve Yen added a comment - 09/Nov/12 1:32 PM

reassigning since tony attached some more info

Show

Steve Yen added a comment - 09/Nov/12 1:32 PM reassigning since tony attached some more info

Steve Yen made changes - 09/Nov/12 1:32 PM

Assignee

Abhinav Dangeti [ abhinav ]

Aleksey Kondratenko [ alkondratenko ]

Hide

Permalink

Aleksey Kondratenko added a comment - 09/Nov/12 4:21 PM

emfile in this case (at least in collect infos from Tony) seem to be caused by CLOSE_WAIT sockets. My leading guess is that it's those hang is_missing_rev requests that we're seeing in ~~MB-7129~~. Only in this environment it's not killing node entirely but rather exhausts file descriptors

Show

Aleksey Kondratenko added a comment - 09/Nov/12 4:21 PM emfile in this case (at least in collect infos from Tony) seem to be caused by CLOSE_WAIT sockets. My leading guess is that it's those hang is_missing_rev requests that we're seeing in MB-7129 . Only in this environment it's not killing node entirely but rather exhausts file descriptors

Aleksey Kondratenko made changes - 09/Nov/12 4:21 PM

Status	Open [ 1 ]	Resolved [ 5 ]
Resolution		Duplicate [ 3 ]

Hide

Permalink

Ketaki Gangal added a comment - 13/Nov/12 1:13 PM

Re-opening this , for repro/ observation on the xdcr- fixed changes.

Show

Ketaki Gangal added a comment - 13/Nov/12 1:13 PM Re-opening this , for repro/ observation on the xdcr- fixed changes.

Ketaki Gangal made changes - 13/Nov/12 1:13 PM

Resolution	Duplicate [ 3 ]
Status	Resolved [ 5 ]	Reopened [ 4 ]
Assignee	Aleksey Kondratenko [ alkondratenko ]	Abhinav Dangeti [ abhinav ]

Hide

Permalink

Abhinav Dangeti added a comment - 14/Nov/12 12:44 PM

When this issue originally occurred, the clusters were in an XDCR setup but before starting the rebalance operation, replication had been deleted, and the failures occurred on the destination cluster.

To investigate whether this issue happens with/without XDCR,

case1: Tried reproducing this with 2 ongoing unidirectional replications, on the destination cluster (with 7 nodes) - rebalanced in 3 nodes (1949) and rebalanced out 5 nodes (1944)
           Source was on 1944 (a 7 node cluster) had a fixed no. of items on both buckets, with no front end load.
           Rebalance on the destination cluster failed with the same reason, where the cluster was "unable to listen" to one of the nodes.

case2: Deleted replications on the source, cleaned the destination cluster, loaded all nodes with (1949).
           Created a 5 node cluster (not part of any xdcr).
           Created 2 buckets and with ongoing front end load:
                    - rebalanced out 3 nodes, rebalanced in 5 nodes :: rebalance operation completed successfully.
                    - rebalanced out 5 nodes, rebalanced in 3 nodes :: rebalance operation completed successfully.

Show

Abhinav Dangeti added a comment - 14/Nov/12 12:44 PM When this issue originally occurred, the clusters were in an XDCR setup but before starting the rebalance operation, replication had been deleted, and the failures occurred on the destination cluster. To investigate whether this issue happens with/without XDCR, case1: Tried reproducing this with 2 ongoing unidirectional replications, on the destination cluster (with 7 nodes) - rebalanced in 3 nodes (1949) and rebalanced out 5 nodes (1944) Source was on 1944 (a 7 node cluster) had a fixed no. of items on both buckets, with no front end load. Rebalance on the destination cluster failed with the same reason, where the cluster was "unable to listen" to one of the nodes. case2: Deleted replications on the source, cleaned the destination cluster, loaded all nodes with (1949). Created a 5 node cluster (not part of any xdcr). Created 2 buckets and with ongoing front end load: - rebalanced out 3 nodes, rebalanced in 5 nodes :: rebalance operation completed successfully. - rebalanced out 5 nodes, rebalanced in 3 nodes :: rebalance operation completed successfully.

Hide

Permalink

Steve Yen added a comment - 15/Nov/12 1:26 PM

bug-scrub: 1949 didn't have the timeout fix? Please try again with 1950. thanks.

Show

Steve Yen added a comment - 15/Nov/12 1:26 PM bug-scrub: 1949 didn't have the timeout fix? Please try again with 1950. thanks.

Hide

Permalink

Steve Yen added a comment - 20/Nov/12 1:47 PM

bug-scrub:

ketaki reports it works

Show

Steve Yen added a comment - 20/Nov/12 1:47 PM bug-scrub: ketaki reports it works

Steve Yen made changes - 20/Nov/12 1:47 PM

Status	Reopened [ 4 ]	Resolved [ 5 ]
Resolution		Fixed [ 1 ]

Farshid Ghods made changes - 04/Feb/13 11:39 AM

Status

Resolved [ 5 ]

Closed [ 6 ]

Rebalance operation failed repetitively while trying to rebalance in 5 nodes and rebalance out 3 nodes on a 5 node cluster, reason possibly because: "Unable to listen" to one of the nodes that was being rebalanced out.

Details

Description

Activity

People

Dates

Agile