[MDEV-36309] The log was only scanned up to *, while the current LSN at the time of the latest checkpoint * was * - Jira

Details

Type: Bug
Status: Needs Feedback (View Workflow)
Priority: Major
Resolution: Unresolved
Affects Version/s: 10.11.10
Fix Version/s: None
Component/s: Storage Engine - InnoDB
Labels:
None
Environment:
Cloudlinux 9.4

Description

Hello,

Since updating to 10.11.10, we haven't hit `Missing FILE_CHECKPOINT` for a while, but we've run into a redo log issue jumping LSN after something making it hit max_connection count and getting signal 11:

Mar 14 08:42:16 uk-fast-web1732 mariadbd[1230235]: 2025-03-14  8:42:16 0 [Note] InnoDB: Truncated .//undo001

Mar 14 08:42:16 uk-fast-web1732 mariadbd[1230235]: 2025-03-14  8:42:16 0 [Note] InnoDB: Starting to truncate .//undo002

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: 250314  8:56:14 [ERROR] mysqld got signal 11 ;

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: Sorry, we probably made a mistake, and this is a bug.

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: Your assistance in bug reporting will enable us to fix this for the next release.

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: We will try our best to scrape up some info that will hopefully help

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: diagnose the problem, but since we have already crashed,

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: something is definitely wrong and this may fail.

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: Server version: 10.11.10-MariaDB source revision: 3d0fb150289716ca75cd64d62823cf715ee47646

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: key_buffer_size=2147483648

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: read_buffer_size=4194304

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: max_used_connections=2001

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: max_threads=2002

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: thread_count=2001

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: It is possible that mysqld could use up to

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 18551062 K  bytes of memory

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: Hope that's ok; if not, decrease some variables in the equation.

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: Thread pointer: 0x7ef22ee3ed58

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: Attempting backtrace. You can use the following information to find out

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: where mysqld died. If you see no messages after this, something went

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: terribly wrong...

Mar 14 08:56:14 uk-fast-web1732 mariadbd[1230235]: 2025-03-14  8:56:14 0 [Note] /srv/mariadb101110/usr/sbin/mariadbd (initiated by: unknown): Normal shutdown

Mar 14 08:56:20 uk-fast-web1732 mariadbd[1230235]: stack_bottom = 0x7ef910c00000 thread_stack 0x49000

Mar 14 08:56:32 uk-fast-web1732 mariadbd[1230235]: /srv/mariadb101110/usr/sbin/mariadbd(my_print_stacktrace+0x2e)[0x557b57fcebee]

Mar 14 08:56:35 uk-fast-web1732 mariadbd[1230235]: 2025-03-14  8:56:35 0 [Warning] /srv/mariadb101110/usr/sbin/mariadbd: Thread 276545663 (user : 'u279') did not exit

Mar 14 08:56:35 uk-fast-web1732 mariadbd[1230235]: 2025-03-14  8:56:35 0 [Warning] /srv/mariadb101110/usr/sbin/mariadbd: Thread 276545658 (user : 'u585') did not exit

Mar 14 08:56:35 uk-fast-web1732 mariadbd[1230235]: 2025-03-14  8:56:35 0 [Warning] /srv/mariadb101110/usr/sbin/mariadbd: Thread 276545650 (user : 'u196) did not exit

Mar 14 08:56:35 uk-fast-web1732 mariadbd[1230235]: 2025-03-14  8:56:35 0 [Warning] /srv/mariadb101110/usr/sbin/mariadbd: Thread 276545644 (user : 'u346') did not exit

.....

Mar 14 08:56:36 uk-fast-web1732 mariadbd[1230235]: /srv/mariadb101110/usr/sbin/mariadbd(handle_fatal_signal+0x478)[0x557b57a938d8]

Mar 14 08:56:43 uk-fast-web1732 mariadbd[1230235]: /lib64/libc.so.6(+0x3e6f0)[0x7f111863e6f0]

Mar 14 08:58:12 uk-fast-web1732 systemd[1]: mariadb.service: Main process exited, code=dumped, status=11/SEGV

Mar 14 08:58:12 uk-fast-web1732 systemd[1]: mariadb.service: Failed with result 'core-dump'.

Mar 14 08:58:17 uk-fast-web1732 systemd[1]: mariadb.service: Scheduled restart job, restart counter is at 1.

Mar 14 08:58:17 uk-fast-web1732 systemd[1]: Stopped MariaDB database server.

Mar 14 08:58:17 uk-fast-web1732 systemd[1]: Starting MariaDB database server...

Mar 14 08:58:18 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:18 0 [ERROR] feedback plugin: failed to retrieve the MAC address

Mar 14 08:58:18 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:18 0 [Note] Starting MariaDB 10.11.10-MariaDB source revision 3d0fb150289716ca75cd64d62823cf715ee47646 server_uid unknown as process 2153522

Mar 14 08:58:18 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:18 0 [Note] RocksDB: 2 column families found

Mar 14 08:58:18 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:18 0 [Note] RocksDB: Column Families at start:

Mar 14 08:58:18 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:18 0 [Note]   cf=default

Mar 14 08:58:18 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:18 0 [Note]     write_buffer_size=67108864

Mar 14 08:58:18 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:18 0 [Note]     target_file_size_base=67108864

Mar 14 08:58:18 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:18 0 [Note]   cf=__system__

Mar 14 08:58:18 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:18 0 [Note]     write_buffer_size=67108864

Mar 14 08:58:18 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:18 0 [Note]     target_file_size_base=67108864

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:46 0 [Note] RocksDB: Table_store: loaded DDL data for 751 tables

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:46 0 [Note] RocksDB: global statistics using get_sched_indexer_t indexer

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:46 0 [Note] MyRocks storage engine plugin has been successfully initialized.

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:46 0 [Note] mariadbd: Aria engine: starting recovery

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: tables to flush: 6 5 4 3 2 1 0

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]:  (0.0 seconds);

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:46 0 [Note] mariadbd: Aria engine: recovery done

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:46 0 [Note] InnoDB: Compressed tables use zlib 1.2.11

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:46 0 [Note] InnoDB: Number of transaction pools: 1

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:46 0 [Note] InnoDB: Using AVX512 instructions

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:46 0 [Note] InnoDB: Using Linux native AIO

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:46 0 [Note] InnoDB: Initializing buffer pool, total size = 50.199GiB, chunk size = 0.784GiB

Mar 14 08:58:46 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:46 0 [Note] InnoDB: Completed initialization of buffer pool

Mar 14 08:58:47 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:47 0 [Note] InnoDB: Buffered log writes (block size=4096 bytes)

Mar 14 08:58:47 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:47 0 [Note] InnoDB: Resetting space id's in the doublewrite buffer

Mar 14 08:58:47 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:47 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=202761402158754

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] InnoDB: End of log at LSN=202762386894310

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [ERROR] InnoDB: The log was only scanned up to 202762386894310, while the current LSN at the time of the latest checkpoint 202761402158754 was 202763082156746!

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] InnoDB: Starting shutdown...

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] Plugin 'FEEDBACK' is disabled.

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'cgroup' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_CFSTATS' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_DBSTATS' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_PERF_CONTEXT' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_PERF_CONTEXT_GLOBAL' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_CF_OPTIONS' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_COMPACTION_STATS' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_GLOBAL_INFO' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_DDL' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_SST_PROPS' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_INDEX_FILE_MAP' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_LOCKS' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_TRX' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] mariadbd: Plugin 'ROCKSDB_DEADLOCK' already installed

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [ERROR] Unknown/unsupported storage engine: InnoDB

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [ERROR] Aborting

Seems the most important part is the following:

Mar 14 08:58:47 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:47 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=202761402158754

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [Note] InnoDB: End of log at LSN=202762386894310

Mar 14 08:58:49 uk-fast-web1732 mariadbd[2153522]: 2025-03-14  8:58:49 0 [ERROR] InnoDB: The log was only scanned up to 202762386894310, while the current LSN at the time of the latest checkpoint 202761402158754 was 202763082156746!

After this only innodb_force_recovery=6 got instance started. We had dump and reimport on a fresh datadir to continue operations. Unfortunately, a lot of tables were had missing data due to:

Mar 14 09:13:38 uk-fast-web1732 mariadbd[2602182]: 2025-03-14  9:13:38 117 [ERROR] InnoDB: We detected index corruption in an InnoDB type table. You have to dump + drop + reimport the table or, in a case of widespread corruption, dump all InnoDB tables and recreate the whole tablespace. If the mariadbd server crashes after the startup or when you dump the tables. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.

Three days prior, another server ran into a similar issue as well, hit connection limit and got SIG 11'd :

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: 250311  7:41:50 [ERROR] mysqld got signal 11 ;

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: Sorry, we probably made a mistake, and this is a bug.

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: Your assistance in bug reporting will enable us to fix this for the next release.

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: We will try our best to scrape up some info that will hopefully help

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: diagnose the problem, but since we have already crashed,

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: something is definitely wrong and this may fail.

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: Server version: 10.11.10-MariaDB source revision: 3d0fb150289716ca75cd64d62823cf715ee47646

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: key_buffer_size=2147483648

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: read_buffer_size=4194304

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: max_used_connections=2001

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: max_threads=2002

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: thread_count=2001

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: It is possible that mysqld could use up to

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 18551062 K  bytes of memory

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: Hope that's ok; if not, decrease some variables in the equation.

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: Thread pointer: 0x7f6bfd708d18

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: Attempting backtrace. You can use the following information to find out

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: where mysqld died. If you see no messages after this, something went

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: terribly wrong...

Mar 11 07:41:50 in-mum-web1118 kernel: [2116370.061280] traps: mariadbd[3376701] general protection fault ip:55de9468d4d9 sp:7f7108bedc30 error:0 in mariadbd[55de93f77000+1776000]

Mar 11 07:41:50 in-mum-web1118 mariadbd[6396]: stack_bottom = 0x7f7530943000 thread_stack 0x49000

Mar 11 07:41:50 in-mum-web1118 kernel: traps: mariadbd[3376701] general protection fault ip:55de9468d4d9 sp:7f7108bedc30 error:0 in mariadbd[55de93f77000+1776000]

Mar 11 07:42:15 in-mum-web1118 systemd-coredump[3461186]: Process 6396 (mariadbd) of user 991 dumped core.#012#012Stack trace of thread 3376701:#012#0  0x000055de9468d4d9 _Z16buf_page_get_low9page_id_tm14rw_lock_type_tP11buf_block_tmP5mtr_tP7dberr_tb (/srv/mariadb101110/usr/sbin/mariadbd)#012#012Stack trace of thread 13030:#012#0  0x00007f938b83c41d n/a (n/a)

Mar 11 07:42:35 in-mum-web1118 systemd[1]: mariadb.service: Main process exited, code=killed, status=11/SEGV

Mar 11 07:42:35 in-mum-web1118 systemd[1]: mariadb.service: Failed with result 'signal'.

Mar 11 07:42:40 in-mum-web1118 systemd[1]: mariadb.service: Service RestartSec=5s expired, scheduling restart.

Mar 11 07:42:40 in-mum-web1118 systemd[1]: mariadb.service: Scheduled restart job, restart counter is at 1.

Mar 11 07:42:41 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:42:41 0 [ERROR] feedback plugin: failed to retrieve the MAC address

Mar 11 07:42:41 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:42:41 0 [Note] Starting MariaDB 10.11.10-MariaDB source revision 3d0fb150289716ca75cd64d62823cf715ee47646 server_uid unknown as process 3491886

Mar 11 07:42:41 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:42:41 0 [Note] RocksDB: 2 column families found

Mar 11 07:42:41 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:42:41 0 [Note] RocksDB: Column Families at start:

Mar 11 07:42:41 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:42:41 0 [Note]   cf=default

Mar 11 07:42:41 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:42:41 0 [Note]     write_buffer_size=67108864

Mar 11 07:42:41 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:42:41 0 [Note]     target_file_size_base=67108864

Mar 11 07:42:41 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:42:41 0 [Note]   cf=__system__

Mar 11 07:42:41 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:42:41 0 [Note]     write_buffer_size=67108864

Mar 11 07:42:41 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:42:41 0 [Note]     target_file_size_base=67108864

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] RocksDB: Table_store: loaded DDL data for 301 tables

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] RocksDB: global statistics using get_sched_indexer_t indexer

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] MyRocks storage engine plugin has been successfully initialized.

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] mariadbd: Aria engine: starting recovery

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: recovered pages: 0% 10% 21% 32% 43% 54% 65% 75% 86% 100% (0.0 seconds); tables to flush: 5 4 3 2 1 0

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: (0.0 seconds);

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] mariadbd: Aria engine: recovery done

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] InnoDB: Compressed tables use zlib 1.2.11

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] InnoDB: Number of transaction pools: 1

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] InnoDB: Using Linux native AIO

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] InnoDB: Initializing buffer pool, total size = 50.300GiB, chunk size = 0.786GiB

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] InnoDB: Completed initialization of buffer pool

Mar 11 07:44:23 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:23 0 [Note] InnoDB: Buffered log writes (block size=4096 bytes)

Mar 11 07:44:24 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:24 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=468213467786054

Mar 11 07:44:28 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:28 0 [Note] InnoDB: End of log at LSN=468215159901757

Mar 11 07:44:28 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:28 0 [ERROR] InnoDB: The log was only scanned up to 468215159901757, while the current LSN at the time of the latest checkpoint 468213467786054 was 468215228276818!

Mar 11 07:44:28 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:28 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error

Mar 11 07:44:28 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:28 0 [Note] InnoDB: Starting shutdown...

Mar 11 07:44:28 in-mum-web1118 mariadbd[3491886]: 2025-03-11  7:44:28 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.

Do you have any ideas? Was there a way to recover them without data loss? We have retained datadir of web1732 if there is anything you would like us to check. Thanks.

Regards,
Arnas

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

web1118.png
188 kB
2025-03-17 16:13
web1732.png
57 kB
2025-03-17 16:18
web1792.png
120 kB
2025-03-17 16:25

Activity

Ascending order - Click to sort in descending order

Marko Mäkelä added a comment - 5 days ago

Based on this output, it seems to me that the write-ahead log file ib_logfile0 of the server is corrupted. Several months ago, we had this happen for a support customer. Then the cause was a proprietary file system that would apparently lose some writes. They provided got strace output from mariadbd and mariadb-backup --backup to prove that all log was being written correctly, but backup would occasionally read back long sequences of NUL bytes. Also MDEV-35791 and MDEV-35334 may have their root cause outside MariaDB Server.

To help us start with the analysis, can you please dump the log file header as well as specify the file size, so that we can know at which file offset the log checkpoint as well as the unexpected end of the log occur?

od -Ax -t x1 -N 0x3000 ib_logfile0

wc -c ib_logfile0

Actual record payload is between file offsets 0x3000 and the end of the file.

Marko Mäkelä added a comment - 5 days ago Based on this output, it seems to me that the write-ahead log file ib_logfile0 of the server is corrupted. Several months ago, we had this happen for a support customer. Then the cause was a proprietary file system that would apparently lose some writes. They provided got strace output from mariadbd and mariadb-backup --backup to prove that all log was being written correctly, but backup would occasionally read back long sequences of NUL bytes. Also MDEV-35791 and MDEV-35334 may have their root cause outside MariaDB Server. To help us start with the analysis, can you please dump the log file header as well as specify the file size, so that we can know at which file offset the log checkpoint as well as the unexpected end of the log occur? od -Ax -t x1 -N 0x3000 ib_logfile0 wc -c ib_logfile0 Actual record payload is between file offsets 0x3000 and the end of the file.

Arnas Klova added a comment - 5 days ago

Hey Marko,

For the record we're using regular ext4 file system.

Here's the info you've requested:

$ od -Ax -t x1 -N 0x3000 ib_logfile0

000000 50 68 79 73 00 00 00 00 00 00 00 00 00 00 b6 ee

000010 4d 61 72 69 61 44 42 20 31 30 2e 31 31 2e 38 00

000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

0001f0 00 00 00 00 00 00 00 00 00 00 00 00 ac 0c da d8

000200 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

001000 00 00 b8 69 0e 71 46 f5 00 00 b8 69 74 e3 df 97

001010 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

001030 00 00 00 00 00 00 00 00 00 00 00 00 3a 53 a9 c4

001040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

002000 00 00 b8 69 11 59 8e a2 00 00 b8 69 75 7b 6d 42

002010 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

002030 00 00 00 00 00 00 00 00 00 00 00 00 31 da 71 61

002040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

$ wc -c ib_logfile0

2147483648 ib_logfile0

Arnas Klova added a comment - 5 days ago Hey Marko, For the record we're using regular ext4 file system. Here's the info you've requested: $ od -Ax -t x1 -N 0x3000 ib_logfile0 000000 50 68 79 73 00 00 00 00 00 00 00 00 00 00 b6 ee 000010 4d 61 72 69 61 44 42 20 31 30 2e 31 31 2e 38 00 000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 * 0001f0 00 00 00 00 00 00 00 00 00 00 00 00 ac 0c da d8 000200 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 * 001000 00 00 b8 69 0e 71 46 f5 00 00 b8 69 74 e3 df 97 001010 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 * 001030 00 00 00 00 00 00 00 00 00 00 00 00 3a 53 a9 c4 001040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 * 002000 00 00 b8 69 11 59 8e a2 00 00 b8 69 75 7b 6d 42 002010 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 * 002030 00 00 00 00 00 00 00 00 00 00 00 00 31 da 71 61 002040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 * 003000 $ wc -c ib_logfile0 2147483648 ib_logfile0

Marko Mäkelä added a comment - 5 days ago

Thank you. It looks like the file offset 0x3000 corresponds to the LSN 0xb6ee. The latest checkpoint LSN is 0xb86911598ea2 (202761402158754) and the end of the log when that checkpoint was created was at LSN 202763082100034. The error message said 202763082156746, though. The error message also said that the log was only successfully read up to the LSN 202762386894310 (0xb8694c0b6de6). The file offset corresponding to that should be
(202762386894310 - 0xb6ee + 12288) % (2147483648 - 12288) = 0x113276f8. The file offsets corresponding to the checkpoint LSN and the "checkpoint end LSN" are 0x568067b4 and 0x3aa353dc, respectively. It would be interesting to see a section of the log near where the parsing failed:

od -Ax -t x1 -j 0x11327600 -N 0x400 ib_logfile0

Potentially, the tail of the circular redo log might have overwritten its head and thus made the database unrecoverable. Were there ever any warnings about that in the server error log? I see that the difference between the checkpoint LSN and the "checkpoint end" LSN is over 0x64000000 bytes, and the log file size is only 0x80000000 bytes (innodb_log_file_size=2g). We don’t know the server’s log_sys.write_lsn at the time it had been killed.

Marko Mäkelä added a comment - 5 days ago Thank you. It looks like the file offset 0x3000 corresponds to the LSN 0xb6ee. The latest checkpoint LSN is 0xb86911598ea2 (202761402158754) and the end of the log when that checkpoint was created was at LSN 202763082100034. The error message said 202763082156746, though. The error message also said that the log was only successfully read up to the LSN 202762386894310 (0xb8694c0b6de6). The file offset corresponding to that should be (202762386894310 - 0xb6ee + 12288) % (2147483648 - 12288) = 0x113276f8. The file offsets corresponding to the checkpoint LSN and the "checkpoint end LSN" are 0x568067b4 and 0x3aa353dc, respectively. It would be interesting to see a section of the log near where the parsing failed: od -Ax -t x1 -j 0x11327600 -N 0x400 ib_logfile0 Potentially, the tail of the circular redo log might have overwritten its head and thus made the database unrecoverable. Were there ever any warnings about that in the server error log? I see that the difference between the checkpoint LSN and the "checkpoint end" LSN is over 0x64000000 bytes, and the log file size is only 0x80000000 bytes ( innodb_log_file_size=2g ). We don’t know the server’s log_sys.write_lsn at the time it had been killed.

Arnas Klova added a comment - 5 days ago

Hey Marko,

Thanks for looking into this. Here's the info you've requested:

$ od -Ax -t x1 -j 0x11327600 -N 0x400 ib_logfile0

11327600 33 5f 61 6e 74 68 6f 6e 79 2f 77 70 5f 61 63 74

11327610 69 6f 6e 73 63 68 65 64 75 6c 65 72 5f 63 6c 61

11327620 69 6d 73 2e 69 62 64 b0 26 c2 9d b6 00 2e 2f 75

11327630 37 38 30 30 38 34 34 35 36 5f 75 59 6b 68 64 2f

11327640 77 70 5f 61 63 74 69 6f 6e 73 63 68 65 64 75 6c

11327650 65 72 5f 63 6c 61 69 6d 73 2e 69 62 64 b0 1d cb

11327660 ca 06 00 2e 2f 75 37 38 30 30 38 34 34 35 36 5f

11327670 56 75 6b 66 32 2f 77 70 5f 65 5f 73 75 62 6d 69

11327680 73 73 69 6f 6e 73 2e 69 62 64 b0 24 c6 1b 57 00

11327690 2e 2f 75 33 37 33 33 34 33 34 36 31 5f 67 79 44

113276a0 53 31 2f 77 70 5f 61 63 74 69 6f 6e 73 63 68 65

113276b0 64 75 6c 65 72 5f 6c 6f 67 73 2e 69 62 64 b0 1a

113276c0 c6 21 2c 00 2e 2f 75 33 36 32 35 39 33 30 38 35

113276d0 5f 4a 35 56 7a 77 2f 77 70 5f 69 74 73 65 63 5f

113276e0 6c 6f 67 73 2e 69 62 64 fa 00 00 00 00 b8 68 e2

113276f0 d1 bf 3b 00 a1 bf c9 d5 b0 2a cb b5 65 00 2e 2f

11327700 75 31 34 37 39 35 34 31 31 31 5f 74 72 76 6c 62

11327710 79 2f 74 72 6c 6c 69 5f 61 63 74 69 6f 6e 73 63

11327720 68 65 64 75 6c 65 72 5f 63 6c 61 69 6d 73 2e 69

11327730 62 64 b0 2b cb b5 64 00 2e 2f 75 31 34 37 39 35

11327740 34 31 31 31 5f 74 72 76 6c 62 79 2f 74 72 6c 6c

11327750 69 5f 61 63 74 69 6f 6e 73 63 68 65 64 75 6c 65

11327760 72 5f 61 63 74 69 6f 6e 73 2e 69 62 64 b0 16 cc

11327770 44 d5 00 2e 2f 75 39 37 33 31 36 37 34 36 31 5f

11327780 38 57 5a 62 69 2f 61 66 62 77 5f 6d 61 69 6c 2e

11327790 69 62 64 b0 16 c6 2f c5 00 2e 2f 75 33 34 36 36

113277a0 32 30 33 39 33 5f 73 77 61 6e 2f 77 70 5f 6f 70

113277b0 74 69 6f 6e 73 2e 69 62 64 b0 1d c6 2a 33 00 2e

113277c0 2f 75 39 38 32 32 39 39 39 36 33 5f 47 55 35 61

113277d0 65 2f 77 70 5f 61 75 74 6f 6d 61 74 69 63 5f 6c

113277e0 6f 67 2e 69 62 64 b0 1d cd 6c 81 00 2e 2f 75 33

113277f0 32 32 33 31 33 33 30 36 5f 6d 69 67 72 61 74 69

11327800 6f 6e 31 31 2f 77 70 5f 6f 70 74 69 6f 6e 73 2e

11327810 69 62 64 b0 26 c0 41 be 00 2e 2f 75 37 38 30 30

11327820 38 34 34 35 36 5f 44 79 54 4f 6b 2f 77 70 5f 61

11327830 63 74 69 6f 6e 73 63 68 65 64 75 6c 65 72 5f 63

11327840 6c 61 69 6d 73 2e 69 62 64 b0 27 cd 96 56 00 2e

11327850 2f 75 33 32 32 33 31 33 33 30 36 5f 6d 69 67 72

11327860 61 74 69 6f 6e 33 2f 77 70 5f 72 61 6e 6b 5f 6d

11327870 61 74 68 5f 34 30 34 5f 6c 6f 67 73 2e 69 62 64

11327880 b0 18 c2 7a 57 00 2e 2f 75 32 37 39 36 37 37 33

11327890 33 34 5f 56 62 56 74 48 2f 77 70 5f 70 6f 73 74

113278a0 6d 65 74 61 2e 69 62 64 b0 1d c8 4a 09 00 2e 2f

113278b0 75 34 30 38 36 38 39 31 39 30 5f 6d 75 72 70 68

113278c0 79 2f 6a 6f 6f 6d 6c 61 34 5f 73 65 73 73 69 6f

113278d0 6e 2e 69 62 64 b0 23 c8 49 fb 00 2e 2f 75 34 30

113278e0 38 36 38 39 31 39 30 5f 6d 75 72 70 68 79 2f 6a

113278f0 6f 6f 6d 6c 61 34 5f 72 73 66 6f 72 6d 5f 63 6f

11327900 6e 66 69 67 2e 69 62 64 b0 17 c6 29 1e 00 2e 2f

11327910 75 33 36 32 35 39 33 30 38 35 5f 75 32 45 55 45

11327920 2f 77 70 5f 6f 70 74 69 6f 6e 73 2e 69 62 64 b0

11327930 18 cc 13 ec 00 2e 2f 75 32 37 37 36 32 38 39 33

11327940 38 5f 42 34 39 52 50 2f 77 70 5f 70 6f 73 74 6d

11327950 65 74 61 2e 69 62 64 b0 19 c9 49 8b 00 2e 2f 75

11327960 36 36 36 37 36 33 39 36 31 5f 72 6d 77 70 78 64

11327970 62 2f 77 70 5f 6f 70 74 69 6f 6e 73 2e 69 62 64

11327980 b0 19 cd 97 80 00 2e 2f 75 38 35 31 34 38 38 34

11327990 34 38 5f 45 66 78 33 6b 2f 30 6d 33 6c 69 5f 77

113279a0 66 68 69 74 73 2e 69 62 64 b0 1b cd 97 86 00 2e

113279b0 2f 75 38 35 31 34 38 38 34 34 38 5f 45 66 78 33

113279c0 6b 2f 30 6d 33 6c 69 5f 77 66 6c 6f 67 69 6e 73

113279d0 2e 69 62 64 b0 26 cd 73 3c 00 2e 2f 75 33 32 32

113279e0 33 31 33 33 30 36 5f 75 6b 48 65 6d 2f 77 70 5f

113279f0 61 63 74 69 6f 6e 73 63 68 65 64 75 6c 65 72 5f

11327a00

From our status exporter, final values before crash:
2025-03-14 08:56:15
innodb_lsn_current 202762519857012
innodb_lsn_flushed 202762487014849
innodb_lsn_last_checkpoint 202760682110184

Unfortunately, there were no warnings prior to the crash. Now that you've mentioned it, while there weren't any warnings in the journal on these two cases, on a separate occasion not that long ago, a different server, web1792, also seemed to run out of 2GB of logfile size. At least it mentioned that `Crash recovery is broken due to insufficient innodb_log_file_size`. It may be related.

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: 250310 15:31:03 [ERROR] mysqld got signal 11 ;

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Sorry, we probably made a mistake, and this is a bug.

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Your assistance in bug reporting will enable us to fix this for the next release.

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: We will try our best to scrape up some info that will hopefully help

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: diagnose the problem, but since we have already crashed,

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: something is definitely wrong and this may fail.

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Server version: 10.11.10-MariaDB source revision: 3d0fb150289716ca75cd64d62823cf715ee47646

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: key_buffer_size=2147483648

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: read_buffer_size=4194304

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: max_used_connections=2001

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: max_threads=2002

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: thread_count=1909

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: It is possible that mysqld could use up to

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 18551062 K  bytes of memory

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Hope that's ok; if not, decrease some variables in the equation.

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Thread pointer: 0x7fab3ecc0d98

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Attempting backtrace. You can use the following information to find out

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: where mysqld died. If you see no messages after this, something went

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: terribly wrong...

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: 2025-03-10 15:31:03 0 [Note] /srv/mariadb101110/usr/sbin/mariadbd (initiated by: unknown): Normal shutdown

Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: stack_bottom = 0x7fbc80f6a000 thread_stack 0x49000

Mar 10 15:31:06 fr-int-web1792 mariadbd[180594]: 2025-03-10 15:31:06 382789322 [ERROR] InnoDB: Crash recovery is broken due to insufficient innodb_log_file_size; last checkpoint LSN=6877127675686311541, current LSN=51276436694122.

...

Mar 10 15:44:07 fr-int-web1792.main-hosting.eu mariadbd[2997491]: 2025-03-10 15:44:07 0 [ERROR] InnoDB: The log was only scanned up to 51276337820651, while the current LSN at the time of the latest checkpoint 51274642525029 was 51276425216188!

We do now have a separate alert for high checkpoint ratio `innodb_checkpoint_age/innodb_checkpoint_max_age` ever since those incidents to warn us and try and to extend innodb_log_file_size with restart if it's getting high (we're aware of https://jira.mariadb.org/browse/MDEV-35577 and its linked issues). Historical data shows that when those servers were corrupted, they exceeded that 1.0 ratio.

Hope this helps.

Arnas Klova added a comment - 5 days ago Hey Marko, Thanks for looking into this. Here's the info you've requested: $ od -Ax -t x1 -j 0x11327600 -N 0x400 ib_logfile0 11327600 33 5f 61 6e 74 68 6f 6e 79 2f 77 70 5f 61 63 74 11327610 69 6f 6e 73 63 68 65 64 75 6c 65 72 5f 63 6c 61 11327620 69 6d 73 2e 69 62 64 b0 26 c2 9d b6 00 2e 2f 75 11327630 37 38 30 30 38 34 34 35 36 5f 75 59 6b 68 64 2f 11327640 77 70 5f 61 63 74 69 6f 6e 73 63 68 65 64 75 6c 11327650 65 72 5f 63 6c 61 69 6d 73 2e 69 62 64 b0 1d cb 11327660 ca 06 00 2e 2f 75 37 38 30 30 38 34 34 35 36 5f 11327670 56 75 6b 66 32 2f 77 70 5f 65 5f 73 75 62 6d 69 11327680 73 73 69 6f 6e 73 2e 69 62 64 b0 24 c6 1b 57 00 11327690 2e 2f 75 33 37 33 33 34 33 34 36 31 5f 67 79 44 113276a0 53 31 2f 77 70 5f 61 63 74 69 6f 6e 73 63 68 65 113276b0 64 75 6c 65 72 5f 6c 6f 67 73 2e 69 62 64 b0 1a 113276c0 c6 21 2c 00 2e 2f 75 33 36 32 35 39 33 30 38 35 113276d0 5f 4a 35 56 7a 77 2f 77 70 5f 69 74 73 65 63 5f 113276e0 6c 6f 67 73 2e 69 62 64 fa 00 00 00 00 b8 68 e2 113276f0 d1 bf 3b 00 a1 bf c9 d5 b0 2a cb b5 65 00 2e 2f 11327700 75 31 34 37 39 35 34 31 31 31 5f 74 72 76 6c 62 11327710 79 2f 74 72 6c 6c 69 5f 61 63 74 69 6f 6e 73 63 11327720 68 65 64 75 6c 65 72 5f 63 6c 61 69 6d 73 2e 69 11327730 62 64 b0 2b cb b5 64 00 2e 2f 75 31 34 37 39 35 11327740 34 31 31 31 5f 74 72 76 6c 62 79 2f 74 72 6c 6c 11327750 69 5f 61 63 74 69 6f 6e 73 63 68 65 64 75 6c 65 11327760 72 5f 61 63 74 69 6f 6e 73 2e 69 62 64 b0 16 cc 11327770 44 d5 00 2e 2f 75 39 37 33 31 36 37 34 36 31 5f 11327780 38 57 5a 62 69 2f 61 66 62 77 5f 6d 61 69 6c 2e 11327790 69 62 64 b0 16 c6 2f c5 00 2e 2f 75 33 34 36 36 113277a0 32 30 33 39 33 5f 73 77 61 6e 2f 77 70 5f 6f 70 113277b0 74 69 6f 6e 73 2e 69 62 64 b0 1d c6 2a 33 00 2e 113277c0 2f 75 39 38 32 32 39 39 39 36 33 5f 47 55 35 61 113277d0 65 2f 77 70 5f 61 75 74 6f 6d 61 74 69 63 5f 6c 113277e0 6f 67 2e 69 62 64 b0 1d cd 6c 81 00 2e 2f 75 33 113277f0 32 32 33 31 33 33 30 36 5f 6d 69 67 72 61 74 69 11327800 6f 6e 31 31 2f 77 70 5f 6f 70 74 69 6f 6e 73 2e 11327810 69 62 64 b0 26 c0 41 be 00 2e 2f 75 37 38 30 30 11327820 38 34 34 35 36 5f 44 79 54 4f 6b 2f 77 70 5f 61 11327830 63 74 69 6f 6e 73 63 68 65 64 75 6c 65 72 5f 63 11327840 6c 61 69 6d 73 2e 69 62 64 b0 27 cd 96 56 00 2e 11327850 2f 75 33 32 32 33 31 33 33 30 36 5f 6d 69 67 72 11327860 61 74 69 6f 6e 33 2f 77 70 5f 72 61 6e 6b 5f 6d 11327870 61 74 68 5f 34 30 34 5f 6c 6f 67 73 2e 69 62 64 11327880 b0 18 c2 7a 57 00 2e 2f 75 32 37 39 36 37 37 33 11327890 33 34 5f 56 62 56 74 48 2f 77 70 5f 70 6f 73 74 113278a0 6d 65 74 61 2e 69 62 64 b0 1d c8 4a 09 00 2e 2f 113278b0 75 34 30 38 36 38 39 31 39 30 5f 6d 75 72 70 68 113278c0 79 2f 6a 6f 6f 6d 6c 61 34 5f 73 65 73 73 69 6f 113278d0 6e 2e 69 62 64 b0 23 c8 49 fb 00 2e 2f 75 34 30 113278e0 38 36 38 39 31 39 30 5f 6d 75 72 70 68 79 2f 6a 113278f0 6f 6f 6d 6c 61 34 5f 72 73 66 6f 72 6d 5f 63 6f 11327900 6e 66 69 67 2e 69 62 64 b0 17 c6 29 1e 00 2e 2f 11327910 75 33 36 32 35 39 33 30 38 35 5f 75 32 45 55 45 11327920 2f 77 70 5f 6f 70 74 69 6f 6e 73 2e 69 62 64 b0 11327930 18 cc 13 ec 00 2e 2f 75 32 37 37 36 32 38 39 33 11327940 38 5f 42 34 39 52 50 2f 77 70 5f 70 6f 73 74 6d 11327950 65 74 61 2e 69 62 64 b0 19 c9 49 8b 00 2e 2f 75 11327960 36 36 36 37 36 33 39 36 31 5f 72 6d 77 70 78 64 11327970 62 2f 77 70 5f 6f 70 74 69 6f 6e 73 2e 69 62 64 11327980 b0 19 cd 97 80 00 2e 2f 75 38 35 31 34 38 38 34 11327990 34 38 5f 45 66 78 33 6b 2f 30 6d 33 6c 69 5f 77 113279a0 66 68 69 74 73 2e 69 62 64 b0 1b cd 97 86 00 2e 113279b0 2f 75 38 35 31 34 38 38 34 34 38 5f 45 66 78 33 113279c0 6b 2f 30 6d 33 6c 69 5f 77 66 6c 6f 67 69 6e 73 113279d0 2e 69 62 64 b0 26 cd 73 3c 00 2e 2f 75 33 32 32 113279e0 33 31 33 33 30 36 5f 75 6b 48 65 6d 2f 77 70 5f 113279f0 61 63 74 69 6f 6e 73 63 68 65 64 75 6c 65 72 5f 11327a00 From our status exporter, final values before crash: 2025-03-14 08:56:15 innodb_lsn_current 202762519857012 innodb_lsn_flushed 202762487014849 innodb_lsn_last_checkpoint 202760682110184 Unfortunately, there were no warnings prior to the crash. Now that you've mentioned it, while there weren't any warnings in the journal on these two cases, on a separate occasion not that long ago, a different server, web1792, also seemed to run out of 2GB of logfile size. At least it mentioned that `Crash recovery is broken due to insufficient innodb_log_file_size`. It may be related. Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: 250310 15:31:03 [ERROR] mysqld got signal 11 ; Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Sorry, we probably made a mistake, and this is a bug. Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Your assistance in bug reporting will enable us to fix this for the next release. Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: We will try our best to scrape up some info that will hopefully help Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: diagnose the problem, but since we have already crashed, Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: something is definitely wrong and this may fail. Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Server version: 10.11.10-MariaDB source revision: 3d0fb150289716ca75cd64d62823cf715ee47646 Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: key_buffer_size=2147483648 Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: read_buffer_size=4194304 Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: max_used_connections=2001 Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: max_threads=2002 Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: thread_count=1909 Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: It is possible that mysqld could use up to Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 18551062 K bytes of memory Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Hope that's ok; if not, decrease some variables in the equation. Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Thread pointer: 0x7fab3ecc0d98 Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: Attempting backtrace. You can use the following information to find out Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: where mysqld died. If you see no messages after this, something went Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: terribly wrong... Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: 2025-03-10 15:31:03 0 [Note] /srv/mariadb101110/usr/sbin/mariadbd (initiated by: unknown): Normal shutdown Mar 10 15:31:03 fr-int-web1792 mariadbd[180594]: stack_bottom = 0x7fbc80f6a000 thread_stack 0x49000 Mar 10 15:31:06 fr-int-web1792 mariadbd[180594]: 2025-03-10 15:31:06 382789322 [ERROR] InnoDB: Crash recovery is broken due to insufficient innodb_log_file_size; last checkpoint LSN=6877127675686311541, current LSN=51276436694122. ... Mar 10 15:44:07 fr-int-web1792.main-hosting.eu mariadbd[2997491]: 2025-03-10 15:44:07 0 [ERROR] InnoDB: The log was only scanned up to 51276337820651, while the current LSN at the time of the latest checkpoint 51274642525029 was 51276425216188! We do now have a separate alert for high checkpoint ratio `innodb_checkpoint_age/innodb_checkpoint_max_age` ever since those incidents to warn us and try and to extend innodb_log_file_size with restart if it's getting high (we're aware of https://jira.mariadb.org/browse/MDEV-35577 and its linked issues). Historical data shows that when those servers were corrupted, they exceeded that 1.0 ratio. Hope this helps.

People

Assignee:: Marko Mäkelä

Reporter:: Arnas Klova

Votes:: 0 Vote for this issue

Watchers:: 4 Start watching this issue

Dates

Created:: 6 days ago 12:27

Updated:: 6 days ago 16:51

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.