Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.6, 10.7(EOL), 10.8(EOL)
Description
The test case is non-deterministic. It currently fails for me every time on a debug build, but the iteration of DELETE when it fails differs between the runs. I suppose it's possible that it may not fail at all on some machines or builds.
--source include/have_innodb.inc
|
--source include/have_sequence.inc
|
|
SET @buffering= @@innodb_change_buffering; |
SET GLOBAL innodb_change_buffering= deletes; |
|
CREATE TABLE t1 ( |
a varchar(1024), |
b varchar(1024), |
c varchar(1024), |
d varchar(1024), |
e varchar(1024), |
f varchar(1024), |
g varchar(1024), |
h varchar(1024), |
key (a), |
key (b), |
key (c), |
key (d) |
) ENGINE=InnoDB;
|
|
INSERT INTO t1 SELECT REPEAT('x',10), REPEAT('x',13), REPEAT('x',427), REPEAT('x',244), REPEAT('x',9), REPEAT('x',112), REPEAT('x',814), REPEAT('x',633) FROM seq_1_to_1024; |
|
CREATE TABLE t2 ( |
a varchar(1024), |
b varchar(1024), |
c varchar(1024), |
d varchar(1024), |
e varchar(1024), |
f varchar(1024), |
g varchar(1024), |
h varchar(1024), |
i varchar(1024), |
j varchar(1024), |
k varchar(1024), |
l varchar(1024), |
m varchar(1024), |
key (a), |
key (b), |
key (c), |
key (d), |
key (e), |
key (f) |
) ENGINE=InnoDB;
|
|
INSERT INTO t2 SELECT REPEAT('x',512), REPEAT('x',512), REPEAT('x',512), REPEAT('x',512), REPEAT('x',512), REPEAT('x',512), REPEAT('x',512), REPEAT('x',512), REPEAT('x',512), REPEAT('x',512), REPEAT('x',512), REPEAT('x',512), REPEAT('x',512) FROM seq_1_to_16384; |
|
--let $run=1024
|
while ($run)
|
{
|
eval DELETE FROM t1 LIMIT 1 /* $run */; |
--dec $run |
}
|
|
# Cleanup
|
DROP TABLE t1, t2; |
SET GLOBAL innodb_change_buffering= @buffering; |
10.6 27b0030b debug |
mariadbd: /data/src/10.6/storage/innobase/include/buf0buf.h:2012: void buf_page_t::set_state(uint32_t): Assertion `s <= READ_FIX' failed.
|
220410 0:39:30 [ERROR] mysqld got signal 6 ;
|
|
#7 0x00007f9dd779e662 in __GI___assert_fail (assertion=0x55c5017869f9 "s <= READ_FIX", file=0x55c501785ca8 "/data/src/10.6/storage/innobase/include/buf0buf.h", line=2012, function=0x55c501786938 "void buf_page_t::set_state(uint32_t)") at assert.c:101
|
#8 0x000055c5010d9ddc in buf_page_t::set_state (this=0x7f9dd0dd19f0, s=2147483649) at /data/src/10.6/storage/innobase/include/buf0buf.h:2012
|
#9 0x000055c5010fdbe8 in buf_page_init_for_read (mode=132, page_id=..., zip_size=0, unzip=false) at /data/src/10.6/storage/innobase/buf/buf0rea.cc:153
|
#10 0x000055c5010fe36b in buf_read_page_low (err=0x7f9dd0b32524, space=0x7f9d80236c68, sync=true, mode=132, page_id=..., zip_size=0, unzip=false) at /data/src/10.6/storage/innobase/buf/buf0rea.cc:299
|
#11 0x000055c5010fed45 in buf_read_page (page_id=..., zip_size=0) at /data/src/10.6/storage/innobase/buf/buf0rea.cc:467
|
#12 0x000055c5010d0425 in buf_page_get_low (page_id=..., zip_size=0, rw_latch=2, guess=0x0, mode=10, mtr=0x7f9dd0b33ce0, err=0x7f9dd0b32a28, allow_ibuf_merge=true) at /data/src/10.6/storage/innobase/buf/buf0buf.cc:2613
|
#13 0x000055c5010d2023 in buf_page_get_gen (page_id=..., zip_size=0, rw_latch=2, guess=0x0, mode=10, mtr=0x7f9dd0b33ce0, err=0x7f9dd0b32a28, allow_ibuf_merge=true) at /data/src/10.6/storage/innobase/buf/buf0buf.cc:3046
|
#14 0x000055c5010988e5 in btr_cur_search_to_nth_level_func (index=0x7f9d801ad248, level=0, tuple=0x7f9d80b94838, mode=PAGE_CUR_LE, latch_mode=2, cursor=0x7f9dd0b33a70, ahi_latch=0x0, mtr=0x7f9dd0b33ce0, autoinc=0) at /data/src/10.6/storage/innobase/btr/btr0cur.cc:1602
|
#15 0x000055c500fd3ac0 in btr_pcur_open_low (index=0x7f9d801ad248, level=0, tuple=0x7f9d80b94838, mode=PAGE_CUR_LE, latch_mode=4098, cursor=0x7f9dd0b33a70, autoinc=0, mtr=0x7f9dd0b33ce0) at /data/src/10.6/storage/innobase/include/btr0pcur.inl:369
|
#16 0x000055c500fd7c33 in row_search_index_entry (index=0x7f9d801ad248, entry=0x7f9d80b94838, mode=4098, pcur=0x7f9dd0b33a70, mtr=0x7f9dd0b33ce0) at /data/src/10.6/storage/innobase/row/row0row.cc:1311
|
#17 0x000055c500ffd70f in row_upd_sec_index_entry (node=0x7f9d80074ea8, thr=0x7f9d800752c0) at /data/src/10.6/storage/innobase/row/row0upd.cc:2007
|
#18 0x000055c500ffe28c in row_upd_sec_step (node=0x7f9d80074ea8, thr=0x7f9d800752c0) at /data/src/10.6/storage/innobase/row/row0upd.cc:2199
|
#19 0x000055c501000e3a in row_upd (node=0x7f9d80074ea8, thr=0x7f9d800752c0) at /data/src/10.6/storage/innobase/row/row0upd.cc:2936
|
#20 0x000055c501001270 in row_upd_step (thr=0x7f9d800752c0) at /data/src/10.6/storage/innobase/row/row0upd.cc:3051
|
#21 0x000055c500fabd03 in row_update_for_mysql (prebuilt=0x7f9d802232a8) at /data/src/10.6/storage/innobase/row/row0mysql.cc:1700
|
#22 0x000055c500dec50c in ha_innobase::delete_row (this=0x7f9d801b1710, record=0x7f9d8022f360 "") at /data/src/10.6/storage/innobase/handler/ha_innodb.cc:8777
|
#23 0x000055c5009e945b in handler::ha_delete_row (this=0x7f9d801b1710, buf=0x7f9d8022f360 "") at /data/src/10.6/sql/handler.cc:7677
|
#24 0x000055c500bbe65f in TABLE::delete_row (this=0x7f9d801b0e18) at /data/src/10.6/sql/sql_delete.cc:281
|
#25 0x000055c500bbb542 in mysql_delete (thd=0x7f9d80000db8, table_list=0x7f9d800156a8, conds=0x0, order_list=0x7f9d80005c00, limit=1, options=0, result=0x0) at /data/src/10.6/sql/sql_delete.cc:830
|
#26 0x000055c5006456b0 in mysql_execute_command (thd=0x7f9d80000db8, is_called_from_prepared_stmt=false) at /data/src/10.6/sql/sql_parse.cc:4822
|
#27 0x000055c500650036 in mysql_parse (thd=0x7f9d80000db8, rawbuf=0x7f9d800155c0 "DELETE FROM t1 LIMIT 1 /* 875 */", length=32, parser_state=0x7f9dd0b35500) at /data/src/10.6/sql/sql_parse.cc:8045
|
#28 0x000055c50063c671 in dispatch_command (command=COM_QUERY, thd=0x7f9d80000db8, packet=0x7f9d8000b879 "DELETE FROM t1 LIMIT 1 /* 875 */", packet_length=32, blocking=true) at /data/src/10.6/sql/sql_parse.cc:1912
|
#29 0x000055c50063af9e in do_command (thd=0x7f9d80000db8, blocking=true) at /data/src/10.6/sql/sql_parse.cc:1409
|
#30 0x000055c5007f49ca in do_handle_one_connection (connect=0x55c5035b2938, put_in_cache=true) at /data/src/10.6/sql/sql_connect.cc:1418
|
#31 0x000055c5007f4669 in handle_one_connection (arg=0x55c5035b2858) at /data/src/10.6/sql/sql_connect.cc:1312
|
#32 0x000055c500d0f00c in pfs_spawn_thread (arg=0x55c5035b2228) at /data/src/10.6/storage/perfschema/pfs.cc:2201
|
#33 0x00007f9dd7c6aea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#34 0x00007f9dd7867def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
The failure apparently started happening on 10.6 after this commit:
commit 8684af76e34641331695860fc13eb9fc2ff94215
|
Author: Marko Mäkelä
|
Date: Thu Mar 24 16:09:04 2022 +0200
|
|
MDEV-28137 Some memory transactions are unnecessarily complex
|
Attachments
Issue Links
- relates to
-
MDEV-35181 Assertion 'state < buf_page_t::READ_FIX' in buf_page_create_low()
-
- Closed
-
In a release build, the test does not always fail. When it does, it triggers a SIGSEGV in a purge task:
10.6 d90c5ddd8beb961434200f7e02fac3a3a121f7e2
#5 buf_page_t::state (this=0x0) at /mariadb/10.6/storage/innobase/include/buf0buf.h:713
#6 buf_pool_t::watch_unset (this=0x55716fb36300 <buf_pool>, id={m_id = 21474836618}, chain=@0x557171c57530: {first = 0x7fd1ba156dd0}) at /mariadb/10.6/storage/innobase/buf/buf0buf.cc:2153
#7 0x000055716ecb59a4 in btr_cur_search_to_nth_level_func (index=index@entry=0x7fd14800ae08, level=level@entry=0, tuple=<optimized out>, mode=mode@entry=PAGE_CUR_LE, latch_mode=<optimized out>, cursor=cursor@entry=0x7fd05cff7d90, ahi_latch=<optimized out>, mtr=<optimized out>, autoinc=<optimized out>) at /mariadb/10.6/storage/innobase/btr/btr0cur.cc:1684
#8 0x000055716f26a3c3 in btr_pcur_open_low (index=0x7fd14800ae08, tuple=<optimized out>, latch_mode=<optimized out>, cursor=0x7fd05cff7d90, mtr=<optimized out>, autoinc=0, mode=PAGE_CUR_LE, level=0) at /mariadb/10.6/storage/innobase/include/btr0pcur.inl:369
#9 0x000055716f26a428 in row_search_index_entry (index=index@entry=0x7fd14800ae08, entry=entry@entry=0x7fd0380bda28, mode=<optimized out>, pcur=pcur@entry=0x7fd05cff7d90, mtr=mtr@entry=0x7fd05cff8000) at /mariadb/10.6/storage/innobase/row/row0row.cc:1311
#10 0x000055716f265623 in row_purge_remove_sec_if_poss_leaf (node=0x557171cb0a80, index=0x7fd14800ae08, entry=0x7fd0380bda28) at /mariadb/10.6/storage/innobase/row/row0purge.cc:534
I can repeat this as described on a debug build, even with https://rr-project.org. The scenario is single-threaded. Let us follow it from the most recent block initialization:
(rr) bt
…
#3 0x000056428b182391 in buf_page_t::set_state (this=0x7f7bcd79b300, s=1)
at /mariadb/10.6/storage/innobase/include/buf0buf.h:2013
#4 0x000056428b1a0df8 in buf_LRU_get_free_only () at /mariadb/10.6/storage/innobase/buf/buf0lru.cc:299
#5 0x000056428b1a141b in buf_LRU_get_free_block (have_mutex=false)
at /mariadb/10.6/storage/innobase/buf/buf0lru.cc:414
#6 0x000056428b1a7441 in buf_page_init_for_read (mode=132, page_id={m_id = 21474836618}, zip_size=0,
unzip=false) at /mariadb/10.6/storage/innobase/buf/buf0rea.cc:119
#7 0x000056428b1a7dfb in buf_read_page_low (err=0x7f7bc405b404, space=0x7f7ba419b6f0, sync=true,
mode=132, page_id={m_id = 21474836618}, zip_size=0, unzip=false)
at /mariadb/10.6/storage/innobase/buf/buf0rea.cc:299
#8 0x000056428b1a882d in buf_read_page (page_id={m_id = 21474836618}, zip_size=0)
at /mariadb/10.6/storage/innobase/buf/buf0rea.cc:467
…
(rr) c
Continuing.
Thread 2 hit Hardware watchpoint 2: -location $b.page.id_
Old value = {m_id = 18446744073709551615}
New value = {m_id = 21474836618}
buf_page_t::init (this=0x7f7bcd79b300, state=2147483648, id={m_id = 21474836618})
at /mariadb/10.6/storage/innobase/include/buf0buf.h:699
699 zip.fix= state;
Continuing.
Thread 2 hit Hardware watchpoint 1: -location bpage.zip.fix
Old value = {m = {<std::__atomic_base<unsigned int>> = {_M_i = 1}, <No data fields>}}
New value = {m = {<std::__atomic_base<unsigned int>> = {_M_i = 2147483648}, <No data fields>}}
std::__atomic_base<unsigned int>::store (__m=std::memory_order_relaxed, __i=2147483648,
this=0x7f7bcd79b408) at /usr/include/c++/11/bits/atomic_base.h:458
458 }
(rr) bt
…
#3 0x000056428b011948 in buf_page_t::init (this=0x7f7bcd79b300, state=2147483648, id=
{m_id = 21474836618}) at /mariadb/10.6/storage/innobase/include/buf0buf.h:699
#4 0x000056428b17afaf in buf_block_t::initialise (this=0x7f7bcd79b300, page_id={m_id = 21474836618},
zip_size=0, fix=2147483648) at /mariadb/10.6/storage/innobase/buf/buf0buf.cc:3188
#5 0x000056428b1a746a in buf_page_init_for_read (mode=132, page_id={m_id = 21474836618}, zip_size=0,
unzip=false) at /mariadb/10.6/storage/innobase/buf/buf0rea.cc:120
So, we had just initialized the block and set it under read-fix:
block->initialise(page_id, zip_size, buf_page_t::READ_FIX);
in buf_page_t::read_complete() by the io-handler thread. */
Everything looks normal until we attempt to merge a buffer pool watch block descriptor into the newly allocated block descriptor:
(rr) bt
#0 buf_pool_t::watch_remove (this=0x56428bd81d80 <buf_pool>, w=0x56428bd88c40 <buf_pool+28352>, chain=
@0x56428d6c56d0: {first = 0x7f7bcd7a6b80}) at /mariadb/10.6/storage/innobase/buf/buf0rea.cc:59
#1 0x000056428b1a7658 in buf_page_init_for_read (mode=132, page_id={m_id = 21474836618}, zip_size=0,
unzip=false) at /mariadb/10.6/storage/innobase/buf/buf0rea.cc:153
watch_remove() returned a value UNFIXED + 1. The assertion fails, because we are attempting to assign the value READ_FIX + 1. In this case, it is actually fine, because the block was already read-fixed.
diff --git a/storage/innobase/include/buf0buf.h b/storage/innobase/include/buf0buf.h
index 7c372379ad3..2dcf3710e09 100644
--- a/storage/innobase/include/buf0buf.h
+++ b/storage/innobase/include/buf0buf.h
@@ -2009,7 +2009,8 @@ inline void buf_page_t::set_state(uint32_t s)
{
mysql_mutex_assert_owner(&buf_pool.mutex);
ut_ad(s <= REMOVE_HASH || s >= UNFIXED);
- ut_ad(s <= READ_FIX);
+ ut_ad(s < WRITE_FIX);
+ ut_ad(s <= READ_FIX || is_read_fixed());
zip.fix= s;
}
That fixes the assertion failure, but the SIGSEGV would remain. I am debugging it further.