[MDEV-25623] Assertion `trn->trid != 0' failed in write_hook_for_undo upon concurrent DML and DROP on Aria table Created: 2021-05-08  Updated: 2023-11-28

Status: Confirmed
Project: MariaDB Server
Component/s: Storage Engine - Aria
Affects Version/s: 10.5, 10.6, 10.7, 10.8, 10.9, 10.10
Fix Version/s: 10.5, 10.6

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Michael Widenius
Resolution: Unresolved Votes: 0
Labels: regression


 Description   

Note: The test case is non-deterministic, run with --repeat=N. It usually fails for me within ~5 attempts on a regular debug, but it can vary on different machines and builds.

CREATE TABLE t1 (a varchar(257), FULLTEXT(a)) ENGINE=Aria;
SELECT * INTO OUTFILE 'f' FROM t1;
 
--connect (con1,localhost,root,,test)
--connect (con2,localhost,root,,test)
--send
  LOAD DATA INFILE 'f' INTO TABLE t1;
--connection con1
--send
  LOAD DATA INFILE 'f' INTO TABLE t1;
 
--connection default
DROP TABLE t1;
--let $datadir= `select @@datadir`
--remove_file $datadir/test/f

10.5 35977e81 debug

mariadbd: /data/src/10.5/storage/maria/ma_blockrec.c:6149: write_hook_for_undo: Assertion `trn->trid != 0' failed.
210509  2:17:06 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f81dd79bf36 in __GI___assert_fail (assertion=0x564fa1a6e45c "trn->trid != 0", file=0x564fa1a6c588 "/data/src/10.5/storage/maria/ma_blockrec.c", line=6149, function=0x564fa1a6ed00 <__PRETTY_FUNCTION__.20162> "write_hook_for_undo") at assert.c:101
#8  0x0000564fa10a4915 in write_hook_for_undo (type=LOGREC_UNDO_BULK_INSERT, trn=0x564fa2ca6840 <dummy_transaction_object>, tbl_info=0x7f81b801f1b8, lsn=0x7f81cb6d8460, hook_arg=0x0) at /data/src/10.5/storage/maria/ma_blockrec.c:6149
#9  0x0000564fa10a4b68 in write_hook_for_undo_bulk_insert (type=LOGREC_UNDO_BULK_INSERT, trn=0x564fa2ca6840 <dummy_transaction_object>, tbl_info=0x7f81b801f1b8, lsn=0x7f81cb6d8460, hook_arg=0x0) at /data/src/10.5/storage/maria/ma_blockrec.c:6246
#10 0x0000564fa1047537 in translog_write_variable_record_1chunk (lsn=0x7f81cb6d8460, type=LOGREC_UNDO_BULK_INSERT, tbl_info=0x7f81b801f1b8, short_trid=0, parts=0x7f81cb6d83d0, buffer_to_flush=0x0, header_length=6, trn=0x564fa2ca6840 <dummy_transaction_object>, hook_arg=0x0) at /data/src/10.5/storage/maria/ma_loghandler.c:5284
#11 0x0000564fa1049f43 in translog_write_variable_record (lsn=0x7f81cb6d8460, type=LOGREC_UNDO_BULK_INSERT, tbl_info=0x7f81b801f1b8, short_trid=0, parts=0x7f81cb6d83d0, trn=0x564fa2ca6840 <dummy_transaction_object>, hook_arg=0x0) at /data/src/10.5/storage/maria/ma_loghandler.c:6195
#12 0x0000564fa104b056 in translog_write_record (lsn=0x7f81cb6d8460, type=LOGREC_UNDO_BULK_INSERT, trn=0x564fa2ca6840 <dummy_transaction_object>, tbl_info=0x7f81b801f1b8, rec_len=9, part_no=3, parts_data=0x7f81cb6d8470, store_share_id=0x7f81cb6d84b6 "7", hook_arg=0x0) at /data/src/10.5/storage/maria/ma_loghandler.c:6505
#13 0x0000564fa10d97a7 in write_log_record_for_bulk_insert (info=0x7f81b801f1b8) at /data/src/10.5/storage/maria/ma_check.c:6959
#14 0x0000564fa102ca83 in ha_maria::start_bulk_insert (this=0x7f81b817fde0, rows=0, flags=0) at /data/src/10.5/storage/maria/ha_maria.cc:2240
#15 0x0000564fa09d0fc5 in handler::ha_start_bulk_insert (this=0x7f81b817fde0, rows=0, flags=0) at /data/src/10.5/sql/handler.h:3452
#16 0x0000564fa0a02aa7 in mysql_load (thd=0x7f81b8000db8, ex=0x7f81b80140c0, table_list=0x7f81b8014148, fields_vars=..., set_fields=..., set_values=..., handle_duplicates=DUP_ERROR, ignore=false, read_file_from_client=false) at /data/src/10.5/sql/sql_load.cc:649
#17 0x0000564fa0a199fc in mysql_execute_command (thd=0x7f81b8000db8) at /data/src/10.5/sql/sql_parse.cc:5086
#18 0x0000564fa0a236aa in mysql_parse (thd=0x7f81b8000db8, rawbuf=0x7f81b8014000 "LOAD DATA INFILE 'f' INTO TABLE t1", length=34, parser_state=0x7f81cb6d9490, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:8099
#19 0x0000564fa0a0f621 in dispatch_command (command=COM_QUERY, thd=0x7f81b8000db8, packet=0x7f81b800b5b9 "LOAD DATA INFILE 'f' INTO TABLE t1", packet_length=34, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1891
#20 0x0000564fa0a0de13 in do_command (thd=0x7f81b8000db8) at /data/src/10.5/sql/sql_parse.cc:1370
#21 0x0000564fa0bbda2b in do_handle_one_connection (connect=0x564fa35a6208, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1410
#22 0x0000564fa0bbd78e in handle_one_connection (arg=0x564fa35a4098) at /data/src/10.5/sql/sql_connect.cc:1312
#23 0x0000564fa1121f69 in pfs_spawn_thread (arg=0x564fa35a5428) at /data/src/10.5/storage/perfschema/pfs.cc:2201
#24 0x00007f81ddcb3609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#25 0x00007f81dd887293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Reproducible on 10.5-10.6.
No obvious problem on a non-debug build.

The failure started happening after this commit in 10.5:

commit 25fa2a68313046b638aaf1779d45d3e8c8757b07
Author: Monty
Date:   Fri Apr 30 15:37:00 2021 +0300
 
    MDEV-25507 CHECK on encrypted Aria table complains about "Wrong LSN"



 Comments   
Comment by Alice Sherepa [ 2022-11-11 ]

probably related:

10.11 d186cb180e424fb4e1669

mysqld: /10.11/storage/maria/ma_blockrec.c:6142: write_hook_for_redo: Assertion `trn->trid != 0' failed.
221111 13:54:58 [ERROR] mysqld got signal 6 ;
 
 
Server version: 10.11.1-MariaDB-debug-log
 
??:0(__assert_fail)[0x7fabb9aebfd6]
maria/ma_blockrec.c:6149(write_hook_for_redo)[0x55de42f0d9d8]
maria/ma_loghandler.c:5282(translog_write_variable_record_1chunk)[0x55de42e133a7]
maria/ma_loghandler.c:6193(translog_write_variable_record)[0x55de42e18acf]
maria/ma_loghandler.c:6503(translog_write_record)[0x55de42e1b27e]
maria/ma_delete.c:1633(_ma_log_delete)[0x55de42f53641]
maria/ma_delete.c:446(d_search)[0x55de42f47fe6]
maria/ma_delete.c:422(d_search)[0x55de42f47b11]
maria/ma_delete.c:235(_ma_ck_real_delete)[0x55de42f45ac0]
maria/ma_delete.c:184(_ma_ck_delete)[0x55de42f44f67]
maria/ma_ft_update.c:161(_ma_ft_erase)[0x55de42f9e8dd]
maria/ma_ft_update.c:241(_ma_ft_update)[0x55de42f9f53f]
maria/ma_update.c:108(maria_update)[0x55de42f2c386]
maria/ha_maria.cc:2425(ha_maria::update_row(unsigned char const*, unsigned char const*))[0x55de42dd50d9]
sql/handler.cc:7636(handler::ha_update_row(unsigned char const*, unsigned char const*))[0x55de428bf735]
sql/sql_update.cc:1099(mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, bool, unsigned long long*, unsigned long long*))[0x55de423098c4]
sql/sql_parse.cc:4408(mysql_execute_command(THD*, bool))[0x55de41f954c4]
sql/sql_parse.cc:7998(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x55de41faeaa7]
sql/sql_parse.cc:1896(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x55de41f84e8d]
sql/sql_parse.cc:1407(do_command(THD*, bool))[0x55de41f81bdd]
sql/threadpool_common.cc:432(threadpool_process_request(THD*))[0x55de426edbca]
sql/threadpool_common.cc:245(tp_callback(TP_connection*))[0x55de426ed059]
sql/threadpool_generic.cc:1556(worker_main(void*))[0x55de42d7c6bc]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x55de4306f31e]
nptl/pthread_create.c:478(start_thread)[0x7fabba006609]
 
Query (0x6290012892a8): UPDATE t SET a = 'e' ORDER BY `c1` LIMIT 9

Generated at Thu Feb 08 09:39:06 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.