Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
10.5, 10.6
Description
origin/10.6 aaef2e1d8c843d1e40b1ce0c5199c3abb3c5da28 2021-11-18T17:47:19+02:00
|
Workflow:
|
1. Start the DB server and create some initial data.
|
2. One session runs a DDL/DML mix.
|
3. During 2. is ongoing SIGKILL the DB server.
|
4. Restart attempt
|
# 2021-11-18T17:44:24 [3378597] | [rr 3525669 23847]2021-11-18 17:43:54 0 [Note] InnoDB: Read redo log up to LSN=100581888
|
# 2021-11-18T17:44:24 [3378597] | [rr 3525669 23851]2021-11-18 17:43:55 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-339c96-10.ibd' with space ID 48. Another data file called ./test/t8.ibd exists with the same space ID.
|
# 2021-11-18T17:44:24 [3378597] | [rr 3525669 23855]2021-11-18 17:43:55 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-339c96-10.ibd' with space ID 48. Another data file called ./test/t8.ibd exists with the same space ID.
|
# 2021-11-18T17:44:24 [3378597] | [rr 3525669 23859]2021-11-18 17:43:55 0 [Note] InnoDB: Starting a batch to recover 301 pages from redo log.
|
# 2021-11-18T17:44:24 [3378597] | [rr 3525669 23873]2021-11-18 17:43:55 0 [ERROR] InnoDB: Space id and page no stored in the page, read in are [page id: space=4279425345, page number=2], should be [page id: space=48, page number=2]
|
# 2021-11-18T17:44:24 [3378597] | [rr 3525669 23878]mysqld: /data/Server/10.6_WAT/storage/innobase/log/log0recv.cc:276: log_phys_t::apply_status log_phys_t::apply(const buf_block_t&, uint16_t&) const: Assertion `mach_read_from_4(frame + 34U) == block.page.id().space()' failed.
|
|
(rr) bt
|
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
|
#1 0x00007fa1a449f859 in __GI_abort () at abort.c:79
|
#2 0x00007fa1a449f729 in __assert_fail_base (fmt=0x7fa1a4635588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55627d1f90c0 "mach_read_from_4(frame + 34U) == block.page.id().space()",
|
file=0x55627d1f8a00 "/data/Server/10.6_WAT/storage/innobase/log/log0recv.cc", line=276, function=<optimized out>) at assert.c:92
|
#3 0x00007fa1a44b0f36 in __GI___assert_fail (assertion=0x55627d1f90c0 "mach_read_from_4(frame + 34U) == block.page.id().space()", file=0x55627d1f8a00 "/data/Server/10.6_WAT/storage/innobase/log/log0recv.cc", line=276,
|
function=0x55627d1f8de0 "log_phys_t::apply_status log_phys_t::apply(const buf_block_t&, uint16_t&) const") at assert.c:101
|
#4 0x000055627bce0c24 in log_phys_t::apply (this=0x7fa198356028, block=..., last_offset=@0x6060001b490c: 0) at /data/Server/10.6_WAT/storage/innobase/log/log0recv.cc:276
|
#5 0x000055627bcc70ec in recv_recover_page (block=0x7fa1981a0aa0, mtr=..., Traceback (most recent call last):
|
File "/lib/x86_64-linux-gnu/../../share/gcc-10/python/libstdcxx/v6/printers.py", line 1522, in __call__
|
return self.lookup[basename].invoke(val)
|
File "/lib/x86_64-linux-gnu/../../share/gcc-10/python/libstdcxx/v6/printers.py", line 1459, in invoke
|
return self.function(self.name, value)
|
File "/lib/x86_64-linux-gnu/../../share/gcc-10/python/libstdcxx/v6/printers.py", line 649, in __init__
|
self.link_type = nodetype.pointer()
|
AttributeError: 'NoneType' object has no attribute 'pointer'
|
p=
|
..., space=0x612000022b40, init=0x0) at /data/Server/10.6_WAT/storage/innobase/log/log0recv.cc:2649
|
#6 0x000055627bcc86a6 in recv_recover_page (space=0x612000022b40, bpage=0x7fa1981a0aa0) at /data/Server/10.6_WAT/storage/innobase/log/log0recv.cc:2837
|
#7 0x000055627c0af55f in buf_page_t::read_complete (this=0x7fa1981a0aa0, node=...) at /data/Server/10.6_WAT/storage/innobase/buf/buf0buf.cc:3672
|
#8 0x000055627c1c8a92 in fil_aio_callback (request=...) at /data/Server/10.6_WAT/storage/innobase/fil/fil0fil.cc:2926
|
#9 0x000055627bd383a6 in io_callback (cb=0x7fa19874b768) at /data/Server/10.6_WAT/storage/innobase/os/os0file.cc:3604
|
#10 0x000055627c2fb1b0 in tpool::task_group::execute (this=0x612000022750, t=0x7fa19874b7c0) at /data/Server/10.6_WAT/tpool/task_group.cc:55
|
#11 0x000055627c2fba79 in tpool::task::execute (this=0x7fa19874b7c0) at /data/Server/10.6_WAT/tpool/task.cc:32
|
#12 0x000055627c2e8227 in tpool::thread_pool_generic::worker_main (this=0x618000000880, thread_var=0x63000001fd80) at /data/Server/10.6_WAT/tpool/tpool_generic.cc:549
|
#13 0x000055627c2fac11 in std::__invoke_impl<void, void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__f=
|
@0x604000000968: (void (tpool::thread_pool_generic::*)(class tpool::thread_pool_generic * const, struct tpool::worker_data *)) 0x55627c2e8044 <tpool::thread_pool_generic::worker_main(tpool::worker_data*)>, __t=@0x604000000960: 0x618000000880)
|
at /usr/include/c++/9/bits/invoke.h:73
|
#14 0x000055627c2fa9bc in std::__invoke<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__fn=
|
@0x604000000968: (void (tpool::thread_pool_generic::*)(class tpool::thread_pool_generic * const, struct tpool::worker_data *)) 0x55627c2e8044 <tpool::thread_pool_generic::worker_main(tpool::worker_data*)>) at /usr/include/c++/9/bits/invoke.h:95
|
#15 0x000055627c2fa84d in 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=0x604000000958) at /usr/include/c++/9/thread:244
|
#16 0x000055627c2fa797 in std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::operator() (this=0x604000000958) at /usr/include/c++/9/thread:251
|
#17 0x000055627c2fa6fc in 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=0x604000000950) at /usr/include/c++/9/thread:195
|
#18 0x00007fa1a48acd84 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
|
#19 0x00007fa1a49c6609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#20 0x00007fa1a459c293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
(rr)
|
|
pluto:/data/rqg/results/1637254461/TBR-1061/dev/shm/rqg/1637254461/218/1/rr
|
RQG
|
===
|
# git clone https://github.com/mleich1/rqg --branch experimental RQG
|
#
|
# GIT_SHOW: HEAD -> experimental 5d964598d1a7eb7957b1afa9b5950ef927803070 2021-10-29T15:21:01+02:00
|
# rqg.pl : Version 4.0.2 (2021-10)
|
#
|
# $RQG_HOME/rqg1.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=CrashRecovery1 \
|
# --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=240 \
|
# --mysqld=--plugin-load-add=file_key_management.so \
|
# --mysqld=--loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
|
# --duration=300 \
|
# --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
|
# --mysqld=--loose-innodb_read_only_compressed=OFF \
|
# --mysqld=--innodb_stats_persistent=off \
|
# --mysqld=--innodb_adaptive_hash_index=off \
|
# --mysqld=--loose-innodb_evict_tables_on_commit_debug=off \
|
# --mysqld=--loose-max-statement-time=30 \
|
# --threads=1 \
|
# --mysqld=--innodb-use-native-aio=0 \
|
# --rr=Extended \
|
# --rr_options=--wait \
|
# --mysqld=--innodb_page_size=4K \
|
# --mysqld=--innodb-buffer-pool-size=5M \
|
# --no_mask \
|
# <local settings>
|
|
Attachments
Issue Links
- relates to
-
MDEV-18644 Support FULL_CRC32 for compressed pages.
- Closed
The table test/t8.ibd has FSP_SPACE_FLAGS of 0x13, that is, innodb_page_size=4k and innodb_checksum_algorithm=full_crc32. In FSP_SPACE_FLAGS of page 2 we have the value 0x8002, which suggests that the page contents is page_compressed. The compressed data stream in that format starts at offset 26. The assertion wrongly expects to find a valid tablespace identifier at offset 34.
For page_compressed pages, we should defer the assertion until the page frame has been decompressed.
I would expect 10.5 to be affected by the same. 10.4 might be affected as well, because it supports innodb_checksum_algorithm=full_crc32, but does not enable it by default.