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

Mariadb crashes after restore 10.11.11

    XMLWordPrintable

Details

    • Bug
    • Status: Open (View Workflow)
    • Major
    • Resolution: Unresolved
    • 10.11.11
    • None
    • Backup, Server
    • 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

          Activity

            People

              Unassigned Unassigned
              shexphobos Xesh
              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.