[MDEV-29606] Assertion `transaction->implicit_xid.is_null()' failed in THD::init_for_queries and Assertion `transaction.is_empty()' failed in prepare_new_connection_state Created: 2022-09-22  Updated: 2023-12-18

Status: Confirmed
Project: MariaDB Server
Component/s: Data Manipulation - Insert, Storage Engine - Spider
Affects Version/s: 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10, 10.11, 11.0, 11.1, 11.2, 11.3, 11.4
Fix Version/s: 10.4, 10.5, 10.6, 10.11, 11.0, 11.1, 11.2, 11.3

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Yuchen Pei
Resolution: Unresolved Votes: 0
Labels: stack-smashing

Issue Links:
Relates
relates to MDEV-29583 Disallow Spider self/dual/multi/cross... Closed
relates to MDEV-30580 Investigate whether self-/multi- refe... Open

 Description    

INSTALL PLUGIN Spider SONAME 'ha_spider.so';
 
CREATE USER Spider@localhost IDENTIFIED BY 'PWD1';
 
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock',DATABASE 'test',user 'Spider',PASSWORD 'PWD1');
 
SET GLOBAL log_output="TABLE";
 
CREATE OR REPLACE TABLE mysql.general_log (a INT) ENGINE=Spider COMMENT='WRAPPER "mysql",srv "srv",TABLE "t"';
 
CREATE TABLE t1 (c INT) ENGINE=Spider COMMENT='WRAPPER "mysql",srv "srv",TABLE "t"' PARTITION BY HASH (c) PARTITIONS 1;
 
XA START 'a';
 
SET GLOBAL general_log=1;
 
INSERT DELAYED INTO t1 (pk) VALUES (1);

Leads to:

10.11.0 6ebdd3013a18b01dbecec76b870810329eb76586 (Debug)

 
mysqld: /test/10.11_dbg/sql/sql_class.cc:1392: void THD::init_for_queries(): Assertion `transaction->implicit_xid.is_null()' failed.

10.11.0 6ebdd3013a18b01dbecec76b870810329eb76586 (Debug)

 
Core was generated by `/test/MD190922-mariadb-10.11.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 0x14f0a00a4700 (LWP 2638039))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x000014f0b9ea8859 in __GI_abort () at abort.c:79
 
#2  0x000014f0b9ea8729 in __assert_fail_base (fmt=0x14f0ba03e588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5556eaf2f278 "transaction->implicit_xid.is_null()", file=0x5556eaf2f050 "/test/10.11_dbg/sql/sql_class.cc", line=1392, function=<optimized out>) at assert.c:92
 
#3  0x000014f0b9eb9fd6 in __GI___assert_fail (assertion=assertion@entry=0x5556eaf2f278 "transaction->implicit_xid.is_null()", file=file@entry=0x5556eaf2f050 "/test/10.11_dbg/sql/sql_class.cc", line=line@entry=1392, function=function@entry=0x5556eaf30f51 "void THD::init_for_queries()") at assert.c:101
 
#4  0x00005556ea2dabac in THD::init_for_queries (this=this@entry=0x14f018000d48) at /test/10.11_dbg/sql/handler.h:926
 
#5  0x00005556ea4b17f5 in prepare_new_connection_state (thd=thd@entry=0x14f018000d48) at /test/10.11_dbg/sql/sql_connect.cc:1246
 
#6  0x00005556ea4b1b14 in thd_prepare_connection (thd=0x14f018000d48) at /test/10.11_dbg/sql/sql_connect.cc:1339
 
#7  0x00005556ea4b2150 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5556ede5e968, put_in_cache=put_in_cache@entry=true) at /test/10.11_dbg/sql/sql_connect.cc:1406
 
#8  0x00005556ea4b24c3 in handle_one_connection (arg=0x5556ede5e968) at /test/10.11_dbg/sql/sql_connect.cc:1318
 
#9  0x000014f0ba3b9609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#10 0x000014f0b9fa5133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

10.4.27 3e3cfa893481abe9524a1657c4246fa9f91d4826 (Debug)

 
mysqld: /test/10.4_dbg/sql/sql_class.cc:1380: void THD::init_for_queries(): Assertion `transaction.is_empty()' failed.

10.4.27 3e3cfa893481abe9524a1657c4246fa9f91d4826 (Debug)

 
Core was generated by `/test/MD190922-mariadb-10.4.27-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 0x151e88981700 (LWP 2173755))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x0000151eca1df859 in __GI_abort () at abort.c:79
 
#2  0x0000151eca1df729 in __assert_fail_base (fmt=0x151eca375588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5641009e3b4e "transaction.is_empty()", file=0x5641009e1ef8 "/test/10.4_dbg/sql/sql_class.cc", line=1380, function=<optimized out>) at assert.c:92
 
#3  0x0000151eca1f0fd6 in __GI___assert_fail (assertion=assertion@entry=0x5641009e3b4e "transaction.is_empty()", file=file@entry=0x5641009e1ef8 "/test/10.4_dbg/sql/sql_class.cc", line=line@entry=1380, function=function@entry=0x5641009e3b65 "void THD::init_for_queries()") at assert.c:101
 
#4  0x00005640ffd75967 in THD::init_for_queries (this=this@entry=0x151e00000d28) at /test/10.4_dbg/sql/handler.h:1712
 
#5  0x00005640fff0623e in prepare_new_connection_state (thd=thd@entry=0x151e00000d28) at /test/10.4_dbg/sql/sql_connect.cc:1255
 
#6  0x00005640fff06558 in thd_prepare_connection (thd=0x151e00000d28) at /test/10.4_dbg/sql/sql_connect.cc:1339
 
#7  0x00005640fff06ad0 in do_handle_one_connection (connect=<optimized out>) at /test/10.4_dbg/sql/sql_connect.cc:1410
 
#8  0x00005640fff06b05 in handle_one_connection (arg=<optimized out>) at /test/10.4_dbg/sql/sql_connect.cc:1324
 
#9  0x0000151eca6f0609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#10 0x0000151eca2dc133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.4.27 (dbg), 10.5.18 (dbg), 10.6.10 (dbg), 10.7.6 (dbg), 10.8.5 (dbg), 10.9.3 (dbg), 10.10.2 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.4.27 (opt), 10.5.18 (opt), 10.6.10 (opt), 10.7.6 (opt), 10.8.5 (opt), 10.9.3 (opt), 10.10.2 (opt), 10.11.0 (dbg), 10.11.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.38 (dbg), 5.7.38 (opt), 8.0.29 (dbg), 8.0.29 (opt)

 Comments   
Comment by Roel Van de Paar [ 2023-01-13 ]

Additional testcase

CREATE OR REPLACE TABLE mysql.general_log (c INT) ENGINE=InnoDB;
 
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock',DATABASE'',USER 'Spider',PASSWORD '');
 
INSTALL PLUGIN Spider SONAME 'ha_spider.so';
 
CREATE TABLE t (d INT) ENGINE=Spider COMMENT='WRAPPER "mysql",srv "srv",TABLE "t"';
 
SET SESSION sql_log_off=1;
 
CREATE USER Spider@localhost IDENTIFIED BY '';
 
SET GLOBAL general_log=1,log_output='TABLE';
 
INSERT INTO t VALUES (1);

Which may (besides the crash) also produce this ERROR:

11.0.1 b075191ba8598af6aff5549e6e19f6255aef258a (Debug)

 
...
 
2023-01-13 16:38:20 25 [Note] Event Scheduler: scheduler thread started with id 25
 
2023-01-13 16:38:20 26 [ERROR] Failed to write to mysql.general_log:
 
mysqld: /test/11.0_dbg/sql/sql_class.cc:1393: void THD::init_for_queries(): Assertion `transaction->implicit_xid.is_null()' failed.

Additionally, removing only OR REPLACE or log_output='TABLE' will render a different outcome:

11.0.1 b075191ba8598af6aff5549e6e19f6255aef258a (Debug)

 
11.0.1-dbg>SET GLOBAL general_log=1;
 
Query OK, 0 rows affected (0.000 sec)
 
 
 
11.0.1-dbg>INSERT INTO t VALUES (1);
 
ERROR 12719 (HY000): An infinite loop is detected when opening table test.t

Comment by Roel Van de Paar [ 2023-12-18 ]

Observed stack corruption:

11.4.0 57618265ad914824ce78108729829df13c75e224 (Debug)

 
mariadbd: /test/bb-11.4-MDEV-7850_dbg/sql/sql_class.cc:1397: void THD::init_for_queries(): Assertion `transaction->implicit_xid.is_null()' failed.

11.4.0 57618265ad914824ce78108729829df13c75e224 (Debug)

 
Core was generated by `/test/MDEV-7850_MD161223-mariadb-11.4.0-linux-x86_64-dbg/bin/mariadbd --no-defa'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  0x00001507b00969fc in ?? ()
 
[Current thread is 1 (LWP 1436590)]
 
(gdb) bt
 
#0  0x00001507b00969fc in ?? ()
 
Backtrace stopped: Cannot access memory at address 0x1507af8fc6b0

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