[MDEV-27711] [ERROR] InnoDB: Missing FILE_CREATE, FILE_DELETE or FILE_MODIFY before FILE_CHECKPOINT during Mariabackup prepare Created: 2022-02-01  Updated: 2022-06-21  Resolved: 2022-06-21

Status: Closed
Project: MariaDB Server
Component/s: mariabackup
Affects Version/s: 10.6.6
Fix Version/s: 10.6.9, 10.7.5, 10.8.4, 10.9.2, 10.10.1

Type: Bug Priority: Major
Reporter: Matthias Leich Assignee: Marko Mäkelä
Resolution: Fixed Votes: 1
Labels: rr-profile

Issue Links:
Relates
relates to MDEV-28870 InnoDB: Missing FILE_CREATE, FILE_DEL... Closed

 Description   

origin/bb-10.6-thiru c3983ee54025d70ffc23daab6af077b592800a22 2022-02-01T12:28:00+05:30  (The tree contains the fix for MDEV-26326).
But the bad effect should not be caused by the fix for MDEV-26326.
 
Workflow:
1. Start server + generate some initial data.
2. Several sessions run a DDL/DML mix.
3. During 2. is ongoing
    mariabackup --backup  to some location A
     mariabackup --prepare on location A
 
# 2022-02-01T02:58:42 [1307818] | [rr 1397379 822]2022-02-01  2:57:01 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
# 2022-02-01T02:58:42 [1307818] | [rr 1397379 826]2022-02-01  2:57:01 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
# 2022-02-01T02:58:42 [1307818] | [rr 1397379 851]2022-02-01  2:57:01 0 [Note] InnoDB: Number of pools: 1
# 2022-02-01T02:58:42 [1307818] | [rr 1397379 855]2022-02-01  2:57:01 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
# 2022-02-01T02:58:42 [1307818] | [rr 1397379 881]2022-02-01  2:57:01 0 [Note] InnoDB: Initializing buffer pool, total size = 104857600, chunk size = 104857600
# 2022-02-01T02:58:42 [1307818] | [rr 1397379 893]2022-02-01  2:57:01 0 [Note] InnoDB: Completed initialization of buffer pool
# 2022-02-01T02:58:42 [1307818] | [rr 1397379 940]2022-02-01  2:57:01 0 [Note] InnoDB: Setting O_DIRECT on file ./ibdata1 failed
# 2022-02-01T02:58:42 [1307818] | [rr 1397379 961]2022-02-01  2:57:01 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=11687970,12259007
# 2022-02-01T02:58:42 [1307818] | [rr 1397379 1003]2022-02-01  2:57:01 0 [ERROR] InnoDB: Missing FILE_CREATE, FILE_DELETE or FILE_MODIFY before FILE_CHECKPOINT for tablespace 1501
# 2022-02-01T02:58:42 [1307818] | [rr 1397379 1007]2022-02-01  2:57:01 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1445] with error Data structure corruption
# 2022-02-01T02:58:42 [1307818] | [rr 1397379 1011][00] FATAL ERROR: 2022-02-01 02:57:01 mariabackup: innodb_init() returned 37 (Data structure corruption).
 
RQG
===
# git clone https://github.com/mleich1/rqg --branch experimental RQG
#
# GIT_SHOW: HEAD -> experimental, origin/experimental 067340e8ec78c25880ccd2e67dd62ad134edc531 2022-01-31T17:10:39+01:00
# rqg.pl  : Version 4.0.4 (2021-12)
#
# $RQG_HOME/rqg.pl \
# --grammar=conf/runtime/alter_online.yy \
# --gendata=conf/runtime/alter_online.zz \
# --mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \
# --mysqld=--loose-idle_write_transaction_timeout=0 \
# --mysqld=--loose-idle_transaction_timeout=0 \
# --mysqld=--loose-idle_readonly_transaction_timeout=0 \
# --mysqld=--connect_timeout=60 \
# --mysqld=--interactive_timeout=28800 \
# --mysqld=--slave_net_timeout=60 \
# --mysqld=--net_read_timeout=30 \
# --mysqld=--net_write_timeout=60 \
# --mysqld=--loose-table_lock_wait_timeout=50 \
# --mysqld=--wait_timeout=28800 \
# --mysqld=--lock-wait-timeout=86400 \
# --mysqld=--innodb-lock-wait-timeout=50 \
# --no-mask \
# --queries=10000000 \
# --seed=random \
# --reporters=Backtrace \
# --reporters=ErrorLog \
# --reporters=Deadlock1 \
# --validators=None \
# --mysqld=--log_output=none \
# --mysqld=--log_bin_trust_function_creators=1 \
# --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
# --engine=InnoDB \
# --restart_timeout=360 \
# --mysqld=--plugin-load-add=file_key_management.so \
# --mysqld=--loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
# --mysqld=--plugin-load-add=provider_lzo.so \
# --mysqld=--plugin-load-add=provider_bzip2.so \
# --mysqld=--plugin-load-add=provider_lzma \
# --mysqld=--plugin-load-add=provider_snappy \
# --mysqld=--plugin-load-add=provider_lz4 \
# --duration=300 \
# --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
# --mysqld=--loose-innodb_read_only_compressed=OFF \
# --reporters=Mariabackup_linux \
# --mysqld=--innodb_log_file_size=402653184 \
# --duration=300 \
# --mysqld=--loose-innodb-sync-debug \
# --mysqld=--innodb_stats_persistent=off \
# --mysqld=--innodb_adaptive_hash_index=off \
# --mysqld=--log-bin \
# --mysqld=--sync-binlog=1 \
# --mysqld=--loose-innodb_evict_tables_on_commit_debug=off \
# --mysqld=--loose-max-statement-time=30 \
# --threads=2 \
# --mysqld=--innodb-use-native-aio=0 \
# --mysqld=--loose-gdb \
# --mysqld=--loose-debug-gdb \
# --rr=Extended \
# --rr_options=--wait \
# --mysqld=--innodb_rollback_on_timeout=OFF \
# --vardir_type=fast \
# --mysqld=--innodb_page_size=16K \
# --mysqld=--innodb-buffer-pool-size=8M \
# --no_mask \
# <local settings>
 
sdp:/data/results/1643708142/TBR-1345/dev/shm/rqg/1643708142/101/1_clone/rr
_RR_TRACE_DIR="." rr replay --mark-stdio mariabackup-0 # mariabackup --backup
_RR_TRACE_DIR="." rr replay --mark-stdio mariabackup-1 # mariabackup --prepare



 Comments   
Comment by Marko Mäkelä [ 2022-06-21 ]

This should have been fixed by MDEV-28870.

Generated at Thu Feb 08 09:54:59 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.