Generic server report and stopping Virtual host '/'. What is the root problem?

[YuryHrytsuk]

Describe the bug

Disclaimer: I post this because I want to understand the root cause of the problem to avoid it in the future

Our services had problems while comunicating with rabbitmq.

aiormq.exceptions.ChannelNotFoundEntity: NOT_FOUND - queue 'my.queue' in vhost '/' process is stopped by supervisor

Error logs from rabbitmq

[error] <0.499.0> ** Generic server <0.499.0> terminating�[0m"
[error] <0.499.0> ** Last message in was {'$gen_cast',{delete,2}}�[0m"
[error] <0.499.0> ** When Server state == {state,#{},undefined,�[0m"
[error] <0.499.0>                             {gc_state,�[0m"
[error] <0.499.0>                                 ""/var/lib/rabbitmq/mnesia/rabbit@myNode1-1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent"",�[0m"
[error] <0.499.0>                                 rabbit_msg_store_ets_index,�[0m"
[error] <0.499.0>                                 {state,#Ref<0.628000897.1409941505.221525>,�[0m"
[error] <0.499.0>                                     <<""/var/lib/rabbitmq/mnesia/rabbit@myNode1-1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent"">>},�[0m"
[error] <0.499.0>                                 #Ref<0.628000897.1409941505.221509>,�[0m"
[error] <0.499.0>                                 #Ref<0.628000897.1409941505.221530>,�[0m"
[error] <0.499.0>                                 <0.494.0>}}�[0m"
[error] <0.499.0> ** Reason for termination ==�[0m"
[error] <0.499.0> ** {{case_clause,{msg_location,<<87,154,26,150,57,108,241,119,135,241,199,3,68,�[0m"
[error] <0.499.0>                                  74,58,177>>,�[0m"
[error] <0.499.0>                                0,2,16775877,9732}},�[0m"
[error] <0.499.0>     [{rabbit_msg_store,'-scan_and_vacuum_message_file/2-fun-0-',4,�[0m"
[error] <0.499.0>                        [{file,""rabbit_msg_store.erl""},{line,2007}]},�[0m"
[error] <0.499.0>      {lists,foldl,3,[{file,""lists.erl""},{line,1594}]},�[0m"
[error] <0.499.0>      {rabbit_msg_store,delete_file,2,�[0m"
[error] <0.499.0>                        [{file,""rabbit_msg_store.erl""},{line,1993}]},�[0m"
[error] <0.499.0>      {rabbit_msg_store_gc,attempt_action,3,�[0m"
[error] <0.499.0>                           [{file,""rabbit_msg_store_gc.erl""},{line,110}]},�[0m"
[error] <0.499.0>      {rabbit_msg_store_gc,handle_cast,2,�[0m"
[error] <0.499.0>                           [{file,""rabbit_msg_store_gc.erl""},{line,85}]},�[0m"
[error] <0.499.0>      {gen_server2,handle_msg,2,[{file,""gen_server2.erl""},{line,1056}]},�[0m"
[error] <0.499.0>      {proc_lib,wake_up,3,[{file,""proc_lib.erl""},{line,251}]}]}�[0m"
[error] <0.499.0> �[0m"
[error] <0.499.0>   crasher:�[0m"
[error] <0.499.0>     initial call: rabbit_msg_store_gc:init/1�[0m"
[error] <0.499.0>     pid: <0.499.0>�[0m"
[error] <0.499.0>     registered_name: []�[0m"
[error] <0.499.0>     exception exit: {{case_clause,�[0m"
[error] <0.499.0>                          {msg_location,�[0m"
[error] <0.499.0>                              <<87,154,26,150,57,108,241,119,135,241,199,3,68,�[0m"
[error] <0.499.0>                                74,58,177>>,�[0m"
[error] <0.499.0>                              0,2,16775877,9732}},�[0m"
[error] <0.499.0>                      [{rabbit_msg_store,�[0m"
[error] <0.499.0>                           '-scan_and_vacuum_message_file/2-fun-0-',4,�[0m"
[error] <0.499.0>                           [{file,""rabbit_msg_store.erl""},{line,2007}]},�[0m"
[error] <0.499.0>                       {lists,foldl,3,[{file,""lists.erl""},{line,1594}]},�[0m"
[error] <0.499.0>                       {rabbit_msg_store,delete_file,2,�[0m"
[error] <0.499.0>                           [{file,""rabbit_msg_store.erl""},{line,1993}]},�[0m"
[error] <0.499.0>                       {rabbit_msg_store_gc,attempt_action,3,�[0m"
[error] <0.499.0>                           [{file,""rabbit_msg_store_gc.erl""},{line,110}]},�[0m"
[error] <0.499.0>                       {rabbit_msg_store_gc,handle_cast,2,�[0m"
[error] <0.499.0>                           [{file,""rabbit_msg_store_gc.erl""},{line,85}]},�[0m"
[error] <0.499.0>                       {gen_server2,handle_msg,2,�[0m"
[error] <0.499.0>                           [{file,""gen_server2.erl""},{line,1056}]},�[0m"
[error] <0.499.0>                       {proc_lib,wake_up,3,�[0m"
[error] <0.499.0>                           [{file,""proc_lib.erl""},{line,251}]}]}�[0m"
[error] <0.499.0>       in function  gen_server2:terminate/3 (gen_server2.erl, line 1172)�[0m"
[error] <0.499.0>     ancestors: [<0.494.0>,<0.480.0>,<0.479.0>,rabbit_vhost_sup_sup,�[0m"
[error] <0.499.0>                   rabbit_sup,<0.254.0>]�[0m"
[error] <0.499.0>     message_queue_len: 0�[0m"
[error] <0.499.0>     messages: []�[0m"
[error] <0.499.0>     links: [<0.494.0>]�[0m"
[error] <0.499.0>     dictionary: [{rand_seed,{#{max => 288230376151711743,type => exsplus,�[0m"
[error] <0.499.0>                                 next => #Fun<rand.5.65977474>,�[0m"
[error] <0.499.0>                                 jump => #Fun<rand.3.65977474>},�[0m"
[error] <0.499.0>                               [189519528190419811|170760680218369350]}}]�[0m"
[error] <0.499.0>     trap_exit: false�[0m"
[error] <0.499.0>     status: running�[0m"
[error] <0.499.0>     heap_size: 10958�[0m"
[error] <0.499.0>     stack_size: 28�[0m"
[error] <0.499.0>     reductions: 593880�[0m"
[error] <0.499.0>   neighbours:�[0m"
[error] <0.499.0> �[0m"
494.0> Stopping message store for directory '/var/lib/rabbitmq/mnesia/rabbit@myNode1-1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent' with reason {{case_clause,{msg_location,<<87,154,26,150,57,108,241,119,135,241,199,3,68,74,58,177>>,0,2,16775877,9732}},[{rabbit_msg_store,'-scan_and_vacuum_message_file/2-fun-0-',4,[{file,""rabbit_msg_store.erl""},{line,2007}]},{lists,foldl,3,[{file,""lists.erl""},{line,1594}]},{rabbit_msg_store,delete_file,2,[{file,""rabbit_msg_store.erl""},{line,1993}]},{rabbit_msg_store_gc,attempt_action,3,[{file,""rabbit_msg_store_gc.erl""},{line,110}]},{rabbit_msg_store_gc,handle_cast,2,[{file,""rabbit_msg_store_gc.erl""},{line,85}]},{gen_server2,handle_msg,2,[{file,""gen_server2.erl""},{line,1056}]},{proc_lib,wake_up,3,[{file,""proc_lib.erl""},{line,251}]}]}�[0m"
[error] <0.494.0> ** Generic server <0.494.0> terminating�[0m"
[error] <0.494.0> ** Last message in was {'EXIT',<0.499.0>,�[0m"
[error] <0.494.0>                            {{case_clause,�[0m"
[error] <0.494.0>                                 {msg_location,�[0m"
[error] <0.494.0>                                     <<87,154,26,150,57,108,241,119,135,241,199,�[0m"
[error] <0.494.0>                                       3,68,74,58,177>>,�[0m"
[error] <0.494.0>                                     0,2,16775877,9732}},�[0m"
[error] <0.494.0>                             [{rabbit_msg_store,�[0m"
[error] <0.494.0>                                  '-scan_and_vacuum_message_file/2-fun-0-',4,�[0m"
[error] <0.494.0>                                  [{file,""rabbit_msg_store.erl""},{line,2007}]},�[0m"
[error] <0.494.0>                              {lists,foldl,3,[{file,""lists.erl""},{line,1594}]},�[0m"
[error] <0.494.0>                              {rabbit_msg_store,delete_file,2,�[0m"
[error] <0.494.0>                                  [{file,""rabbit_msg_store.erl""},{line,1993}]},�[0m"
[error] <0.494.0>                              {rabbit_msg_store_gc,attempt_action,3,�[0m"
[error] <0.494.0>                                  [{file,""rabbit_msg_store_gc.erl""},�[0m"
[error] <0.494.0>                                   {line,110}]},�[0m"
[error] <0.494.0>                              {rabbit_msg_store_gc,handle_cast,2,�[0m"
[error] <0.494.0>                                  [{file,""rabbit_msg_store_gc.erl""},{line,85}]},�[0m"
[error] <0.494.0>                              {gen_server2,handle_msg,2,�[0m"
[error] <0.494.0>                                  [{file,""gen_server2.erl""},{line,1056}]},�[0m"
[error] <0.494.0>                              {proc_lib,wake_up,3,�[0m"
[error] <0.494.0>                                  [{file,""proc_lib.erl""},{line,251}]}]}}�[0m"
[error] <0.494.0> ** When Server state == {msstate,�[0m"
[error] <0.494.0>                             ""/var/lib/rabbitmq/mnesia/rabbit@myNode1-1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent"",�[0m"
[error] <0.494.0>                             rabbit_msg_store_ets_index,�[0m"
[error] <0.494.0>                             {state,#Ref<0.628000897.1409941505.221525>,�[0m"
[error] <0.494.0>                                 <<""/var/lib/rabbitmq/mnesia/rabbit@myNode1-1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent"">>},�[0m"
[error] <0.494.0>                             3,�[0m"
[error] <0.494.0>                             {writer,�[0m"
[error] <0.494.0>                                 {file_descriptor,prim_file,�[0m"
[error] <0.494.0>                                     #{handle =>�[0m"
[error] <0.494.0>                                           #Ref<0.628000897.1417543693.225346>,�[0m"
[error] <0.494.0>                                       owner => <0.494.0>,�[0m"
[error] <0.494.0>                                       r_buffer =>�[0m"
[error] <0.494.0>                                           #Ref<0.628000898.158990337.156504>,�[0m"
[error] <0.494.0>                                       r_ahead_size => 0}},�[0m"
[error] <0.494.0>                                 #Ref<0.628000898.158990337.156505>},�[0m"
[error] <0.494.0>                             21805,undefined,#{},�[0m"
[error] <0.494.0>                             #Ref<0.628000898.158859265.156514>,<0.499.0>,�[0m"
[error] <0.494.0>                             #Ref<0.628000897.1409941505.221530>,�[0m"
[error] <0.494.0>                             #Ref<0.628000897.1409941505.221509>,�[0m"
[error] <0.494.0>                             #Ref<0.628000897.1409941505.221531>,�[0m"
[error] <0.494.0>                             #Ref<0.628000897.1409941505.221532>,#{},�[0m"
[error] <0.494.0>                             #{<<35,224,178,247,86,96,31,218,71,185,253,142,211,�[0m"
[error] <0.494.0>                                 157,217,62>> =>�[0m"
[error] <0.494.0>                                   {<0.509.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<83,121,25,152,161,210,210,240,228,128,181,116,�[0m"
[error] <0.494.0>                                 76,206,13,183>> =>�[0m"
[error] <0.494.0>                                   {<0.515.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<92,218,237,139,20,96,189,1,184,5,63,95,63,139,�[0m"
[error] <0.494.0>                                 14,187>> =>�[0m"
[error] <0.494.0>                                   {<0.542.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<114,54,222,16,238,175,0,220,85,212,26,91,175,�[0m"
[error] <0.494.0>                                 255,230,64>> =>�[0m"
[error] <0.494.0>                                   {<0.521.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<121,74,249,119,179,78,139,21,27,237,166,23,135,�[0m"
[error] <0.494.0>                                 208,221,82>> =>�[0m"
[error] <0.494.0>                                   {<0.539.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<147,62,183,64,205,100,17,202,218,58,48,199,16,�[0m"
[error] <0.494.0>                                 93,14,235>> =>�[0m"
[error] <0.494.0>                                   {<0.503.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<159,53,31,194,22,179,38,29,137,63,161,59,7,44,�[0m"
[error] <0.494.0>                                 46,130>> =>�[0m"
[error] <0.494.0>                                   {<0.527.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<169,81,14,54,35,167,193,205,194,204,196,9,165,�[0m"
[error] <0.494.0>                                 118,70,251>> =>�[0m"
[error] <0.494.0>                                   {<0.524.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<""±T['ÒDÍн5çÇ#I,U"">> =>�[0m"
[error] <0.494.0>                                   {<0.536.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<224,156,31,120,200,177,48,184,207,9,178,22,5,�[0m"
[error] <0.494.0>                                 64,39,122>> =>�[0m"
[error] <0.494.0>                                   {<0.506.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<226,32,126,167,181,110,16,153,227,32,20,218,57,�[0m"
[error] <0.494.0>                                 136,182,174>> =>�[0m"
[error] <0.494.0>                                   {<0.518.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<230,233,48,236,194,16,99,204,3,19,138,112,164,�[0m"
[error] <0.494.0>                                 100,245,139>> =>�[0m"
[error] <0.494.0>                                   {<0.533.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<241,4,109,125,213,120,59,242,113,174,120,117,�[0m"
[error] <0.494.0>                                 111,231,194,235>> =>�[0m"
[error] <0.494.0>                                   {<0.512.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>},�[0m"
[error] <0.494.0>                               <<243,187,21,141,98,110,189,142,90,50,227,30,83,�[0m"
[error] <0.494.0>                                 106,34,180>> =>�[0m"
[error] <0.494.0>                                   {<0.530.0>,�[0m"
[error] <0.494.0>                                    #Fun<rabbit_variable_queue.1.56700977>}},�[0m"
[error] <0.494.0>                             true,16777216,#{},�[0m"
[error] <0.494.0>                             {4000,800}}�[0m"
[error] <0.494.0> ** Reason for termination ==�[0m"
[error] <0.494.0> ** {noproc,{gen_server2,call,[<0.499.0>,stop,infinity]}}�[0m"
[error] <0.494.0> ** In 'terminate' callback with reason ==�[0m"
[error] <0.494.0> ** {{case_clause,{msg_location,<<87,154,26,150,57,108,241,119,135,241,199,3,68,�[0m"
[error] <0.494.0>                                  74,58,177>>,�[0m"
[error] <0.494.0>                                0,2,16775877,9732}},�[0m"
[error] <0.494.0>     [{rabbit_msg_store,'-scan_and_vacuum_message_file/2-fun-0-',4,�[0m"
[error] <0.494.0>                        [{file,""rabbit_msg_store.erl""},{line,2007}]},�[0m"
[error] <0.494.0>      {lists,foldl,3,[{file,""lists.erl""},{line,1594}]},�[0m"
[error] <0.494.0>      {rabbit_msg_store,delete_file,2,�[0m"
[error] <0.494.0>                        [{file,""rabbit_msg_store.erl""},{line,1993}]},�[0m"https://github.com/rabbitmq/rabbitmq-server/issues/14071
[error] <0.494.0>      {rabbit_msg_store_gc,attempt_action,3,�[0m"
[error] <0.494.0>                           [{file,""rabbit_msg_store_gc.erl""},{line,110}]},�[0m"
[error] <0.494.0>      {rabbit_msg_store_gc,handle_cast,2,�[0m"
[error] <0.494.0>                           [{file,""rabbit_msg_store_gc.erl""},{line,85}]},�[0m"
[error] <0.494.0>      {gen_server2,handle_msg,2,[{file,""gen_server2.erl""},{line,1056}]},�[0m"
[error] <0.494.0>      {proc_lib,wake_up,3,[{file,""proc_lib.erl""},{line,251}]}]}�[0m"
[error] <0.494.0> �[0m"
[error] <0.494.0>   crasher:�[0m"
[error] <0.494.0>     initial call: rabbit_msg_store:init/1�[0m"
[error] <0.494.0>     pid: <0.494.0>�[0m"
[error] <0.494.0>     registered_name: []�[0m"
[error] <0.494.0>     exception exit: {noproc,{gen_server2,call,[<0.499.0>,stop,infinity]}}�[0m"
[error] <0.494.0>       in function  gen_server2:terminate/3 (gen_server2.erl, line 1161)�[0m"
[error] <0.494.0>     ancestors: [<0.480.0>,<0.479.0>,rabbit_vhost_sup_sup,rabbit_sup,�[0m"
[error] <0.494.0>                   <0.254.0>]�[0m"
[error] <0.494.0>     message_queue_len: 1�[0m"
[error] <0.494.0>     messages: [{'$gen_cast',{write,<<121,74,249,119,179,78,139,21,27,237,�[0m"
[error] <0.494.0>                                         166,23,135,208,221,82>>,�[0m"
[error] <0.494.0>                                       15000,�[0m"
[error] <0.494.0>                                       <<102,253,112,2,15,55,212,229,137,236,�[0m"
[error] <0.494.0>                                         200,79,78,42,219,120>>,�[0m"
[error] <0.494.0>                                       flow}}]�[0m"
[error] <0.494.0>     links: [<0.480.0>]�[0m"
[error] <0.494.0>     dictionary: [{rand_seed,{#{max => 288230376151711743,type => exsplus,�[0m"
[error] <0.494.0>                                 next => #Fun<rand.5.65977474>,�[0m"
[error] <0.494.0>                                 jump => #Fun<rand.3.65977474>},�[0m"
[error] <0.494.0>                               [66032787660396296|6050238792782565]}},�[0m"
[error] <0.494.0>                   {{credit_to,<0.539.0>},394}]�[0m"
[error] <0.494.0>     trap_exit: true�[0m"
[error] <0.494.0>     status: running�[0m"
[error] <0.494.0>     heap_size: 46422�[0m"
[error] <0.494.0>     stack_size: 28�[0m"
[error] <0.494.0>     reductions: 2459381�[0m"
[error] <0.494.0>   neighbours:�[0m"
[error] <0.494.0> �[0m"
[error] <0.480.0>     supervisor: {<0.480.0>,rabbit_vhost_sup}�[0m"
[error] <0.480.0>     errorContext: child_terminated�[0m"
[error] <0.480.0>     reason: {noproc,{gen_server2,call,[<0.499.0>,stop,infinity]}}�[0m"
[error] <0.480.0>     offender: [{pid,<0.494.0>},�[0m"
[error] <0.480.0>                {id,msg_store_persistent},�[0m"
[error] <0.480.0>                {mfargs,�[0m"
[error] <0.480.0>                    {rabbit_msg_store,start_link,�[0m"
[error] <0.480.0>                        [<<""/"">>,msg_store_persistent,�[0m"
[error] <0.480.0>                         ""/var/lib/rabbitmq/mnesia/rabbit@myNode1-1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L"",�[0m"
[error] <0.480.0>                         [<<147,62,183,64,205,100,17,202,218,58,48,199,16,93,14,�[0m"
[error] <0.480.0>                            235>>,�[0m"
[error] <0.480.0>                          <<224,156,31,120,200,177,48,184,207,9,178,22,5,64,39,�[0m"
[error] <0.480.0>                            122>>,�[0m"
[error] <0.480.0>                          <<35,224,178,247,86,96,31,218,71,185,253,142,211,157,�[0m"
[error] <0.480.0>                            217,62>>,�[0m"
[error] <0.480.0>                          <<241,4,109,125,213,120,59,242,113,174,120,117,111,�[0m"
[error] <0.480.0>                            231,194,235>>,�[0m"
[error] <0.480.0>                          <<83,121,25,152,161,210,210,240,228,128,181,116,76,�[0m"
[error] <0.480.0>                            206,13,183>>,�[0m"
[error] <0.480.0>                          <<226,32,126,167,181,110,16,153,227,32,20,218,57,136,�[0m"
[error] <0.480.0>                            182,174>>,�[0m"
[error] <0.480.0>                          <<114,54,222,16,238,175,0,220,85,212,26,91,175,255,�[0m"
[error] <0.480.0>                            230,64>>,�[0m"
[error] <0.480.0>                          <<169,81,14,54,35,167,193,205,194,204,196,9,165,118,�[0m"
[error] <0.480.0>                            70,251>>,�[0m"
[error] <0.480.0>                          <<159,53,31,194,22,179,38,29,137,63,161,59,7,44,46,130>>,�[0m"
[error] <0.480.0>                          <<243,187,21,141,98,110,189,142,90,50,227,30,83,106,�[0m"
[error] <0.480.0>                            34,180>>,�[0m"
[error] <0.480.0>                          <<230,233,48,236,194,16,99,204,3,19,138,112,164,100,�[0m"
[error] <0.480.0>                            245,139>>,�[0m"
[error] <0.480.0>                          <<""±T['ÒDÍн5çÇ#I,U"">>,�[0m"
[error] <0.480.0>                          <<121,74,249,119,179,78,139,21,27,237,166,23,135,208,�[0m"
[error] <0.480.0>                            221,82>>,�[0m"
[error] <0.480.0>                          <<92,218,237,139,20,96,189,1,184,5,63,95,63,139,14,�[0m"
[error] <0.480.0>                            187>>],�[0m"
[error] <0.480.0>                         {#Fun<rabbit_classic_queue_index_v2.9.72743984>,�[0m"
[error] <0.480.0>                          {start,�[0m"
[error] <0.480.0>                              [{resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""simcore.services.director-v2.scheduling"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""io.simcore.service.wallets"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_simcore.services.director-v2.scheduling"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_io.simcore.service.dynamic-service-running"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""io.simcore.service.tracking"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""simcore.services.instrumentation"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_simcore.services.instrumentation"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""io.simcore.service.wallets-credit-limit-reached"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""io.simcore.service.dynamic-service-running"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_io.simcore.service.wallets-credit-limit-reached"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_io.simcore.service.wallets"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_io.simcore.service.tracking"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,<<""default"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,<<""cpu_bound"">>}]}}]}},�[0m"
[error] <0.480.0>                {restart_type,transient},�[0m"
[error] <0.480.0>                {significant,false},�[0m"
[error] <0.480.0>                {shutdown,600000},�[0m"
[error] <0.480.0>                {child_type,worker}]�[0m"
[error] <0.480.0> �[0m"
[error] <0.480.0>     supervisor: {<0.480.0>,rabbit_vhost_sup}�[0m"
[error] <0.480.0>     errorContext: shutdown�[0m"
[error] <0.480.0>     reason: reached_max_restart_intensity�[0m"
[error] <0.480.0>     offender: [{pid,<0.494.0>},�[0m"
[error] <0.480.0>                {id,msg_store_persistent},�[0m"
[error] <0.480.0>                {mfargs,�[0m"
[error] <0.480.0>                    {rabbit_msg_store,start_link,�[0m"
[error] <0.480.0>                        [<<""/"">>,msg_store_persistent,�[0m"
[error] <0.480.0>                         ""/var/lib/rabbitmq/mnesia/rabbit@myNode1-1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L"",�[0m"
[error] <0.480.0>                         [<<147,62,183,64,205,100,17,202,218,58,48,199,16,93,14,�[0m"
[error] <0.480.0>                            235>>,�[0m"
[error] <0.480.0>                          <<224,156,31,120,200,177,48,184,207,9,178,22,5,64,39,�[0m"
[error] <0.480.0>                            122>>,�[0m"
[error] <0.480.0>                          <<35,224,178,247,86,96,31,218,71,185,253,142,211,157,�[0m"
[error] <0.480.0>                            217,62>>,�[0m"
[error] <0.480.0>                          <<241,4,109,125,213,120,59,242,113,174,120,117,111,�[0m"
[error] <0.480.0>                            231,194,235>>,�[0m"
[error] <0.480.0>                          <<83,121,25,152,161,210,210,240,228,128,181,116,76,�[0m"
[error] <0.480.0>                            206,13,183>>,�[0m"
[error] <0.480.0>                          <<226,32,126,167,181,110,16,153,227,32,20,218,57,136,�[0m"
[error] <0.480.0>                            182,174>>,�[0m"
[error] <0.480.0>                          <<114,54,222,16,238,175,0,220,85,212,26,91,175,255,�[0m"
[error] <0.480.0>                            230,64>>,�[0m"
[error] <0.480.0>                          <<169,81,14,54,35,167,193,205,194,204,196,9,165,118,�[0m"
[error] <0.480.0>                            70,251>>,�[0m"
[error] <0.480.0>                          <<159,53,31,194,22,179,38,29,137,63,161,59,7,44,46,130>>,�[0m"
[error] <0.480.0>                          <<243,187,21,141,98,110,189,142,90,50,227,30,83,106,�[0m"
[error] <0.480.0>                            34,180>>,�[0m"
[error] <0.480.0>                          <<230,233,48,236,194,16,99,204,3,19,138,112,164,100,�[0m"
[error] <0.480.0>                            245,139>>,�[0m"
[error] <0.480.0>                          <<""±T['ÒDÍн5çÇ#I,U"">>,�[0m"
[error] <0.480.0>                          <<121,74,249,119,179,78,139,21,27,237,166,23,135,208,�[0m"
[error] <0.480.0>                            221,82>>,�[0m"
[error] <0.480.0>                          <<92,218,237,139,20,96,189,1,184,5,63,95,63,139,14,�[0m"
[error] <0.480.0>                            187>>],�[0m"
[error] <0.480.0>                         {#Fun<rabbit_classic_queue_index_v2.9.72743984>,�[0m"
[error] <0.480.0>                          {start,�[0m"
[error] <0.480.0>                              [{resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""simcore.services.director-v2.scheduling"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""io.simcore.service.wallets"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_simcore.services.director-v2.scheduling"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_io.simcore.service.dynamic-service-running"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""io.simcore.service.tracking"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""simcore.services.instrumentation"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_simcore.services.instrumentation"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""io.simcore.service.wallets-credit-limit-reached"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""io.simcore.service.dynamic-service-running"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_io.simcore.service.wallets-credit-limit-reached"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_io.simcore.service.wallets"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,�[0m"
[error] <0.480.0>                                   <<""delayed_io.simcore.service.tracking"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,<<""default"">>},�[0m"
[error] <0.480.0>                               {resource,<<""/"">>,queue,<<""cpu_bound"">>}]}}]}},�[0m"
[error] <0.480.0>                {restart_type,transient},�[0m"
[error] <0.480.0>                {significant,false},�[0m"
[error] <0.480.0>                {shutdown,600000},�[0m"
[error] <0.480.0>                {child_type,worker}]�[0m"
[error] <0.480.0> �[0m"
...
[error] <0.484.0> ** Generic server <0.484.0> terminating�[0m"
[error] <0.484.0> ** Last message in was {'EXIT',<0.480.0>,shutdown}�[0m"
[error] <0.484.0> ** When Server state == <<""/"">>�[0m"
[error] <0.484.0> ** Reason for termination ==�[0m"
[error] <0.484.0> ** {{badmatch,{error,{premature_eof,""/var/lib/rabbitmq/mnesia/rabbit@myNode1-1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/recovery.dets""}}},�[0m"
[error] <0.484.0>     [{rabbit_recovery_terms,close_table,1,�[0m"
[error] <0.484.0>                             [{file,""rabbit_recovery_terms.erl""},{line,164}]},�[0m"
[error] <0.484.0>      {gen_server,try_terminate,3,[{file,""gen_server.erl""},{line,1143}]},�[0m"
[error] <0.484.0>      {gen_server,terminate,10,[{file,""gen_server.erl""},{line,1339}]},�[0m"
[error] <0.484.0>      {proc_lib,init_p_do_apply,3,[{file,""proc_lib.erl""},{line,241}]}]}�[0m"
[error] <0.484.0> �[0m"
[error] <0.484.0>   crasher:�[0m"
[error] <0.484.0>     initial call: rabbit_recovery_terms:init/1�[0m"
[error] <0.484.0>     pid: <0.484.0>�[0m"
[error] <0.484.0>     registered_name: []�[0m"
[error] <0.484.0>     exception error: no match of right hand side value {error,�[0m"
[error] <0.484.0>                                                         {premature_eof,�[0m"
[error] <0.484.0>                                                          ""/var/lib/rabbitmq/mnesia/rabbit@myNode1-1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/recovery.dets""}}�[0m"
[error] <0.484.0>       in function  rabbit_recovery_terms:close_table/1 (rabbit_recovery_terms.erl, line 164)�[0m"
[error] <0.484.0>       in call from gen_server:try_terminate/3 (gen_server.erl, line 1143)�[0m"
[error] <0.484.0>       in call from gen_server:terminate/10 (gen_server.erl, line 1339)�[0m"
[error] <0.484.0>     ancestors: [<0.480.0>,<0.479.0>,rabbit_vhost_sup_sup,rabbit_sup,�[0m"
[error] <0.484.0>                   <0.254.0>]�[0m"
[error] <0.484.0>     message_queue_len: 0�[0m"
[error] <0.484.0>     messages: []�[0m"
[error] <0.484.0>     links: [<0.480.0>,<0.268.0>]�[0m"
[error] <0.484.0>     dictionary: []�[0m"
[error] <0.484.0>     trap_exit: true�[0m"
[error] <0.484.0>     status: running�[0m"
[error] <0.484.0>     heap_size: 4185�[0m"
[error] <0.484.0>     stack_size: 28�[0m"
[error] <0.484.0>     reductions: 476835�[0m"
[error] <0.484.0>   neighbours:�[0m"
[error] <0.484.0> �[0m"
[error] <0.480.0>     supervisor: {<0.480.0>,rabbit_vhost_sup}�[0m"
[error] <0.480.0>     errorContext: shutdown_error�[0m"
[error] <0.480.0>     reason: {{badmatch,�[0m"
[error] <0.480.0>                  {error,�[0m"
[error] <0.480.0>                      {premature_eof,�[0m"
[error] <0.480.0>                          ""/var/lib/rabbitmq/mnesia/rabbit@myNode1-1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/recovery.dets""}}},�[0m"
[error] <0.480.0>              [{rabbit_recovery_terms,close_table,1,�[0m"
[error] <0.480.0>                   [{file,""rabbit_recovery_terms.erl""},{line,164}]},�[0m"
[error] <0.480.0>               {gen_server,try_terminate,3,�[0m"
[error] <0.480.0>                   [{file,""gen_server.erl""},{line,1143}]},�[0m"
[error] <0.480.0>               {gen_server,terminate,10,[{file,""gen_server.erl""},{line,1339}]},�[0m"
[error] <0.480.0>               {proc_lib,init_p_do_apply,3,�[0m"
[error] <0.480.0>                   [{file,""proc_lib.erl""},{line,241}]}]}�[0m"
[error] <0.480.0>     offender: [{pid,<0.484.0>},�[0m"
[error] <0.480.0>                {id,rabbit_recovery_terms},�[0m"
[error] <0.480.0>                {mfargs,{rabbit_recovery_terms,start_link,[<<""/"">>]}},�[0m"
[error] <0.480.0>                {restart_type,transient},�[0m"
[error] <0.480.0>                {significant,false},�[0m"
[error] <0.480.0>                {shutdown,300000},�[0m"
[error] <0.480.0>                {child_type,worker}]�[0m"
[error] <0.480.0> �[0m"
[error] <0.479.0>     supervisor: {<0.479.0>,rabbit_vhost_sup_wrapper}�[0m"
[error] <0.479.0>     errorContext: child_terminated�[0m"
[error] <0.479.0>     reason: shutdown�[0m"
[error] <0.479.0>     offender: [{pid,<0.480.0>},�[0m"
[error] <0.479.0>                {id,rabbit_vhost_sup},�[0m"
[error] <0.479.0>                {mfargs,{rabbit_vhost_sup_wrapper,start_vhost_sup,[<<""/"">>]}},�[0m"
[error] <0.479.0>                {restart_type,permanent},�[0m"
[error] <0.479.0>                {significant,false},�[0m"
[error] <0.479.0>                {shutdown,infinity},�[0m"
[error] <0.479.0>                {child_type,supervisor}]�[0m"
[error] <0.479.0> �[0m"
03.557918+00:00 [info] <0.481.0> Virtual host '/' is stopping�[0m"
03.558246+00:00 [info] <0.42130736.0> Closing all connections in vhost '/' on node 'rabbit@myNode1-1' because the vhost is stopping�[0m"
03.559710+00:00 [info] <0.42130725.0> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@myNode1-1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L' for vhost '/' exists�[0m"
...
more errors

Reproduction steps

We run rabbit in a single replica inside docker swarm. Our services couldn't start due to some problems with rabbitmq. It happened the first time (in years) and sporadically.

Expected behavior

Rabbit runs without closing virtual host (aka healthy)

Additional context

It happened at 00:01 UTC tonight and got solved after we restarted rabbitmq container around 6:30 AM UTC.

rabbitmq: 3.13.7

docker compose spec

  rabbit:
    image: custom/rabbitmq:3.13.7-management
    init: true
    hostname: "{{.Node.Hostname}}-{{.Task.Slot}}"
    environment:
      RABBITMQ_DEFAULT_USER: ${RABBIT_USER}
      RABBITMQ_DEFAULT_PASS: ${RABBIT_PASSWORD}
    volumes:
      - rabbit_data:/var/lib/rabbitmq
    networks:
      - default
      - computational_services_subnet
      - interactive_services_subnet
      - autoscaling_subnet
    healthcheck:
      # see https://www.rabbitmq.com/monitoring.html#individual-checks for info about health-checks available in rabbitmq
      test: rabbitmq-diagnostics -q status
      interval: 5s
      timeout: 30s
      retries: 5
      start_period: 5s

Dockerfile

ARG VERSION
FROM rabbitmq:${VERSION}
# installs plugins
RUN rabbitmq-plugins enable \
    --offline rabbitmq_management \
    rabbitmq_management_agent \
    rabbitmq_web_dispatch \
    rabbitmq_prometheus

Metrics

[gomoripeti]

According to the stacktrace this crash happens when the classic queue shared message store tries to delete a message file (rdq file) which it does not need any more (all message in the file have been removed from queues)

You mentioned root cause, but as you added the bug label I want to mention that the rdq file deletion was refactored in 4.1.1 so this "bug" won't happen there any more, so we might consider it fixed (might happen in a slightly different scenario during compaction). A GH discussion would be more appropriate.

Regarding the root cause when I saw this crash I could only find out that usually the shared message store only stores the same message once, even if it was published to multiple queues. However in certain scenarios the same message can be stored multiple times. In this case the same message is stored multiple times and in different files. That's fine but what is unexpected is that the stored messages have different sizes on disk (that's what I suspect). The code is not prepared for this and crashes.

I've seen two examples when the size was different for the same message:

• one between an upgrade from 3.12 and 3.13 where Erlang version was changed, and erlang term_to_binary resulted in different binaries on Erlang 25 and 26 (the atoms are stored differently)
• in another case the AMQP 0.9.1 properties were stored only in binary format in one instance and both in binary and decoded in another instance.

I would be curious what the Core Team thinks how this later case can happen (what route the message needs to take within the broker? dead-lettering? maybe shovelling with a direct connection?) and if it can still cause a similar crash theoretically during compaction in 4.1 and above?

[YuryHrytsuk]

You mentioned root cause, but as you added the bug label I want to mention that the rdq file deletion was refactored in 4.1.1 so this "bug" won't happen there any more

Could you refer to the commit and release note related to this refactoring / fix?

[gomoripeti]

This is the PR that eliminates the "scanning" operation before the file delete (its the scanning that crashed for you):

#13987

[YuryHrytsuk]

in 4.1.1 so this "bug" won't happen there any more, so we might consider it fixed (might happen in a slightly different scenario during compaction)

If we update to 4.1.1, is there any way to be sure that we don't encounter this bug ("in slightly different scenario") anymore?