{"action":"created","issue":{"url":"https://api.github.com/repos/rabbitmq/rabbitmq-server/issues/676","repository_url":"https://api.github.com/repos/rabbitmq/rabbitmq-server","labels_url":"https://api.github.com/repos/rabbitmq/rabbitmq-server/issues/676/labels{/name}","comments_url":"https://api.github.com/repos/rabbitmq/rabbitmq-server/issues/676/comments","events_url":"https://api.github.com/repos/rabbitmq/rabbitmq-server/issues/676/events","html_url":"https://github.com/rabbitmq/rabbitmq-server/issues/676","id":138520184,"number":676,"title":"Cluster blocked after pause minority","user":{"login":"dcorbacho","id":646577,"avatar_url":"https://avatars.githubusercontent.com/u/646577?v=3","gravatar_id":"","url":"https://api.github.com/users/dcorbacho","html_url":"https://github.com/dcorbacho","followers_url":"https://api.github.com/users/dcorbacho/followers","following_url":"https://api.github.com/users/dcorbacho/following{/other_user}","gists_url":"https://api.github.com/users/dcorbacho/gists{/gist_id}","starred_url":"https://api.github.com/users/dcorbacho/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/dcorbacho/subscriptions","organizations_url":"https://api.github.com/users/dcorbacho/orgs","repos_url":"https://api.github.com/users/dcorbacho/repos","events_url":"https://api.github.com/users/dcorbacho/events{/privacy}","received_events_url":"https://api.github.com/users/dcorbacho/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":5,"created_at":"2016-03-04T16:40:13Z","updated_at":"2016-03-31T09:47:51Z","closed_at":null,"body":"# Test\r\n\r\nRabbit cluster with 3 Ubuntu machines (rabbit04, rabbit05, rabbit06) running 3.6.1.\r\n\r\nWhile running the tests to reproduce https://github.com/rabbitmq/rabbitmq-server/issues/545, the cluster got stuck for over 48h and it doesn't unblocks.\r\n\r\nLogs are available [here](https://drive.google.com/folderview?id=0B7YDkFQ4mjPmbG12N3dENnYxdmM&usp=sharing). The startup_log contains extra dbg logs\r\n\r\n## rabbit04\r\nIs blocked in `rabbit:stop()` awaiting for `rabbit_boot` to finish. The boot process is waiting for `mnesia:change_config/2` which is at the same time stuck in `mnesia_controller:connect_nodes/1`.\r\nThe controller is awaiting in this receive clause: https://github.com/erlang/otp/blob/maint/lib/mnesia/src/mnesia_controller.erl#L460 for the schema to be merged in `try_merge_schema`.\r\n\r\nMnesia seems to be blocked in a transaction aborted as `cyclic` over the `rabbit_exchange` table. Which in fact, doesn't appear in any of the mnesia locks. \r\n\r\n```\r\n2016-03-03 08:18:51 [{pid,<5588.4805.0>},\r\n                     {registered_name,[]},\r\n                     {current_stacktrace,\r\n                         [{timer,sleep,1,[{file,\"timer.erl\"},{line,153}]},\r\n                          {rabbit,await_startup,1,\r\n                              [{file,\"src/rabbit.erl\"},{line,378}]},\r\n                          {rabbit,stop,0,[{file,\"src/rabbit.erl\"},{line,323}]},\r\n                          {rabbit,stop_and_halt,0,\r\n                              [{file,\"src/rabbit.erl\"},{line,332}]},\r\n                          {rpc,'-handle_call_call/6-fun-0-',5,\r\n                              [{file,\"rpc.erl\"},{line,206}]}]},\r\n                     {initial_call,{erlang,apply,2}},\r\n                     {message_queue_len,0},\r\n                     {links,[]},\r\n                     {monitors,[]},\r\n                     {monitored_by,[<5588.14.0>]},\r\n                     {heap_size,233}]\r\n2016-03-03 08:18:51 [{pid,<5588.4503.0>},\r\n                     {registered_name,rabbit_outside_app_process},\r\n                     {current_stacktrace,\r\n                         [{gen,do_call,4,[{file,\"gen.erl\"},{line,168}]},\r\n                          {gen_server,call,3,\r\n                              [{file,\"gen_server.erl\"},{line,208}]},\r\n                          {app_utils,'-manage_applications/6-fun-0-',6,\r\n                              [{file,\"src/app_utils.erl\"},{line,118}]},\r\n                          {lists,foldl,3,[{file,\"lists.erl\"},{line,1262}]},\r\n                          {app_utils,manage_applications,6,\r\n                              [{file,\"src/app_utils.erl\"},{line,117}]},\r\n                          {rabbit,start_apps,1,\r\n                              [{file,\"src/rabbit.erl\"},{line,346}]},\r\n                          {rabbit,broker_start,0,\r\n                              [{file,\"src/rabbit.erl\"},{line,286}]},\r\n                          {rabbit,start_it,1,\r\n                              [{file,\"src/rabbit.erl\"},{line,303}]}]},\r\n                     {initial_call,{erlang,apply,2}},\r\n                     {message_queue_len,0},\r\n                     {links,[<5588.4537.0>]},\r\n                     {monitors,[{process,<5588.7.0>}]},\r\n                     {monitored_by,[]},\r\n                     {heap_size,6772}]\r\n2016-03-03 08:18:51 [{pid,<5588.4580.0>},\r\n                     {registered_name,rabbit},\r\n                     {current_stacktrace,\r\n                         [{mnesia_controller,connect_nodes,2,\r\n                              [{file,\"mnesia_controller.erl\"},{line,460}]},\r\n                          {rabbit_mnesia,change_extra_db_nodes,2,\r\n                              [{file,\"src/rabbit_mnesia.erl\"},{line,758}]},\r\n                          {rabbit_mnesia,init_db,3,\r\n                              [{file,\"src/rabbit_mnesia.erl\"},{line,447}]},\r\n                          {rabbit_mnesia,init_db_and_upgrade,3,\r\n                              [{file,\"src/rabbit_mnesia.erl\"},{line,478}]},\r\n                          {rabbit_mnesia,init,0,\r\n                              [{file,\"src/rabbit_mnesia.erl\"},{line,110}]},\r\n                          {rabbit_boot_steps,'-run_step/2-lc$^1/1-1-',1,\r\n                              [{file,\"src/rabbit_boot_steps.erl\"},{line,49}]},\r\n                          {rabbit_boot_steps,run_step,2,\r\n                              [{file,\"src/rabbit_boot_steps.erl\"},{line,49}]},\r\n                          {rabbit_boot_steps,'-run_boot_steps/1-lc$^0/1-0-',\r\n                              1,\r\n                              [{file,\"src/rabbit_boot_steps.erl\"},\r\n                               {line,26}]}]},\r\n                     {initial_call,{application_master,start_it,4}},\r\n                     {message_queue_len,1},\r\n                     {links,[<5588.4581.0>,<5588.4610.0>,<5588.4579.0>]},\r\n                     {monitors,[]},\r\n                     {monitored_by,[<5588.4604.0>]},\r\n                     {heap_size,10958}] \r\n```\r\n\r\n## rabbit05\r\n\r\nIs stuck with delegate calls and in-flight transactions. Also, several errors of channel terminate timeout.\r\n\r\n```\r\n=CRASH REPORT==== 2-Mar-2016::14:48:30 ===\r\n  crasher:\r\n    initial call: gen:init_it/6\r\n    pid: <0.5206.0>\r\n    registered_name: []\r\n    exception exit: {{badmatch,{error,{channel_operation_timeout,5000}}},\r\n                     [{rabbit_channel,terminate,2,\r\n                                      [{file,\"src/rabbit_channel.erl\"},\r\n                                       {line,614}]},\r\n                      {gen_server2,terminate,3,\r\n                                   [{file,\"src/gen_server2.erl\"},{line,1146}]},\r\n                      {proc_lib,wake_up,3,\r\n                                [{file,\"proc_lib.erl\"},{line,250}]}]}\r\n      in function  gen_server2:terminate/3 (src/gen_server2.erl, line 1149)\r\n    ancestors: [<0.5203.0>,<0.5199.0>,<0.5188.0>,<0.5187.0>,<0.665.0>,\r\n                  <0.664.0>,<0.663.0>,rabbit_sup,<0.120.0>]\r\n    messages: [{'DOWN',#Ref<0.0.2.52544>,process,<7847.3102.0>,normal},\r\n                  {'DOWN',#Ref<0.0.2.52545>,process,<7846.9755.0>,normal}]\r\n    links: []\r\n    dictionary: [{{xtype_to_module,fanout},rabbit_exchange_type_fanout},\r\n                  {msg_size_for_gc,24000},\r\n                  {{credit_from,<7846.9755.0>},200},\r\n                  {{credit_from,<0.5214.0>},200},\r\n                  {process_name,\r\n                      {rabbit_channel,\r\n                          {<<\"10.100.0.121:46213 -> 10.100.0.85:5672\">>,1}}},\r\n                  {delegate,delegate_4},\r\n                  {guid_secure,\r\n                      {{3,'rabbit@t-srv-rabbit05',#Ref<0.0.1.53952>},1}},\r\n                  {channel_operation_timeout,5000},\r\n                  {{credit_from,<7847.3102.0>},200},\r\n                  {credit_flow_default_credit,{200,50}},\r\n                  {{credit_to,<0.5189.0>},50},\r\n                  {guid,{{3499031759,2980528650,367330770,1247722968},799}}]\r\n    trap_exit: true\r\n    status: running\r\n    heap_size: 4185\r\n    stack_size: 27\r\n    reductions: 248033\r\n  neighbours:\r\n```\r\n\r\nThere seems to be a cyclic transaction error in mnesia, which causes the transaction to be restarted. It is executing a function from rabbit_amqqueue.\r\n\r\n```\r\n(<0.4753.0>) call mnesia:select_lock({tid,2243,<0.4753.0>},{tidstore,5267528,[],1},read,[{'$1',[],['$1']}],rabbit_queue)\r\n(<0.4753.0>) call mnesia:lock_table({tid,2243,<0.4753.0>},{tidstore,5267528,[],1},rabbit_queue,read)\r\n(<0.4753.0>) exception_from {mnesia,lock_table,4} {exit,{aborted,{cyclic,'rabbit@t-srv-rabbit05',\r\n                       {rabbit_queue,'______WHOLETABLE_____'},\r\n                       read,read,\r\n                       {tid,1893,<0.4603.0>}}}}\r\n(<0.4753.0>) call mnesia_tm:restart(mnesia,{tid,2243,<0.4753.0>},{tidstore,5267528,[],1},#Fun<rabbit_amqqueue.33.41098263>,[],758,infinity,sync,{cyclic,'rabbit@t-srv-rabbit05',\r\n        {rabbit_queue,'______WHOLETABLE_____'},\r\n        read,read,\r\n        {tid,1893,<0.4603.0>}})\r\n```\r\nThe transaction which might being handled is https://github.com/rabbitmq/rabbitmq-common/blob/stable/src/rabbit_amqqueue.erl#L891, as the maybe stuck output shows a process blocked handling the down of a node and the dbg output over mnesia shows also qlc queries. In this case, there are write and read locks over the `rabbit_queue` table.\r\n\r\n# rabbit06\r\n\r\nThis node seems stuck trying to sync the mirrored queues:\r\n```\r\n2016-03-03 08:38:29 [{pid,<5588.1588.0>},\r\n                     {registered_name,[]},\r\n                     {current_stacktrace,\r\n                         [{rabbit_mirror_queue_sync,master_go,8,\r\n                              [{file,\"src/rabbit_mirror_queue_sync.erl\"},\r\n                               {line,94}]},\r\n                          {rabbit_mirror_queue_master,sync_mirrors,3,\r\n                              [{file,\"src/rabbit_mirror_queue_master.erl\"},\r\n                               {line,159}]},\r\n                          {rabbit_amqqueue_process,handle_call,3,\r\n                              [{file,\"src/rabbit_amqqueue_process.erl\"},\r\n                               {line,1112}]},\r\n                          {gen_server2,handle_msg,2,\r\n                              [{file,\"src/gen_server2.erl\"},{line,1028}]},\r\n                          {proc_lib,wake_up,3,\r\n                              [{file,\"proc_lib.erl\"},{line,250}]}]},\r\n                     {initial_call,{proc_lib,init_p,5}},\r\n                     {message_queue_len,520},\r\n                     {links,\r\n                         [<5588.1587.0>,<5588.1832.0>,<5588.5645.0>,\r\n                          #Port<5588.8835>]},\r\n                     {monitors,[]},\r\n                     {monitored_by,\r\n                         [<5588.931.0>,<5588.5644.0>,<5588.923.0>,\r\n                          <5588.934.0>,<5588.822.0>]},\r\n                     {heap_size,514838}]\r\n```\r\n\r\nThere is another transaction permanently restarted in mnesia, originates from `mnesia_loader` as in rabbit04\r\n\r\n```\r\n(<0.5754.0>) exception_from {mnesia_tm,apply_fun,3} {exit,{aborted,{cyclic,'rabbit@t-srv-rabbit05',\r\n                       {rabbit_durable_queue,'______WHOLETABLE_____'},\r\n                       write,write,\r\n                       {tid,1893,<21740.4603.0>}}}}\r\n(<0.5754.0>) call mnesia_tm:check_exit(#Fun<mnesia_loader.4.89306253>,[],761,infinity,{aborted,{cyclic,'rabbit@t-srv-rabbit05',\r\n                 {rabbit_durable_queue,'______WHOLETABLE_____'},\r\n                 write,write,\r\n                 {tid,1893,<21740.4603.0>}}},async)\r\n(<0.5754.0>) call mnesia_tm:maybe_restart(#Fun<mnesia_loader.4.89306253>,[],761,infinity,async,{cyclic,'rabbit@t-srv-rabbit05',\r\n        {rabbit_durable_queue,'______WHOLETABLE_____'},\r\n        write,write,\r\n        {tid,1893,<21740.4603.0>}})\r\n(<0.5754.0>) call mnesia_tm:try_again(infinity)\r\n(<0.5754.0>) returned from mnesia_tm:try_again/1 -> yes\r\n(<0.5754.0>) call mnesia_tm:restart(mnesia,{tid,2329,<0.5754.0>},{tidstore,7417936,[],1},#Fun<mnesia_loader.4.89306253>,[],761,infinity,async,{cyclic,'rabbit@t-srv-rabbit05',\r\n        {rabbit_durable_queue,'______WHOLETABLE_____'},\r\n        write,write,\r\n        {tid,1893,<21740.4603.0>}})\r\n```"},"comment":{"url":"https://api.github.com/repos/rabbitmq/rabbitmq-server/issues/comments/203856382","html_url":"https://github.com/rabbitmq/rabbitmq-server/issues/676#issuecomment-203856382","issue_url":"https://api.github.com/repos/rabbitmq/rabbitmq-server/issues/676","id":203856382,"user":{"login":"dcorbacho","id":646577,"avatar_url":"https://avatars.githubusercontent.com/u/646577?v=3","gravatar_id":"","url":"https://api.github.com/users/dcorbacho","html_url":"https://github.com/dcorbacho","followers_url":"https://api.github.com/users/dcorbacho/followers","following_url":"https://api.github.com/users/dcorbacho/following{/other_user}","gists_url":"https://api.github.com/users/dcorbacho/gists{/gist_id}","starred_url":"https://api.github.com/users/dcorbacho/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/dcorbacho/subscriptions","organizations_url":"https://api.github.com/users/dcorbacho/orgs","repos_url":"https://api.github.com/users/dcorbacho/repos","events_url":"https://api.github.com/users/dcorbacho/events{/privacy}","received_events_url":"https://api.github.com/users/dcorbacho/received_events","type":"User","site_admin":false},"created_at":"2016-03-31T09:47:50Z","updated_at":"2016-03-31T09:47:50Z","body":"@noahhaon we don't have any workaround in RabbitMQ. \r\n\r\nIf upgrade is not a possibility, you might want to evaluate the option of backporting the Mnesia patch and build your own Erlang release. It is always a bit delicate, but there have been few changes in Mnesia lately."}}