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

Doublewrite recovery of innodb_checksum_algorithm=full_crc32 page_compressed pages does not work

Details

    Description

      Scenario:
      		 
      1. Start the server and load some initial data.
      		 
      2. Several connections run concurrent a random mix of DDL and DML.
      		 
      3. During 2. is ongoing SIGKILL the server
      		 
      4. The restart fails with
      		 
      ...
      		 
      # 2025-02-26T12:26:51 [309330] | 2025-02-26 12:26:07 0 [Note] InnoDB: To recover: LSN 187242689/187312128; 392 pages
      		 
      # 2025-02-26T12:26:51 [309330] | mariadbd: /data/Server/10.6-MDEV-36122/storage/innobase/fil/fil0crypt.cc:643: dberr_t fil_space_decrypt_full_crc32(ulint, fil_space_crypt_t*, byte*, byte*): Assertion `key_version != (0)' failed.
      		 
      # 2025-02-26T12:27:40 [309330] | Thread 2 (Thread 498866.499388 (mariadbd)):
      		 
      # 2025-02-26T12:27:40 [309330] | #0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=140079542539840) at ./nptl/pthread_kill.c:44
      		 
      # 2025-02-26T12:27:40 [309330] | #1  __pthread_kill_internal (signo=6, threadid=140079542539840) at ./nptl/pthread_kill.c:78
      		 
      # 2025-02-26T12:27:40 [309330] | #2  __GI___pthread_kill (threadid=140079542539840, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
      		 
      # 2025-02-26T12:27:40 [309330] | #3  0x00007f66dfa36476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
      		 
      # 2025-02-26T12:27:40 [309330] | #4  0x00007f66dfa1c7f3 in __GI_abort () at ./stdlib/abort.c:79
      		 
      # 2025-02-26T12:27:40 [309330] | #5  0x00007f66dfa1c71b in __assert_fail_base (fmt=0x7f66dfbd1130 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55911b3571da "key_version != (0)", file=0x55911b356560 "/data/Server/10.6-MDEV-36122/storage/innobase/fil/fil0crypt.cc", line=643, function=<optimized out>) at ./assert/assert.c:92
      		 
      # 2025-02-26T12:27:40 [309330] | #6  0x00007f66dfa2de96 in __GI___assert_fail (assertion=0x55911b3571da "key_version != (0)", file=0x55911b356560 "/data/Server/10.6-MDEV-36122/storage/innobase/fil/fil0crypt.cc", line=643, function=0x55911b356850 "dberr_t fil_space_decrypt_full_crc32(ulint, fil_space_crypt_t*, byte*, byte*)") at ./assert/assert.c:101
      		 
      # 2025-02-26T12:27:40 [309330] | #7  0x000055911adafa0a in fil_space_decrypt_full_crc32 (space=190, crypt_data=0x55911d6ac730, tmp_frame=tmp_frame@entry=0x7f66c0004000 "", src_frame=src_frame@entry=0x7f66d6f9c000 "") at 10.6-MDEV-36122/storage/innobase/fil/fil0crypt.cc:643
      		 
      # 2025-02-26T12:27:40 [309330] | #8  0x000055911adb0df8 in fil_space_decrypt (space_id=<optimized out>, crypt_data=<optimized out>, tmp_frame=tmp_frame@entry=0x7f66c0004000 "", physical_size=physical_size@entry=16384, fsp_flags=<optimized out>, src_frame=src_frame@entry=0x7f66d6f9c000 "") at 10.6-MDEV-36122/storage/innobase/fil/fil0crypt.cc:768
      		 
      # 2025-02-26T12:27:40 [309330] | #9  0x000055911adb0e7b in fil_space_decrypt (space=0x55911d6ac890, tmp_frame=0x7f66c0004000 "", src_frame=src_frame@entry=0x7f66d6f9c000 "") at 10.6-MDEV-36122/storage/innobase/fil/fil0crypt.cc:795
      		 
      # 2025-02-26T12:27:40 [309330] | #10 0x000055911aabb3e6 in recv_dblwr_t::find_encrypted_page (this=0x55911b9d0e60 <recv_sys+2400>, node=..., page_no=3, buf=buf@entry=0x7f66d6f9c000 "") at 10.6-MDEV-36122/storage/innobase/log/log0recv.cc:4864
      		 
      # 2025-02-26T12:27:40 [309330] | #11 0x000055911acee49d in buf_page_t::read_complete (this=0x7f66d6807870, node=...) at 10.6-MDEV-36122/storage/innobase/buf/buf0buf.cc:3771
      		 
      # 2025-02-26T12:27:40 [309330] | #12 0x000055911ada6fbc in IORequest::read_complete (this=this@entry=0x55911d557d88, io_error=0) at 10.6-MDEV-36122/storage/innobase/fil/fil0fil.cc:2807
      		 
      # 2025-02-26T12:27:40 [309330] | #13 0x000055911aaf573a in read_io_callback (c=0x55911d557d10) at 10.6-MDEV-36122/storage/innobase/os/os0file.cc:3234
      		 
      # 2025-02-26T12:27:40 [309330] | #14 0x000055911ae3597d in tpool::task_group::execute (this=0x55911d557c50, t=t@entry=0x55911d557d68) at 10.6-MDEV-36122/tpool/task_group.cc:55
      		 
      # 2025-02-26T12:27:40 [309330] | #15 0x000055911ae35d3d in tpool::task::execute (this=0x55911d557d68) at 10.6-MDEV-36122/tpool/task.cc:32
      		 
      # 2025-02-26T12:27:40 [309330] | #16 0x000055911ae323bd in tpool::thread_pool_generic::worker_main (this=0x55911d50ea10, thread_var=0x55911d50ee30) at 10.6-MDEV-36122/tpool/tpool_generic.cc:574
      		 
      # 2025-02-26T12:27:40 [309330] | #17 0x000055911ae3260c in std::__invoke_impl<void, void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__t=<optimized out>, __f=<optimized out>) at /usr/include/c++/11/bits/invoke.h:74
      		 
      # 2025-02-26T12:27:40 [309330] | #18 std::__invoke<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__fn=<optimized out>) at /usr/include/c++/11/bits/invoke.h:96
      		 
      # 2025-02-26T12:27:40 [309330] | #19 std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::_M_invoke<0ul, 1ul, 2ul> (this=<optimized out>) at /usr/include/c++/11/bits/std_thread.h:259
      		 
      # 2025-02-26T12:27:40 [309330] | #20 std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::operator() (this=<optimized out>) at /usr/include/c++/11/bits/std_thread.h:266
      		 
      # 2025-02-26T12:27:40 [309330] | #21 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> > >::_M_run (this=<optimized out>) at /usr/include/c++/11/bits/std_thread.h:211
      		 
      # 2025-02-26T12:27:40 [309330] | #22 0x00007f66dfe02253 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
      		 
      # 2025-02-26T12:27:40 [309330] | #23 0x00007f66dfa88ac3 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
      		 
      # 2025-02-26T12:27:40 [309330] | #24 0x00007f66dfb19a04 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100
      		 
      pluto:/data/results/1740572032/CR-2060$ _RR_TRACE_DIR=./1/rr rr replay
      		 
       
      		 
      Per Marko: This seems to be a problem caused by the code for MDEV-34898.

      Attachments

        Activity

          mleich Matthias Leich added a comment - 

          RQG Test setup
          		 
          -----------------------
          		 
          # git clone https://github.com/mleich1/rqg --branch <pick the right branch> RQG
          		 
          #
          		 
          # GIT_SHOW: HEAD -> master, origin/master, origin/HEAD cb2ddc8316c26d7daefd9b6ec892054cef376369 2025-02-26T12:16:35+01:00
          		 
          # rqg.pl  : Version 4.5.0 (2023-12)
          		 
          #
          		 
          # $RQG_HOME/rqg.pl \
          		 
          # --grammar=conf/mariadb/innodb_compression_encryption.yy \
          		 
          # --gendata=conf/mariadb/innodb_compression_encryption.zz \
          		 
          # --max_gd_duration=1800 \
          		 
          # --mysqld=--innodb-encrypt-log \
          		 
          # --mysqld=--innodb-encrypt-tables \
          		 
          # --reporters=CrashRecovery \
          		 
          # --redefine=conf/mariadb/redefine_innodb_undo.yy \
          		 
          # --mysqld=--innodb-immediate-scrub-data-uncompressed=1 \
          		 
          # --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 \
          		 
          # --no_mask \
          		 
          # --queries=10000000 \
          		 
          # --seed=random \
          		 
          # --reporters=None \
          		 
          # --reporters=ErrorLog \
          		 
          # --reporters=Deadlock \
          		 
          # --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=240 \
          		 
          # --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.so \
          		 
          # --mysqld=--plugin-load-add=provider_snappy.so \
          		 
          # --mysqld=--plugin-load-add=provider_lz4.so \
          		 
          # --mysqld=--loose-innodb_compression_level=1 \
          		 
          # --duration=300 \
          		 
          # --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
          		 
          # --mysqld=--lock-wait-timeout=86400 \
          		 
          # --mysqld=--innodb-lock-wait-timeout=50 \
          		 
          # --mysqld=--sql_mode=traditional \
          		 
          # --mysqld=--innodb_file_per_table=1 \
          		 
          # --mysqld=--loose-innodb_read_only_compressed=OFF \
          		 
          # --mysqld=--innodb_stats_persistent=off \
          		 
          # --mysqld=--innodb_adaptive_hash_index=on \
          		 
          # --mysqld=--innodb_random_read_ahead=OFF \
          		 
          # --mysqld=--loose-innodb_evict_tables_on_commit_debug=on \
          		 
          # --threads=9 \
          		 
          # --rr=Extended \
          		 
          # --rr_options=--wait \
          		 
          # --mysqld=--innodb_undo_log_truncate=OFF \
          		 
          # --mysqld=--innodb_undo_tablespaces=3 \
          		 
          # --mysqld=--innodb_rollback_on_timeout=OFF \
          		 
          # --mysqld=--innodb_page_size=16K \
          		 
          # --mysqld=--innodb-buffer-pool-size=10M \
          		 
          # --vardir_type=fast \
          		 
          # --no_mask \
          		 
          # <local settings>

          mleich Matthias Leich added a comment - RQG Test setup ----------------------- # git clone https://github.com/mleich1/rqg --branch <pick the right branch> RQG # # GIT_SHOW: HEAD -> master, origin/master, origin/HEAD cb2ddc8316c26d7daefd9b6ec892054cef376369 2025-02-26T12:16:35+01:00 # rqg.pl : Version 4.5.0 (2023-12) # # $RQG_HOME/rqg.pl \ # --grammar=conf/mariadb/innodb_compression_encryption.yy \ # --gendata=conf/mariadb/innodb_compression_encryption.zz \ # --max_gd_duration=1800 \ # --mysqld=--innodb-encrypt-log \ # --mysqld=--innodb-encrypt-tables \ # --reporters=CrashRecovery \ # --redefine=conf/mariadb/redefine_innodb_undo.yy \ # --mysqld=--innodb-immediate-scrub-data-uncompressed=1 \ # --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 \ # --no_mask \ # --queries=10000000 \ # --seed=random \ # --reporters=None \ # --reporters=ErrorLog \ # --reporters=Deadlock \ # --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=240 \ # --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.so \ # --mysqld=--plugin-load-add=provider_snappy.so \ # --mysqld=--plugin-load-add=provider_lz4.so \ # --mysqld=--loose-innodb_compression_level=1 \ # --duration=300 \ # --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \ # --mysqld=--lock-wait-timeout=86400 \ # --mysqld=--innodb-lock-wait-timeout=50 \ # --mysqld=--sql_mode=traditional \ # --mysqld=--innodb_file_per_table=1 \ # --mysqld=--loose-innodb_read_only_compressed=OFF \ # --mysqld=--innodb_stats_persistent=off \ # --mysqld=--innodb_adaptive_hash_index=on \ # --mysqld=--innodb_random_read_ahead=OFF \ # --mysqld=--loose-innodb_evict_tables_on_commit_debug=on \ # --threads=9 \ # --rr=Extended \ # --rr_options=--wait \ # --mysqld=--innodb_undo_log_truncate=OFF \ # --mysqld=--innodb_undo_tablespaces=3 \ # --mysqld=--innodb_rollback_on_timeout=OFF \ # --mysqld=--innodb_page_size=16K \ # --mysqld=--innodb-buffer-pool-size=10M \ # --vardir_type=fast \ # --no_mask \ # <local settings>

          People

            thiru Thirunarayanan Balathandayuthapani
            mleich Matthias Leich
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

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