3.13.2: daily exception logged {timeout,{gen_server,call,[os_mon_sysinfo,get_mem_info]}}

[Faerylnahr]

Hi everybody,

I've installed RabbitMQ 3.13.2 on Erlang 26.2.5 on Windows about two weeks ago. Everything runs fine except that the RabbitMQ is always crashing at 00:16 in the morning with below message, almost every day. We currently have only 1 producer and 3 consumers with a message rate of approx. 60/s. Unfortunately I don't get the point why it crashes.

Maybe someone can point me into the right direction with this log excerpt:

2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> ** Generic server memsup terminating
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> ** Last message in was {'EXIT',<0.479800.0>,
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> {timeout,
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> {gen_server,call,
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> [os_mon_sysinfo,get_mem_info]}}}
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> ** When Server state == [{data,[{"Timeout",60000}]},
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> {items,{"Memory Usage",
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> [{"Allocated",13555761152},
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> {"Total",25769267200}]}},
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> {items,{"Worst Memory User",
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> [{"Pid",<0.622.0>},{"Memory",19130664}]}}]
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> ** Reason for termination ==
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> ** {timeout,{gen_server,call,[os_mon_sysinfo,get_mem_info]}}
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0>
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> crasher:
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> initial call: memsup:init/1
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> pid: <0.139.0>
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> registered_name: memsup
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> exception exit: {timeout,{gen_server,call,[os_mon_sysinfo,get_mem_info]}}
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> in function gen_server:handle_common_reply/8 (gen_server.erl, line 1226)
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> ancestors: [os_mon_sup,<0.135.0>]
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> message_queue_len: 0
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> messages: []
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> links: [<0.136.0>]
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> dictionary: []
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> trap_exit: true
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> status: running
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> heap_size: 6772
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> stack_size: 28
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> reductions: 71309969
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0> neighbours:
2024-06-03 00:15:26.612000+02:00 [error] <0.139.0>
2024-06-03 00:15:26.612000+02:00 [error] <0.136.0> supervisor: {local,os_mon_sup}
2024-06-03 00:15:26.612000+02:00 [error] <0.136.0> errorContext: child_terminated
2024-06-03 00:15:26.612000+02:00 [error] <0.136.0> reason: {timeout,{gen_server,call,[os_mon_sysinfo,get_mem_info]}}
2024-06-03 00:15:26.612000+02:00 [error] <0.136.0> offender: [{pid,<0.139.0>},
2024-06-03 00:15:26.612000+02:00 [error] <0.136.0> {id,memsup},
2024-06-03 00:15:26.612000+02:00 [error] <0.136.0> {mfargs,{memsup,start_link,[]}},
2024-06-03 00:15:26.612000+02:00 [error] <0.136.0> {restart_type,permanent},
2024-06-03 00:15:26.612000+02:00 [error] <0.136.0> {significant,false},
2024-06-03 00:15:26.612000+02:00 [error] <0.136.0> {shutdown,2000},
2024-06-03 00:15:26.612000+02:00 [error] <0.136.0> {child_type,worker}]

Thanks in advance! :)

[lukebakken]

Hello, thanks for using RabbitMQ.

There is NO RabbitMQ crash here. The Erlang VM on which RabbitMQ runs uses the word "crash" to mean what is usually called an "exception" in other programming languages and VMs.

You can ignore this message, it is due to a timeout in retrieving system information. My guess is that something else is consuming enough resources at that time of day to cause this particular operation to take longer than 5 seconds (the default timeout).

I would start by checking the Windows Event viewer, and perhaps disabling anti-virus. Maybe a system scan happens at midnight every night?

[lukebakken]

Just FYI, when RabbitMQ / Erlang starts on Windows, some child processes are also started:

I'm wondering if, in your environment, something is killing the win32sysinfo.exe process. That's the one that is queried to get disk and memory information, and, if not there, apparently seems to crash RabbitMQ.

[Faerylnahr]

Good point but if that's the case shouldn't be the amount of free disk space not visible at all? I've checked the task manager and the win32sysinfo.exe is still running.
Nevertheless I'm still trying to get the approvals for exporting the event logs 😆 Some kind of security scan is still my main suspect 🙄

[Faerylnahr]

Just a short update: our main suspect is currently the snapshot provider - as the server is provided as a vm. We'll now request to exclude this server from the snapshot provider - let's see if that helps.

[vaibhavballi]

@Faerylnahr

Did this issue got resolved? What was the root cause?

[michaelklishin]

The usual suspects are anti-virus software and too few cores available to a reasonably busy node. Both can block collection of certain metrics via external tools (there are very few of those metrics, even though they are available resources ones and thus pretty relevant).

[michaelklishin]

A very similar discussion (same version, same exception, same OS) #12293.