[MDEV-22445] Crash on HANDLER READ NEXT after XA PREPARE Created: 2020-05-04  Updated: 2023-03-07  Resolved: 2021-10-20

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, XA
Affects Version/s: 10.1, 10.2, 10.3, 10.4, 10.5, 10.6, 10.7
Fix Version/s: 10.2.41, 10.3.32, 10.4.22, 10.5.13, 10.6.5

Type: Bug Priority: Critical
Reporter: Roel Van de Paar Assignee: Nikita Malyavin
Resolution: Fixed Votes: 0
Labels: affects-tests, upstream-5.5

Issue Links:
Relates
relates to MDEV-742 LP:803649 - Xa recovery failed on cli... Closed
relates to MDEV-14846 InnoDB: assertion on trx->state becau... Closed
relates to MDEV-30801 SIGABRT in trx_start_if_not_started_l... Open

 Description    

USE test;
 
CREATE TABLE t (a INT KEY) ENGINE=InnoDB;
 
HANDLER t OPEN AS t;
 
XA START '0';
 
SELECT * FROM t;
 
XA END '0';
 
XA PREPARE '0';
 
HANDLER t READ NEXT;

Leads to:

2020-05-04 06:53:45 0x7f1e288ff700  InnoDB: Assertion failure in file /test/10.5_opt/storage/innobase/trx/trx0trx.cc line 2250

10.5.3 f544a712c8a2ef3f3ecba80cb2782b1839fb36ab

 
Core was generated by `/test/MD010520-mariadb-10.5.3-linux-x86_64-opt/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 0x7f408d89c700 (LWP 2429977))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
#1  0x000055a0aa642ac7 in my_write_core (sig=sig@entry=6) at /test/10.5_opt/mysys/stacktrace.c:518
 
#2  0x000055a0aa0047ca in handle_fatal_signal (sig=6) at /test/10.5_opt/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  0x00007f408bfe0801 in __GI_abort () at abort.c:79
 
#6  0x000055a0a9d0e61a in ut_dbg_assertion_failed (expr=expr@entry=0x0, file=file@entry=0x55a0aa96d4b8 "/test/10.5_opt/storage/innobase/trx/trx0trx.cc", line=line@entry=2250) at /test/10.5_opt/storage/innobase/ut/ut0dbg.cc:60
 
#7  0x000055a0aa475f0b in trx_start_if_not_started_xa_low (trx=0x7f4078002160, read_write=read_write@entry=false) at /test/10.5_opt/storage/innobase/trx/trx0trx.cc:2250
 
#8  0x000055a0aa31c63b in ha_innobase::init_table_handle_for_HANDLER (this=0x7f4059465830) at /test/10.5_opt/storage/innobase/handler/ha_innodb.cc:3270
 
#9  0x000055a0a9dd79a2 in mysql_ha_read (thd=thd@entry=0x7f4059412018, tables=tables@entry=0x7f40594471a0, mode=RFIRST, keyname=0x0, key_expr=0x0, ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.5_opt/sql/sql_handler.cc:877
 
#10 0x000055a0a9e10816 in mysql_execute_command (thd=thd@entry=0x7f4059412018) at /test/10.5_opt/sql/sql_parse.cc:5517
 
#11 0x000055a0a9e1622c in mysql_parse (thd=0x7f4059412018, rawbuf=<optimized out>, length=19, parser_state=0x7f408d89b4d0, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.5_opt/sql/sql_parse.cc:7957
 
#12 0x000055a0a9e0b855 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f4059412018, packet=packet@entry=0x7f405943a019 "", 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_opt/sql/sql_parse.cc:1839
 
#13 0x000055a0a9e09ae6 in do_command (thd=0x7f4059412018) at /test/10.5_opt/sql/sql_parse.cc:1358
 
#14 0x000055a0a9efe29e in do_handle_one_connection (connect=<optimized out>, connect@entry=0x7f408b4329b8, put_in_cache=put_in_cache@entry=true) at /test/10.5_opt/sql/sql_connect.cc:1422
 
#15 0x000055a0a9efe444 in handle_one_connection (arg=arg@entry=0x7f408b4329b8) at /test/10.5_opt/sql/sql_connect.cc:1319
 
#16 0x000055a0aa26a53a in pfs_spawn_thread (arg=0x7f408b44b018) at /test/10.5_opt/storage/perfschema/pfs.cc:2201
 
#17 0x00007f408ccc36db in start_thread (arg=0x7f408d89c700) at pthread_create.c:463
 
#18 0x00007f408c0c188f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

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

Bug confirmed not present in:

MySQL: 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 Marko Mäkelä [ 2020-05-04 ]

No further operations are allowed after XA PREPARE, other than XA ROLLBACK or XA COMMIT. The HANDLER t READ NEXT should return ER_XAER_OUTSIDE or similar error.

Comment by Roel Van de Paar [ 2020-10-27 ]

Different testcase, slightly different stack

CREATE TABLE t (i INT) ENGINE=InnoDB;;
 
CREATE TABLE t2 (a INT, KEY(a)) ENGINE=InnoDB;;
 
XA BEGIN 'x';
 
SELECT DATE_SUB(a, INTERVAL 1 MINUTE) FROM t2 ORDER BY a;
 
HANDLER t OPEN;
 
XA END 'x';
 
XA PREPARE 'x';
 
HANDLER t READ FIRST;

Leads to:

10.6.0 5d4599f9750140f92cfdbbe4d292ae1b8dd456f8 (Optimized)

 
Core was generated by `/test/MD201020-mariadb-10.6.0-linux-x86_64-opt/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:56
 
[Current thread is 1 (Thread 0x149eb05ff700 (LWP 1353274))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
#1  0x000055c60a6d0a4f in my_write_core (sig=sig@entry=6) at /test/10.6_opt/mysys/stacktrace.c:424
 
#2  0x000055c60a0f4130 in handle_fatal_signal (sig=6) at /test/10.6_opt/sql/signal_handler.cc:330
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#5  0x0000149eb1a2d859 in __GI_abort () at abort.c:79
 
#6  0x000055c609db8f98 in ut_dbg_assertion_failed (expr=expr@entry=0x0, file=file@entry=0x55c60a9f0d90 "/test/10.6_opt/storage/innobase/trx/trx0trx.cc", line=line@entry=2230) at /test/10.6_opt/storage/innobase/ut/ut0dbg.cc:60
 
#7  0x000055c609db7c83 in trx_start_if_not_started_xa_low (trx=0x149eb08be1c0, read_write=<optimized out>) at /test/10.6_opt/storage/innobase/trx/trx0trx.cc:2230
 
#8  trx_start_if_not_started_xa_low (trx=0x149eb08be1c0, read_write=<optimized out>) at /test/10.6_opt/storage/innobase/trx/trx0trx.cc:2203
 
#9  0x000055c60a40f6ac in ha_innobase::init_table_handle_for_HANDLER (this=0x149e54054c50) at /test/10.6_opt/storage/innobase/handler/ha_innodb.cc:3035
 
#10 0x000055c609ea8330 in mysql_ha_read (thd=thd@entry=0x149e54000c58, tables=tables@entry=0x149e54010510, mode=RFIRST, keyname=0x0, key_expr=0x0, ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.6_opt/sql/handler.h:4108
 
#11 0x000055c609eed7d8 in mysql_execute_command (thd=0x149e54000c58) at /test/10.6_opt/sql/sql_limit.h:69
 
#12 0x000055c609edb03f in mysql_parse (thd=0x149e54000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:7833
 
#13 0x000055c609ee6967 in dispatch_command (command=COM_QUERY, thd=0x149e54000c58, packet=0x149e54008009 "", packet_length=<optimized out>) at /test/10.6_opt/sql/sql_class.h:1253
 
#14 0x000055c609ee8d42 in do_command (thd=0x149e54000c58) at /test/10.6_opt/sql/sql_parse.cc:1343
 
#15 0x000055c609fec6e1 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55c60d3a7798, put_in_cache=put_in_cache@entry=true) at /test/10.6_opt/sql/sql_connect.cc:1410
 
#16 0x000055c609fecb5d in handle_one_connection (arg=arg@entry=0x55c60d3a7798) at /test/10.6_opt/sql/sql_connect.cc:1312
 
#17 0x000055c60a372266 in pfs_spawn_thread (arg=0x55c60d3229c8) at /test/10.6_opt/storage/perfschema/pfs.cc:2201
 
#18 0x0000149eb1f3b609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#19 0x0000149eb1b2a293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.1.48 (dbg), 10.1.48 (opt), 10.2.35 (dbg), 10.2.35 (opt), 10.3.26 (dbg), 10.3.26 (opt), 10.4.16 (dbg), 10.4.16 (opt), 10.5.7 (dbg), 10.5.7 (opt), 10.6.0 (dbg), 10.6.0 (opt)
MySQL: 5.5.62 (dbg)

Bug confirmed not present in:
MySQL: 5.5.62 (opt), 5.6.50 (dbg), 5.6.50 (opt), 5.7.32 (dbg), 5.7.32 (opt), 8.0.22 (dbg), 8.0.22 (opt)

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

I also observed an assert with this testacse:

CREATE TABLE t (c INT) ENGINE=InnoDB;
 
XA START 'a';
 
HANDLER t OPEN h;
 
INSERT INTO t VALUES (0);
 
XA END 'a';
 
XA PREPARE 'a';
 
HANDLER h READ NEXT;

In MySQL 5.5:

MS 5.5.62 (Debug)

 
InnoDB: Failing assertion: trx->conc_state == 1

MS 5.5.62 (Debug)

 
Core was generated by `/test/MS280421-mysql-5.5.62-linux-x86_64-dbg/bin/mysqld --no-defaults --core --'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
[Current thread is 1 (Thread 0x1520d3e4a700 (LWP 1596931))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x00001520e48c7859 in __GI_abort () at abort.c:79
 
#2  0x0000555d1a9b262e in trx_assign_read_view (trx=<optimized out>) at /test/5.5_dbg/storage/innobase/trx/trx0trx.c:1106
 
#3  0x0000555d1a93a05a in ha_innobase::init_table_handle_for_HANDLER (this=0x1520c400c2c0) at /test/5.5_dbg/storage/innobase/handler/ha_innodb.cc:2187
 
#4  0x0000555d1a68f983 in mysql_ha_read (thd=thd@entry=0x555d1bf48d20, tables=tables@entry=0x1520c4004fe8, mode=RNEXT, keyname=0x0, key_expr=0x1520c40054a8, ha_rkey_mode=HA_READ_KEY_EXACT, cond=<optimized out>, select_limit_cnt=1, offset_limit_cnt=0) at /test/5.5_dbg/sql/sql_handler.cc:647
 
#5  0x0000555d1a6aeff2 in mysql_execute_command (thd=thd@entry=0x555d1bf48d20) at /test/5.5_dbg/sql/sql_parse.cc:3811
 
#6  0x0000555d1a6b1be7 in mysql_parse (thd=thd@entry=0x555d1bf48d20, rawbuf=<optimized out>, length=19, parser_state=parser_state@entry=0x1520d3e49610) at /test/5.5_dbg/sql/sql_parse.cc:5831
 
#7  0x0000555d1a6b345d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x555d1bf48d20, packet=packet@entry=0x555d1bfd0261 "", packet_length=packet_length@entry=19) at /test/5.5_dbg/sql/sql_class.h:758
 
#8  0x0000555d1a6b4d23 in do_command (thd=0x555d1bf48d20) at /test/5.5_dbg/sql/sql_parse.cc:776
 
#9  0x0000555d1a765392 in do_handle_one_connection (thd_arg=thd_arg@entry=0x555d1bf48d20) at /test/5.5_dbg/sql/sql_connect.cc:870
 
#10 0x0000555d1a765464 in handle_one_connection (arg=0x555d1bf48d20) at /test/5.5_dbg/sql/sql_connect.cc:789
 
#11 0x00001520e4dcf609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#12 0x00001520e49c4293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment by Roel Van de Paar [ 2021-05-04 ]

Found this different assert and stack with partitioning:

CREATE TABLE t (c INT) ENGINE=InnoDB PARTITION BY LIST (c) (PARTITION p1 VALUES IN (1));
 
XA START 'a';
 
HANDLER t OPEN t1;
 
INSERT INTO t VALUES (1);
 
XA END 'a';
 
XA PREPARE 'a';
 
HANDLER t1 READ NEXT;

Leads to:

10.6.1 9db14e93acc4ec9023d50686c66dbef7d4d8c15c (Optimized)

 
Core was generated by `/test/MD270421-mariadb-10.6.1-linux-x86_64-opt/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
[Current thread is 1 (Thread 0x14feb4670700 (LWP 2053366))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x000014febda9b859 in __GI_abort () at abort.c:79
 
#2  0x0000555d50658fa1 in ut_dbg_assertion_failed (expr=expr@entry=0x0, file=file@entry=0x555d51247660 "/test/10.6_opt/storage/innobase/trx/trx0trx.cc", line=line@entry=2159) at /test/10.6_opt/storage/innobase/ut/ut0dbg.cc:60
 
#3  0x0000555d50657ec6 in trx_start_if_not_started_low (trx=<optimized out>, read_write=<optimized out>) at /test/10.6_opt/storage/innobase/trx/trx0trx.cc:2159
 
#4  0x0000555d50d899f5 in row_search_mvcc (buf=buf@entry=0x14fe5c019258 "\377", mode=<optimized out>, mode@entry=PAGE_CUR_G, prebuilt=0x14fe5c028ff0, match_mode=match_mode@entry=0, direction=direction@entry=0) at /test/10.6_opt/storage/innobase/row/row0sel.cc:4620
 
#5  0x0000555d50cbd4f0 in ha_innobase::index_read (find_flag=HA_READ_AFTER_KEY, key_len=0, key_ptr=0x0, buf=0x14fe5c019258 "\377", this=0x14fe5c027110) at /test/10.6_opt/storage/innobase/handler/ha_innodb.cc:8606
 
#6  ha_innobase::index_first (buf=0x14fe5c019258 "\377", this=0x14fe5c027110) at /test/10.6_opt/storage/innobase/handler/ha_innodb.cc:8968
 
#7  ha_innobase::rnd_next (buf=0x14fe5c019258 "\377", this=0x14fe5c027110) at /test/10.6_opt/storage/innobase/handler/ha_innodb.cc:9061
 
#8  ha_innobase::rnd_next (this=0x14fe5c027110, buf=0x14fe5c019258 "\377") at /test/10.6_opt/storage/innobase/handler/ha_innodb.cc:9051
 
#9  0x0000555d5099b867 in handler::ha_rnd_next (this=this@entry=0x14fe5c027110, buf=buf@entry=0x14fe5c019258 "\377") at /test/10.6_opt/sql/handler.cc:3068
 
#10 0x0000555d50c07081 in ha_partition::rnd_next (this=0x14fe5c0268a0, buf=0x14fe5c019258 "\377") at /test/10.6_opt/sql/ha_partition.cc:5242
 
#11 0x0000555d5099b867 in handler::ha_rnd_next (this=0x14fe5c0268a0, buf=0x14fe5c019258 "\377") at /test/10.6_opt/sql/handler.cc:3068
 
#12 0x0000555d50746faa in mysql_ha_read (thd=thd@entry=0x14fe5c000c58, tables=tables@entry=0x14fe5c0109d8, mode=<optimized out>, keyname=0x0, key_expr=<optimized out>, ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.6_opt/sql/sql_handler.cc:908
 
#13 0x0000555d5078a702 in mysql_execute_command (thd=0x14fe5c000c58) at /test/10.6_opt/sql/sql_limit.h:85
 
#14 0x0000555d50779064 in mysql_parse (thd=0x14fe5c000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:8018
 
#15 0x0000555d507850a5 in dispatch_command (command=COM_QUERY, thd=0x14fe5c000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.6_opt/sql/sql_class.h:1332
 
#16 0x0000555d50787007 in do_command (thd=0x14fe5c000c58, blocking=blocking@entry=true) at /test/10.6_opt/sql/sql_parse.cc:1406
 
#17 0x0000555d50889ed7 in do_handle_one_connection (connect=<optimized out>, put_in_cache=true) at /test/10.6_opt/sql/sql_connect.cc:1410
 
#18 0x0000555d5088a23d in handle_one_connection (arg=arg@entry=0x555d52f23358) at /test/10.6_opt/sql/sql_connect.cc:1312
 
#19 0x0000555d50c0f418 in pfs_spawn_thread (arg=0x555d52e9b698) at /test/10.6_opt/storage/perfschema/pfs.cc:2201
 
#20 0x000014febdfa9609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#21 0x000014febdb98293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

10.6.1 9db14e93acc4ec9023d50686c66dbef7d4d8c15c (Debug)

 
mysqld: /test/10.6_dbg/storage/innobase/row/row0sel.cc:4571: dberr_t row_search_mvcc(byte*, page_cur_mode_t, row_prebuilt_t*, ulint, ulint): Assertion `!trx_is_started(trx) || trx->state == TRX_STATE_ACTIVE' failed.

10.6.1 9db14e93acc4ec9023d50686c66dbef7d4d8c15c (Debug)

 
Core was generated by `/test/MD270421-mariadb-10.6.1-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
[Current thread is 1 (Thread 0x14cb40081700 (LWP 2034537))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x000014cb48ce3859 in __GI_abort () at abort.c:79
 
#2  0x000014cb48ce3729 in __assert_fail_base (fmt=0x14cb48e79588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x557cbd93b270 "!trx_is_started(trx) || trx->state == TRX_STATE_ACTIVE", file=0x557cbd9398c0 "/test/10.6_dbg/storage/innobase/row/row0sel.cc", line=4571, function=<optimized out>) at assert.c:92
 
#3  0x000014cb48cf4f36 in __GI___assert_fail (assertion=assertion@entry=0x557cbd93b270 "!trx_is_started(trx) || trx->state == TRX_STATE_ACTIVE", file=file@entry=0x557cbd9398c0 "/test/10.6_dbg/storage/innobase/row/row0sel.cc", line=line@entry=4571, function=function@entry=0x557cbd93aff8 "dberr_t row_search_mvcc(byte*, page_cur_mode_t, row_prebuilt_t*, ulint, ulint)") at assert.c:101
 
#4  0x0000557cbd292d2e in row_search_mvcc (buf=buf@entry=0x14caf4028018 "\377", mode=<optimized out>, prebuilt=0x14caf4032de8, match_mode=0, direction=direction@entry=0) at /usr/include/c++/9/atomic:250
 
#5  0x0000557cbd0cc55f in ha_innobase::index_read (this=this@entry=0x14caf4028d60, buf=buf@entry=0x14caf4028018 "\377", key_ptr=key_ptr@entry=0x0, key_len=key_len@entry=0, find_flag=find_flag@entry=HA_READ_AFTER_KEY) at /test/10.6_dbg/storage/innobase/handler/ha_innodb.cc:8606
 
#6  0x0000557cbd0cc7e4 in ha_innobase::index_first (this=this@entry=0x14caf4028d60, buf=buf@entry=0x14caf4028018 "\377") at /test/10.6_dbg/storage/innobase/handler/ha_innodb.cc:8968
 
#7  0x0000557cbd0cc86d in ha_innobase::rnd_next (this=0x14caf4028d60, buf=0x14caf4028018 "\377") at /test/10.6_dbg/storage/innobase/handler/ha_innodb.cc:9061
 
#8  0x0000557cbcccee9f in handler::ha_rnd_next (this=this@entry=0x14caf4028d60, buf=buf@entry=0x14caf4028018 "\377") at /test/10.6_dbg/sql/handler.cc:3068
 
#9  0x0000557cbcfff3a7 in ha_partition::rnd_next (this=0x14caf4028470, buf=0x14caf4028018 "\377") at /test/10.6_dbg/sql/ha_partition.cc:5242
 
#10 0x0000557cbcccee9f in handler::ha_rnd_next (this=0x14caf4028470, buf=0x14caf4028018 "\377") at /test/10.6_dbg/sql/handler.cc:3068
 
#11 0x0000557cbc9aa598 in mysql_ha_read (thd=thd@entry=0x14caf4000db8, tables=tables@entry=0x14caf4014138, mode=<optimized out>, keyname=0x0, key_expr=<optimized out>, ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.6_dbg/sql/sql_handler.cc:908
 
#12 0x0000557cbca04789 in mysql_execute_command (thd=thd@entry=0x14caf4000db8) at /test/10.6_dbg/sql/sql_limit.h:85
 
#13 0x0000557cbc9ebf81 in mysql_parse (thd=thd@entry=0x14caf4000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14cb40080410) at /test/10.6_dbg/sql/sql_parse.cc:8018
 
#14 0x0000557cbc9fadb3 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14caf4000db8, packet=packet@entry=0x14caf400b789 "", packet_length=packet_length@entry=20, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:1332
 
#15 0x0000557cbc9fe1a6 in do_command (thd=0x14caf4000db8, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1406
 
#16 0x0000557cbcb58a6a in do_handle_one_connection (connect=<optimized out>, connect@entry=0x557cc080e978, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
 
#17 0x0000557cbcb5906f in handle_one_connection (arg=arg@entry=0x557cc080e978) at /test/10.6_dbg/sql/sql_connect.cc:1312
 
#18 0x0000557cbd00b2ca in pfs_spawn_thread (arg=0x557cc06f8298) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
 
#19 0x000014cb491f1609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#20 0x000014cb48de0293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.3.29 (opt), 10.4.19 (opt), 10.5.10 (opt), 10.6.1 (opt)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.38 (dbg), 10.2.38 (opt), 10.3.29 (dbg), 10.4.19 (dbg), 10.5.10 (dbg), 10.6.1 (dbg)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.34 (dbg), 5.7.34 (opt), 8.0.24 (dbg), 8.0.24 (opt)

This one does not affect 10.2 as:

10.2.38 (Debug)

 
10.2.38-dbg>HANDLER t OPEN t1;
 
ERROR 1031 (HY000): Storage engine partition of the table `test`.`t` doesn't have this option

Changing the first line of the testcase to CREATE TABLE t (c INT) ENGINE=InnoDB; gives the stack above.

Comment by Marko Mäkelä [ 2021-05-04 ]

The assertion expression looks valid to me. After XA PREPARE, the only allowed actions on the same connection are disconnect (see MDEV-742), XA COMMIT, XA ROLLBACK, or server shutdown. No statement that would access InnoDB tables is allowed. The HANDLER statement is violating this specification, and it should have been rejected in the SQL layer.

Comment by Roel Van de Paar [ 2021-05-04 ]

It would seem that this can lead to data corruption?

Comment by Roel Van de Paar [ 2021-09-17 ]

Affects 10.7 also with same stack.

10.7.0 d552e092c9f3e20da078d1b62b976f629f73d3a4 (Debug)

 
Core was generated by `/test/MD180921-mariadb-10.7.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
[Current thread is 1 (Thread 0x150a940c0700 (LWP 4340))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x0000150a97ea0859 in __GI_abort () at abort.c:79
 
#2  0x000055e80687785f in ut_dbg_assertion_failed (expr=expr@entry=0x0, file=file@entry=0x55e806edb7b0 "/test/10.7_dbg/storage/innobase/trx/trx0trx.cc", line=line@entry=2062) at /test/10.7_dbg/storage/innobase/ut/ut0dbg.cc:60
 
#3  0x000055e8068619e1 in trx_start_if_not_started_xa_low (trx=<optimized out>, read_write=read_write@entry=false) at /test/10.7_dbg/storage/innobase/trx/trx0trx.cc:2062
 
#4  0x000055e80661f075 in ha_innobase::init_table_handle_for_HANDLER (this=0x150a4c026f00) at /test/10.7_dbg/storage/innobase/handler/ha_innodb.cc:3590
 
#5  0x000055e805f3d1bd in mysql_ha_read (thd=thd@entry=0x150a4c000db8, tables=tables@entry=0x150a4c013db8, mode=RFIRST, keyname=0x0, key_expr=0xa5a5a5a5a5a5a5a5, ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.7_dbg/sql/sql_handler.cc:888
 
#6  0x000055e805f96f00 in mysql_execute_command (thd=thd@entry=0x150a4c000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.7_dbg/sql/sql_limit.h:85
 
#7  0x000055e805f7ed4b in mysql_parse (thd=thd@entry=0x150a4c000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x150a940bf400) at /test/10.7_dbg/sql/sql_parse.cc:8028
 
#8  0x000055e805f8d944 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x150a4c000db8, packet=packet@entry=0x150a4c00b729 "", packet_length=packet_length@entry=19, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_class.h:1358
 
#9  0x000055e805f90d4a in do_command (thd=0x150a4c000db8, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_parse.cc:1402
 
#10 0x000055e806106ed8 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55e80a03a3e8, put_in_cache=put_in_cache@entry=true) at /test/10.7_dbg/sql/sql_connect.cc:1418
 
#11 0x000055e8061074dd in handle_one_connection (arg=arg@entry=0x55e80a03a3e8) at /test/10.7_dbg/sql/sql_connect.cc:1312
 
#12 0x000055e80657047e in pfs_spawn_thread (arg=0x55e809f392c8) at /test/10.7_dbg/storage/perfschema/pfs.cc:2201
 
#13 0x0000150a983af609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#14 0x0000150a97f9d293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment by Nikita Malyavin [ 2021-10-07 ]

Right,
changing the last line as follows:

CREATE TABLE t (a INT KEY) ENGINE=InnoDB;
 
HANDLER t OPEN AS t;
 
XA START '0';
 
SELECT * FROM t;
 
XA END '0';
 
XA PREPARE '0';
 
SELECT * FROM t;

would lead to an error ER_XAER_RMFAIL.

Simply the check should be added: thd->transaction.xid_state.check_has_uncommitted_xa()

Comment by Nikita Malyavin [ 2021-10-07 ]

The patch for review is: https://github.com/MariaDB/server/commit/65e2c2859d4e3ff7e7a035df571996ceb8b95c92

Comment by Aleksey Midenkov [ 2021-10-11 ]

Ok to push.

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