Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
10.11.11
-
None
-
CentOS Stream 9
Description
MariaDB crashes after the restore process on two different nodes.
Restore log:
20250517/xtrabackup_info
++ sleep 1
++ mariabackup --prepare --target-dir=/var/lib/mysql/20250517/
mariabackup based on MariaDB server 10.11.11-MariaDB Linux (x86_64)
[00] 2025-05-17 13:10:01 cd to /var/lib/mysql/20250517/
[00] 2025-05-17 13:10:01 open files limit requested 0, set to 1024
[00] 2025-05-17 13:10:01 This target seems to be not prepared yet.
[00] 2025-05-17 13:10:01 InnoDB: The universal page size of the database is set to 65536.
[00] 2025-05-17 13:10:01 mariabackup: using the following InnoDB configuration for recovery:
[00] 2025-05-17 13:10:01 innodb_data_home_dir = .
[00] 2025-05-17 13:10:01 innodb_data_file_path = ibdata1:50M;ibdata2:50M:autoextend
[00] 2025-05-17 13:10:01 innodb_log_group_home_dir = .
[00] 2025-05-17 13:10:01 InnoDB: Using Linux native AIO
[00] 2025-05-17 13:10:01 Starting InnoDB instance for recovery.
[00] 2025-05-17 13:10:01 mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2025-05-17 13:10:01 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2025-05-17 13:10:01 0 [Note] InnoDB: Number of transaction pools: 1
2025-05-17 13:10:01 0 [Note] InnoDB: Using AVX512 instructions
2025-05-17 13:10:01 0 [Note] InnoDB: Using Linux native AIO
2025-05-17 13:10:01 0 [Note] InnoDB: Initializing buffer pool, total size = 100.000MiB, chunk size = 100.000MiB
2025-05-17 13:10:01 0 [Note] InnoDB: Completed initialization of buffer pool
2025-05-17 13:10:01 0 [Note] InnoDB: Memory-mapped log (block size=4096 bytes)
2025-05-17 13:10:01 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=53550772279186
2025-05-17 13:10:01 0 [Note] InnoDB: Multi-batch recovery needed at LSN 53550829671543
2025-05-17 13:10:01 0 [Note] InnoDB: End of log at LSN=53550831223154
2025-05-17 13:10:01 0 [Note] InnoDB: To recover: LSN 53550829671543/53550831223154; 1973 pages
2025-05-17 13:10:02 0 [Note] InnoDB: To recover: 68 pages
2025-05-17 13:10:02 0 [Note] InnoDB: Buffered log writes (block size=4096 bytes)
[00] 2025-05-17 13:10:02 Last binlog file , position 0
[00] 2025-05-17 13:10:02 mariabackup: Recovered WSREP position: d9f2f364-185f-11f0-8a91-3e66cc704935:467433588 domain_id: 0
[00] 2025-05-17 13:10:02 completed OK!
+++ date
++ echo 'Backup DB extracted-prepared' Sat May 17 01:10:02 PM UTC 2025
Starting and crashing in loops:
2025-05-17 13:10:03 0 [Note] Starting MariaDB 10.11.11-MariaDB-log source revision e69f8cae1a15e15b9e4f5e0f8497e1f17bdc81a4 server_uid iqPy/beUH2sz6jDtmRjQ6whcy0g= as process 404150
2025-05-17 13:10:03 0 [Warning] You need to use --log-bin to make --binlog-format work.
2025-05-17 13:10:03 0 [Note] InnoDB: innodb_page_size=65536
2025-05-17 13:10:03 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2025-05-17 13:10:03 0 [Note] InnoDB: Number of transaction pools: 1
2025-05-17 13:10:03 0 [Note] InnoDB: Using AVX512 instructions
2025-05-17 13:10:03 0 [Note] InnoDB: Using Linux native AIO
2025-05-17 13:10:03 0 [Note] InnoDB: Initializing buffer pool, total size = 2.000GiB, chunk size = 32.000MiB
2025-05-17 13:10:03 0 [Note] InnoDB: Completed initialization of buffer pool
2025-05-17 13:10:03 0 [Note] InnoDB: Buffered log writes (block size=4096 bytes)
2025-05-17 13:10:03 0 [Note] InnoDB: End of log at LSN=53550831223154
2025-05-17 13:10:04 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 15 row operations to undo
2025-05-17 13:10:04 0 [Note] InnoDB: Trx id counter is 4471182634
2025-05-17 13:10:04 0 [Note] InnoDB: Resizing redo log from 12.016KiB to 1.000GiB; LSN=53550831223154
2025-05-17 13:10:04 0 [Note] InnoDB: Buffered log writes (block size=4096 bytes)
2025-05-17 13:10:04 0 [Note] InnoDB: 128 rollback segments are active.
2025-05-17 13:10:04 0 [Note] InnoDB: Setting file '/var/lib/mysql/db/ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
2025-05-17 13:10:04 0 [Note] InnoDB: File '/var/lib/mysql/db/ibtmp1' size is now 12.000MiB.
2025-05-17 13:10:04 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
2025-05-17 13:10:04 0 [Note] InnoDB: Rolled back recovered transaction 4471182301
2025-05-17 13:10:04 0 [Note] InnoDB: Rollback of non-prepared transactions completed
2025-05-17 13:10:04 0 [Note] InnoDB: log sequence number 53550831223154; transaction id 4471182636
2025-05-17 13:10:04 0 [Note] Plugin 'FEEDBACK' is disabled.
2025-05-17 13:10:04 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/db/ib_buffer_pool
2025-05-17 13:10:04 0 [Note] InnoDB: Cannot open '/var/lib/mysql/db/ib_buffer_pool' for reading: No such file or directory
2025-05-17 13:10:04 0 [Note] Server socket created on IP: '0.0.0.0'.
2025-05-17 13:10:04 0 [Warning] 'user' entry '@ip-172-31-101-11.us-west-2.compute.internal' ignored in --skip-name-resolve mode.
2025-05-17 13:10:04 0 [Warning] 'proxies_priv' entry '@% root@ip-172-31-101-11.us-west-2.compute.internal' ignored in --skip-name-resolve mode.
2025-05-17 13:10:04 0 [Note] /usr/sbin/mariadbd: ready for connections.
Version: '10.11.11-MariaDB-log' socket: '/var/lib/mysql/db/mysql.sock' port: 3306 MariaDB Server
2025-05-17 13:12:10 0x7fcd4e3a3640 InnoDB: Assertion failure in file /home/buildbot/buildbot/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX/mariadb-10.11.11/storage/innobase/trx/trx0purge.cc line 894
InnoDB: Failing assertion: tail.trx_no <= last_trx_no
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mariadbd startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
InnoDB: about forcing recovery.
250517 13:12:10 [ERROR] /usr/sbin/mariadbd got signal 6 ;
Sorry, we probably made a mistake, and this is a bug.
Your assistance in bug reporting will enable us to fix this for the next release.
To report this bug, see https://mariadb.com/kb/en/reporting-bugs about how to report
a bug on https://jira.mariadb.org/.
Please include the information from the server start above, to the end of the
information below.
Server version: 10.11.11-MariaDB-log source revision: e69f8cae1a15e15b9e4f5e0f8497e1f17bdc81a4
The information page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mariadbd/
contains instructions to obtain a better version of the backtrace below.
Following these instructions will help MariaDB developers provide a fix quicker.
Attempting backtrace. Include this in the bug report.
(note: Retrieving this information may fail)
Thread pointer: 0x55fee46f8448
stack_bottom = 0x7fcd4e3a4000 thread_stack 0x40000
2025-05-17 13:12:10 0 [Note] /usr/sbin/mariadbd (initiated by: unknown): Normal shutdown
/usr/sbin/mariadbd(my_print_stacktrace+0x2e)[0x55fee0d5605e]
/usr/sbin/mariadbd(handle_fatal_signal+0x305)[0x55fee082a855]
/lib64/libc.so.6(+0x3e730)[0x7fcdeb63e730]
/lib64/libc.so.6(+0x8ba6c)[0x7fcdeb68ba6c]
/lib64/libc.so.6(raise+0x16)[0x7fcdeb63e686]
/lib64/libc.so.6(abort+0xd3)[0x7fcdeb628833]
/usr/sbin/mariadbd(+0x6c437c)[0x55fee044337c]
/usr/sbin/mariadbd(+0x6c12fe)[0x55fee04402fe]
/usr/sbin/mariadbd(+0x722684)[0x55fee04a1684]
/usr/sbin/mariadbd(+0xe7ea53)[0x55fee0bfda53]
/usr/sbin/mariadbd(_ZN5tpool10task_group7executeEPNS_4taskE+0x7c)[0x55fee0ced98c]
/usr/sbin/mariadbd(_ZN5tpool19thread_pool_generic11worker_mainEPNS_11worker_dataE+0x4f)[0x55fee0cec6ef]
/lib64/libstdc++.so.6(+0xdbad4)[0x7fcdebadbad4]
/lib64/libc.so.6(+0x89d22)[0x7fcdeb689d22]
/lib64/libc.so.6(+0x10ed40)[0x7fcdeb70ed40]
Connection ID (thread ID): 0
Status: NOT_KILLED
Query (0x0): (null)Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_cond
ition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache
=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elim
ination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from
_having=on,not_null_range_scan=off,hash_join_cardinality=off,cset_narrowing=off
Writing a core file...
Working directory at /var/lib/mysql/db
Resource Limits (excludes unlimited resources):
Limit Soft Limit Hard Limit Units
Max stack size 8388608 unlimited bytes
Max processes 29819 29819 processes
Max open files 32768 32768 files
Max locked memory 8388608 8388608 bytes
Max pending signals 29819 29819 signals
Max msgqueue size 819200 819200 bytes
Max nice priority 0 0
Max realtime priority 0 0
Core pattern: |/usr/lib/systemd/systemd-coredump %P %u %g %s %t %c %h
Kernel version: Linux version 5.14.0-511.el9.x86_64 (mockbuild@x86-05.stream.rdu2.redhat.com) (gcc (GCC) 11.5.0 20240719 (Red Hat 11.5.0-2), GNU ld version 2.35.2-54.el9) #1 SMP PREEMPT_DYNAMIC Thu Sep
19 06:52:39 UTC 2024
2025-05-17 13:12:16 0 [Note] Starting MariaDB 10.11.11-MariaDB-log source revision e69f8cae1a15e15b9e4f5e0f8497e1f17bdc81a4 server_uid iqPy/beUH2sz6jDtmRjQ6whcy0g= as process 404409
2025-05-17 13:12:16 0 [Warning] You need to use --log-bin to make --binlog-format work.
2025-05-17 13:12:16 0 [Note] InnoDB: innodb_page_size=65536
2025-05-17 13:12:16 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2025-05-17 13:12:16 0 [Note] InnoDB: Number of transaction pools: 1
2025-05-17 13:12:16 0 [Note] InnoDB: Using AVX512 instructions
2025-05-17 13:12:16 0 [Note] InnoDB: Using Linux native AIO
2025-05-17 13:12:16 0 [Note] InnoDB: Initializing buffer pool, total size = 2.000GiB, chunk size = 32.000MiB
2025-05-17 13:12:16 0 [Note] InnoDB: Completed initialization of buffer pool
2025-05-17 13:12:16 0 [Note] InnoDB: File system buffers for log disabled (block size=4096 bytes)
2025-05-17 13:12:16 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=53550831223170
2025-05-17 13:12:16 0 [Note] InnoDB: End of log at LSN=53550831312048
2025-05-17 13:12:16 0 [Note] InnoDB: Retry with innodb_force_recovery=5
2025-05-17 13:12:16 0 [ERROR] InnoDB: Plugin initialization aborted with error Data structure corruption
2025-05-17 13:12:16 0 [Note] InnoDB: Starting shutdown...
2025-05-17 13:12:16 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2025-05-17 13:12:16 0 [Note] Plugin 'FEEDBACK' is disabled.
2025-05-17 13:12:16 0 [ERROR] Unknown/unsupported storage engine: InnoDB
2025-05-17 13:12:16 0 [ERROR] Aborting
On the node where the backup has been created:
2025-05-17 9:44:30 907838786 [Note] WSREP: Desyncing and pausing the provider
2025-05-17 9:44:30 0 [Note] WSREP: Member 2.0 (11D) desyncs itself from group
2025-05-17 9:44:30 0 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 467433588)
2025-05-17 9:44:30 907838786 [Note] WSREP: pause
2025-05-17 9:44:30 907838786 [Note] WSREP: Provider paused at d9f2f364-185f-11f0-8a91-3e66cc704935:467433588 (491262745)
2025-05-17 9:44:30 907838786 [Note] WSREP: Provider paused at: 467433588
2025-05-17 9:44:30 907838786 [Note] WSREP: Server desynched from group during BACKUP STAGE BLOCK_DDL.
2025-05-17 9:44:35 907838786 [Note] WSREP: Resuming and resyncing the provider
2025-05-17 9:44:35 907838786 [Note] WSREP: resume
2025-05-17 9:44:35 907838786 [Note] WSREP: resuming provider at 491262745
2025-05-17 9:44:35 907838786 [Note] WSREP: Provider resumed.
2025-05-17 9:44:35 0 [Note] WSREP: Member 2.0 (11D) resyncs itself to group.
2025-05-17 9:44:35 0 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 467433588)
2025-05-17 9:44:35 0 [Note] WSREP: Processing event queue:... -nan% (0/0 events) complete.
2025-05-17 9:44:35 0 [Note] WSREP: Member 2.0 (11D) synced with group.
2025-05-17 9:44:35 0 [Note] WSREP: Processing event queue:... 100.0% (1/1 events) complete.
2025-05-17 9:44:35 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 467433588)
2025-05-17 9:44:35 108 [Note] WSREP: Server 11D synced with group
Attachments
Issue Links
- relates to
-
MDEV-33757 Get rid of TrxUndoRsegs code
-
- Closed
-