[MDEV-20038] Assertion `rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)' failed. in btr_cur_search_to_nth_level_func - Jira

Details

Type: Bug
Status: Stalled (View Workflow)
Priority: Major
Resolution: Unresolved
Affects Version/s: 10.0.26, 10.3.11, 10.4.7, 10.0(EOL), 10.1(EOL), 10.2(EOL), 10.5
Fix Version/s: 10.5
Component/s: Storage Engine - InnoDB, Storage Engine - XtraDB
Labels:

Description

Assert hit during RQG testing on

10.4.7 commit 70c2bde931246ea4966d82fa56773b8ef1e0074f     2019-07-09

mysqld: storage/innobase/btr/btr0cur.cc:1444: dberr_t btr_cur_search_to_nth_level_func(dict_index_t*, ulint, const dtuple_t*, page_cur_mode_t, ulint, btr_cur_t*, rw_lock_t*, const char*, unsigned int, mtr_t*, ib_uint64_t): Assertion `rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)' failed.

190710 19:41:21 [ERROR] mysqld got signal 6 ;

...

# 2019-07-10T19:41:42 [243109] | Query (0x7fd098011180): UPDATE t2 SET col1 = 1175 LIMIT 2  /* E_R Thread9 QNO 607 CON_ID 24 */

# 2019-07-10T19:41:42 [243109] | Connection ID (thread ID): 366

# 2019-07-10T19:41:42 [243109] | Status: NOT_KILLED

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

MDEV-20038.tgz
3 kB
2019-07-11 17:28
MDEV-20038.yy
1 kB
2019-08-23 13:53
prt
76 kB
2019-07-11 17:29
simp_MDEV-20038.cfg
38 kB
2019-08-23 13:54

Activity

Ascending order - Click to sort in descending order

View 6 older comments

Marko Mäkelä added a comment - 2019-08-23 07:56

I gave MDEV-20038.tgz one more try on mysql-5.6.31 (replacing ALGORITHM=NOCOPY with ALGORITHM=INPLACE in order to avoid a syntax error). According to top, the mysqltest_background.sh is not running in parallel with the test, and that might explain why the failure is not being repeated.

mleich, could you please check if MySQL 5.6 or 5.7 are affected? I used the following procedure:

cd /mariadb/mysql-server

git checkout mysql-5.6.31

mkdir /dev/shm/5.6

cd /dev/shm/5.6

CXXFLAGS='-O2 -std=gnu++98' cmake -DWITH_DEBUG=ON -DWITH_EMBEDDED_SERVER=OFF /mariadb/mysql-server

nice make -j$(nproc}

cd /mariadb/mysql-server

MTR_BINDIR=/dev/shm/5.6 perl -I. mysql-test-run.pl main.ml_MDEV-20038

Marko Mäkelä added a comment - 2019-08-23 07:56 I gave MDEV-20038.tgz one more try on mysql-5.6.31 (replacing ALGORITHM=NOCOPY with ALGORITHM=INPLACE in order to avoid a syntax error). According to top , the mysqltest_background.sh is not running in parallel with the test, and that might explain why the failure is not being repeated. mleich , could you please check if MySQL 5.6 or 5.7 are affected? I used the following procedure: cd /mariadb/mysql-server git checkout mysql-5.6.31 mkdir /dev/shm/5.6 cd /dev/shm/5.6 CXXFLAGS='-O2 -std=gnu++98' cmake -DWITH_DEBUG=ON -DWITH_EMBEDDED_SERVER=OFF /mariadb/mysql-server nice make -j$(nproc} cd /mariadb/mysql-server MTR_BINDIR=/dev/shm/5.6 perl -I. mysql-test-run.pl main.ml_MDEV-20038

Matthias Leich added a comment - 2019-08-23 13:51 - edited

Replay also on MySQL 5.6.31-debug-log

      https://github.com/mysql/mysql-server , git checkout 5.6 , commit 6594835303da437105bb3841df976620b716e088

      There comes a

       2019-08-23 15:42:21 7f8c4d6b9700  InnoDB: Assertion failure in thread 140240571045632 in file row0ins.cc line 1913

       InnoDB: Failing assertion: s_latch == rw_lock_own(&index->lock, 352)

       ....

       Query (7f8c20004c90): UPDATE t2 SET col1 = 2722 LIMIT 2  /* E_R Thread2 QNO 7933 CON_ID 10 */

       Status: NOT_KILLED

if algorithm = NOCOPY gets replaced by algorithm INPLACE.

The MTR based brute force test case does not run well on 5.6.

So I uploaded the RQG test

MDEV-20038.yy -- Simplified RQG grammar

simp_MDEV-20038.cfg - RQG config file

The test needs (only) threads=4 and replays in ~ 60s on MySQL 5.6.

Matthias Leich added a comment - 2019-08-23 13:51 - edited Replay also on MySQL 5.6.31-debug-log https://github.com/mysql/mysql-server , git checkout 5.6 , commit 6594835303da437105bb3841df976620b716e088 There comes a 2019-08-23 15:42:21 7f8c4d6b9700 InnoDB: Assertion failure in thread 140240571045632 in file row0ins.cc line 1913 InnoDB: Failing assertion: s_latch == rw_lock_own(&index->lock, 352) .... Query (7f8c20004c90): UPDATE t2 SET col1 = 2722 LIMIT 2 /* E_R Thread2 QNO 7933 CON_ID 10 */ Status: NOT_KILLED if algorithm = NOCOPY gets replaced by algorithm INPLACE. The MTR based brute force test case does not run well on 5.6. So I uploaded the RQG test MDEV-20038.yy -- Simplified RQG grammar simp_MDEV-20038.cfg - RQG config file The test needs (only) threads=4 and replays in ~ 60s on MySQL 5.6.

Elena Stepanova added a comment - 2020-01-29 17:58

Another attempt. The test case below currently fails for me on 10.4 debug within 1-100 attempts (unfortunately, can't give any better stats, it's really this volatile). Luckily, the test case is fast.
The rr profile with mysqld binary can be found here.

--source include/have_sequence.inc

--source include/have_innodb.inc

CREATE TABLE t1 (id INT, a CHAR(65), b VARCHAR(64), PRIMARY KEY(id,a,b), UNIQUE(a(64),id)) ENGINE=InnoDB;

INSERT INTO t1 (id,a,b) SELECT seq, '', '' FROM seq_1_to_100;

--connect (con1,localhost,root,,test)

ALTER TABLE t1 ADD f INT;

ALTER TABLE t1 ADD KEY(f);

--connection default

--send

    ALTER TABLE t1 DROP KEY f;

--connection con1

UPDATE t1 SET b = 'foo';

# Cleanup

--disconnect con1

--connection default

--reap

DROP TABLE t1;

10.4 bc891054
mysqld: /data/src/10.4/storage/innobase/btr/btr0cur.cc:1508: dberr_t btr_cur_search_to_nth_level_func(dict_index_t, ulint, const dtuple_t, page_cur_mode_t, ulint, btr_cur_t, rw_lock_t, const char, unsigned int, mtr_t, ib_uint64_t): Assertion `rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)' failed.
200129 19:55:52 [ERROR] mysqld got signal 6 ;

#6 0x00007fd3fd51ae67 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x561887cb0e30 "rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)", file=file@entry=0x561887cb0070 "/data/src/10.4/storage/innobase/btr/btr0cur.cc", line=line@entry=1508, function=function@entry=0x561887cb5140 <btr_cur_search_to_nth_level_func(dict_index_t, unsigned long, dtuple_t const, page_cur_mode_t, unsigned long, btr_cur_t, rw_lock_t, char const, unsigned int, mtr_t, unsigned long)::__PRETTY_FUNCTION__> "dberr_t btr_cur_search_to_nth_level_func(dict_index_t, ulint, const dtuple_t, page_cur_mode_t, ulint, btr_cur_t, rw_lock_t, const char, unsigned int, mtr_t, ib_uint64_t)") at assert.c:92
#7 0x00007fd3fd51af12 in __GI___assert_fail (assertion=0x561887cb0e30 "rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)", file=0x561887cb0070 "/data/src/10.4/storage/innobase/btr/btr0cur.cc", line=1508, function=0x561887cb5140 <btr_cur_search_to_nth_level_func(dict_index_t, unsigned long, dtuple_t const, page_cur_mode_t, unsigned long, btr_cur_t, rw_lock_t, char const, unsigned int, mtr_t, unsigned long)::__PRETTY_FUNCTION__> "dberr_t btr_cur_search_to_nth_level_func(dict_index_t, ulint, const dtuple_t, page_cur_mode_t, ulint, btr_cur_t, rw_lock_t, const char, unsigned int, mtr_t, ib_uint64_t)") at assert.c:101
#8 0x00005618875323a4 in btr_cur_search_to_nth_level_func (index=0x7fd3a41a7418, level=0, tuple=0x7fd3a802a308, mode=PAGE_CUR_GE, latch_mode=1, cursor=0x7fd3f805daa0, ahi_latch=0x0, file=0x561887c46b90 "/data/src/10.4/storage/innobase/row/row0ins.cc", line=2155, mtr=0x7fd3f805e0f0, autoinc=0) at /data/src/10.4/storage/innobase/btr/btr0cur.cc:1508
#9 0x00005618873e6e31 in btr_pcur_open_low (index=0x7fd3a41a7418, level=0, tuple=0x7fd3a802a308, mode=PAGE_CUR_GE, latch_mode=16385, cursor=0x7fd3f805daa0, file=0x561887c46b90 "/data/src/10.4/storage/innobase/row/row0ins.cc", line=2155, autoinc=0, mtr=0x7fd3f805e0f0) at /data/src/10.4/storage/innobase/include/btr0pcur.ic:441
#10 0x00005618873ed065 in row_ins_scan_sec_index_for_duplicate (flags=0, index=0x7fd3a41a7418, entry=0x7fd3a802a308, thr=0x7fd3a805c2e0, s_latch=true, mtr=0x7fd3f805e0f0, offsets_heap=0x7fd3a80936c0) at /data/src/10.4/storage/innobase/row/row0ins.cc:2155
#11 0x00005618873effe7 in row_ins_sec_index_entry_low (flags=0, mode=33, index=0x7fd3a41a7418, offsets_heap=0x7fd3a80936c0, heap=0x7fd3a80a0b50, entry=0x7fd3a802a308, trx_id=0, thr=0x7fd3a805c2e0) at /data/src/10.4/storage/innobase/row/row0ins.cc:3041
#12 0x00005618873f0e0b in row_ins_sec_index_entry (index=0x7fd3a41a7418, entry=0x7fd3a802a308, thr=0x7fd3a805c2e0, check_foreign=true) at /data/src/10.4/storage/innobase/row/row0ins.cc:3330
#13 0x0000561887479cf1 in row_upd_sec_index_entry (node=0x7fd3a805bf78, thr=0x7fd3a805c2e0) at /data/src/10.4/storage/innobase/row/row0upd.cc:2519
#14 0x0000561887479f56 in row_upd_sec_step (node=0x7fd3a805bf78, thr=0x7fd3a805c2e0) at /data/src/10.4/storage/innobase/row/row0upd.cc:2546
#15 0x000056188747cf77 in row_upd (node=0x7fd3a805bf78, thr=0x7fd3a805c2e0) at /data/src/10.4/storage/innobase/row/row0upd.cc:3327
#16 0x000056188747d3bd in row_upd_step (thr=0x7fd3a805c2e0) at /data/src/10.4/storage/innobase/row/row0upd.cc:3442
#17 0x0000561887418c94 in row_update_for_mysql (prebuilt=0x7fd3a805b718) at /data/src/10.4/storage/innobase/row/row0mysql.cc:1889
#18 0x0000561887273e06 in ha_innobase::update_row (this=0x7fd3a807a668, old_row=0x7fd3a8025360 "\377\021", new_row=0x7fd3a80252d0 "\377\021") at /data/src/10.4/storage/innobase/handler/ha_innodb.cc:8830
#19 0x000056188703579a in handler::ha_update_row (this=0x7fd3a807a668, old_data=0x7fd3a8025360 "\377\021", new_data=0x7fd3a80252d0 "\377\021") at /data/src/10.4/sql/handler.cc:6720
#20 0x0000561886dd54b1 in mysql_update (thd=0x7fd3a8000af0, table_list=0x7fd3a8011eb0, fields=..., values=..., conds=0x0, order_num=0, order=0x0, limit=18446744073709551599, ignore=false, found_return=0x7fd3f8060840, updated_return=0x7fd3f8060900) at /data/src/10.4/sql/sql_update.cc:1055
#21 0x0000561886cc5967 in mysql_execute_command (thd=0x7fd3a8000af0) at /data/src/10.4/sql/sql_parse.cc:4377
#22 0x0000561886cd290d in mysql_parse (thd=0x7fd3a8000af0, rawbuf=0x7fd3a8011dd8 "UPDATE t1 SET b = 'foo'", length=23, parser_state=0x7fd3f8061160, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7901
#23 0x0000561886cbdada in dispatch_command (command=COM_QUERY, thd=0x7fd3a8000af0, packet=0x7fd3a807d931 "UPDATE t1 SET b = 'foo'", packet_length=23, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1842
#24 0x0000561886cbc167 in do_command (thd=0x7fd3a8000af0) at /data/src/10.4/sql/sql_parse.cc:1360
#25 0x0000561886e45381 in do_handle_one_connection (connect=0x56188a5835c0) at /data/src/10.4/sql/sql_connect.cc:1412
#26 0x0000561886e450d0 in handle_one_connection (arg=0x56188a5835c0) at /data/src/10.4/sql/sql_connect.cc:1316
#27 0x000056188784d7cd in pfs_spawn_thread (arg=0x56188a4a22f0) at /data/src/10.4/storage/perfschema/pfs.cc:1869
#28 0x00007fd3ff4a34a4 in start_thread (arg=0x7fd3f8062700) at pthread_create.c:456
#29 0x00007fd3fd5d7d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Couldn't reproduce with this test case on other versions, only 10.4. Could be just the matter of luck.

Elena Stepanova added a comment - 2020-01-29 17:58 Another attempt. The test case below currently fails for me on 10.4 debug within 1-100 attempts (unfortunately, can't give any better stats, it's really this volatile). Luckily, the test case is fast. The rr profile with mysqld binary can be found here . --source include/have_sequence.inc --source include/have_innodb.inc CREATE TABLE t1 (id INT , a CHAR (65), b VARCHAR (64), PRIMARY KEY (id,a,b), UNIQUE (a(64),id)) ENGINE=InnoDB; INSERT INTO t1 (id,a,b) SELECT seq, '' , '' FROM seq_1_to_100; --connect (con1,localhost,root,,test) ALTER TABLE t1 ADD f INT ; ALTER TABLE t1 ADD KEY (f); --connection default --send ALTER TABLE t1 DROP KEY f; --connection con1 UPDATE t1 SET b = 'foo' ; # Cleanup --disconnect con1 --connection default --reap DROP TABLE t1; 10.4 bc891054 mysqld: /data/src/10.4/storage/innobase/btr/btr0cur.cc:1508: dberr_t btr_cur_search_to_nth_level_func(dict_index_t*, ulint, const dtuple_t*, page_cur_mode_t, ulint, btr_cur_t*, rw_lock_t*, const char*, unsigned int, mtr_t*, ib_uint64_t): Assertion `rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)' failed. 200129 19:55:52 [ERROR] mysqld got signal 6 ; #6 0x00007fd3fd51ae67 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x561887cb0e30 "rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)", file=file@entry=0x561887cb0070 "/data/src/10.4/storage/innobase/btr/btr0cur.cc", line=line@entry=1508, function=function@entry=0x561887cb5140 <btr_cur_search_to_nth_level_func(dict_index_t*, unsigned long, dtuple_t const*, page_cur_mode_t, unsigned long, btr_cur_t*, rw_lock_t*, char const*, unsigned int, mtr_t*, unsigned long)::__PRETTY_FUNCTION__> "dberr_t btr_cur_search_to_nth_level_func(dict_index_t*, ulint, const dtuple_t*, page_cur_mode_t, ulint, btr_cur_t*, rw_lock_t*, const char*, unsigned int, mtr_t*, ib_uint64_t)") at assert.c:92 #7 0x00007fd3fd51af12 in __GI___assert_fail (assertion=0x561887cb0e30 "rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)", file=0x561887cb0070 "/data/src/10.4/storage/innobase/btr/btr0cur.cc", line=1508, function=0x561887cb5140 <btr_cur_search_to_nth_level_func(dict_index_t*, unsigned long, dtuple_t const*, page_cur_mode_t, unsigned long, btr_cur_t*, rw_lock_t*, char const*, unsigned int, mtr_t*, unsigned long)::__PRETTY_FUNCTION__> "dberr_t btr_cur_search_to_nth_level_func(dict_index_t*, ulint, const dtuple_t*, page_cur_mode_t, ulint, btr_cur_t*, rw_lock_t*, const char*, unsigned int, mtr_t*, ib_uint64_t)") at assert.c:101 #8 0x00005618875323a4 in btr_cur_search_to_nth_level_func (index=0x7fd3a41a7418, level=0, tuple=0x7fd3a802a308, mode=PAGE_CUR_GE, latch_mode=1, cursor=0x7fd3f805daa0, ahi_latch=0x0, file=0x561887c46b90 "/data/src/10.4/storage/innobase/row/row0ins.cc", line=2155, mtr=0x7fd3f805e0f0, autoinc=0) at /data/src/10.4/storage/innobase/btr/btr0cur.cc:1508 #9 0x00005618873e6e31 in btr_pcur_open_low (index=0x7fd3a41a7418, level=0, tuple=0x7fd3a802a308, mode=PAGE_CUR_GE, latch_mode=16385, cursor=0x7fd3f805daa0, file=0x561887c46b90 "/data/src/10.4/storage/innobase/row/row0ins.cc", line=2155, autoinc=0, mtr=0x7fd3f805e0f0) at /data/src/10.4/storage/innobase/include/btr0pcur.ic:441 #10 0x00005618873ed065 in row_ins_scan_sec_index_for_duplicate (flags=0, index=0x7fd3a41a7418, entry=0x7fd3a802a308, thr=0x7fd3a805c2e0, s_latch=true, mtr=0x7fd3f805e0f0, offsets_heap=0x7fd3a80936c0) at /data/src/10.4/storage/innobase/row/row0ins.cc:2155 #11 0x00005618873effe7 in row_ins_sec_index_entry_low (flags=0, mode=33, index=0x7fd3a41a7418, offsets_heap=0x7fd3a80936c0, heap=0x7fd3a80a0b50, entry=0x7fd3a802a308, trx_id=0, thr=0x7fd3a805c2e0) at /data/src/10.4/storage/innobase/row/row0ins.cc:3041 #12 0x00005618873f0e0b in row_ins_sec_index_entry (index=0x7fd3a41a7418, entry=0x7fd3a802a308, thr=0x7fd3a805c2e0, check_foreign=true) at /data/src/10.4/storage/innobase/row/row0ins.cc:3330 #13 0x0000561887479cf1 in row_upd_sec_index_entry (node=0x7fd3a805bf78, thr=0x7fd3a805c2e0) at /data/src/10.4/storage/innobase/row/row0upd.cc:2519 #14 0x0000561887479f56 in row_upd_sec_step (node=0x7fd3a805bf78, thr=0x7fd3a805c2e0) at /data/src/10.4/storage/innobase/row/row0upd.cc:2546 #15 0x000056188747cf77 in row_upd (node=0x7fd3a805bf78, thr=0x7fd3a805c2e0) at /data/src/10.4/storage/innobase/row/row0upd.cc:3327 #16 0x000056188747d3bd in row_upd_step (thr=0x7fd3a805c2e0) at /data/src/10.4/storage/innobase/row/row0upd.cc:3442 #17 0x0000561887418c94 in row_update_for_mysql (prebuilt=0x7fd3a805b718) at /data/src/10.4/storage/innobase/row/row0mysql.cc:1889 #18 0x0000561887273e06 in ha_innobase::update_row (this=0x7fd3a807a668, old_row=0x7fd3a8025360 "\377\021", new_row=0x7fd3a80252d0 "\377\021") at /data/src/10.4/storage/innobase/handler/ha_innodb.cc:8830 #19 0x000056188703579a in handler::ha_update_row (this=0x7fd3a807a668, old_data=0x7fd3a8025360 "\377\021", new_data=0x7fd3a80252d0 "\377\021") at /data/src/10.4/sql/handler.cc:6720 #20 0x0000561886dd54b1 in mysql_update (thd=0x7fd3a8000af0, table_list=0x7fd3a8011eb0, fields=..., values=..., conds=0x0, order_num=0, order=0x0, limit=18446744073709551599, ignore=false, found_return=0x7fd3f8060840, updated_return=0x7fd3f8060900) at /data/src/10.4/sql/sql_update.cc:1055 #21 0x0000561886cc5967 in mysql_execute_command (thd=0x7fd3a8000af0) at /data/src/10.4/sql/sql_parse.cc:4377 #22 0x0000561886cd290d in mysql_parse (thd=0x7fd3a8000af0, rawbuf=0x7fd3a8011dd8 "UPDATE t1 SET b = 'foo'", length=23, parser_state=0x7fd3f8061160, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7901 #23 0x0000561886cbdada in dispatch_command (command=COM_QUERY, thd=0x7fd3a8000af0, packet=0x7fd3a807d931 "UPDATE t1 SET b = 'foo'", packet_length=23, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1842 #24 0x0000561886cbc167 in do_command (thd=0x7fd3a8000af0) at /data/src/10.4/sql/sql_parse.cc:1360 #25 0x0000561886e45381 in do_handle_one_connection (connect=0x56188a5835c0) at /data/src/10.4/sql/sql_connect.cc:1412 #26 0x0000561886e450d0 in handle_one_connection (arg=0x56188a5835c0) at /data/src/10.4/sql/sql_connect.cc:1316 #27 0x000056188784d7cd in pfs_spawn_thread (arg=0x56188a4a22f0) at /data/src/10.4/storage/perfschema/pfs.cc:1869 #28 0x00007fd3ff4a34a4 in start_thread (arg=0x7fd3f8062700) at pthread_create.c:456 #29 0x00007fd3fd5d7d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97 Couldn't reproduce with this test case on other versions, only 10.4. Could be just the matter of luck.

Elena Stepanova added a comment - 2023-10-09 16:39

Yet another attempt
rr:/data/MDEV-20038/rr-profile-packed

10.5 b04af64882f233e3937f729aac321de504db3f63
(rr) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x0000146bae9fe859 in __GI_abort () at abort.c:79
#2 0x0000146bae9fe729 in __assert_fail_base (fmt=0x146baeb94588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55f81ea7d680 "rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)",
file=0x55f81ea7b720 "/data/MDEV-20038/10.5/storage/innobase/btr/btr0cur.cc", line=1504, function=<optimized out>) at assert.c:92
#3 0x0000146baea0ffd6 in __GI___assert_fail (assertion=0x55f81ea7d680 "rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)", file=0x55f81ea7b720 "/data/MDEV-20038/10.5/storage/innobase/btr/btr0cur.cc",
line=1504, function=0x55f81ea7ce40 "dberr_t btr_cur_search_to_nth_level(dict_index_t, ulint, const dtuple_t, page_cur_mode_t, ulint, btr_cur_t, const char, unsigned int, mtr_t*, ib_uint64_t)")
at assert.c:101
#4 0x000055f81d6f30a7 in btr_cur_search_to_nth_level (index=0x617000080408, level=0, tuple=0x6190001aaa08, mode=PAGE_CUR_GE, latch_mode=1, cursor=0x146b93667330,
file=0x55f81e92e580 "/data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc", line=2162, mtr=0x146b93667bd0, autoinc=0) at /data/MDEV-20038/10.5/storage/innobase/btr/btr0cur.cc:1504
#5 0x000055f81d48bfb7 in btr_pcur_open_low (index=0x617000080408, level=0, tuple=0x6190001aaa08, mode=PAGE_CUR_GE, latch_mode=16385, cursor=0x146b93667330,
file=0x55f81e92e580 "/data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc", line=2162, autoinc=0, mtr=0x146b93667bd0) at /data/MDEV-20038/10.5/storage/innobase/include/btr0pcur.inl:441
#6 0x000055f81d4985fb in row_ins_scan_sec_index_for_duplicate (flags=0, index=0x617000080408, entry=0x6190001aaa08, thr=0x6210000e9588, s_latch=true, mtr=0x146b93667bd0, offsets_heap=0x6190001aae80)
at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:2162
#7 0x000055f81d49d93d in row_ins_sec_index_entry_low (flags=0, mode=33, index=0x617000080408, offsets_heap=0x6190001aae80, heap=0x6190001ab380, entry=0x6190001aaa08, trx_id=0, thr=0x6210000e9588)
at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:3087
#8 0x000055f81d49efdc in row_ins_sec_index_entry (index=0x617000080408, entry=0x6190001aaa08, thr=0x6210000e9588, check_foreign=true) at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:3372
#9 0x000055f81d5977ce in row_upd_sec_index_entry (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:2237
#10 0x000055f81d597d0f in row_upd_sec_step (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:2264
#11 0x000055f81d59ce68 in row_upd (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:3028
#12 0x000055f81d59d634 in row_upd_step (thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:3143
#13 0x000055f81d4e7c33 in row_update_for_mysql (prebuilt=0x6210000e8988) at /data/MDEV-20038/10.5/storage/innobase/row/row0mysql.cc:1801
#14 0x000055f81d168e13 in ha_innobase::update_row (this=0x61d0002ae4b8, old_row=0x623000053290 "\004", new_row=0x623000052538 "\004") at /data/MDEV-20038/10.5/storage/innobase/handler/ha_innodb.cc:8477
#15 0x000055f81c932997 in handler::ha_update_row (this=0x61d0002ae4b8, old_data=0x623000053290 "\004", new_data=0x623000052538 "\004") at /data/MDEV-20038/10.5/sql/handler.cc:7334
#16 0x000055f81c453249 in mysql_update (thd=0x62b0000e0218, table_list=0x62b0000e7468, fields=..., values=..., conds=0x0, order_num=0, order=0x0, limit=18446744073709551615, ignore=false,
found_return=0x146b9366a1d0, updated_return=0x146b9366a1f0) at /data/MDEV-20038/10.5/sql/sql_update.cc:1090
#17 0x000055f81c185263 in mysql_execute_command (thd=0x62b0000e0218) at /data/MDEV-20038/10.5/sql/sql_parse.cc:4484
#18 0x000055f81c19d075 in mysql_parse (thd=0x62b0000e0218, rawbuf=0x62b0000e7238 "/* WRK-1 QNO 9845 */ UPDATE `advanced_db`.`t5_InnoDB` SET `col_varchar` = CONVERT('rehabilitation' USING UCS2)",
length=110, parser_state=0x146b9366ab00, is_com_multi=false, is_next_command=false) at /data/MDEV-20038/10.5/sql/sql_parse.cc:8120
#19 0x000055f81c175363 in dispatch_command (command=COM_QUERY, thd=0x62b0000e0218,
packet=0x6290002ee219 "/* WRK-1 QNO 9845 */ UPDATE `advanced_db`.`t5_InnoDB` SET `col_varchar` = CONVERT('rehabilitation' USING UCS2)", packet_length=110, is_com_multi=false, is_next_command=false)
at /data/MDEV-20038/10.5/sql/sql_parse.cc:1891
#20 0x000055f81c172622 in do_command (thd=0x62b0000e0218) at /data/MDEV-20038/10.5/sql/sql_parse.cc:1375
#21 0x000055f81c56061e in do_handle_one_connection (connect=0x608000002b38, put_in_cache=true) at /data/MDEV-20038/10.5/sql/sql_connect.cc:1416
#22 0x000055f81c55ffb2 in handle_one_connection (arg=0x608000002b38) at /data/MDEV-20038/10.5/sql/sql_connect.cc:1318
#23 0x0000146baef28609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#24 0x0000146baeafb133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Elena Stepanova added a comment - 2023-10-09 16:39 Yet another attempt rr:/data/ MDEV-20038 /rr-profile-packed 10.5 b04af64882f233e3937f729aac321de504db3f63 (rr) bt #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 #1 0x0000146bae9fe859 in __GI_abort () at abort.c:79 #2 0x0000146bae9fe729 in __assert_fail_base (fmt=0x146baeb94588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55f81ea7d680 "rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)", file=0x55f81ea7b720 "/data/MDEV-20038/10.5/storage/innobase/btr/btr0cur.cc", line=1504, function=<optimized out>) at assert.c:92 #3 0x0000146baea0ffd6 in __GI___assert_fail (assertion=0x55f81ea7d680 "rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)", file=0x55f81ea7b720 "/data/MDEV-20038/10.5/storage/innobase/btr/btr0cur.cc", line=1504, function=0x55f81ea7ce40 "dberr_t btr_cur_search_to_nth_level(dict_index_t*, ulint, const dtuple_t*, page_cur_mode_t, ulint, btr_cur_t*, const char*, unsigned int, mtr_t*, ib_uint64_t)") at assert.c:101 #4 0x000055f81d6f30a7 in btr_cur_search_to_nth_level (index=0x617000080408, level=0, tuple=0x6190001aaa08, mode=PAGE_CUR_GE, latch_mode=1, cursor=0x146b93667330, file=0x55f81e92e580 "/data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc", line=2162, mtr=0x146b93667bd0, autoinc=0) at /data/MDEV-20038/10.5/storage/innobase/btr/btr0cur.cc:1504 #5 0x000055f81d48bfb7 in btr_pcur_open_low (index=0x617000080408, level=0, tuple=0x6190001aaa08, mode=PAGE_CUR_GE, latch_mode=16385, cursor=0x146b93667330, file=0x55f81e92e580 "/data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc", line=2162, autoinc=0, mtr=0x146b93667bd0) at /data/MDEV-20038/10.5/storage/innobase/include/btr0pcur.inl:441 #6 0x000055f81d4985fb in row_ins_scan_sec_index_for_duplicate (flags=0, index=0x617000080408, entry=0x6190001aaa08, thr=0x6210000e9588, s_latch=true, mtr=0x146b93667bd0, offsets_heap=0x6190001aae80) at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:2162 #7 0x000055f81d49d93d in row_ins_sec_index_entry_low (flags=0, mode=33, index=0x617000080408, offsets_heap=0x6190001aae80, heap=0x6190001ab380, entry=0x6190001aaa08, trx_id=0, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:3087 #8 0x000055f81d49efdc in row_ins_sec_index_entry (index=0x617000080408, entry=0x6190001aaa08, thr=0x6210000e9588, check_foreign=true) at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:3372 #9 0x000055f81d5977ce in row_upd_sec_index_entry (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:2237 #10 0x000055f81d597d0f in row_upd_sec_step (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:2264 #11 0x000055f81d59ce68 in row_upd (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:3028 #12 0x000055f81d59d634 in row_upd_step (thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:3143 #13 0x000055f81d4e7c33 in row_update_for_mysql (prebuilt=0x6210000e8988) at /data/MDEV-20038/10.5/storage/innobase/row/row0mysql.cc:1801 #14 0x000055f81d168e13 in ha_innobase::update_row (this=0x61d0002ae4b8, old_row=0x623000053290 "\004", new_row=0x623000052538 "\004") at /data/MDEV-20038/10.5/storage/innobase/handler/ha_innodb.cc:8477 #15 0x000055f81c932997 in handler::ha_update_row (this=0x61d0002ae4b8, old_data=0x623000053290 "\004", new_data=0x623000052538 "\004") at /data/MDEV-20038/10.5/sql/handler.cc:7334 #16 0x000055f81c453249 in mysql_update (thd=0x62b0000e0218, table_list=0x62b0000e7468, fields=..., values=..., conds=0x0, order_num=0, order=0x0, limit=18446744073709551615, ignore=false, found_return=0x146b9366a1d0, updated_return=0x146b9366a1f0) at /data/MDEV-20038/10.5/sql/sql_update.cc:1090 #17 0x000055f81c185263 in mysql_execute_command (thd=0x62b0000e0218) at /data/MDEV-20038/10.5/sql/sql_parse.cc:4484 #18 0x000055f81c19d075 in mysql_parse (thd=0x62b0000e0218, rawbuf=0x62b0000e7238 "/* WRK-1 QNO 9845 */ UPDATE `advanced_db`.`t5_InnoDB` SET `col_varchar` = CONVERT('rehabilitation' USING UCS2)", length=110, parser_state=0x146b9366ab00, is_com_multi=false, is_next_command=false) at /data/MDEV-20038/10.5/sql/sql_parse.cc:8120 #19 0x000055f81c175363 in dispatch_command (command=COM_QUERY, thd=0x62b0000e0218, packet=0x6290002ee219 "/* WRK-1 QNO 9845 */ UPDATE `advanced_db`.`t5_InnoDB` SET `col_varchar` = CONVERT('rehabilitation' USING UCS2)", packet_length=110, is_com_multi=false, is_next_command=false) at /data/MDEV-20038/10.5/sql/sql_parse.cc:1891 #20 0x000055f81c172622 in do_command (thd=0x62b0000e0218) at /data/MDEV-20038/10.5/sql/sql_parse.cc:1375 #21 0x000055f81c56061e in do_handle_one_connection (connect=0x608000002b38, put_in_cache=true) at /data/MDEV-20038/10.5/sql/sql_connect.cc:1416 #22 0x000055f81c55ffb2 in handle_one_connection (arg=0x608000002b38) at /data/MDEV-20038/10.5/sql/sql_connect.cc:1318 #23 0x0000146baef28609 in start_thread (arg=<optimized out>) at pthread_create.c:477 #24 0x0000146baeafb133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Marko Mäkelä added a comment - 2023-10-10 06:27

In that trace, the mini-transaction is only holding the index.lock, in SX mode, not S mode:

(rr) p *(mtr_memo_slot_t*)mtr.m_memo.m_first_block.m_data

$2 = {object = 0x617000080578, type = MTR_MEMO_SX_LOCK}

The index latch was acquired a little earlier by the same thread:

#2  0x000055f81d2ce4af in mtr_t::sx_lock (this=0x146b93667bd0, lock=0x617000080578, file=0x55f81e92e580 "/data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc", line=2897)

    at /data/MDEV-20038/10.5/storage/innobase/include/mtr0mtr.h:251

#3  0x000055f81d49c8bf in row_ins_sec_mtr_start_and_check_if_aborted (mtr=0x146b93667bd0, index=0x617000080408, check=true, search_mode=545) at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:2897

#4  0x000055f81d49d8f6 in row_ins_sec_index_entry_low (flags=0, mode=33, index=0x617000080408, offsets_heap=0x6190001aae80, heap=0x6190001ab380, entry=0x6190001aaa08, trx_id=0, thr=0x6210000e9588)

    at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:3082

#5  0x000055f81d49efdc in row_ins_sec_index_entry (index=0x617000080408, entry=0x6190001aaa08, thr=0x6210000e9588, check_foreign=true) at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:3372

#6  0x000055f81d5977ce in row_upd_sec_index_entry (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:2237

#7  0x000055f81d597d0f in row_upd_sec_step (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:2264

#8  0x000055f81d59ce68 in row_upd (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:3028

#9  0x000055f81d59d634 in row_upd_step (thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:3143

#10 0x000055f81d4e7c33 in row_update_for_mysql (prebuilt=0x6210000e8988) at /data/MDEV-20038/10.5/storage/innobase/row/row0mysql.cc:1801

#11 0x000055f81d168e13 in ha_innobase::update_row (this=0x61d0002ae4b8, old_row=0x623000053290 "\004", new_row=0x623000052538 "\004") at /data/MDEV-20038/10.5/storage/innobase/handler/ha_innodb.cc:8477

The failing debug assertion is too strict. It should qualify also an SX latch and not only S latch on the index. Would the following patch work, or would it trigger an assertion failure somewhere else?

diff --git a/storage/innobase/btr/btr0cur.cc b/storage/innobase/btr/btr0cur.cc

index e076a3b7962..c76d167dcab 100644

--- a/storage/innobase/btr/btr0cur.cc

+++ b/storage/innobase/btr/btr0cur.cc

@@ -1501,8 +1501,9 @@ dberr_t btr_cur_search_to_nth_level(dict_index_t *index, ulint level,

 	default:

 		if (!srv_read_only_mode) {

 			if (s_latch_by_caller) {

-				ut_ad(rw_lock_own(dict_index_get_lock(index),

-				              RW_LOCK_S));

+				ut_ad(rw_lock_own_flagged(&index->lock,

+							  RW_LOCK_FLAG_SX

+							  | RW_LOCK_FLAG_S));

 			} else if (!modify_external) {

 				/* BTR_SEARCH_TREE is intended to be used with

 				BTR_ALREADY_S_LATCHED */

In ~~MDEV-30400~~ and ~~MDEV-24142~~, this code had been refactored in MariaDB Server 10.6. A corresponding assertion is at the start of btr_cur_t::search_leaf():

  ut_ad(!(latch_mode & BTR_ALREADY_S_LATCHED) ||

        mtr->memo_contains_flagged(&index()->lock,

                                   MTR_MEMO_S_LOCK | MTR_MEMO_SX_LOCK |

                                   MTR_MEMO_X_LOCK));

This assertion checks that if the caller claims that the index tree was already latched, the mtr_t::m_memo must contain the index tree in one of the modes. For latch_mode=BTR_MODIFY_TREE we additionally assert that the exclusive index latch is being held.

Marko Mäkelä added a comment - 2023-10-10 06:27 In that trace, the mini-transaction is only holding the index.lock , in SX mode, not S mode: (rr) p *(mtr_memo_slot_t*)mtr.m_memo.m_first_block.m_data $2 = {object = 0x617000080578, type = MTR_MEMO_SX_LOCK} The index latch was acquired a little earlier by the same thread: #2 0x000055f81d2ce4af in mtr_t::sx_lock (this=0x146b93667bd0, lock=0x617000080578, file=0x55f81e92e580 "/data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc", line=2897) at /data/MDEV-20038/10.5/storage/innobase/include/mtr0mtr.h:251 #3 0x000055f81d49c8bf in row_ins_sec_mtr_start_and_check_if_aborted (mtr=0x146b93667bd0, index=0x617000080408, check=true, search_mode=545) at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:2897 #4 0x000055f81d49d8f6 in row_ins_sec_index_entry_low (flags=0, mode=33, index=0x617000080408, offsets_heap=0x6190001aae80, heap=0x6190001ab380, entry=0x6190001aaa08, trx_id=0, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:3082 #5 0x000055f81d49efdc in row_ins_sec_index_entry (index=0x617000080408, entry=0x6190001aaa08, thr=0x6210000e9588, check_foreign=true) at /data/MDEV-20038/10.5/storage/innobase/row/row0ins.cc:3372 #6 0x000055f81d5977ce in row_upd_sec_index_entry (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:2237 #7 0x000055f81d597d0f in row_upd_sec_step (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:2264 #8 0x000055f81d59ce68 in row_upd (node=0x6210000e91d8, thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:3028 #9 0x000055f81d59d634 in row_upd_step (thr=0x6210000e9588) at /data/MDEV-20038/10.5/storage/innobase/row/row0upd.cc:3143 #10 0x000055f81d4e7c33 in row_update_for_mysql (prebuilt=0x6210000e8988) at /data/MDEV-20038/10.5/storage/innobase/row/row0mysql.cc:1801 #11 0x000055f81d168e13 in ha_innobase::update_row (this=0x61d0002ae4b8, old_row=0x623000053290 "\004", new_row=0x623000052538 "\004") at /data/MDEV-20038/10.5/storage/innobase/handler/ha_innodb.cc:8477 The failing debug assertion is too strict. It should qualify also an SX latch and not only S latch on the index. Would the following patch work, or would it trigger an assertion failure somewhere else? diff --git a/storage/innobase/btr/btr0cur.cc b/storage/innobase/btr/btr0cur.cc index e076a3b7962..c76d167dcab 100644 --- a/storage/innobase/btr/btr0cur.cc +++ b/storage/innobase/btr/btr0cur.cc @@ -1501,8 +1501,9 @@ dberr_t btr_cur_search_to_nth_level(dict_index_t *index, ulint level, default: if (!srv_read_only_mode) { if (s_latch_by_caller) { - ut_ad(rw_lock_own(dict_index_get_lock(index), - RW_LOCK_S)); + ut_ad(rw_lock_own_flagged(&index->lock, + RW_LOCK_FLAG_SX + | RW_LOCK_FLAG_S)); } else if (!modify_external) { /* BTR_SEARCH_TREE is intended to be used with BTR_ALREADY_S_LATCHED */ In MDEV-30400 and MDEV-24142 , this code had been refactored in MariaDB Server 10.6. A corresponding assertion is at the start of btr_cur_t::search_leaf() : ut_ad(!(latch_mode & BTR_ALREADY_S_LATCHED) || mtr->memo_contains_flagged(&index()->lock, MTR_MEMO_S_LOCK | MTR_MEMO_SX_LOCK | MTR_MEMO_X_LOCK)); This assertion checks that if the caller claims that the index tree was already latched, the mtr_t::m_memo must contain the index tree in one of the modes. For latch_mode=BTR_MODIFY_TREE we additionally assert that the exclusive index latch is being held.

MariaDB Server

Assertion `rw_lock_own(dict_index_get_lock(index), RW_LOCK_S)' failed. in btr_cur_search_to_nth_level_func

Details

Description

Attachments

Attachments

Activity

People

Dates

Git Integration