Raft log WAL process for the coordination system failed on boot , vesion:4.1.2

[lzz505750587]

Describe the bug

rabbitmq coordination starts failed after normal shutdown

Reproduction steps

can't reproduce

Expected behavior

rabbitmq start successful

Additional context

2025-08-15 16:59:50.554 [critical] <0.644.0> Stopping application 'sysmon_handler'
2025-08-15 16:59:50.557 [critical] <0.644.0> Stopping application 'osiris'
2025-08-15 16:59:50.560 [critical] <0.644.0> Stopping application 'mnesia'
2025-08-15 16:59:50.565 [info] <0.644.0> Successfully stopped RabbitMQ and its dependencies
2025-08-15 16:59:50.566 [info] <0.644.0> Halting Erlang VM with the following applications:, khepri_mnesia_migration, horus, erts, observer_cli, redbug, stdout_formatter, aten, amqp10_common, cowlib, inets, systemd, enough, seshat, gen_batch_server, cuttlefish, credentials_obfuscation, recon, ranch, thoas, runtime_tools, xmerl, tools, syntax_tools, ssl, public_key, asn1, crypto, compiler, sasl, stdlib, kernel,
2025-08-15 17:01:53.120 [notice] <0.250.0> Logging: configured log handlers are now ACTIVE
2025-08-15 17:01:53.130 [info] <0.250.0> ra: starting system coordination
2025-08-15 17:01:53.131 [info] <0.250.0> starting Ra system: coordination in directory: /var/lib/rabbitmq/mnesia/rabbit@zrabbit_192_168_32_75/coordination/rabbit@zrabbit_192_168_32_75
2025-08-15 17:01:53.139 [info] <0.258.0> ra_coordination_log_ets: in system coordination initialising. Mem table opts: [set,{write_concurrency,auto},public,{compressed,false}]
2025-08-15 17:01:53.212 [info] <0.264.0> ra system 'coordination' running pre init for 1 registered servers
2025-08-15 17:01:53.237 [info] <0.265.0> ra: meta data store initialised for system coordination. 1 record(s) recovered
2025-08-15 17:01:53.251 [notice] <0.270.0> WAL: ra_coordination_log_wal init, mem-tables table name: ra_coordination_log_open_mem_tables
2025-08-15 17:01:53.260 [error] <0.269.0>     supervisor: {<0.269.0>,ra_log_wal_sup}, errorContext: start_error, reason: function_clause, offender: [{pid,undefined}, {id,ra_log_wal}, {mfargs,{ra_log_wal,start_link, [#{garbage_collect => false, min_heap_size => 233, min_bin_vheap_size => 46422, name => ra_coordination_log_wal, dir =>, "/var/lib/rabbitmq/mnesia/rabbit@zrabbit_192_168_32_75/coordination/rabbit@zrabbit_192_168_32_75", hibernate_after => undefined, names =>, #{directory =>, ra_coordination_directory, directory_rev =>, ra_coordination_directory_reverse, log_ets => ra_coordination_log_ets, log_meta =>, ra_coordination_log_meta, log_sup => ra_coordination_log_sup, open_mem_tbls =>, ra_coordination_log_open_mem_tables, segment_writer =>, ra_coordination_segment_writer, server_sup =>, ra_coordination_server_sup_sup, wal => ra_coordination_log_wal, wal_sup =>, ra_coordination_log_wal_sup}, segment_writer =>, ra_coordination_segment_writer, compute_checksums => true, max_batch_size => 4096, max_entries => undefined, max_size_bytes => 64000000, pre_allocate => false, sync_method => datasync, write_strategy => default}]}}, {restart_type,permanent}, {significant,false}, {shutdown,5000}, {child_type,worker}],
2025-08-15 17:01:53.261 [error] <0.263.0>     supervisor: {local,ra_coordination_log_sup}, errorContext: start_error, reason: {shutdown,{failed_to_start_child,ra_log_wal,function_clause}}, offender: [{pid,undefined}, {id,ra_log_wal_sup}, {mfargs, {ra_log_wal_sup,start_link, [#{garbage_collect => false,min_heap_size => 233, min_bin_vheap_size => 46422, name => ra_coordination_log_wal, dir =>, "/var/lib/rabbitmq/mnesia/rabbit@zrabbit_192_168_32_75/coordination/rabbit@zrabbit_192_168_32_75", hibernate_after => undefined, names =>, #{directory => ra_coordination_directory, directory_rev =>, ra_coordination_directory_reverse, log_ets => ra_coordination_log_ets, log_meta => ra_coordination_log_meta, log_sup => ra_coordination_log_sup, open_mem_tbls =>, ra_coordination_log_open_mem_tables, segment_writer =>, ra_coordination_segment_writer, server_sup => ra_coordination_server_sup_sup, wal => ra_coordination_log_wal, wal_sup => ra_coordination_log_wal_sup}, segment_writer => ra_coordination_segment_writer, compute_checksums => true,max_batch_size => 4096, max_entries => undefined,max_size_bytes => 64000000, pre_allocate => false,sync_method => datasync, write_strategy => default}]}}, {restart_type,permanent}, {significant,false}, {shutdown,infinity}, {child_type,supervisor}],
2025-08-15 17:01:53.260 [error] <0.270.0>   crasher:, initial call: ra_log_wal:init/1, pid: <0.270.0>, registered_name: [], exception exit: function_clause, in function  gen_batch_server:init_it/6 (src/gen_batch_server.erl, line 174), ancestors: [<0.269.0>,ra_coordination_log_sup,<0.257.0>,ra_systems_sup, ra_sup,<0.214.0>], message_queue_len: 0, messages: [], links: [<0.269.0>], dictionary: [], trap_exit: true, status: running, heap_size: 2586, stack_size: 28, reductions: 4591, neighbours:,
2025-08-15 17:01:53.443 [error] <0.257.0>     supervisor: {<0.257.0>,ra_system_sup}, errorContext: start_error, reason: {shutdown, {failed_to_start_child,ra_log_wal_sup, {shutdown, {failed_to_start_child,ra_log_wal,function_clause}}}}, offender: [{pid,undefined}, {id,ra_log_sup}, {mfargs,{ra_log_sup,start_link, [#{message_queue_data => off_heap, name => coordination, names =>, #{directory =>, ra_coordination_directory, directory_rev =>, ra_coordination_directory_reverse, log_ets => ra_coordination_log_ets, log_meta =>, ra_coordination_log_meta, log_sup => ra_coordination_log_sup, open_mem_tbls =>, ra_coordination_log_open_mem_tables, segment_writer =>, ra_coordination_segment_writer, server_sup =>, ra_coordination_server_sup_sup, wal => ra_coordination_log_wal, wal_sup =>, ra_coordination_log_wal_sup}, data_dir =>, "/var/lib/rabbitmq/mnesia/rabbit@zrabbit_192_168_32_75/coordination/rabbit@zrabbit_192_168_32_75", wal_max_size_bytes => 64000000, wal_max_batch_size => 4096, wal_max_entries => undefined, compress_mem_tables => false, default_max_append_entries_rpc_batch_size =>, 128, segment_compute_checksums => true, server_min_bin_vheap_size => 46422, wal_compute_checksums => true, wal_min_bin_vheap_size => 46422, wal_data_dir =>, "/var/lib/rabbitmq/mnesia/rabbit@zrabbit_192_168_32_75/coordination/rabbit@zrabbit_192_168_32_75", segment_max_entries => 4096, segment_max_pending => 1024, segment_max_size_bytes => 64000000, wal_write_strategy => default, wal_sync_method => datasync, wal_garbage_collect => false, wal_pre_allocate => false, wal_min_heap_size => 233, server_min_heap_size => 233, default_max_pipeline_count => 4096, snapshot_chunk_size => 1000000, receive_snapshot_timeout => 30000, low_priority_commands_flush_size => 16, low_priority_commands_in_memory_size =>, 16, machine_upgrade_strategy => all}]}}, {restart_type,permanent}, {significant,false}, {shutdown,infinity}, {child_type,supervisor}],
2025-08-15 17:01:53.444 [error] <0.250.0> Failed to start Ra system "coordination": {error, {{shutdown, {failed_to_start_child, ra_log_sup, {shutdown, {failed_to_start_child, ra_log_wal_sup, {shutdown, {failed_to_start_child, ra_log_wal, function_clause}}}}}}, {child,undefined,coordination, {ra_system_sup,start_link, [#{message_queue_data =>, off_heap, name => coordination, names =>, #{directory =>, ra_coordination_directory, directory_rev =>, ra_coordination_directory_reverse, log_ets =>, ra_coordination_log_ets, log_meta =>, ra_coordination_log_meta, log_sup =>, ra_coordination_log_sup, open_mem_tbls =>, ra_coordination_log_open_mem_tables, segment_writer =>, ra_coordination_segment_writer, server_sup =>, ra_coordination_server_sup_sup, wal =>, ra_coordination_log_wal, wal_sup =>, ra_coordination_log_wal_sup}, data_dir =>, "/var/lib/rabbitmq/mnesia/rabbit@zrabbit_192_168_32_75/coordination/rabbit@zrabbit_192_168_32_75", wal_max_size_bytes =>, 64000000, wal_max_batch_size => 4096, wal_max_entries => undefined, compress_mem_tables => false, default_max_append_entries_rpc_batch_size =>, 128, segment_compute_checksums =>, true, server_min_bin_vheap_size =>, 46422, wal_compute_checksums => true, wal_min_bin_vheap_size =>, 46422, wal_data_dir =>, "/var/lib/rabbitmq/mnesia/rabbit@zrabbit_192_168_32_75/coordination/rabbit@zrabbit_192_168_32_75", segment_max_entries => 4096, segment_max_pending => 1024, segment_max_size_bytes =>, 64000000, wal_write_strategy => default, wal_sync_method => datasync, wal_garbage_collect => false, wal_pre_allocate => false, wal_min_heap_size => 233, server_min_heap_size => 233, default_max_pipeline_count =>, 4096, snapshot_chunk_size =>, 1000000, receive_snapshot_timeout =>, 30000, low_priority_commands_flush_size =>, 16, low_priority_commands_in_memory_size =>, 16, machine_upgrade_strategy =>, all}]}, permanent,false,infinity, supervisor, [ra_system_sup]}}}
2025-08-15 17:01:53.459 [error] <0.250.0> , BOOT FAILED, ===========, Error during startup: {error, {{shutdown, {failed_to_start_child,ra_log_sup, {shutdown, {failed_to_start_child,ra_log_wal_sup, {shutdown, {failed_to_start_child,ra_log_wal, function_clause}}}}}}, {child,undefined,coordination, {ra_system_sup,start_link, [#{message_queue_data => off_heap, name => coordination, names =>, #{directory => ra_coordination_directory, directory_rev =>, ra_coordination_directory_reverse, log_ets => ra_coordination_log_ets, log_meta => ra_coordination_log_meta, log_sup => ra_coordination_log_sup, open_mem_tbls =>, ra_coordination_log_open_mem_tables, segment_writer =>, ra_coordination_segment_writer, server_sup => ra_coordination_server_sup_sup, wal => ra_coordination_log_wal, wal_sup => ra_coordination_log_wal_sup}, data_dir =>, "/var/lib/rabbitmq/mnesia/rabbit@zrabbit_192_168_32_75/coordination/rabbit@zrabbit_192_168_32_75", wal_max_size_bytes => 64000000, wal_max_batch_size => 4096, wal_max_entries => undefined, compress_mem_tables => false, default_max_append_entries_rpc_batch_size => 128, segment_compute_checksums => true, server_min_bin_vheap_size => 46422, wal_compute_checksums => true, wal_min_bin_vheap_size => 46422, wal_data_dir =>, "/var/lib/rabbitmq/mnesia/rabbit@zrabbit_192_168_32_75/coordination/rabbit@zrabbit_192_168_32_75", segment_max_entries => 4096, segment_max_pending => 1024, segment_max_size_bytes => 64000000, wal_write_strategy => default, wal_sync_method => datasync, wal_garbage_collect => false, wal_pre_allocate => false, wal_min_heap_size => 233, server_min_heap_size => 233, default_max_pipeline_count => 4096, snapshot_chunk_size => 1000000, receive_snapshot_timeout => 30000, low_priority_commands_flush_size => 16, low_priority_commands_in_memory_size => 16, machine_upgrade_strategy => all}]}, permanent,false,infinity,supervisor, [ra_system_sup]}}},
2025-08-15 17:01:54.484 [error] <0.250.0> Failed to boot,running NeedReset:false, peer:false, delete_mnesia_when_start_fails:true "/var/lib/rabbitmq/mnesia" home_dir:"/var/lib/rabbitmq".

[michaelklishin]

@lzz505750587 you seem to be the only one who could reproduce this Ra log WAL process exception.

There aren't any details besides a function_clause in the trace but it immediately makes me think of #10052 and its duplicates: if the node's data directory is not readable or writeable, you can fun into a lot of unexpected storage-related exceptions or failed assertions, and the Raft log storage is one of candidates.

We cannot suggest much with this log snippet alone. We do not guess in this community.