Couchbase Server

[RN 2.0.1]ns_server experiences random timeouts supposedly due to lack of async io threads causing rebalance to fail and other potential badness

Details

  • Flagged:
    Release Note

Description

SUBJ.

In many diags we were seeing we're seeing occasional timeouts here and there. Sometimes and perhaps most of the time they don't affect correct operation of product. After all erlang is famous for it's fault resiliency.

But sometimes it causes rebalance to fail. I.e. see MB-7166 where mb_master which supervised ns_orchestrator which supervised rebalance died due to timeout. Which according to normal error handling behavior of Erlang caused it's restart. But part of restart was shutting down of child processes, including obviously rebalancer.

In my personal experience this is quite easy to hit on physical hardware and spinning disks. But apparently we're now getting in on Xen and SSDs as well as potentially (MB-7152) on physical hardware and SSDs.

Activity

Ascending order - Click to sort in descending order
Hide
Permalink
Aleksey Kondratenko added a comment -
Note there's related bug: MB-6595 which we started hitting before switching off async io threads. We're working on investigating it as well and so far we have some evidence that it's somehow but we not sure how is related by somewhat excessive rate of page allocations/deallocations by erlang.

Anyways, MB-6595 is most likely distinct issue. In my own experience timeouts are easier to hit with async io threads off so there seems to be two causes of timeouts. And this ticket (lack of async io threads) seems like worst one.
Show
Aleksey Kondratenko added a comment - Note there's related bug: MB-6595 which we started hitting before switching off async io threads. We're working on investigating it as well and so far we have some evidence that it's somehow but we not sure how is related by somewhat excessive rate of page allocations/deallocations by erlang. Anyways, MB-6595 is most likely distinct issue. In my own experience timeouts are easier to hit with async io threads off so there seems to be two causes of timeouts. And this ticket (lack of async io threads) seems like worst one.
Hide
Permalink
Steve Yen added a comment - - edited
run test on durable, spinning disks. alk can reconfigure the cluster quickly. then farshid needs to run sys tests.
Show
Steve Yen added a comment - - edited run test on durable, spinning disks. alk can reconfigure the cluster quickly. then farshid needs to run sys tests.
Hide
Permalink
Thuan Nguyen added a comment -
I got rebalance failed in swap 2 nodes in windows in ec2 with build 2.0.0-1950 (total 6 nodes cluster. Add 2 nodes and remove 2 nodes at the same time)
The error is the same in bug MB-7166

[ns_server:debug,2012-11-15T9:02:53.231,ns_1@10.110.206.19:<0.8660.8>:ebucketmigrator_srv:init:452]Got old ebucketmigrator state from <0.5539.8>:
{state,#Port<0.18137>,#Port<0.18135>,#Port<0.18138>,#Port<0.18136>,<0.5540.8>,
       <<"cut off">>,<<"cut off">>,[],1013009,false,false,0,
       {1352,970173,215041},
       completed,
       {<0.8656.8>,#Ref<0.0.72.194985>},
       <<"replication_ns_1@10.110.206.19">>,<0.5539.8>,
       {had_backfill,undefined,undefined,[]},
       false}.
[ns_server:debug,2012-11-15T9:02:53.231,ns_1@10.110.206.19:<0.733.0>:ns_process_registry:handle_info:98]Got exit msg: {'EXIT',<0.8656.8>,{#Ref<0.0.72.194974>,<0.8660.8>}}
[error_logger:info,2012-11-15T9:02:53.231,ns_1@10.110.206.19:error_logger<0.5.0>:ale_error_logger_handler:log_report:72]
=========================PROGRESS REPORT=========================
          supervisor: {local,'ns_vbm_new_sup-default'}
             started: [{pid,<0.8660.8>},
                       {name,{new_child_id,"ST",'ns_1@10.110.218.124'}},
                       {mfargs,
                           {ebucketmigrator_srv,start_link,
                               [{"10.110.218.124",11209},
                                {"10.110.206.19",11209},
                                [{old_state_retriever,
                                     #Fun<ns_vbm_new_sup.0.113560106>},
                                 {on_not_ready_vbuckets,
                                     #Fun<tap_replication_manager.2.88495417>},
                                 {username,"default"},
                                 {password,[]},
                                 {vbuckets,"ST"},
                                 {takeover,false},
                                 {suffix,"ns_1@10.110.206.19"}]]}},
                       {restart_type,temporary},
                       {shutdown,60000},
                       {child_type,worker}]

[ns_server:debug,2012-11-15T9:02:53.262,ns_1@10.110.206.19:<0.8660.8>:ebucketmigrator_srv:init:569]Reusing old upstream:
[{vbuckets,"ST"},{name,<<"replication_ns_1@10.110.206.19">>},{takeover,false}]
[rebalance:debug,2012-11-15T9:02:53.262,ns_1@10.110.206.19:<0.8660.8>:ebucketmigrator_srv:init:588]upstream_sender pid: <0.8661.8>
[user:info,2012-11-15T9:02:53.309,ns_1@10.110.206.19:ns_config<0.722.0>:ns_janitor:maybe_stop_rebalance_status:147]Resetting rebalance status since it's not really running
[ns_server:debug,2012-11-15T9:02:53.309,ns_1@10.110.206.19:capi_set_view_manager-default<0.27429.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs
[ns_server:debug,2012-11-15T9:02:53.309,ns_1@10.110.206.19:ns_config_rep<0.27107.0>:ns_config_rep:do_push_keys:317]Replicating some config keys ([rebalance_status,rebalancer_pid]..)
[ns_server:debug,2012-11-15T9:02:53.324,ns_1@10.110.206.19:ns_config_log<0.729.0>:ns_config_log:log_common:111]config change:
rebalancer_pid ->
undefined

Link to manifest of build 2.0.0-1950 http://builds.hq.northscale.net/latestbuilds/couchbase-server-enterprise_x86_64_2.0.0-1950-rel.setup.exe.manifest.xml

Here is the link to collect info of all nodes https://s3.amazonaws.com/bugdb/jira/MB-7182/8nodes-ci-1950-reset-reb-disk-commit-failed-20121115-113405.tgz
Show
Thuan Nguyen added a comment - I got rebalance failed in swap 2 nodes in windows in ec2 with build 2.0.0-1950 (total 6 nodes cluster. Add 2 nodes and remove 2 nodes at the same time) The error is the same in bug MB-7166 [ns_server:debug,2012-11-15T9:02:53.231, ns_1@10.110.206.19 :<0.8660.8>:ebucketmigrator_srv:init:452]Got old ebucketmigrator state from <0.5539.8>: {state,#Port<0.18137>,#Port<0.18135>,#Port<0.18138>,#Port<0.18136>,<0.5540.8>,        <<"cut off">>,<<"cut off">>,[],1013009,false,false,0,        {1352,970173,215041},        completed,        {<0.8656.8>,#Ref<0.0.72.194985>},        <<" replication_ns_1@10.110.206.19 ">>,<0.5539.8>,        {had_backfill,undefined,undefined,[]},        false}. [ns_server:debug,2012-11-15T9:02:53.231, ns_1@10.110.206.19 :<0.733.0>:ns_process_registry:handle_info:98]Got exit msg: {'EXIT',<0.8656.8>,{#Ref<0.0.72.194974>,<0.8660.8>}} [error_logger:info,2012-11-15T9:02:53.231, ns_1@10.110.206.19 :error_logger<0.5.0>:ale_error_logger_handler:log_report:72] =========================PROGRESS REPORT=========================           supervisor: {local,'ns_vbm_new_sup-default'}              started: [{pid,<0.8660.8>},                        {name,{new_child_id,"ST",' ns_1@10.110.218.124 '}},                        {mfargs,                            {ebucketmigrator_srv,start_link,                                [{"10.110.218.124",11209},                                 {"10.110.206.19",11209},                                 [{old_state_retriever,                                      #Fun<ns_vbm_new_sup.0.113560106>},                                  {on_not_ready_vbuckets,                                      #Fun<tap_replication_manager.2.88495417>},                                  {username,"default"},                                  {password,[]},                                  {vbuckets,"ST"},                                  {takeover,false},                                  {suffix," ns_1@10.110.206.19 "}]]}},                        {restart_type,temporary},                        {shutdown,60000},                        {child_type,worker}] [ns_server:debug,2012-11-15T9:02:53.262, ns_1@10.110.206.19 :<0.8660.8>:ebucketmigrator_srv:init:569]Reusing old upstream: [{vbuckets,"ST"},{name,<<" replication_ns_1@10.110.206.19 ">>},{takeover,false}] [rebalance:debug,2012-11-15T9:02:53.262, ns_1@10.110.206.19 :<0.8660.8>:ebucketmigrator_srv:init:588]upstream_sender pid: <0.8661.8> [user:info,2012-11-15T9:02:53.309, ns_1@10.110.206.19 :ns_config<0.722.0>:ns_janitor:maybe_stop_rebalance_status:147]Resetting rebalance status since it's not really running [ns_server:debug,2012-11-15T9:02:53.309, ns_1@10.110.206.19 :capi_set_view_manager-default<0.27429.0>:capi_set_view_manager:handle_info:349]doing replicate_newnodes_docs [ns_server:debug,2012-11-15T9:02:53.309, ns_1@10.110.206.19 :ns_config_rep<0.27107.0>:ns_config_rep:do_push_keys:317]Replicating some config keys ([rebalance_status,rebalancer_pid]..) [ns_server:debug,2012-11-15T9:02:53.324, ns_1@10.110.206.19 :ns_config_log<0.729.0>:ns_config_log:log_common:111]config change: rebalancer_pid -> undefined Link to manifest of build 2.0.0-1950 http://builds.hq.northscale.net/latestbuilds/couchbase-server-enterprise_x86_64_2.0.0-1950-rel.setup.exe.manifest.xml Here is the link to collect info of all nodes https://s3.amazonaws.com/bugdb/jira/MB-7182/8nodes-ci-1950-reset-reb-disk-commit-failed-20121115-113405.tgz
Hide
Permalink
Aleksey Kondratenko added a comment -
Would be nice if you could pick up 1952 asap. It has some better logging around perhaps related problem of MB-7152
Show
Aleksey Kondratenko added a comment - Would be nice if you could pick up 1952 asap. It has some better logging around perhaps related problem of MB-7152
Hide
Permalink
Thuan Nguyen added a comment -
Will do with 1952
Show
Thuan Nguyen added a comment - Will do with 1952
Hide
Permalink
Thuan Nguyen added a comment -
I hit this bug again in build 2.0.0-1952 on windows 2008 R2 64bit in ec2
Add 2 nodes to cluster of 6 nodes, rebalance failed with error
"Resetting rebalance status since it's not really running" after more than one hour running

Here is the collect info of all nodes https://s3.amazonaws.com/bugdb/jira/MB-7182/8nodes-ci-1952-reset-reb-20121119121657.tgz
Link to manifest file of this build http://builds.hq.northscale.net/latestbuilds/couchbase-server-enterprise_x86_64_2.0.0-1952-rel.setup.exe.manifest.xml
Show
Thuan Nguyen added a comment - I hit this bug again in build 2.0.0-1952 on windows 2008 R2 64bit in ec2 Add 2 nodes to cluster of 6 nodes, rebalance failed with error "Resetting rebalance status since it's not really running" after more than one hour running Here is the collect info of all nodes https://s3.amazonaws.com/bugdb/jira/MB-7182/8nodes-ci-1952-reset-reb-20121119121657.tgz Link to manifest file of this build http://builds.hq.northscale.net/latestbuilds/couchbase-server-enterprise_x86_64_2.0.0-1952-rel.setup.exe.manifest.xml
Hide
Permalink
Steve Yen added a comment -
an important 2.0.1 bug
Show
Steve Yen added a comment - an important 2.0.1 bug
Hide
Permalink
Dipti Borkar added a comment -
This may need an erlang upgrade or moving back to async or both.

Given that its a big change, too risky 2.0.1
Show
Dipti Borkar added a comment - This may need an erlang upgrade or moving back to async or both. Given that its a big change, too risky 2.0.1
Hide
Permalink
Aleksey Kondratenko added a comment -
We believe workaround we merged to couchdb's 2.0.1 branch fixes problem.
Show
Aleksey Kondratenko added a comment - We believe workaround we merged to couchdb's 2.0.1 branch fixes problem.
Hide
Permalink
Karen Zeller added a comment -
<class id="cluster"/>

<issue type="cb" ref="MB-7182"/>


<rntext>

<para>
The server had experienced random timeouts possible due to lack of asynchronous I/O threads. This
caused rebalance to fail. This has been fixed.
</para>
Show
Karen Zeller added a comment - <class id="cluster"/> <issue type="cb" ref=" MB-7182 "/> <rntext> <para> The server had experienced random timeouts possible due to lack of asynchronous I/O threads. This caused rebalance to fail. This has been fixed. </para>

People

  • Assignee:
    Karen Zeller
    Reporter:
    Aleksey Kondratenko
Vote (0)
Watch (3)

Dates

  • Created:
    Updated:
    Resolved: