Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
10.6.6
Description
GIT_SHOW: HEAD, origin/bb-10.6-release 6dd07fbd042132729e5dea0a6a9b35f07a33e9e5 2022-02-03T16:51:08+02:00
|
|
mysqld: /data/Server/bb-10.6-releaseB/storage/innobase/mtr/mtr0mtr.cc:1207: void mtr_t::page_lock(buf_block_t*, ulint): Assertion `state < buf_page_t::UNFIXED || page_id_t(page_get_space_id(block->page.frame), page_get_page_no(block->page.frame)) == block->page.id()' failed.
|
...
|
(rr) bt
|
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
|
#1 0x00007f66fe3cc859 in __GI_abort () at abort.c:79
|
#2 0x00007f66fe3cc729 in __assert_fail_base (fmt=0x7f66fe562588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
|
assertion=0x564faa3ecf18 "state < buf_page_t::UNFIXED || page_id_t(page_get_space_id(block->page.frame), page_get_page_no(block->page.frame)) == block->page.id()",
|
file=0x564faa3ebf18 "/data/Server/bb-10.6-releaseB/storage/innobase/mtr/mtr0mtr.cc", line=1207, function=<optimized out>) at assert.c:92
|
#3 0x00007f66fe3ddf36 in __GI___assert_fail (
|
assertion=0x564faa3ecf18 "state < buf_page_t::UNFIXED || page_id_t(page_get_space_id(block->page.frame), page_get_page_no(block->page.frame)) == block->page.id()",
|
file=0x564faa3ebf18 "/data/Server/bb-10.6-releaseB/storage/innobase/mtr/mtr0mtr.cc", line=1207, function=0x564faa3ece78 "void mtr_t::page_lock(buf_block_t*, ulint)") at assert.c:101
|
#4 0x0000564fa9b7c77d in mtr_t::page_lock (this=0x607509018820, block=0x607509051ca0, rw_latch=2) at /data/Server/bb-10.6-releaseB/storage/innobase/mtr/mtr0mtr.cc:1207
|
#5 0x0000564fa9d581eb in buf_page_get_low (page_id=..., zip_size=0, rw_latch=2, guess=0x0, mode=12, mtr=0x607509018820, err=0x0, allow_ibuf_merge=false)
|
at /data/Server/bb-10.6-releaseB/storage/innobase/buf/buf0buf.cc:2957
|
#6 0x0000564fa9d58712 in buf_page_get_gen (page_id=..., zip_size=0, rw_latch=2, guess=0x0, mode=12, mtr=0x607509018820, err=0x0, allow_ibuf_merge=false)
|
at /data/Server/bb-10.6-releaseB/storage/innobase/buf/buf0buf.cc:3028
|
#7 0x0000564fa9df4411 in fil_crypt_get_page_throttle (state=0x607509018d60, offset=312, mtr=0x607509018820, sleeptime_ms=0x6075090187c8)
|
at /data/Server/bb-10.6-releaseB/storage/innobase/fil/fil0crypt.cc:1705
|
#8 0x0000564fa9df4793 in fil_crypt_rotate_page (key_state=0x607509018d54, state=0x607509018d60) at /data/Server/bb-10.6-releaseB/storage/innobase/fil/fil0crypt.cc:1788
|
#9 0x0000564fa9df4eef in fil_crypt_rotate_pages (key_state=0x607509018d54, state=0x607509018d60) at /data/Server/bb-10.6-releaseB/storage/innobase/fil/fil0crypt.cc:1925
|
#10 0x0000564fa9df5785 in fil_crypt_thread () at /data/Server/bb-10.6-releaseB/storage/innobase/fil/fil0crypt.cc:2099
|
#11 0x0000564fa9d7c08f in std::__invoke_impl<void, void (*)()> (__f=@0x669f0c03b718: 0x564fa9df559f <fil_crypt_thread()>) at /usr/include/c++/9/bits/invoke.h:60
|
#12 0x0000564fa9d7c03b in std::__invoke<void (*)()> (__fn=@0x669f0c03b718: 0x564fa9df559f <fil_crypt_thread()>) at /usr/include/c++/9/bits/invoke.h:95
|
#13 0x0000564fa9d7bfdc in std::thread::_Invoker<std::tuple<void (*)()> >::_M_invoke<0ul> (this=0x669f0c03b718) at /usr/include/c++/9/thread:244
|
#14 0x0000564fa9d7bfae in std::thread::_Invoker<std::tuple<void (*)()> >::operator() (this=0x669f0c03b718) at /usr/include/c++/9/thread:251
|
#15 0x0000564fa9d7bf8e in std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)()> > >::_M_run (this=0x669f0c03b710) at /usr/include/c++/9/thread:195
|
#16 0x00007ffc844ecde4 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
|
#17 0x0000607509023609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#18 0x00007f66fe4c9293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
pluto:/data/results/1675702417/TBR-1227$ _RR_TRACE_DIR=./1/rr/ rr replay --mark-stdio
|
(rr)
|
|
# git clone https://github.com/mleich1/rqg --branch <pick the right branch> RQG
|
#
|
# GIT_SHOW: HEAD -> master, origin/master, origin/HEAD 624894590f3b4e59919b9c621783265b584e5482 2023-01-30T17:12:10+01:00
|
# rqg.pl : Version 4.2.1 (2022-12)
|
#
|
# $RQG_HOME/rqg.pl \
|
# --duration=300 \
|
# --queries=10000000 \
|
# --no_mask \
|
# --seed=random \
|
# --max_gd_duration=1200 \
|
# --skip_gendata \
|
# --engine=InnoDB \
|
# --rpl_mode=none \
|
# --gendata_sql=simp_TBR-1227.sql \
|
# --mysqld=--log-output=none \
|
# --mysqld=--wait_timeout=28800 \
|
# --mysqld=--loose-innodb_read_only_compressed=OFF \
|
# --mysqld=--plugin-load-add=file_key_management.so \
|
# --mysqld=--innodb_page_size=64K \
|
# --mysqld=--slave_net_timeout=60 \
|
# --mysqld=--log_bin_trust_function_creators=1 \
|
# --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
|
# --mysqld=--loose-table_lock_wait_timeout=50 \
|
# --mysqld=--loose_innodb_lock_schedule_algorithm=fcfs \
|
# --mysqld=--loose-max-statement-time=30 \
|
# --mysqld=--lock-wait-timeout=86400 \
|
# --mysqld=--file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
|
# --mysqld=--net_read_timeout=30 \
|
# --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
|
# --mysqld=--interactive_timeout=28800 \
|
# --mysqld=--log-bin \
|
# --mysqld=--loose-idle_transaction_timeout=0 \
|
# --mysqld=--net_write_timeout=60 \
|
# --mysqld=--innodb-lock-wait-timeout=50 \
|
# --mysqld=--loose-idle_readonly_transaction_timeout=0 \
|
# --mysqld=--connect_timeout=60 \
|
# --mysqld=--innodb-buffer-pool-size=24M \
|
# --mysqld=--loose-plugin-load-add=provider_lz4.so \
|
# --mysqld=--sync-binlog=1 \
|
# --mysqld=--loose-idle_write_transaction_timeout=0 \
|
# --reporters=Backtrace,Deadlock,None \
|
# --validators=None \
|
# --grammar=simp_TBR-1227.yy \
|
# --threads=1 \
|
# <local settings>
|
|
I tried to derive some MTR test but had no luck.
|
|
simp_TBR-1227.yy
|
----------------------------
|
my_int:
|
{ if (not defined $my_int) { $my_int = 1 } else { ++$my_int } ; return $my_int } ;
|
|
thread1:
|
INSERT INTO t1 (col1, col_text) VALUES ( my_int , REPEAT(SUBSTR(CAST( $my_int AS CHAR),1,1), @fill_amount) ) ;
|
|
thread1_connect:
|
SET AUTOCOMMIT = 0; SET @fill_amount = (@@innodb_page_size * 2 ) + 1 ;
|
|
thread1_init:
|
SET GLOBAL innodb_encrypt_tables = 1 , GLOBAL innodb_random_read_ahead = 1 , GLOBAL innodb_encryption_threads = 1 ; CREATE TABLE t1 ( col1 INT, col_text TEXT ) ENGINE = InnoDB ROW_FORMAT = Dynamic ;
|
|
Thread 10 hit Hardware watchpoint 3: -location block->page.zip.fix.m._M_i
Old value = 2147483648
New value = 536870912
std::__atomic_base<unsigned int>::fetch_sub (__m=std::memory_order_relaxed, __i=1610612736, this=0x607509051cf8)
at /usr/include/c++/9/bits/atomic_base.h:551
551 { return __atomic_fetch_sub(&_M_i, __i, int(__m)); }
(rr) where
#0 std::__atomic_base<unsigned int>::fetch_sub (__m=std::memory_order_relaxed, __i=1610612736, this=0x607509051cf8)
at /usr/include/c++/9/bits/atomic_base.h:551
#1 Atomic_relaxed<unsigned int>::fetch_sub (this=0x607509051cf8, i=1610612736, o=std::memory_order_relaxed)
at /data/Server/bb-10.6-releaseB/include/my_atomic_wrapper.h:55
#2 0x0000564fa9d5bc80 in buf_page_t::read_complete (this=0x607509051ca0, node=...)
at /data/Server/bb-10.6-releaseB/storage/innobase/buf/buf0buf.cc:3737
#3 0x0000564fa9de828c in fil_aio_callback (request=...) at /data/Server/bb-10.6-releaseB/storage/innobase/fil/fil0fil.cc:2930
#4 0x0000564fa9b89466 in io_callback (cb=0x67f8598baee0) at /data/Server/bb-10.6-releaseB/storage/innobase/os/os0file.cc:3604
#5 0x0000564fa9e7628a in tpool::task_group::execute (this=0x564facd75400, t=0x67f8598baf38)
at /data/Server/bb-10.6-releaseB/tpool/task_group.cc:55
#6 0x0000564fa9e765c4 in tpool::task::execute (this=0x67f8598baf38) at /data/Server/bb-10.6-releaseB/tpool/task.cc:32
#7 0x0000564fa9e6efa7 in tpool::thread_pool_generic::worker_main (this=0x564facd31260, thread_var=0x564facd40d80)
at /data/Server/bb-10.6-releaseB/tpool/tpool_generic.cc:549
#8 0x0000564fa9e76092 in std::__invoke_impl<void, void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__f=
@0x581f100028d8: (void (tpool::thread_pool_generic::*)(tpool::thread_pool_generic * const, tpool::worker_data *)) 0x564fa9e6ef0e <tpool::thread_pool_generic::worker_main(tpool::worker_data*)>, __t=@0x581f100028d0: 0x564facd31260) at /usr/include/c++/9/bits/invoke.h:73
#9 0x0000564fa9e75f74 in std::__invoke<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__fn=
@0x581f100028d8: (void (tpool::thread_pool_generic::*)(tpool::thread_pool_generic * const, tpool::worker_data *)) 0x564fa9e6ef0e <tpool::thread_pool_generic::worker_main(tpool::worker_data*)>) at /usr/include/c++/9/bits/invoke.h:95
#10 0x0000564fa9e75e93 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=0x581f100028c8) at /usr/include/c++/9/thread:244
#11 0x0000564fa9e75e2e in std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::operator() (this=0x581f100028c8) at /usr/include/c++/9/thread:251
#12 0x0000564fa9e75e0e 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=0x581f100028c0) at /usr/include/c++/9/thread:195
#13 0x00007ffc844ecde4 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#14 0x0000607509023609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x00007f66fe4c9293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
(rr) when
Current event: 37835
(rr) p read_id
$2 = {m_id = 0}
Above page is an uninitialized page and we mark the page state as UNFIXED.
Encryption threads tries to acquire the page and we end up crashing in
mysqld: /data/Server/bb-10.6-releaseB/storage/innobase/mtr/mtr0mtr.cc:1207: void mtr_t::page_lock(buf_block_t*, ulint): Assertion `state < buf_page_t::UNFIXED || page_id_t(page_get_space_id(block->page.frame), page_get_page_no(block->page.frame)) == block->page.id()'
Thread 3 hit Hardware watchpoint 2: -location block->page.zip.fix
Old value = {m = {<std::__atomic_base<unsigned int>> = {static _S_alignment = 4, _M_i = 536870912}, <No data fields>}}
New value = {m = {<std::__atomic_base<unsigned int>> = {static _S_alignment = 4, _M_i = 536870913}, <No data fields>}}
Thread 3 hit Hardware watchpoint 3: -location block->page.zip.fix.m._M_i
Old value = 536870912
New value = 536870913
std::__atomic_base<unsigned int>::fetch_add (__m=std::memory_order_relaxed, __i=1, this=0x607509051cf8)
at /usr/include/c++/9/bits/atomic_base.h:541
541 { return __atomic_fetch_add(&_M_i, __i, int(__m)); }
(rr) where
#0 std::__atomic_base<unsigned int>::fetch_add (__m=std::memory_order_relaxed, __i=1, this=0x607509051cf8)
at /usr/include/c++/9/bits/atomic_base.h:541
#1 Atomic_relaxed<unsigned int>::fetch_add (this=0x607509051cf8, i=1, o=std::memory_order_relaxed)
at /data/Server/bb-10.6-releaseB/include/my_atomic_wrapper.h:53
#2 0x0000564fa9b1a18d in buf_page_t::fix (this=0x607509051ca0, count=1) at /data/Server/bb-10.6-releaseB/storage/innobase/include/buf0buf.h:865
#3 0x0000564fa9d56a2f in buf_page_get_low (page_id=..., zip_size=0, rw_latch=2, guess=0x0, mode=12, mtr=0x607509018820, err=0x0,
allow_ibuf_merge=false) at /data/Server/bb-10.6-releaseB/storage/innobase/buf/buf0buf.cc:2557
#4 0x0000564fa9d58712 in buf_page_get_gen (page_id=..., zip_size=0, rw_latch=2, guess=0x0, mode=12, mtr=0x607509018820, err=0x0,
allow_ibuf_merge=false) at /data/Server/bb-10.6-releaseB/storage/innobase/buf/buf0buf.cc:3028
#5 0x0000564fa9df4411 in fil_crypt_get_page_throttle (state=0x607509018d60, offset=312, mtr=0x607509018820, sleeptime_ms=0x6075090187c8)
at /data/Server/bb-10.6-releaseB/storage/innobase/fil/fil0crypt.cc:1705
#6 0x0000564fa9df4793 in fil_crypt_rotate_page (key_state=0x607509018d54, state=0x607509018d60)
at /data/Server/bb-10.6-releaseB/storage/innobase/fil/fil0crypt.cc:1788
#7 0x0000564fa9df4eef in fil_crypt_rotate_pages (key_state=0x607509018d54, state=0x607509018d60)
at /data/Server/bb-10.6-releaseB/storage/innobase/fil/fil0crypt.cc:1925
#8 0x0000564fa9df5785 in fil_crypt_thread () at /data/Server/bb-10.6-releaseB/storage/innobase/fil/fil0crypt.cc:2099
#9 0x0000564fa9d7c08f in std::__invoke_impl<void, void (*)()> (__f=@0x669f0c03b718: 0x564fa9df559f <fil_crypt_thread()>)
at /usr/include/c++/9/bits/invoke.h:60
#10 0x0000564fa9d7c03b in std::__invoke<void (*)()> (__fn=@0x669f0c03b718: 0x564fa9df559f <fil_crypt_thread()>)
at /usr/include/c++/9/bits/invoke.h:95
#11 0x0000564fa9d7bfdc in std::thread::_Invoker<std::tuple<void (*)()> >::_M_invoke<0ul> (this=0x669f0c03b718) at /usr/include/c++/9/thread:244
#12 0x0000564fa9d7bfae in std::thread::_Invoker<std::tuple<void (*)()> >::operator() (this=0x669f0c03b718) at /usr/include/c++/9/thread:251
#13 0x0000564fa9d7bf8e in std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)()> > >::_M_run (this=0x669f0c03b710)
at /usr/include/c++/9/thread:195
#14 0x00007ffc844ecde4 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#15 0x0000607509023609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#16 0x00007f66fe4c9293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
(rr) when
Current event: 37891
In fil_crypt_get_page_throttle(), we need to check whether page is allocated before fetching the buffer pool?
buf_block_t* block = buf_page_get_gen(page_id, zip_size, RW_X_LATCH,
NULL,
BUF_PEEK_IF_IN_POOL, mtr);
if (block != NULL) {
/* page was in buffer pool */
state->crypt_stat.pages_read_from_cache++;
return block;
}
if (space->is_stopping()) {
return NULL;
}
if (DB_SUCCESS_LOCKED_REC
!= fseg_page_is_allocated(space, state->offset)) {
/* page is already freed */
return NULL;
}