Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-36309

The log was only scanned up to *, while the current LSN at the time of the latest checkpoint * was *

Details

    • Bug
    • Status: Needs Feedback (View Workflow)
    • Major
    • Resolution: Unresolved
    • 10.11.10
    • None
    • Storage Engine - InnoDB
    • None
    • 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

        1. web1118.png
          web1118.png
          188 kB
        2. web1732.png
          web1732.png
          57 kB
        3. web1792.png
          web1792.png
          120 kB

        Activity

          Descending order - Click to sort in ascending order
          arnklo Arnas Klova added a comment -

          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.

          arnklo Arnas Klova added a comment - 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.
          marko Marko Mäkelä added a comment -

          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 Marko Mäkelä added a comment - 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.
          arnklo Arnas Klova added a comment -

          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

          arnklo Arnas Klova added a comment - 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 Marko Mäkelä added a comment -

          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 Marko Mäkelä added a comment - 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.

          People

            marko Marko Mäkelä
            arnklo Arnas Klova
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:

              Git Integration

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