rabbit_mgmt_external_stats terminating with case_clause

[faithfull]

Someday ago, i have upgrade my rabbitmq from 3.10.7 to 3.10.8. there is no more error log about

"rabbit_mgmt_external_stats terminating with badmatch #5490"

#5490

but today，my rabbitmq show another error log and this log have not appear before， is this a bug from 3.10.8 ？

image ： bitnami/rabbitmq:3.10.8-debian-11-r0

2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> ** Generic server rabbit_mgmt_external_stats terminating
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> ** Last message in was emit_update
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> ** When Server state == {state,1048576,
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> [{{io_sync,count},121471},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_file_handle_open_attempt,count},2},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{queue_index_read,count},1},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{msg_store_read,count},0},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_read,count},19},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{queue_index_write,count},295},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{msg_store_write,count},0},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_write,count},121471},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_seek,time},57400},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{mnesia_ram_tx,count},100630},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{mnesia_disk_tx,count},885},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_read,bytes},703},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_write,bytes},699704424},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_seek,count},1511},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_sync,time},49093063},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_reopen,count},0},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_file_handle_open_attempt,time},72},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_read,time},260},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{io_write,time},16672039}],
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {set,2,16,16,8,80,48,
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> []},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {{[],[],[],[],[],[],
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> [{'rabbit@rabbitmq-ac-2.rabbitmq-ac-headless.rabbitmq.svc.cluster.local',
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> <0.224.0>}],
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> [],[],[],[],[],[],
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> [{'rabbit@rabbitmq-ac-0.rabbitmq-ac-headless.rabbitmq.svc.cluster.local',
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> <0.2157.6>}],
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> [],[]}}},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> undefined,5000,undefined}
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> ** Reason for termination ==
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> ** {{case_clause,[#Port<0.19>,#Port<0.281840>]},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> [{rabbit_net,dist_info,4,[{file,"rabbit_net.erl"},{line,353}]},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {rabbit_net,'-dist_info/0-lc$^1/1-1-',2,
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> [{file,"rabbit_net.erl"},{line,340}]},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {rabbit_mgmt_external_stats,emit_node_node_stats,1,
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> [{file,"rabbit_mgmt_external_stats.erl"},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {line,436}]},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {rabbit_mgmt_external_stats,handle_info,2,
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> [{file,"rabbit_mgmt_external_stats.erl"},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {line,410}]},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,695}]},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,771}]},
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0> {proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,226}]}]}
2022-10-12 04:06:49.829663+08:00 [error] <0.3856.0>
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> crasher:
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> initial call: rabbit_mgmt_external_stats:init/1
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> pid: <0.3856.0>
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> registered_name: rabbit_mgmt_external_stats
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> exception error: no case clause matching [#Port<0.19>,#Port<0.281840>]
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> in function rabbit_net:dist_info/4 (rabbit_net.erl, line 353)
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> in call from rabbit_net:'-dist_info/0-lc$^1/1-1-'/2 (rabbit_net.erl, line 340)
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> in call from rabbit_mgmt_external_stats:emit_node_node_stats/1 (rabbit_mgmt_external_stats.erl, line 436)
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> in call from rabbit_mgmt_external_stats:handle_info/2 (rabbit_mgmt_external_stats.erl, line 410)
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> in call from gen_server:try_dispatch/4 (gen_server.erl, line 695)
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> in call from gen_server:handle_msg/6 (gen_server.erl, line 771)
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> ancestors: [rabbit_mgmt_agent_sup,rabbit_mgmt_agent_sup_sup,<0.3852.0>]
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> message_queue_len: 0
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> messages: []
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> links: [<0.3855.0>]
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> dictionary: []
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> trap_exit: false
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> status: running
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> heap_size: 28690
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> stack_size: 29
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> reductions: 4795936325
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0> neighbours:
2022-10-12 04:06:49.831327+08:00 [error] <0.3856.0>
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> supervisor: {local,rabbit_mgmt_agent_sup}
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> errorContext: child_terminated
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> reason: {{case_clause,[#Port<0.19>,#Port<0.281840>]},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> [{rabbit_net,dist_info,4,[{file,"rabbit_net.erl"},{line,353}]},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {rabbit_net,'-dist_info/0-lc$^1/1-1-',2,
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> [{file,"rabbit_net.erl"},{line,340}]},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {rabbit_mgmt_external_stats,emit_node_node_stats,1,
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> [{file,"rabbit_mgmt_external_stats.erl"},{line,436}]},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {rabbit_mgmt_external_stats,handle_info,2,
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> [{file,"rabbit_mgmt_external_stats.erl"},{line,410}]},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,695}]},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,771}]},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {proc_lib,init_p_do_apply,3,
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> [{file,"proc_lib.erl"},{line,226}]}]}
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> offender: [{pid,<0.3856.0>},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {id,rabbit_mgmt_external_stats},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {mfargs,{rabbit_mgmt_external_stats,start_link,[]}},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {restart_type,permanent},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {significant,false},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {shutdown,5000},
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0> {child_type,worker}]
2022-10-12 04:06:49.832095+08:00 [error] <0.3855.0>
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> supervisor: {local,rabbit_mgmt_agent_sup}
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> errorContext: start_error
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> reason: {{case_clause,[#Port<0.19>,#Port<0.281840>]},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> [{rabbit_net,dist_info,4,[{file,"rabbit_net.erl"},{line,353}]},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {rabbit_net,'-dist_info/0-lc$^1/1-1-',2,
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> [{file,"rabbit_net.erl"},{line,340}]},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {rabbit_mgmt_external_stats,emit_node_node_stats,1,
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> [{file,"rabbit_mgmt_external_stats.erl"},{line,436}]},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {rabbit_mgmt_external_stats,init,1,
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> [{file,"rabbit_mgmt_external_stats.erl"},{line,401}]},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {gen_server,init_it,2,[{file,"gen_server.erl"},{line,423}]},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {gen_server,init_it,6,[{file,"gen_server.erl"},{line,390}]},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {proc_lib,init_p_do_apply,3,
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> [{file,"proc_lib.erl"},{line,226}]}]}
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> offender: [{pid,<0.3856.0>},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {id,rabbit_mgmt_external_stats},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {mfargs,{rabbit_mgmt_external_stats,start_link,[]}},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {restart_type,permanent},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {significant,false},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {shutdown,5000},
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0> {child_type,worker}]
2022-10-12 04:06:49.836245+08:00 [error] <0.3855.0>
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> crasher:
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> initial call: rabbit_mgmt_external_stats:init/1
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> pid: <0.27329.113>
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> registered_name: []
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> exception error: no case clause matching [#Port<0.19>,#Port<0.281840>]
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> in function rabbit_net:dist_info/4 (rabbit_net.erl, line 353)
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> in call from rabbit_net:'-dist_info/0-lc$^1/1-1-'/2 (rabbit_net.erl, line 340)
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> in call from rabbit_mgmt_external_stats:emit_node_node_stats/1 (rabbit_mgmt_external_stats.erl, line 436)
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> in call from rabbit_mgmt_external_stats:init/1 (rabbit_mgmt_external_stats.erl, line 401)
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> in call from gen_server:init_it/2 (gen_server.erl, line 423)
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> in call from gen_server:init_it/6 (gen_server.erl, line 390)
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> ancestors: [rabbit_mgmt_agent_sup,rabbit_mgmt_agent_sup_sup,<0.3852.0>]
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> message_queue_len: 0
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> messages: []
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> links: [<0.3855.0>]
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> dictionary: []
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> trap_exit: false
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> status: running
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> heap_size: 2586
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> stack_size: 29
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> reductions: 87707
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113> neighbours:
2022-10-12 04:06:49.836405+08:00 [error] <0.27329.113>

[faithfull]

@michaelklishin can you give me some suggest？

[michaelklishin]

@faithfull consider providing at least some details on the RabbitMQ version used, the environment you've observed this in, and so on. We do not guess in this community.

You are looking at #5496 which was addressed in #5534, which shipped in 3.11.x, 3.10.8 and 3.9.23 according to the dates and the change log.

[faithfull]

hi ,my rabbitmq version is 3.10.8. erlang 25.1.1 ，i have 3 rabbitmq node running on the k8s cluster.

[michaelklishin]

There is a very rare (at least I have no idea how to reproduce it) condition when a node has none or more than one distribution links at the time when the code expects one. Prior to #5496 we did not take
into account the "no values" case. Here you have more than one. Again, I'm not sure how to reproduce or what would be the right thing to do.

The outcome of this is that some node stats won't be available, not much else.

[michaelklishin]

We do not know how to reproduce it but have tried making the metric collector more defensive in #6127.