[MDEV-22257] Assertion `trx_id > 0 || (flags & BTR_KEEP_SYS_FLAG)' failed in btr_cur_optimistic_update | Assertion `id' failed in trx_write_trx_id Created: 2020-04-16  Updated: 2022-02-21  Resolved: 2022-02-21

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Temporary, Data Manipulation - Update, Storage Engine - InnoDB
Affects Version/s: 10.2, 10.3, 10.4, 10.5
Fix Version/s: 10.2.38, 10.3.29, 10.4.19, 10.5.10, 10.6.0

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Marko Mäkelä
Resolution: Duplicate Votes: 1
Labels: None

Issue Links:
Duplicate
duplicates MDEV-22255 SIGABRT: Assertion `id' failed in trx... Closed
Relates
relates to MDEV-13269 Upgrade tests for InnoDB undo log Closed

 Description    

# mysqld options required for replay:  --sql_mode=
 
USE test;
 
CREATE TEMPORARY TABLE t (c INT) ENGINE=InnoDB;
 
SET @@SESSION.tx_read_only=1;
 
INSERT INTO t VALUES(0);
 
UPDATE t SET c=NULL;

Leads to:

10.5.3 364e7a9ae6b5fbf69494cec30733b5ad28738cbb

 
mysqld: /test/10.5_dbg/storage/innobase/btr/btr0cur.cc:4540: dberr_t btr_cur_optimistic_update(ulint, btr_cur_t*, offset_t**, mem_heap_t**, const upd_t*, ulint, que_thr_t*, trx_id_t, mtr_t*): Assertion `trx_id > 0 || (flags & BTR_KEEP_SYS_FLAG)' failed.

10.5.3 364e7a9ae6b5fbf69494cec30733b5ad28738cbb

 
Core was generated by `/test/MD110420-mariadb-10.5.3-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
[Current thread is 1 (Thread 0x7f8dbbb15700 (LWP 24424))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
#1  0x00005647775eb21e in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
 
#2  0x0000564776d9108f in handle_fatal_signal (sig=6) at /test/10.5_dbg/sql/signal_handler.cc:329
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
#5  0x00007f8dba259801 in __GI_abort () at abort.c:79
 
#6  0x00007f8dba24939a in __assert_fail_base (fmt=0x7f8dba3d07d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x564777a71538 "trx_id > 0 || (flags & BTR_KEEP_SYS_FLAG)", file=file@entry=0x564777a70618 "/test/10.5_dbg/storage/innobase/btr/btr0cur.cc", line=line@entry=4540, function=function@entry=0x564777a74560 <btr_cur_optimistic_update(unsigned long, btr_cur_t*, unsigned short**, mem_block_info_t**, upd_t const*, unsigned long, que_thr_t*, unsigned long, mtr_t*)::__PRETTY_FUNCTION__> "dberr_t btr_cur_optimistic_update(ulint, btr_cur_t*, offset_t**, mem_heap_t**, const upd_t*, ulint, que_thr_t*, trx_id_t, mtr_t*)") at assert.c:92
 
#7  0x00007f8dba249412 in __GI___assert_fail (assertion=assertion@entry=0x564777a71538 "trx_id > 0 || (flags & BTR_KEEP_SYS_FLAG)", file=file@entry=0x564777a70618 "/test/10.5_dbg/storage/innobase/btr/btr0cur.cc", line=line@entry=4540, function=function@entry=0x564777a74560 <btr_cur_optimistic_update(unsigned long, btr_cur_t*, unsigned short**, mem_block_info_t**, upd_t const*, unsigned long, que_thr_t*, unsigned long, mtr_t*)::__PRETTY_FUNCTION__> "dberr_t btr_cur_optimistic_update(ulint, btr_cur_t*, offset_t**, mem_heap_t**, const upd_t*, ulint, que_thr_t*, trx_id_t, mtr_t*)") at assert.c:101
 
#8  0x00005647773e4508 in btr_cur_optimistic_update (flags=flags@entry=2, cursor=cursor@entry=0x7f8d8e423798, offsets=offsets@entry=0x7f8dbbb12238, heap=heap@entry=0x7f8dbbb122f8, update=0x7f8d8e4c9c00, cmpl_info=1, thr=0x7f8d8e4c9db0, trx_id=0, mtr=0x7f8dbbb12dd0) at /test/10.5_dbg/storage/innobase/btr/btr0cur.cc:4540
 
#9  0x00005647773180df in row_upd_clust_rec (flags=flags@entry=2, node=node@entry=0x7f8d8e4c9ad8, index=index@entry=0x7f8d8e484898, offsets=<optimized out>, offsets@entry=0x7f8dbbb12310, offsets_heap=offsets_heap@entry=0x7f8dbbb122f8, thr=thr@entry=0x7f8d8e4c9db0, mtr=0x7f8dbbb12dd0) at /test/10.5_dbg/storage/innobase/row/row0upd.cc:2563
 
#10 0x000056477731f463 in row_upd_clust_step (node=node@entry=0x7f8d8e4c9ad8, thr=thr@entry=0x7f8d8e4c9db0) at /test/10.5_dbg/storage/innobase/row/row0upd.cc:2894
 
#11 0x00005647773204a8 in row_upd (thr=0x7f8d8e4c9db0, node=0x7f8d8e4c9ad8) at /test/10.5_dbg/storage/innobase/row/row0upd.cc:2995
 
#12 row_upd_step (thr=thr@entry=0x7f8d8e4c9db0) at /test/10.5_dbg/storage/innobase/row/row0upd.cc:3139
 
#13 0x00005647772cad44 in row_update_for_mysql (prebuilt=0x7f8d8e4c9098) at /test/10.5_dbg/storage/innobase/row/row0mysql.cc:1888
 
#14 0x000056477715dd38 in ha_innobase::update_row (this=0x7f8d8e42cea0, old_row=0x7f8d8e44a0b0 <incomplete sequence \375>, new_row=0x7f8d8e44a0a8 "\377") at /test/10.5_dbg/storage/innobase/handler/ha_innodb.cc:8568
 
#15 0x0000564776da56ae in handler::ha_update_row (this=0x7f8d8e42cea0, old_data=0x7f8d8e44a0b0 <incomplete sequence \375>, new_data=0x7f8d8e44a0a8 "\377") at /test/10.5_dbg/sql/handler.cc:7000
 
#16 0x0000564776bde51c in mysql_update (thd=thd@entry=0x7f8d8e415088, table_list=<optimized out>, fields=..., values=..., conds=<optimized out>, order_num=<optimized out>, order=<optimized out>, limit=18446744073709551615, ignore=<optimized out>, found_return=<optimized out>, updated_return=<optimized out>) at /test/10.5_dbg/sql/sql_update.cc:1056
 
#17 0x0000564776ae885e in mysql_execute_command (thd=thd@entry=0x7f8d8e415088) at /test/10.5_dbg/sql/sql_parse.cc:4363
 
#18 0x0000564776af49d1 in mysql_parse (thd=thd@entry=0x7f8d8e415088, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f8dbbb14450, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:7953
 
#19 0x0000564776ae0719 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f8d8e415088, packet=packet@entry=0x7f8d8e467089 "UPDATE t SET c=NULL", packet_length=packet_length@entry=19, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:1839
 
#20 0x0000564776adef6f in do_command (thd=0x7f8d8e415088) at /test/10.5_dbg/sql/sql_parse.cc:1358
 
#21 0x0000564776c39a53 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x7f8d92c433a8, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1422
 
#22 0x0000564776c39d82 in handle_one_connection (arg=arg@entry=0x7f8d92c433a8) at /test/10.5_dbg/sql/sql_connect.cc:1319
 
#23 0x000056477709a080 in pfs_spawn_thread (arg=0x7f8db9845888) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
 
#24 0x00007f8dbaf3c6db in start_thread (arg=0x7f8dbbb15700) at pthread_create.c:463
 
#25 0x00007f8dba33a88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.2.32 (dbg), 10.3.23 (dbg), 10.4.13 (dbg), 10.5.2 (dbg), 10.5.3 (dbg)

Bug confirmed not present in:
MariaDB: 10.1.45 (dbg), 10.1.45 (opt), 10.2.32 (opt), 10.3.23 (opt), 10.4.13 (opt), 10.5.2 (opt), 10.5.3 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.47 (dbg), 5.6.47 (opt), 5.7.29 (dbg), 5.7.29 (opt), 8.0.19 (dbg), 8.0.19 (opt)

 Comments   
Comment by Roel Van de Paar [ 2020-04-16 ]

See also https://jira.mariadb.org/browse/MDEV-13269?focusedCommentId=98666&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-98666 where this assert is mentioned also.

Comment by Roel Van de Paar [ 2020-04-28 ]

Additional testcase (KEY added) leading to a different assert

# mysqld options required for replay: --sql_mode=
 
USE test;
 
CREATE TEMPORARY TABLE t (c INT KEY) ENGINE=InnoDB;
 
INSERT INTO t VALUES (1);
 
START TRANSACTION READ ONLY;
 
UPDATE t SET c=0;

Leads to:

10.5.3 98003440c2f8d20164a191ced1b7d92b283bb68f

 
mysqld: /test/10.5_dbg/storage/innobase/include/trx0sys.h:92: void trx_write_trx_id(byte*, trx_id_t): Assertion `id' failed.

10.5.3 98003440c2f8d20164a191ced1b7d92b283bb68f

 
Core was generated by `/test/MD210420-mariadb-10.5.3-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
[Current thread is 1 (Thread 0x7f3dabf69700 (LWP 630174))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
#1  0x00005613bf13703d in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
 
#2  0x00005613be8dcd7b in handle_fatal_signal (sig=6) at /test/10.5_dbg/sql/signal_handler.cc:329
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
#5  0x00007f3daa6ad801 in __GI_abort () at abort.c:79
 
#6  0x00007f3daa69d39a in __assert_fail_base (fmt=0x7f3daa8247d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x5613bf535da9 "id", file=file@entry=0x5613bf52be18 "/test/10.5_dbg/storage/innobase/include/trx0sys.h", line=line@entry=92, function=function@entry=0x5613bf5903c0 <_ZZL16trx_write_trx_idPhmE19__PRETTY_FUNCTION__> "void trx_write_trx_id(byte*, trx_id_t)") at assert.c:92
 
#7  0x00007f3daa69d412 in __GI___assert_fail (assertion=assertion@entry=0x5613bf535da9 "id", file=file@entry=0x5613bf52be18 "/test/10.5_dbg/storage/innobase/include/trx0sys.h", line=line@entry=92, function=function@entry=0x5613bf5903c0 <_ZZL16trx_write_trx_idPhmE19__PRETTY_FUNCTION__> "void trx_write_trx_id(byte*, trx_id_t)") at assert.c:101
 
#8  0x00005613bee6b848 in trx_write_trx_id (id=0, db_trx_id=0x7f3d7e8236e1 "") at /test/10.5_dbg/storage/innobase/include/trx0sys.h:92
 
#9  row_upd_clust_rec_by_insert (mtr=0x7f3dabf66dd0, foreign=false, referenced=0, thr=0x7f3d7e8c9db8, index=0x7f3d7e883898, node=0x7f3d7e8c9ae0) at /test/10.5_dbg/storage/innobase/row/row0upd.cc:2398
 
#10 row_upd_clust_step (node=node@entry=0x7f3d7e8c9ae0, thr=thr@entry=0x7f3d7e8c9db8) at /test/10.5_dbg/storage/innobase/row/row0upd.cc:2916
 
#11 0x00005613bee6c5c0 in row_upd (thr=0x7f3d7e8c9db8, node=0x7f3d7e8c9ae0) at /test/10.5_dbg/storage/innobase/row/row0upd.cc:2995
 
#12 row_upd_step (thr=thr@entry=0x7f3d7e8c9db8) at /test/10.5_dbg/storage/innobase/row/row0upd.cc:3139
 
#13 0x00005613bee16e2e in row_update_for_mysql (prebuilt=0x7f3d7e8c9098) at /test/10.5_dbg/storage/innobase/row/row0mysql.cc:1888
 
#14 0x00005613beca9c74 in ha_innobase::update_row (this=0x7f3d7e834ea0, old_row=0x7f3d7e8525b0 "\377\001", new_row=0x7f3d7e8525a8 "\377") at /test/10.5_dbg/storage/innobase/handler/ha_innodb.cc:8568
 
#15 0x00005613be8f12f8 in handler::ha_update_row (this=0x7f3d7e834ea0, old_data=0x7f3d7e8525b0 "\377\001", new_data=0x7f3d7e8525a8 "\377") at /test/10.5_dbg/sql/handler.cc:7007
 
#16 0x00005613be729aaa in mysql_update (thd=thd@entry=0x7f3d7e815088, table_list=<optimized out>, fields=..., values=..., conds=<optimized out>, order_num=<optimized out>, order=<optimized out>, limit=18446744073709551615, ignore=<optimized out>, found_return=<optimized out>, updated_return=<optimized out>) at /test/10.5_dbg/sql/sql_update.cc:1059
 
#17 0x00005613be633d8a in mysql_execute_command (thd=thd@entry=0x7f3d7e815088) at /test/10.5_dbg/sql/sql_parse.cc:4363
 
#18 0x00005613be63ff2b in mysql_parse (thd=thd@entry=0x7f3d7e815088, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f3dabf68450, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:7957
 
#19 0x00005613be62bc45 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f3d7e815088, packet=packet@entry=0x7f3d7e867089 "UPDATE t SET c=0", packet_length=packet_length@entry=16, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:1839
 
#20 0x00005613be62a49b in do_command (thd=0x7f3d7e815088) at /test/10.5_dbg/sql/sql_parse.cc:1358
 
#21 0x00005613be785415 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x7f3d8a3c53a8, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1422
 
#22 0x00005613be785744 in handle_one_connection (arg=arg@entry=0x7f3d8a3c53a8) at /test/10.5_dbg/sql/sql_connect.cc:1319
 
#23 0x00005613bebe5fb0 in pfs_spawn_thread (arg=0x7f3da9c45b08) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
 
#24 0x00007f3dab3906db in start_thread (arg=0x7f3dabf69700) at pthread_create.c:463
 
#25 0x00007f3daa78e88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.2.32 (dbg), 10.3.23 (dbg), 10.4.13 (dbg), 10.5.2 (dbg), 10.5.3 (dbg)

Bug confirmed not present in:
MariaDB: 10.1.45 (dbg), 10.1.45 (opt), 10.2.32 (opt), 10.3.23 (opt), 10.4.13 (opt), 10.5.2 (opt), 10.5.3 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.47 (dbg), 5.6.47 (opt), 5.7.29 (dbg), 5.7.29 (opt), 8.0.19 (dbg), 8.0.19 (opt)

Comment by Elena Stepanova [ 2021-01-26 ]

Looks the same as MDEV-22255

Comment by Roel Van de Paar [ 2021-01-27 ]

Hmm yes may be yet another assert in the same series. @Dev: please fix together.

Comment by Marko Mäkelä [ 2022-02-21 ]

Both debug assertions were indeed relaxed or removed as part of MDEV-22255.

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