[MDEV-17976] [Draft] Assertion `lock->magic_n == 22643' failed in rw_lock_validate Created: 2018-12-11  Updated: 2021-01-09  Resolved: 2019-10-17

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2, 10.3
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Unassigned
Resolution: Duplicate Votes: 0
Labels: None

Attachments: File magic1.test.reproducible.5    
Issue Links:
Blocks
is blocked by MDEV-17975 Assertion `! is_set()' or `!is_set() ... Closed
Duplicate
is duplicated by MDEV-16222 Assertion `0' failed in row_purge_rem... Closed
Relates
relates to MDEV-16222 Assertion `0' failed in row_purge_rem... Closed

 Description   

https://travis-ci.org/elenst/travis-tests/jobs/466147463

10.3 ac31ff6275cfb5de74c0069a53e5575dac317225

mysqld: /home/travis/src/storage/innobase/sync/sync0rw.cc:865: bool rw_lock_validate(const rw_lock_t*): Assertion `lock->magic_n == 22643' failed.
181211 11:51:03 [ERROR] mysqld got signal 6 ;
 
#3  0x00007f1aace07ca2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#4  0x0000564ecf16ca70 in rw_lock_validate (lock=0x7f1a48134bf0) at /home/travis/src/storage/innobase/sync/sync0rw.cc:865
#5  0x0000564ecf16cf72 in rw_lock_own_flagged (lock=0x7f1a48134bf0, flags=3) at /home/travis/src/storage/innobase/sync/sync0rw.cc:1036
#6  0x0000564ecf0bf52d in rw_lock_s_lock_func (lock=0x7f1a48134bf0, pass=0, file_name=0x564ecf8838c8 "/home/travis/src/storage/innobase/btr/btr0cur.cc", line=1332) at /home/travis/src/storage/innobase/include/sync0rw.ic:282
#7  0x0000564ecf0bf653 in pfs_rw_lock_s_lock_func (lock=0x7f1a48134bf0, pass=0, file_name=0x564ecf8838c8 "/home/travis/src/storage/innobase/btr/btr0cur.cc", line=1332) at /home/travis/src/storage/innobase/include/sync0rw.ic:660
#8  0x0000564ecf0ce3a9 in mtr_t::s_lock (this=0x7f1a727faaa0, lock=0x7f1a48134bf0, file=0x564ecf8838c8 "/home/travis/src/storage/innobase/btr/btr0cur.cc", line=1332) at /home/travis/src/storage/innobase/include/mtr0mtr.ic:238
#9  0x0000564ecf1eae8b in btr_cur_search_to_nth_level_func (index=0x7f1a48134a28, level=0, tuple=0x7f1a5c049d48, mode=PAGE_CUR_LE, latch_mode=1, cursor=0x564ed2462308, ahi_latch=0x0, file=0x564ecf834ab0 "/home/travis/src/storage/innobase/row/row0purge.cc", line=100, mtr=0x7f1a727faaa0, autoinc=0) at /home/travis/src/storage/innobase/btr/btr0cur.cc:1332
#10 0x0000564ecf202416 in btr_pcur_open_with_no_init_func (index=0x7f1a48134a28, tuple=0x7f1a5c049d48, mode=PAGE_CUR_LE, latch_mode=1, cursor=0x564ed2462308, ahi_latch=0x0, file=0x564ecf834ab0 "/home/travis/src/storage/innobase/row/row0purge.cc", line=100, mtr=0x7f1a727faaa0) at /home/travis/src/storage/innobase/include/btr0pcur.ic:527
#11 0x0000564ecf2033fb in btr_pcur_restore_position_func (latch_mode=1, cursor=0x564ed2462308, file=0x564ecf834ab0 "/home/travis/src/storage/innobase/row/row0purge.cc", line=100, mtr=0x7f1a727faaa0) at /home/travis/src/storage/innobase/btr/btr0pcur.cc:362
#12 0x0000564ecf10f345 in row_purge_reposition_pcur (mode=1, node=0x564ed2462270, mtr=0x7f1a727faaa0) at /home/travis/src/storage/innobase/row/row0purge.cc:100
#13 0x0000564ecf10fc3b in row_purge_poss_sec (node=0x564ed2462270, index=0x7f1a48151578, entry=0x7f1a5c112b98, sec_pcur=0x7f1a727fb030, sec_mtr=0x7f1a727fb290, is_tree=false) at /home/travis/src/storage/innobase/row/row0purge.cc:341
#14 0x0000564ecf1109c3 in row_purge_remove_sec_if_poss_leaf (node=0x564ed2462270, index=0x7f1a48151578, entry=0x7f1a5c112b98) at /home/travis/src/storage/innobase/row/row0purge.cc:604
#15 0x0000564ecf110ea8 in row_purge_remove_sec_if_poss (node=0x564ed2462270, index=0x7f1a48151578, entry=0x7f1a5c112b98) at /home/travis/src/storage/innobase/row/row0purge.cc:717
#16 0x0000564ecf1110af in row_purge_del_mark (node=0x564ed2462270) at /home/travis/src/storage/innobase/row/row0purge.cc:791
#17 0x0000564ecf112665 in row_purge_record_func (node=0x564ed2462270, undo_rec=0x7f1a640fc478 "\002E\016\210\t\032", thr=0x564ed24621b8, updated_extern=false) at /home/travis/src/storage/innobase/row/row0purge.cc:1190
#18 0x0000564ecf1129a2 in row_purge (node=0x564ed2462270, undo_rec=0x7f1a640fc478 "\002E\016\210\t\032", thr=0x564ed24621b8) at /home/travis/src/storage/innobase/row/row0purge.cc:1257
#19 0x0000564ecf112d4d in row_purge_step (thr=0x564ed24621b8) at /home/travis/src/storage/innobase/row/row0purge.cc:1343
#20 0x0000564ecf095f7a in que_thr_step (thr=0x564ed24621b8) at /home/travis/src/storage/innobase/que/que0que.cc:1042
#21 0x0000564ecf0961aa in que_run_threads_low (thr=0x564ed24621b8) at /home/travis/src/storage/innobase/que/que0que.cc:1104
#22 0x0000564ecf09639a in que_run_threads (thr=0x564ed24621b8) at /home/travis/src/storage/innobase/que/que0que.cc:1144
#23 0x0000564ecf15d615 in srv_task_execute () at /home/travis/src/storage/innobase/srv/srv0srv.cc:2451
#24 0x0000564ecf15d7b7 in srv_worker_thread (arg=0x0) at /home/travis/src/storage/innobase/srv/srv0srv.cc:2499
#25 0x00007f1aad9c9184 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#26 0x00007f1aaced5ffd in clone () from /lib/x86_64-linux-gnu/libc.so.6

elenst-dev d73323d1fb32464a1ad9137f07becaa638791fdd

perl ./runall-new.pl --basedir=/home/travis/server --vardir=/home/travis/logs/vardir --duration=350 --threads=6 --seed=1544529043 --reporters=Backtrace,ErrorLog,Deadlock --validators=TransformerNoComparator --views --redefine=conf/mariadb/alter_table.yy --redefine=conf/mariadb/instant_add.yy --redefine=conf/mariadb/sp.yy --redefine=conf/mariadb/bulk_insert.yy --redefine=conf/mariadb/sequences.yy --redefine=conf/mariadb/modules/sql_mode.yy --redefine=conf/mariadb/modules/acl.yy --mysqld=--log_output=FILE --mysqld=--max-statement-time=30 --mysqld=--lock-wait-timeout=10 --mysqld=--loose-innodb-lock-wait-timeout=5 --mysqld=--loose-debug_assert_on_not_freed_memory=0 --grammar=conf/mariadb/optimizer.yy --skip-gendata --gendata-advanced --vcols --transformers=ExecuteAsIntersect,ExecuteAsExcept,ExecuteAsCTE,ExecuteAsExecuteImmediate,ExecuteAsDeleteReturning,ExecuteAsInsertSelect,ExecuteAsUnion,ExecuteAsUpdateDelete,ExecuteAsView,ExecuteAsPreparedTwice --redefine=conf/mariadb/versioning.yy

Not reproducible via MTR yet, but the first attempt to re-run the initial test failed in a similar fashion, with an extra assertion (see the beginning and the end of the code block):

10.3 ac31ff6275

mysqld: /data/src/10.3-travis/storage/innobase/rem/rem0rec.cc:785: ulint* rec_get_offsets_func(const rec_t*, const dict_index_t*, ulint*, bool, ulint, const char*, unsigned int, mem_heap_t**): Assertion `index' failed.
181211 22:28:20 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
Server version: 10.3.12-MariaDB-debug-log
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=8
max_threads=153
thread_count=14
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467474 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f9498000b00
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x7f94b27fbe98 thread_stack 0x49000
mysqld: /data/src/10.3-travis/storage/innobase/sync/sync0rw.cc:865: bool rw_lock_validate(const rw_lock_t*): Assertion `lock->magic_n == 22643' failed.
Aborted (core dumped)



 Comments   
Comment by Elena Stepanova [ 2018-12-12 ]

More variations from basically the same test:

10.3 ac31ff6275c

181212 12:48:27 [ERROR] mysqld got signal 11 ;
 
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x000055a43e4a5bc3 in dict_table_is_comp (table=0xa5a5a5a5a5a5a5a5) at /data/src/10.3/storage/innobase/include/dict0dict.ic:538
538		return (table->flags & DICT_TF_COMPACT) != 0;
 
Thread 1 (Thread 0x7f8d6b7fe700 (LWP 23649)):
#0  0x000055a43e4a5bc3 in dict_table_is_comp (table=0xa5a5a5a5a5a5a5a5) at /data/src/10.3/storage/innobase/include/dict0dict.ic:538
#1  0x000055a43e4a99c6 in rec_get_offsets_func (rec=0x7f8d5800d237 "", index=0x7f8d3411fe38, offsets=0x0, leaf=true, n_fields=1, file=0x55a43eb76440 "/data/src/10.3/storage/innobase/row/row0purge.cc", line=1391, heap=0x55a4420e6660) at /data/src/10.3/storage/innobase/rem/rem0rec.cc:788
#2  0x000055a43e51a9bc in purge_node_t::validate_pcur (this=0x55a4420e65d8) at /data/src/10.3/storage/innobase/row/row0purge.cc:1389
#3  0x000055a43e516db9 in row_purge_reposition_pcur (mode=1, node=0x55a4420e65d8, mtr=0x7f8d6b7fcae0) at /data/src/10.3/storage/innobase/row/row0purge.cc:98
#4  0x000055a43e51771d in row_purge_poss_sec (node=0x55a4420e65d8, index=0x7f8d3413bc98, entry=0x7f8d5801d9f8, sec_pcur=0x7f8d6b7fd070, sec_mtr=0x7f8d6b7fd2d0, is_tree=false) at /data/src/10.3/storage/innobase/row/row0purge.cc:341
#5  0x000055a43e5184b2 in row_purge_remove_sec_if_poss_leaf (node=0x55a4420e65d8, index=0x7f8d3413bc98, entry=0x7f8d5801d9f8) at /data/src/10.3/storage/innobase/row/row0purge.cc:604
#6  0x000055a43e51899a in row_purge_remove_sec_if_poss (node=0x55a4420e65d8, index=0x7f8d3413bc98, entry=0x7f8d5801d9f8) at /data/src/10.3/storage/innobase/row/row0purge.cc:717
#7  0x000055a43e518ba7 in row_purge_del_mark (node=0x55a4420e65d8) at /data/src/10.3/storage/innobase/row/row0purge.cc:791
#8  0x000055a43e51a162 in row_purge_record_func (node=0x55a4420e65d8, undo_rec=0x7f8d48069858 "", thr=0x55a4420e6408, updated_extern=false) at /data/src/10.3/storage/innobase/row/row0purge.cc:1190
#9  0x000055a43e51a49f in row_purge (node=0x55a4420e65d8, undo_rec=0x7f8d48069858 "", thr=0x55a4420e6408) at /data/src/10.3/storage/innobase/row/row0purge.cc:1257
#10 0x000055a43e51a84d in row_purge_step (thr=0x55a4420e6408) at /data/src/10.3/storage/innobase/row/row0purge.cc:1343
#11 0x000055a43e49d758 in que_thr_step (thr=0x55a4420e6408) at /data/src/10.3/storage/innobase/que/que0que.cc:1042
#12 0x000055a43e49d98b in que_run_threads_low (thr=0x55a4420e6408) at /data/src/10.3/storage/innobase/que/que0que.cc:1104
#13 0x000055a43e49db7c in que_run_threads (thr=0x55a4420e6408) at /data/src/10.3/storage/innobase/que/que0que.cc:1144
#14 0x000055a43e56573c in srv_task_execute () at /data/src/10.3/storage/innobase/srv/srv0srv.cc:2451
#15 0x000055a43e5658e1 in srv_worker_thread (arg=0x0) at /data/src/10.3/storage/innobase/srv/srv0srv.cc:2499
#16 0x00007f8da4655494 in start_thread (arg=0x7f8d6b7fe700) at pthread_create.c:333
#17 0x00007f8da2c5693f in clone () from /lib/x86_64-linux-gnu/libc.so.6

2018-12-12 12:51:27 0x7f69ac20d700  InnoDB: Assertion failure in file /data/src/10.3/storage/innobase/btr/btr0sea.cc line 1494
InnoDB: Failing assertion: my_atomic_addlint(&(block)->n_pointers, 0) == 0
 
#6  0x000055be403df544 in ut_dbg_assertion_failed (expr=0x55be409f0bb8 "my_atomic_addlint(&(block)->n_pointers, 0) == 0", file=0x55be409f0418 "/data/src/10.3/storage/innobase/btr/btr0sea.cc", line=1494) at /data/src/10.3/storage/innobase/ut/ut0dbg.cc:60
#7  0x000055be40433460 in btr_search_build_page_hash_index (index=0x7f693832db88, block=0x7f698bc7acc8, ahi_latch=0x55be43447510, n_fields=0, n_bytes=1, left_side=0) at /data/src/10.3/storage/innobase/btr/btr0sea.cc:1494
#8  0x000055be404339b3 in btr_search_info_update_slow (info=0x7f69384aa060, cursor=0x7f69ac209eb0) at /data/src/10.3/storage/innobase/btr/btr0sea.cc:1572
#9  0x000055be4040ac38 in btr_search_info_update (index=0x7f693832db88, cursor=0x7f69ac209eb0) at /data/src/10.3/storage/innobase/include/btr0sea.ic:84
#10 0x000055be404112fb in btr_cur_search_to_nth_level_func (index=0x7f693832db88, level=0, tuple=0x7f6938437348, mode=PAGE_CUR_LE, latch_mode=2, cursor=0x7f69ac209eb0, ahi_latch=0x0, file=0x55be40974180 "/data/src/10.3/storage/innobase/row/row0ins.cc", line=2620, mtr=0x7f69ac20a2d0, autoinc=2939) at /data/src/10.3/storage/innobase/btr/btr0cur.cc:2301
#11 0x000055be402e5863 in btr_pcur_open_low (index=0x7f693832db88, level=0, tuple=0x7f6938437348, mode=PAGE_CUR_LE, latch_mode=2, cursor=0x7f69ac209eb0, file=0x55be40974180 "/data/src/10.3/storage/innobase/row/row0ins.cc", line=2620, autoinc=2939, mtr=0x7f69ac20a2d0) at /data/src/10.3/storage/innobase/include/btr0pcur.ic:464
#12 0x000055be402ec53e in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x7f693832db88, n_uniq=2, entry=0x7f6938437348, n_ext=0, thr=0x7f69382f93c8, dup_chk_only=false) at /data/src/10.3/storage/innobase/row/row0ins.cc:2620
#13 0x000055be402ee422 in row_ins_clust_index_entry (index=0x7f693832db88, entry=0x7f6938437348, thr=0x7f69382f93c8, n_ext=0, dup_chk_only=false) at /data/src/10.3/storage/innobase/row/row0ins.cc:3253
#14 0x000055be402ee8d8 in row_ins_index_entry (index=0x7f693832db88, entry=0x7f6938437348, thr=0x7f69382f93c8) at /data/src/10.3/storage/innobase/row/row0ins.cc:3378
#15 0x000055be402eee9a in row_ins_index_entry_step (node=0x7f6928431010, thr=0x7f69382f93c8) at /data/src/10.3/storage/innobase/row/row0ins.cc:3528
#16 0x000055be402ef2d4 in row_ins (node=0x7f6928431010, thr=0x7f69382f93c8) at /data/src/10.3/storage/innobase/row/row0ins.cc:3671
#17 0x000055be402efad9 in row_ins_step (thr=0x7f69382f93c8) at /data/src/10.3/storage/innobase/row/row0ins.cc:3916
#18 0x000055be4031021c in row_insert_for_mysql (mysql_rec=0x7f69283a2c78 "\276\250\374", prebuilt=0x7f69284305f8, ins_mode=ROW_INS_NORMAL) at /data/src/10.3/storage/innobase/row/row0mysql.cc:1459
#19 0x000055be401b8898 in ha_innobase::write_row (this=0x7f69280f07c8, record=0x7f69283a2c78 "\276\250\374") at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:8040
#20 0x000055be3fea2f50 in handler::ha_write_row (this=0x7f69280f07c8, buf=0x7f69283a2c78 "\276\250\374") at /data/src/10.3/sql/handler.cc:6237
#21 0x000055be405f8765 in ha_partition::write_row (this=0x7f69280a9bf8, buf=0x7f69283a2c78 "\276\250\374") at /data/src/10.3/sql/ha_partition.cc:4316
#22 0x000055be3fea2f50 in handler::ha_write_row (this=0x7f69280a9bf8, buf=0x7f69283a2c78 "\276\250\374") at /data/src/10.3/sql/handler.cc:6237
#23 0x000055be3fb60271 in write_record (thd=0x7f6938000b00, table=0x7f69280a8fb0, info=0x7f693834e3a8) at /data/src/10.3/sql/sql_insert.cc:2020
#24 0x000055be3fb654fa in select_insert::send_data (this=0x7f693834e360, values=...) at /data/src/10.3/sql/sql_insert.cc:3854
#25 0x000055be3fc13b6c in end_send (join=0x7f69384105a8, join_tab=0x7f693842a788, end_of_records=false) at /data/src/10.3/sql/sql_select.cc:20576
#26 0x000055be3fc113a4 in evaluate_join_record (join=0x7f69384105a8, join_tab=0x7f693842a3d8, error=0) at /data/src/10.3/sql/sql_select.cc:19616
#27 0x000055be3fc26326 in AGGR_OP::end_send (this=0x7f6938414520) at /data/src/10.3/sql/sql_select.cc:27439
#28 0x000055be3fc1072f in sub_select_postjoin_aggr (join=0x7f69384105a8, join_tab=0x7f693842a3d8, end_of_records=true) at /data/src/10.3/sql/sql_select.cc:19112
#29 0x000055be3fc10a5c in sub_select (join=0x7f69384105a8, join_tab=0x7f693842a028, end_of_records=true) at /data/src/10.3/sql/sql_select.cc:19347
#30 0x000055be3fc10224 in do_select (join=0x7f69384105a8, procedure=0x0) at /data/src/10.3/sql/sql_select.cc:18938
#31 0x000055be3fbe8db5 in JOIN::exec_inner (this=0x7f69384105a8) at /data/src/10.3/sql/sql_select.cc:4040
#32 0x000055be3fbe81f6 in JOIN::exec (this=0x7f69384105a8) at /data/src/10.3/sql/sql_select.cc:3834
#33 0x000055be3fbe9496 in mysql_select (thd=0x7f6938000b00, tables=0x7f693802a818, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=553245739776, result=0x7f693834e360, unit=0x7f69380049b0, select_lex=0x7f6938005120) at /data/src/10.3/sql/sql_select.cc:4239
#34 0x000055be3fbdb3bc in handle_select (thd=0x7f6938000b00, lex=0x7f69380048e8, result=0x7f693834e360, setup_tables_done_option=1073741824) at /data/src/10.3/sql/sql_select.cc:385
#35 0x000055be3fb9f792 in mysql_execute_command (thd=0x7f6938000b00) at /data/src/10.3/sql/sql_parse.cc:4833
#36 0x000055be3fba9d8f in mysql_parse (thd=0x7f6938000b00, rawbuf=0x7f6938029f08 "INSERT INTO `view_t9` SELECT * FROM `view_t9` /* QNO 337 CON_ID 17 */", length=69, parser_state=0x7f69ac20c640, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:8091
#37 0x000055be3fb96f43 in dispatch_command (command=COM_QUERY, thd=0x7f6938000b00, packet=0x7f69380773c1 "INSERT INTO `view_t9` SELECT * FROM `view_t9` /* QNO 337 CON_ID 17 */", packet_length=69, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1850
#38 0x000055be3fb95967 in do_command (thd=0x7f6938000b00) at /data/src/10.3/sql/sql_parse.cc:1395
#39 0x000055be3fcfd6a4 in do_handle_one_connection (connect=0x55be438a3af0) at /data/src/10.3/sql/sql_connect.cc:1402
#40 0x000055be3fcfd428 in handle_one_connection (arg=0x55be438a3af0) at /data/src/10.3/sql/sql_connect.cc:1308
#41 0x00007f69b10e7494 in start_thread (arg=0x7f69ac20d700) at pthread_create.c:333
#42 0x00007f69af6e893f in clone () from /lib/x86_64-linux-gnu/libc.so.6

Occurrence of the 2nd one: https://travis-ci.org/elenst/travis-tests/jobs/517305311

Comment by Elena Stepanova [ 2018-12-12 ]

I can't remove a single extra grammar from the scenario, the failures stop happening – or rather, other known failures start happening, mainly acl-related – but I can't remove acl.yy either, even though it should have nothing to do with InnoDB issues. Will have to wait till at least MDEV-17975 and MDEV-17974 are fixed, then try again.

Comment by Elena Stepanova [ 2018-12-13 ]

The last above-mentioned assertion failure also occurred on Travis:
https://travis-ci.org/elenst/travis-tests/jobs/467607655

elenst-dev a88bcf42ca1e71390de25774ff26c692f64e494e

perl ./runall-new.pl --basedir=/home/travis/server --vardir=/home/travis/logs/vardir --duration=350 --threads=6 --seed=1544725221 --reporters=Backtrace,ErrorLog,Deadlock --validators=TransformerNoComparator --views --redefine=conf/mariadb/alter_table.yy --redefine=conf/mariadb/instant_add.yy --redefine=conf/mariadb/sp.yy --redefine=conf/mariadb/bulk_insert.yy --redefine=conf/mariadb/sequences.yy --redefine=conf/mariadb/modules/admin.yy --redefine=conf/mariadb/modules/userstat.yy --mysqld=--log_output=FILE --mysqld=--max-statement-time=30 --mysqld=--lock-wait-timeout=10 --mysqld=--loose-innodb-lock-wait-timeout=5 --mysqld=--loose-debug_assert_on_not_freed_memory=0 --grammar=conf/runtime/metadata_stability.yy --gendata=conf/runtime/metadata_stability.zz --skip-gendata --gendata-advanced --vcols --transformers=ExecuteAsIntersect,ExecuteAsExcept,ExecuteAsCTE,ExecuteAsExecuteImmediate,ExecuteAsDeleteReturning,ExecuteAsInsertSelect,ExecuteAsUnion,ExecuteAsUpdateDelete,ExecuteAsView,ExecuteAsPreparedTwice --redefine=conf/mariadb/versioning.yy

10.4 4752a039b5fd8858e4562cff50cb486dea355a69

2018-12-13 18:21:58 0x7f0a98114700  InnoDB: Assertion failure in file /home/travis/src/storage/innobase/btr/btr0sea.cc line 1494
InnoDB: Failing assertion: my_atomic_addlint(&(block)->n_pointers, 0) == 0
 
#6  0x0000564640cb93f3 in ut_dbg_assertion_failed (expr=0x5646413cf328 "my_atomic_addlint(&(block)->n_pointers, 0) == 0", file=0x5646413ceb70 "/home/travis/src/storage/innobase/btr/btr0sea.cc", line=1494) at /home/travis/src/storage/innobase/ut/ut0dbg.cc:60
#7  0x0000564640d0e978 in btr_search_build_page_hash_index (index=0x7f0a943f4748, block=0x7f0a7d790508, ahi_latch=0x564643a624d0, n_fields=0, n_bytes=1, left_side=0) at /home/travis/src/storage/innobase/btr/btr0sea.cc:1494
#8  0x0000564640d0eee6 in btr_search_info_update_slow (info=0x7f0a9436f488, cursor=0x7f0a981115b0) at /home/travis/src/storage/innobase/btr/btr0sea.cc:1572
#9  0x0000564640ce4e54 in btr_search_info_update (index=0x7f0a943f4748, cursor=0x7f0a981115b0) at /home/travis/src/storage/innobase/include/btr0sea.ic:84
#10 0x0000564640ceb902 in btr_cur_search_to_nth_level_func (index=0x7f0a943f4748, level=0, tuple=0x7f0a9408f9d8, mode=PAGE_CUR_LE, latch_mode=2, cursor=0x7f0a981115b0, ahi_latch=0x0, file=0x5646413586f0 "/home/travis/src/storage/innobase/row/row0ins.cc", line=2629, mtr=0x7f0a981119d0, autoinc=152) at /home/travis/src/storage/innobase/btr/btr0cur.cc:2408
#11 0x0000564640bcd4e0 in btr_pcur_open_low (index=0x7f0a943f4748, level=0, tuple=0x7f0a9408f9d8, mode=PAGE_CUR_LE, latch_mode=2, cursor=0x7f0a981115b0, file=0x5646413586f0 "/home/travis/src/storage/innobase/row/row0ins.cc", line=2629, autoinc=152, mtr=0x7f0a981119d0) at /home/travis/src/storage/innobase/include/btr0pcur.ic:459
#12 0x0000564640bd4402 in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x7f0a943f4748, n_uniq=2, entry=0x7f0a9408f9d8, n_ext=0, thr=0x7f0a945a5dd0, dup_chk_only=false) at /home/travis/src/storage/innobase/row/row0ins.cc:2629
#13 0x0000564640bd62c6 in row_ins_clust_index_entry (index=0x7f0a943f4748, entry=0x7f0a9408f9d8, thr=0x7f0a945a5dd0, n_ext=0, dup_chk_only=false) at /home/travis/src/storage/innobase/row/row0ins.cc:3252
#14 0x0000564640bd677c in row_ins_index_entry (index=0x7f0a943f4748, entry=0x7f0a9408f9d8, thr=0x7f0a945a5dd0) at /home/travis/src/storage/innobase/row/row0ins.cc:3377
#15 0x0000564640bd6e52 in row_ins_index_entry_step (node=0x7f0a9469d908, thr=0x7f0a945a5dd0) at /home/travis/src/storage/innobase/row/row0ins.cc:3545
#16 0x0000564640bd7295 in row_ins (node=0x7f0a9469d908, thr=0x7f0a945a5dd0) at /home/travis/src/storage/innobase/row/row0ins.cc:3688
#17 0x0000564640bd7a8c in row_ins_step (thr=0x7f0a945a5dd0) at /home/travis/src/storage/innobase/row/row0ins.cc:3933
#18 0x0000564640bf7aee in row_insert_for_mysql (mysql_rec=0x7f0a9468d578 ",\250\374\002\220\334!\224\n\177", prebuilt=0x7f0a9469cc58, ins_mode=ROW_INS_NORMAL) at /home/travis/src/storage/innobase/row/row0mysql.cc:1460
#19 0x0000564640a9238d in ha_innobase::write_row (this=0x7f0a941a19e8, record=0x7f0a9468d578 ",\250\374\002\220\334!\224\n\177") at /home/travis/src/storage/innobase/handler/ha_innodb.cc:8046
#20 0x000056464087e2c2 in handler::ha_write_row (this=0x7f0a941a19e8, buf=0x7f0a9468d578 ",\250\374\002\220\334!\224\n\177") at /home/travis/src/sql/handler.cc:6273
#21 0x000056464051bc12 in write_record (thd=0x7f0a9427dcd0, table=0x7f0a9465f600, info=0x7f0a98112790) at /home/travis/src/sql/sql_insert.cc:1696
#22 0x000056464054e8de in read_sep_field (thd=0x7f0a9427dcd0, info=..., table_list=0x7f0a94471450, fields_vars=..., set_fields=..., set_values=..., read_info=..., enclosed=..., skip_lines=0, ignore_check_option_errors=false) at /home/travis/src/sql/sql_load.cc:1153
#23 0x000056464054ce9e in mysql_load (thd=0x7f0a9427dcd0, ex=0x7f0a944713c8, table_list=0x7f0a94471450, fields_vars=..., set_fields=..., set_values=..., handle_duplicates=DUP_REPLACE, ignore=false, read_file_from_client=false) at /home/travis/src/sql/sql_load.cc:661
#24 0x0000564640561d95 in mysql_execute_command (thd=0x7f0a9427dcd0) at /home/travis/src/sql/sql_parse.cc:5129
#25 0x000056464056b450 in mysql_parse (thd=0x7f0a9427dcd0, rawbuf=0x7f0a94471298 "LOAD DATA INFILE 'load_view_t9' REPLACE INTO TABLE view_t9 /* QNO 4574 CON_ID 14 */", length=83, parser_state=0x7f0a98113650, is_com_multi=false, is_next_command=false) at /home/travis/src/sql/sql_parse.cc:8103
#26 0x000056464055833a in dispatch_command (command=COM_QUERY, thd=0x7f0a9427dcd0, packet=0x7f0a9454e6a1 " LOAD DATA INFILE 'load_view_t9' REPLACE INTO TABLE view_t9 /* QNO 4574 CON_ID 14 */ ", packet_length=85, is_com_multi=false, is_next_command=false) at /home/travis/src/sql/sql_parse.cc:1850
#27 0x0000564640556d57 in do_command (thd=0x7f0a9427dcd0) at /home/travis/src/sql/sql_parse.cc:1395
#28 0x00005646406c2b16 in do_handle_one_connection (connect=0x564643e473d0) at /home/travis/src/sql/sql_connect.cc:1402
#29 0x00005646406c2867 in handle_one_connection (arg=0x564643e473d0) at /home/travis/src/sql/sql_connect.cc:1308
#30 0x00007f0a9bed76ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#31 0x00007f0a9b36c41d in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
Query (0x7f0a94471298): LOAD DATA INFILE 'load_view_t9' REPLACE INTO TABLE view_t9 /* QNO 4574 CON_ID 14 */
Connection ID (thread ID): 45
Status: NOT_KILLED

Comment by Elena Stepanova [ 2019-01-07 ]

Fresh occurrence on 10.2: https://travis-ci.org/elenst/travis-tests/jobs/475403573

Comment by Elena Stepanova [ 2019-01-27 ]

Another occurrence on a 10.2-based tree: https://travis-ci.org/elenst/travis-tests/jobs/484340326 [2585 14 4]

Comment by Elena Stepanova [ 2019-02-02 ]

New occurrence of the second assertion failure from the description on 10.4:
https://travis-ci.org/elenst/travis-tests/jobs/487550295 [2656 22 2]

10.4 74eb4fc

mysqld: /home/travis/src/storage/innobase/rem/rem0rec.cc:826: ulint* rec_get_offsets_func(const rec_t*, const dict_index_t*, ulint*, bool, ulint, const char*, unsigned int, mem_heap_t**): Assertion `index' failed.
190202  8:45:18 [ERROR] mysqld got signal 6 ;
 
#3  0x00007f881c4c3c82 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#4  0x00005588a640e8c3 in rec_get_offsets_func (rec=0x7f87f8789848 "", index=0x0, offsets=0x0, leaf=true, n_fields=18446744073709551615, file=0x5588a6c0c370 "/home/travis/src/storage/innobase/row/row0vers.cc", line=908, heap=0x7f87eaffb5e0) at /home/travis/src/storage/innobase/rem/rem0rec.cc:826
#5  0x00005588a64b92db in row_vers_old_has_index_entry (also_curr=true, rec=0x7f87f8789848 "", mtr=0x7f87eaffb9e0, index=0x7f87ac17ae18, ientry=0x7f87d405c238, roll_ptr=4785074634176254, trx_id=0, vcol_info=0x5588a959ba80) at /home/travis/src/storage/innobase/row/row0vers.cc:907
#6  0x00005588a647f0e6 in row_purge_poss_sec (node=0x5588a959b8e0, index=0x7f87ac17ae18, entry=0x7f87d405c238, sec_pcur=0x7f87eaffbf70, sec_mtr=0x7f87eaffc210, is_tree=false) at /home/travis/src/storage/innobase/row/row0purge.cc:345
#7  0x00005588a647fdf4 in row_purge_remove_sec_if_poss_leaf (node=0x5588a959b8e0, index=0x7f87ac17ae18, entry=0x7f87d405c238) at /home/travis/src/storage/innobase/row/row0purge.cc:607
#8  0x00005588a64802db in row_purge_remove_sec_if_poss (node=0x5588a959b8e0, index=0x7f87ac17ae18, entry=0x7f87d405c238) at /home/travis/src/storage/innobase/row/row0purge.cc:720
#9  0x00005588a64804fa in row_purge_del_mark (node=0x5588a959b8e0) at /home/travis/src/storage/innobase/row/row0purge.cc:794
#10 0x00005588a6481b1f in row_purge_record_func (node=0x5588a959b8e0, undo_rec=0x7f87d41177d8 "", thr=0x5588a959b828, updated_extern=false) at /home/travis/src/storage/innobase/row/row0purge.cc:1194
#11 0x00005588a6481e84 in row_purge (node=0x5588a959b8e0, undo_rec=0x7f87d41177d8 "", thr=0x5588a959b828) at /home/travis/src/storage/innobase/row/row0purge.cc:1261
#12 0x00005588a6482217 in row_purge_step (thr=0x5588a959b828) at /home/travis/src/storage/innobase/row/row0purge.cc:1347
#13 0x00005588a6402c96 in que_thr_step (thr=0x5588a959b828) at /home/travis/src/storage/innobase/que/que0que.cc:1042
#14 0x00005588a6402ec9 in que_run_threads_low (thr=0x5588a959b828) at /home/travis/src/storage/innobase/que/que0que.cc:1104
#15 0x00005588a64030ba in que_run_threads (thr=0x5588a959b828) at /home/travis/src/storage/innobase/que/que0que.cc:1144
#16 0x00005588a64edcc4 in trx_purge (n_purge_threads=4, truncate=false) at /home/travis/src/storage/innobase/trx/trx0purge.cc:1325
#17 0x00005588a64c2315 in srv_do_purge (n_total_purged=0x7f87eaffced8) at /home/travis/src/storage/innobase/srv/srv0srv.cc:2579
#18 0x00005588a64c274c in srv_purge_coordinator_thread (arg=0x0) at /home/travis/src/storage/innobase/srv/srv0srv.cc:2702
#19 0x00007f881d30c6ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#20 0x00007f881c59d41d in clone () from /lib/x86_64-linux-gnu/libc.so.6

Comment by Elena Stepanova [ 2019-03-05 ]

10.4:

10.4 47b7ca62

mysqld: /home/vsts/src/storage/innobase/sync/sync0rw.cc:861: bool rw_lock_validate(const rw_lock_t*): Assertion `lock->magic_n == 22643' failed.
190304 21:22:32 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f8af8323c82 in __GI___assert_fail (assertion=0x55e5b4e58a38 "lock->magic_n == 22643", file=0x55e5b4e587f8 "/home/vsts/src/storage/innobase/sync/sync0rw.cc", line=861, function=0x55e5b4e
594c0 <rw_lock_validate(rw_lock_t const*)::__PRETTY_FUNCTION__> "bool rw_lock_validate(const rw_lock_t*)") at assert.c:101
#8  0x000055e5b470810c in rw_lock_validate (lock=0x7f8ac8136640) at /home/vsts/src/storage/innobase/sync/sync0rw.cc:861
#9  0x000055e5b4707b2c in rw_lock_x_lock_func (lock=0x7f8ac8136640, pass=0, file_name=0x55e5b4eb29d0 "/home/vsts/src/storage/innobase/dict/dict0dict.cc", line=368) at /home/vsts/src/storage/innoba
se/sync/sync0rw.cc:668
#10 0x000055e5b48089ee in pfs_rw_lock_x_lock_func (lock=0x7f8ac8136640, pass=0, file_name=0x55e5b4eb29d0 "/home/vsts/src/storage/innobase/dict/dict0dict.cc", line=368) at /home/vsts/src/storage/in
nobase/include/sync0rw.ic:558
#11 0x000055e5b480d3dd in dict_table_stats_lock (table=0x7f8ac81819d8, latch_mode=2) at /home/vsts/src/storage/innobase/dict/dict0dict.cc:368
#12 0x000055e5b480c9d9 in dict_stats_deinit (table=0x7f8ac81819d8) at /home/vsts/src/storage/innobase/include/dict0stats.ic:181
#13 0x000055e5b480d8c4 in dict_table_close (table=0x7f8ac81819d8, dict_locked=0, try_drop=1) at /home/vsts/src/storage/innobase/dict/dict0dict.cc:529
#14 0x000055e5b4694705 in row_prebuilt_free (prebuilt=0x7f8ac8117d68, dict_locked=0) at /home/vsts/src/storage/innobase/row/row0mysql.cc:1041
#15 0x000055e5b452b51e in ha_innobase::close (this=0x7f8ac80f4fd8) at /home/vsts/src/storage/innobase/handler/ha_innodb.cc:6542
#16 0x000055e5b42fe6ec in handler::ha_close (this=0x7f8ac80f4fd8) at /home/vsts/src/sql/handler.cc:2967
#17 0x000055e5b40d7969 in closefrm (table=0x7f8ac80f4170) at /home/vsts/src/sql/table.cc:3993
#18 0x000055e5b421f8e5 in intern_close_table (table=0x7f8ac80f4170) at /home/vsts/src/sql/table_cache.cc:222
#19 0x000055e5b421fd0a in tc_purge (mark_flushed=false) at /home/vsts/src/sql/table_cache.cc:335
#20 0x000055e5b4229fe6 in backup_flush (thd=0x7f8ac8000d10) at /home/vsts/src/sql/backup.cc:207
#21 0x000055e5b4229c70 in run_backup_stage (thd=0x7f8ac8000d10, stage=BACKUP_LOCK_COMMIT) at /home/vsts/src/sql/backup.cc:110
#22 0x000055e5b3fba3ec in mysql_execute_command (thd=0x7f8ac8000d10) at /home/vsts/src/sql/sql_parse.cc:5288
#23 0x000055e5b3fc44b1 in mysql_parse (thd=0x7f8ac8000d10, rawbuf=0x7f8ac8031c78 "BACKUP STAGE BLOCK_COMMIT /* QNO 3850 CON_ID 16 */", length=50, parser_state=0x7f8af4f021d0, is_com_multi=false, i
s_next_command=false) at /home/vsts/src/sql/sql_parse.cc:8157
#24 0x000055e5b3faf84e in dispatch_command (command=COM_QUERY, thd=0x7f8ac8000d10, packet=0x7f8ac800a971 "BACKUP STAGE BLOCK_COMMIT /* QNO 3850 CON_ID 16 */", packet_length=50, is_com_multi=false,
 is_next_command=false) at /home/vsts/src/sql/sql_parse.cc:1829
#25 0x000055e5b3fadfd0 in do_command (thd=0x7f8ac8000d10) at /home/vsts/src/sql/sql_parse.cc:1358
#26 0x000055e5b4127785 in do_handle_one_connection (connect=0x55e5b7fc6a30) at /home/vsts/src/sql/sql_connect.cc:1399
#27 0x000055e5b41274c3 in handle_one_connection (arg=0x55e5b7fc6a30) at /home/vsts/src/sql/sql_connect.cc:1302
#28 0x00007f8af91786ba in start_thread (arg=0x7f8af4f03700) at pthread_create.c:333
#29 0x00007f8af83fd41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Reproducible on 10.4 by re-running the attached test magic1.test.reproducible.5 (with --default-server-options and --repeat=N with big enough N), but can't simplify it due to the number of bugs in 10.4

Comment by Elena Stepanova [ 2019-05-10 ]

All attempts to reproduce with concurrent tests hit MDEV-16222.

Comment by Marko Mäkelä [ 2019-10-17 ]

Is this bug still repeatable? I think that it could very well be related to MDEV-16222 (accessing a freed object in purge, probably related to indexed virtual columns).

Comment by Elena Stepanova [ 2019-10-17 ]

It had never been reproducible (hence "draft"), but it hasn't been observed for quite a while now, so I suppose it's quite possible that it was fixed by MDEV-16222 or something similar. I'll close it for now as a duplicate of MDEV-16222.

Generated at Thu Feb 08 08:40:34 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.