Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.6
Description
Stack trace is
(gdb) where
|
#0 __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
|
#1 0x0000559f2974c742 in my_write_core (sig=6) at /data/Server/bb-10.6-MDEV-14180/mysys/stacktrace.c:424
|
#2 0x0000559f284b114f in handle_fatal_signal (sig=6) at /data/Server/bb-10.6-MDEV-14180/sql/signal_handler.cc:344
|
#3 <signal handler called>
|
#4 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
|
#5 0x00007f0bd4697859 in __GI_abort () at abort.c:79
|
#6 0x00007f0bd4697729 in __assert_fail_base (fmt=0x7f0bd482d588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
|
assertion=0x559f2a76ffe0 "max_doc_id > 0", file=0x559f2a76b820 "/data/Server/bb-10.6-MDEV-14180/storage/innobase/fts/fts0fts.cc",
|
line=4780, function=<optimized out>) at assert.c:92
|
#7 0x00007f0bd46a8f36 in __GI___assert_fail (assertion=0x559f2a76ffe0 "max_doc_id > 0",
|
file=0x559f2a76b820 "/data/Server/bb-10.6-MDEV-14180/storage/innobase/fts/fts0fts.cc", line=4780,
|
function=0x559f2a770020 "doc_id_t fts_init_doc_id(const dict_table_t*)") at assert.c:101
|
#8 0x0000559f295054a6 in c (table=0x618000262908)
|
at /data/Server/bb-10.6-MDEV-14180/storage/innobase/fts/fts0fts.cc:4780
|
#9 0x0000559f294f7bb8 in fts_get_next_doc_id (table=0x618000262908, doc_id=0x7f0ba4cbbfb0)
|
at /data/Server/bb-10.6-MDEV-14180/storage/innobase/fts/fts0fts.cc:2516
|
#10 0x0000559f29140752 in row_mysql_convert_row_to_innobase (row=0x621000096b18, prebuilt=0x621000096188,
|
mysql_rec=0x61a0002d78b8 "\322S\n", blob_heap=0x7f0ba4cbc0f0)
|
at /data/Server/bb-10.6-MDEV-14180/storage/innobase/row/row0mysql.cc:621
|
#11 0x0000559f29145296 in row_insert_for_mysql (mysql_rec=0x61a0002d78b8 "\322S\n", prebuilt=0x621000096188, ins_mode=ROW_INS_NORMAL)
|
at /data/Server/bb-10.6-MDEV-14180/storage/innobase/row/row0mysql.cc:1321
|
#12 0x0000559f28dcfabd in ha_innobase::write_row (this=0x61d0008d72b8, record=0x61a0002d78b8 "\322S\n")
|
at /data/Server/bb-10.6-MDEV-14180/storage/innobase/handler/ha_innodb.cc:7667
|
#13 0x0000559f284e21b0 in handler::ha_write_row (this=0x61d0008d72b8, buf=0x61a0002d78b8 "\322S\n")
|
at /data/Server/bb-10.6-MDEV-14180/sql/handler.cc:7240
|
#14 0x0000559f27c6c15b in write_record (thd=0x62b000150218, table=0x6190004f4798, info=0x7f0ba4cbce60, sink=0x0)
|
at /data/Server/bb-10.6-MDEV-14180/sql/sql_insert.cc:2113
|
#15 0x0000559f27c64a53 in mysql_insert (thd=0x62b000150218, table_list=0x62b0001574d0, fields=..., values_list=..., update_fields=...,
|
update_values=..., duplic=DUP_ERROR, ignore=false, result=0x0) at /data/Server/bb-10.6-MDEV-14180/sql/sql_insert.cc:1104
|
#16 0x0000559f27d2148b in mysql_execute_command (thd=0x62b000150218) at /data/Server/bb-10.6-MDEV-14180/sql/sql_parse.cc:4556
|
#17 0x0000559f27d387fd in mysql_parse (thd=0x62b000150218,
|
rawbuf=0x62b000157238 "INSERT INTO t1 (col1,col2, col_int, col_string, col_text) VALUES ( 2643, 2643 - 1, 2643, REPEAT(SUBSTR(CAST( --Type <RET> for more, q to quit, c to continue without paging--
|
2643 AS CHAR),1,1), 10), REPEAT(SUBSTR(CAST( 2643 AS CHAR),1,1), @fill_amount) ) /* E_R Thr"..., length=225,
|
parser_state=0x7f0ba4cbdb20) at /data/Server/bb-10.6-MDEV-14180/sql/sql_parse.cc:8016
|
#18 0x0000559f27d10b40 in dispatch_command (command=COM_QUERY, thd=0x62b000150218,
|
packet=0x629000c3f219 " INSERT INTO t1 (col1,col2, col_int, col_string, col_text) VALUES ( 2643, 2643 - 1, 2643, REPEAT(SUBSTR(CAST( 2643 AS CHAR),1,1), 10), REPEAT(SUBSTR(CAST( 2643 AS CHAR),1,1), @fill_amount) ) /* E_R Th"..., packet_length=227, blocking=true)
|
at /data/Server/bb-10.6-MDEV-14180/sql/sql_parse.cc:1897
|
#19 0x0000559f27d0df21 in do_command (thd=0x62b000150218, blocking=true) at /data/Server/bb-10.6-MDEV-14180/sql/sql_parse.cc:1406
|
#20 0x0000559f28109de4 in do_handle_one_connection (connect=0x6080000033b8, put_in_cache=true)
|
at /data/Server/bb-10.6-MDEV-14180/sql/sql_connect.cc:1410
|
#21 0x0000559f28109746 in handle_one_connection (arg=0x6080000033b8) at /data/Server/bb-10.6-MDEV-14180/sql/sql_connect.cc:1312
|
#22 0x00007f0bd4bc0609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#23 0x00007f0bd4794293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
From the error log looks like InnoDB encountered lock wait issue:
2021-06-11 16:10:34 19 [ERROR] InnoDB: (Lock wait timeout) while getting next doc id for table `test`.`t1`
|
All concurrent threads are waiting for MDL on the table. There is no other thread does work on table inside InnoDB. Basically failure happened in fts_cmp_set_sync_doc_id()
Core dump is present in
sdp:/data/Results/1623436157/TBR-1123
|
gdb -c ./dev/shm/vardir/1623436157/28/1/data/core /data/Server_bin/bb-10.6-MDEV-14180_asan/bin/mysqld
|
pluto:/data/Results/1626787333/TBR-1123-MDEV-25984/dev/shm/vardir/1626787333/94/1/rr
# 2021-07-20T14:39:29 [2351929] | [rr 2358553 355791]mysqld: /data/Server/10.6Y/storage/innobase/fts/fts0fts.cc:4784: doc_id_t fts_init_doc_id(const dict_table_t*): Assertion `max_doc_id > 0' failed.
# 2021-07-20T14:39:29 [2351929] | Thread 3 (Thread 2358553.2362740):
# 2021-07-20T14:39:29 [2351929] | #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
# 2021-07-20T14:39:29 [2351929] | #1 0x00007eff5f49e859 in __GI_abort () at abort.c:79
# 2021-07-20T14:39:29 [2351929] | #2 0x00007eff5f49e729 in __assert_fail_base (fmt=0x7eff5f634588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55af4aa36b40 "max_doc_id > 0", file=0x55af4aa32380 "/data/Server/10.6Y/storage/innobase/fts/fts0fts.cc", line=4784, function=<optimized out>) at assert.c:92
# 2021-07-20T14:39:29 [2351929] | #3 0x00007eff5f4aff36 in __GI___assert_fail (assertion=0x55af4aa36b40 "max_doc_id > 0", file=0x55af4aa32380 "/data/Server/10.6Y/storage/innobase/fts/fts0fts.cc", line=4784, function=0x55af4aa36b80 "doc_id_t fts_init_doc_id(const dict_table_t*)") at assert.c:101
# 2021-07-20T14:39:29 [2351929] | #4 0x000055af499dfd3a in fts_init_doc_id (table=0x6180001ac108) at /data/Server/10.6Y/storage/innobase/fts/fts0fts.cc:4784
# 2021-07-20T14:39:29 [2351929] | #5 0x000055af499d24b0 in fts_get_next_doc_id (table=0x6180001ac108, doc_id=0x7eff3a47bfb0) at /data/Server/10.6Y/storage/innobase/fts/fts0fts.cc:2520
# 2021-07-20T14:39:29 [2351929] | #6 0x000055af4961d724 in row_mysql_convert_row_to_innobase (row=0x6210000cdb88, prebuilt=0x6210000cd188, mysql_rec=0x61a000672cb8 "d\377\r\f", blob_heap=0x7eff3a47c0f0) at /data/Server/10.6Y/storage/innobase/row/row0mysql.cc:621
# 2021-07-20T14:39:29 [2351929] | #7 0x000055af49622137 in row_insert_for_mysql (mysql_rec=0x61a000672cb8 "d\377\r\f", prebuilt=0x6210000cd188, ins_mode=ROW_INS_NORMAL) at /data/Server/10.6Y/storage/innobase/row/row0mysql.cc:1314
# 2021-07-20T14:39:29 [2351929] | #8 0x000055af492ab7e1 in ha_innobase::write_row (this=0x61d0003656b8, record=0x61a000672cb8 "d\377\r\f") at /data/Server/10.6Y/storage/innobase/handler/ha_innodb.cc:7781
# 2021-07-20T14:39:29 [2351929] | #9 0x000055af489d7bb8 in handler::ha_write_row (this=0x61d0003656b8, buf=0x61a000672cb8 "d\377\r\f") at /data/Server/10.6Y/sql/handler.cc:7500
# 2021-07-20T14:39:29 [2351929] | #10 0x000055af481362b1 in write_record (thd=0x62b0001ab218, table=0x6190007c3898, info=0x7eff3a47ce60, sink=0x0) at /data/Server/10.6Y/sql/sql_insert.cc:2135
# 2021-07-20T14:39:29 [2351929] | #11 0x000055af4812eb77 in mysql_insert (thd=0x62b0001ab218, table_list=0x62b0001b24d0, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false, result=0x0) at /data/Server/10.6Y/sql/sql_insert.cc:1123
# 2021-07-20T14:39:29 [2351929] | #12 0x000055af481eb5a5 in mysql_execute_command (thd=0x62b0001ab218, is_called_from_prepared_stmt=false) at /data/Server/10.6Y/sql/sql_parse.cc:4566
# 2021-07-20T14:39:29 [2351929] | #13 0x000055af4820291e in mysql_parse (thd=0x62b0001ab218, rawbuf=0x62b0001b2238 "INSERT INTO t4 (col1,col2, col_int, col_string, col_text) VALUES ( 3085, 3085, 3085, REPEAT(SUBSTR(CAST( 3085 AS CHAR),1,1), 10), REPEAT(SUBSTR(CAST( 3085 - 1 AS CHAR),1,1), @fill_amount) ) /* E_R Thread6 QNO 306 CON_ID 31 */", length=225, parser_state=0x7eff3a47db20) at /data/Server/10.6Y/sql/sql_parse.cc:8026
# 2021-07-20T14:39:29 [2351929] | #14 0x000055af481dabbd in dispatch_command (command=COM_QUERY, thd=0x62b0001ab218, packet=0x629000dc0219 " INSERT INTO t4 (col1,col2, col_int, col_string, col_text) VALUES ( 3085, 3085, 3085, REPEAT(SUBSTR(CAST( 3085 AS CHAR),1,1), 10), REPEAT(SUBSTR(CAST( 3085 - 1 AS CHAR),1,1), @fill_amount) ) /* E_R Thread6 QNO 306 CON_ID 31 */ ", packet_length=227, blocking=true) at /data/Server/10.6Y/sql/sql_parse.cc:1896
# 2021-07-20T14:39:29 [2351929] | #15 0x000055af481d7f95 in do_command (thd=0x62b0001ab218, blocking=true) at /data/Server/10.6Y/sql/sql_parse.cc:1404
# 2021-07-20T14:39:29 [2351929] | #16 0x000055af485d60fb in do_handle_one_connection (connect=0x608000003a38, put_in_cache=true) at /data/Server/10.6Y/sql/sql_connect.cc:1410
# 2021-07-20T14:39:29 [2351929] | #17 0x000055af485d5a58 in handle_one_connection (arg=0x6080000038b8) at /data/Server/10.6Y/sql/sql_connect.cc:1312
# 2021-07-20T14:39:29 [2351929] | #18 0x00007eff5f9c7609 in start_thread (arg=<optimized out>) at pthread_create.c:477
# 2021-07-20T14:39:29 [2351929] | #19 0x00007eff5f59b293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
origin/10.6 ae62f115beea8cb7c532ef1a72c359548316df9c 2021-07-20T10:55:03+03:00
10.6.4
RQG
-----
git clone https://github.com/mleich1/rqg --branch experimental RQG
perl rqg.pl \
--grammar=conf/mariadb/table_stress_innodb.yy \
--gendata=conf/mariadb/table_stress.zz \
--gendata_sql=conf/mariadb/table_stress.sql \
--rpl_mode=mixed \ <== not required but set during the run above
--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-sync-debug \
--mysqld=--innodb_stats_persistent=on \
--mysqld=--innodb_adaptive_hash_index=on \
--mysqld=--loose-innodb_evict_tables_on_commit_debug=off \
--mysqld=--loose-max-statement-time=30 \
--threads=9 \
--mysqld=--innodb-use-native-aio=0 \
--rr=Extended \
--rr_options="--wait" \
--mysqld=--innodb_page_size=64K \
--mysqld=--innodb-buffer-pool-size=24M \
--no_mask \
<local settings>
error pattern
[ 'TBR-1123-MDEV-25984', 'mysqld: .{1,250}fts0fts.cc:.{1,10}: doc_id_t fts_init_doc_id\(const dict_table_t\*\): Assertion \`max_doc_id > 0\' failed.+RESULT: The RQG run ended with status STATUS_SERVER_CRASHED' ],