[MDEV-29178] Assertion `sp > last_savepoint()' failed in federatedx_io_mysql::savepoint_set or crash upon shutdown Created: 2022-07-27  Updated: 2023-11-28

Status: Confirmed
Project: MariaDB Server
Component/s: Locking, Storage Engine - Federated
Affects Version/s: 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10, 10.11
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Oleksandr Byelkin
Resolution: Unresolved Votes: 0
Labels: ASAN, locking

Issue Links:
Duplicate
is duplicated by MDEV-12907 federated.federated_bug_585688 failed... Closed
Relates
relates to MDEV-29317 Assertion `sp && savepoint_next && *s... Open
relates to MDEV-30083 SIGSEGV's in federatedx_txn::sp_acqui... Open

 Description    

INSTALL SONAME 'ha_federatedx';
 
eval CREATE SERVER fedlink FOREIGN DATA WRAPPER mysql OPTIONS (USER 'root', HOST '127.0.0.1', DATABASE 'test', PORT $MASTER_MYPORT);
 
 
 
CREATE TABLE t (a INT);
 
CREATE TABLE t_fed ENGINE=FEDERATED CONNECTION='fedlink/t';
 
 
 
START TRANSACTION;
 
--error ER_BAD_FIELD_ERROR
 
UPDATE t_fed SET a = 1 WHERE b > 0;
 
 
 
--connect (con1,localhost,root,,test)
 
UPDATE t_fed SET a = 1;
 
 
 
# Cleanup
 
--disconnect con1
 
--connection default
 
DROP TABLE t_fed, t;
 
UNINSTALL SONAME 'ha_federatedx';

10.3 bd935a41

 
mysqld: /data/src/10.3/storage/federatedx/federatedx_io_mysql.cc:240: virtual int federatedx_io_mysql::savepoint_set(ulong): Assertion `sp > last_savepoint()' failed.
 
220727 16:00:11 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007f4b8cb48662 in __GI___assert_fail (assertion=0x7f4b86b1e0ce "sp > last_savepoint()", file=0x7f4b86b1df88 "/data/src/10.3/storage/federatedx/federatedx_io_mysql.cc", line=240, function=0x7f4b86b1e0e8 "virtual int federatedx_io_mysql::savepoint_set(ulong)") at assert.c:101
 
#8  0x00007f4b86b1a23e in federatedx_io_mysql::savepoint_set (this=0x7f4b740ac6b8, sp=1) at /data/src/10.3/storage/federatedx/federatedx_io_mysql.cc:240
 
#9  0x00007f4b86b18d20 in federatedx_txn::sp_acquire (this=0x7f4b680084d0, sp=0x7f4b680084e0) at /data/src/10.3/storage/federatedx/federatedx_txn.cc:301
 
#10 0x00007f4b86b19179 in federatedx_txn::stmt_begin (this=0x7f4b680084d0) at /data/src/10.3/storage/federatedx/federatedx_txn.cc:366
 
#11 0x00007f4b86b14dbc in ha_federatedx::external_lock (this=0x7f4b74037438, thd=0x7f4b68000d90, lock_type=1) at /data/src/10.3/storage/federatedx/ha_federatedx.cc:3504
 
#12 0x000055a6883cde11 in handler::ha_external_lock (this=0x7f4b74037438, thd=0x7f4b68000d90, lock_type=1) at /data/src/10.3/sql/handler.cc:6420
 
#13 0x000055a6884f7c55 in lock_external (thd=0x7f4b68000d90, tables=0x7f4b680123b0, count=1) at /data/src/10.3/sql/lock.cc:391
 
#14 0x000055a6884f7905 in mysql_lock_tables (thd=0x7f4b68000d90, sql_lock=0x7f4b68012380, flags=0) at /data/src/10.3/sql/lock.cc:336
 
#15 0x000055a6884f77c2 in mysql_lock_tables (thd=0x7f4b68000d90, tables=0x7f4b68012378, count=1, flags=0) at /data/src/10.3/sql/lock.cc:299
 
#16 0x000055a68800880a in lock_tables (thd=0x7f4b68000d90, tables=0x7f4b680119c0, count=1, flags=0) at /data/src/10.3/sql/sql_base.cc:5370
 
#17 0x000055a6881a20d2 in mysql_update (thd=0x7f4b68000d90, table_list=0x7f4b680119c0, fields=..., values=..., conds=0x0, order_num=0, order=0x0, limit=18446744073709551615, ignore=false, found_return=0x7f4b86afbef0, updated_return=0x7f4b86afbfb0) at /data/src/10.3/sql/sql_update.cc:372
 
#18 0x000055a68809c174 in mysql_execute_command (thd=0x7f4b68000d90) at /data/src/10.3/sql/sql_parse.cc:4344
 
#19 0x000055a6880a81aa in mysql_parse (thd=0x7f4b68000d90, rawbuf=0x7f4b680118f0 "UPDATE t_fed SET a = 1", length=22, parser_state=0x7f4b86afc5b0, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7871
 
#20 0x000055a6880949df in dispatch_command (command=COM_QUERY, thd=0x7f4b68000d90, packet=0x7f4b68023571 "UPDATE t_fed SET a = 1", packet_length=22, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1852
 
#21 0x000055a68809339d in do_command (thd=0x7f4b68000d90) at /data/src/10.3/sql/sql_parse.cc:1398
 
#22 0x000055a6882109e8 in do_handle_one_connection (connect=0x55a68a614250) at /data/src/10.3/sql/sql_connect.cc:1403
 
#23 0x000055a688210753 in handle_one_connection (arg=0x55a68a614250) at /data/src/10.3/sql/sql_connect.cc:1308
 
#24 0x000055a688bc0866 in pfs_spawn_thread (arg=0x55a68a6d4cf0) at /data/src/10.3/storage/perfschema/pfs.cc:1869
 
#25 0x00007f4b8cce1ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#26 0x00007f4b8cc11def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

A slightly different test case instead causes a crash/ASAN errors on shutdown:

INSTALL SONAME 'ha_federatedx';
 
 
 
eval CREATE SERVER fedlink FOREIGN DATA WRAPPER mysql OPTIONS (USER 'root', HOST '127.0.0.1', DATABASE 'test', PORT $MASTER_MYPORT);
 
CREATE TABLE t (a int);
 
CREATE TABLE t_fed ENGINE=FEDERATED CONNECTION='fedlink/t';
 
 
 
START TRANSACTION;
 
UPDATE t_fed SET a = 1;
 
 
 
--connect (con1,localhost,root,,test)
 
--error 0,ER_BAD_FIELD_ERROR
 
UPDATE t_fed SET x = 1;
 
 
 
--connection default
 
COMMIT;

10.3 bd935a41

 
==1950275==ERROR: AddressSanitizer: heap-use-after-free on address 0x62a00005b3f8 at pc 0x55ebce248a60 bp 0x7f25885b8970 sp 0x7f25885b8968
 
READ of size 8 at 0x62a00005b3f8 thread T8
 
    #0 0x55ebce248a5f in thd_increment_bytes_sent /data/src/10.3/sql/sql_class.cc:4345
 
    #1 0x55ebce10244e in net_real_write /data/src/10.3/sql/net_serv.cc:743
 
    #2 0x55ebce102bbf in net_flush /data/src/10.3/sql/net_serv.cc:384
 
    #3 0x55ebce10374a in net_write_command /data/src/10.3/sql/net_serv.cc:533
 
    #4 0x55ebce90cc43 in cli_advanced_command /data/src/10.3/sql-common/client.c:714
 
    #5 0x55ebce905d07 in mysql_close_slow_part /data/src/10.3/sql-common/client.c:3754
 
    #6 0x55ebce905d07 in mysql_close_slow_part /data/src/10.3/sql-common/client.c:3746
 
    #7 0x55ebce905d68 in mysql_close /data/src/10.3/sql-common/client.c:3766
 
    #8 0x55ebce905d68 in mysql_close /data/src/10.3/sql-common/client.c:3759
 
    #9 0x7f2588864084 in federatedx_io_mysql::~federatedx_io_mysql() /data/src/10.3/storage/federatedx/federatedx_io_mysql.cc:153
 
    #10 0x7f25888640c1 in federatedx_io_mysql::~federatedx_io_mysql() /data/src/10.3/storage/federatedx/federatedx_io_mysql.cc:157
 
    #11 0x7f2588861aa4 in federatedx_txn::close(st_fedrated_server*) /data/src/10.3/storage/federatedx/federatedx_txn.cc:86
 
    #12 0x7f258884b481 in free_server /data/src/10.3/storage/federatedx/ha_federatedx.cc:1677
 
    #13 0x7f258884baf3 in free_share /data/src/10.3/storage/federatedx/ha_federatedx.cc:1716
 
    #14 0x7f2588857977 in ha_federatedx::close() /data/src/10.3/storage/federatedx/ha_federatedx.cc:1846
 
    #15 0x55ebce5ca7d0 in closefrm(TABLE*) /data/src/10.3/sql/table.cc:3790
 
    #16 0x55ebce8405a7 in intern_close_table /data/src/10.3/sql/table_cache.cc:222
 
    #17 0x55ebce8405a7 in tc_purge(bool) /data/src/10.3/sql/table_cache.cc:335
 
    #18 0x55ebce1fdcfe in close_cached_tables(THD*, TABLE_LIST*, bool, unsigned long) /data/src/10.3/sql/sql_base.cc:377
 
    #19 0x55ebce0e28cb in clean_up /data/src/10.3/sql/mysqld.cc:2241
 
    #20 0x55ebce0e28cb in clean_up /data/src/10.3/sql/mysqld.cc:2208
 
    #21 0x55ebce0e784d in unireg_end() /data/src/10.3/sql/mysqld.cc:2116
 
    #22 0x55ebce0f07e6 in kill_server /data/src/10.3/sql/mysqld.cc:2043
 
    #23 0x55ebce0f250d in kill_server_thread /data/src/10.3/sql/mysqld.cc:2066
 
    #24 0x55ebcf8c34a4 in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
 
    #25 0x7f2593461ea6 in start_thread nptl/pthread_create.c:477
 
    #26 0x7f2593391dee in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xfddee)
 
 
 
0x62a00005b3f8 is located 4600 bytes inside of 23104-byte region [0x62a00005a200,0x62a00005fc40)
 
freed by thread T5 here:
 
    #0 0x7f2593d03b6f in __interceptor_free ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:123
 
    #1 0x55ebce0e8df8 in one_thread_per_connection_end(THD*, bool) /data/src/10.3/sql/mysqld.cc:3131
 
    #2 0x55ebce67c2b5 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1422
 
    #3 0x55ebce67cc7a in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
 
    #4 0x55ebcf8c34a4 in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
 
    #5 0x7f2593461ea6 in start_thread nptl/pthread_create.c:477
 
 
 
previously allocated by thread T5 here:
 
    #0 0x7f2593d03e8f in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:145
 
    #1 0x55ebcf994812 in my_malloc /data/src/10.3/mysys/my_malloc.c:101
 
    #2 0x55ebce67bb0e in ilink::operator new(unsigned long) /data/src/10.3/sql/sql_list.h:622
 
    #3 0x55ebce67bb0e in CONNECT::create_thd(THD*) /data/src/10.3/sql/sql_connect.cc:1507
 
    #4 0x55ebce67bf1e in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1346
 
    #5 0x55ebce67cc7a in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
 
    #6 0x55ebcf8c34a4 in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
 
    #7 0x7f2593461ea6 in start_thread nptl/pthread_create.c:477
 
 
 
Thread T8 created by T3 here:
 
    #0 0x7f2593caf2a2 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cpp:214
 
    #1 0x55ebcf8c7afa in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1919
 
    #2 0x55ebce0e4a6f in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1275
 
    #3 0x55ebce0e4a6f in signal_hand /data/src/10.3/sql/mysqld.cc:3620
 
    #4 0x55ebcf8c34a4 in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
 
    #5 0x7f2593461ea6 in start_thread nptl/pthread_create.c:477
 
 
 
Thread T3 created by T0 here:
 
    #0 0x7f2593caf2a2 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cpp:214
 
    #1 0x55ebcf8c7afa in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1919
 
    #2 0x55ebce0fcdff in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1275
 
    #3 0x55ebce0fcdff in start_signal_handler /data/src/10.3/sql/mysqld.cc:3516
 
    #4 0x55ebce0fcdff in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6127
 
    #5 0x7f25932bad09 in __libc_start_main ../csu/libc-start.c:308
 
 
 
Thread T5 created by T0 here:
 
    #0 0x7f2593caf2a2 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cpp:214
 
    #1 0x55ebcf8c7afa in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1919
 
    #2 0x55ebce0eaf2b in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1275
 
    #3 0x55ebce0eaf2b in create_thread_to_handle_connection(CONNECT*) /data/src/10.3/sql/mysqld.cc:6668
 
    #4 0x55ebce0fb23d in create_new_thread /data/src/10.3/sql/mysqld.cc:6738
 
    #5 0x55ebce0fb23d in handle_connections_sockets() /data/src/10.3/sql/mysqld.cc:6996
 
    #6 0x55ebce0fd1e5 in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6290
 
    #7 0x7f25932bad09 in __libc_start_main ../csu/libc-start.c:308
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.3/sql/sql_class.cc:4345 in thd_increment_bytes_sent
 
Shadow bytes around the buggy address:
 
  0x0c5480003620: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c5480003630: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c5480003640: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c5480003650: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c5480003660: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
=>0x0c5480003670: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd[fd]
 
  0x0c5480003680: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c5480003690: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c54800036a0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c54800036b0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c54800036c0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
Shadow byte legend (one shadow byte represents 8 application bytes):
 
  Addressable:           00
 
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
 
  Freed heap region:       fd
 
  Stack left redzone:      f1
 
  Stack mid redzone:       f2
 
  Stack right redzone:     f3
 
  Stack after return:      f5
 
  Stack use after scope:   f8
 
  Global redzone:          f9
 
  Global init order:       f6
 
  Poisoned by user:        f7
 
  Container overflow:      fc
 
  Array cookie:            ac
 
  Intra object redzone:    bb
 
  ASan internal:           fe
 
  Left alloca redzone:     ca
 
  Right alloca redzone:    cb
 
  Shadow gap:              cc
 
==1950275==ABORTING



 Comments   
Comment by Roel Van de Paar [ 2022-10-28 ]

Ran into the same

--source include/have_innodb.inc
 
--let $SOCKET= `SELECT @@global.socket`
 
INSTALL SONAME 'ha_federatedx.so';
 
CREATE USER federatedx@localhost IDENTIFIED BY '';
 
eval CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET "$SOCKET",DATABASE 'test',user 'federatedx',PASSWORD'');
 
CREATE TABLE t1 (c INT KEY,c2 BLOB,c3 TEXT) ENGINE=InnoDB;
 
CREATE TABLE t2 CONNECTION='srv/t1' ENGINE=FEDERATED;
 
START TRANSACTION;
 
--error 1054 
DELETE FROM t2 WHERE other=0;
 
--error 1050
 
CREATE TABLE t2 (d INT) ENGINE=FEDERATED;
 
INSERT INTO t2 VALUES (1);
 
 
 
# Cleanup
 
DROP TABLE t1,t2;
 
UNINSTALL SONAME 'ha_federatedx';

Or at the CLI

INSTALL SONAME 'ha_federatedx.so';
 
CREATE USER federatedx@localhost IDENTIFIED BY '';
 
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock',DATABASE 'test',user 'federatedx',PASSWORD'');  # Change socket location as needed
 
CREATE TABLE t1 (c INT KEY,c2 BLOB,c3 TEXT) ENGINE=InnoDB;
 
CREATE TABLE t2 CONNECTION='srv/t1' ENGINE=FEDERATED;
 
START TRANSACTION;
 
DELETE FROM t2 WHERE other=0;
 
CREATE TABLE t2 (d INT) ENGINE=FEDERATED;
 
INSERT INTO t2 VALUES (1);

Leads to:

10.11.1 50c5743adc87e1cdec1431a02558f6540fe5a6d5 (Debug)

 
mysqld: /test/10.11_dbg/storage/federatedx/federatedx_io_mysql.cc:240: virtual int federatedx_io_mysql::savepoint_set(ulong): Assertion `sp > last_savepoint()' failed.

10.11.1 50c5743adc87e1cdec1431a02558f6540fe5a6d5 (Debug)

 
Core was generated by `/test/MD221022-mariadb-10.11.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 0x14cbdc0ca700 (LWP 57709))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x000014cc0383c859 in __GI_abort () at abort.c:79
 
#2  0x000014cc0383c729 in __assert_fail_base (fmt=0x14cc039d2588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x14cbdc077585 "sp > last_savepoint()", file=0x14cbdc077658 "/test/10.11_dbg/storage/federatedx/federatedx_io_mysql.cc", line=240, function=<optimized out>) at assert.c:92
 
#3  0x000014cc0384dfd6 in __GI___assert_fail (assertion=assertion@entry=0x14cbdc077585 "sp > last_savepoint()", file=file@entry=0x14cbdc077658 "/test/10.11_dbg/storage/federatedx/federatedx_io_mysql.cc", line=line@entry=240, function=function@entry=0x14cbdc077698 "virtual int federatedx_io_mysql::savepoint_set(ulong)") at assert.c:101
 
#4  0x000014cbdc070118 in federatedx_io_mysql::savepoint_set (this=0x14cb380423d8, sp=1) at /test/10.11_dbg/storage/federatedx/federatedx_io_mysql.cc:240
 
#5  0x000014cbdc06f5c0 in federatedx_txn::sp_acquire (this=0x14cb3802e5e0, sp=<optimized out>) at /test/10.11_dbg/storage/federatedx/federatedx_txn.cc:312
 
#6  0x000014cbdc06f89a in federatedx_txn::stmt_begin (this=<optimized out>) at /test/10.11_dbg/storage/federatedx/federatedx_txn.cc:377
 
#7  0x000014cbdc06a7cc in ha_federatedx::external_lock (this=0x14cb3803e3a0, thd=0x14cb38000d48, lock_type=1) at /test/10.11_dbg/storage/federatedx/ha_federatedx.cc:3520
 
#8  0x000055714d806ce6 in handler::ha_external_lock (this=0x14cb3803e3a0, thd=thd@entry=0x14cb38000d48, lock_type=lock_type@entry=1) at /test/10.11_dbg/sql/handler.cc:7095
 
#9  0x000055714d9693a8 in lock_external (count=1, tables=0x14cb380149c0, thd=0x14cb38000d48) at /test/10.11_dbg/sql/lock.cc:396
 
#10 mysql_lock_tables (thd=thd@entry=0x14cb38000d48, sql_lock=sql_lock@entry=0x14cb38014990, flags=flags@entry=0) at /test/10.11_dbg/sql/lock.cc:341
 
#11 0x000055714d96a17b in mysql_lock_tables (thd=thd@entry=0x14cb38000d48, tables=tables@entry=0x14cb38014988, count=count@entry=1, flags=flags@entry=0) at /test/10.11_dbg/sql/lock.cc:304
 
#12 0x000055714d49aaf1 in lock_tables (thd=thd@entry=0x14cb38000d48, tables=0x14cb38013308, count=<optimized out>, flags=flags@entry=0) at /test/10.11_dbg/sql/sql_base.cc:5821
 
#13 0x000055714d49c892 in open_and_lock_tables (thd=thd@entry=0x14cb38000d48, options=<optimized out>, tables=<optimized out>, tables@entry=0x14cb38013308, derived=derived@entry=true, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x14cbdc0c8ad0) at /test/10.11_dbg/sql/sql_base.cc:5581
 
#14 0x000055714d4dd9f5 in open_and_lock_tables (flags=0, derived=true, tables=0x14cb38013308, thd=0x14cb38000d48) at /test/10.11_dbg/sql/sql_base.h:510
 
#15 mysql_insert (thd=thd@entry=0x14cb38000d48, table_list=0x14cb38013308, fields=@0x14cb38005e68: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55714eaa3ea0 <end_of_list>, last = 0x14cb38005e68, elements = 0}, <No data fields>}, values_list=@0x14cb38005eb0: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x14cb38013f40, last = 0x14cb38013f40, elements = 1}, <No data fields>}, update_fields=@0x14cb38005e98: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55714eaa3ea0 <end_of_list>, last = 0x14cb38005e98, elements = 0}, <No data fields>}, update_values=@0x14cb38005e80: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55714eaa3ea0 <end_of_list>, last = 0x14cb38005e80, elements = 0}, <No data fields>}, duplic=DUP_ERROR, ignore=false, result=0x0) at /test/10.11_dbg/sql/sql_insert.cc:758
 
#16 0x000055714d52051a in mysql_execute_command (thd=thd@entry=0x14cb38000d48, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_parse.cc:4563
 
#17 0x000055714d50cf90 in mysql_parse (thd=thd@entry=0x14cb38000d48, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14cbdc0c9300) at /test/10.11_dbg/sql/sql_parse.cc:8023
 
#18 0x000055714d51a4ac in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14cb38000d48, packet=packet@entry=0x14cb3800af09 "INSERT INTO t2 VALUES (1)", packet_length=packet_length@entry=25, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_class.h:1346
 
#19 0x000055714d51c8f4 in do_command (thd=0x14cb38000d48, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407
 
#20 0x000055714d679067 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55714fb70598, put_in_cache=put_in_cache@entry=true) at /test/10.11_dbg/sql/sql_connect.cc:1416
 
#21 0x000055714d679536 in handle_one_connection (arg=0x55714fb70598) at /test/10.11_dbg/sql/sql_connect.cc:1318
 
#22 0x000014cc03d4d609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#23 0x000014cc03939133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

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

Comment by Roel Van de Paar [ 2022-10-28 ]

This additional testcase (easy to convert to MTR, ref last comment) leads to a (very) slightly different stack (txn_begin instead of stmt_begin)

INSTALL SONAME 'ha_federatedx.so';
 
CREATE USER federatedx@localhost IDENTIFIED BY '';
 
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock',DATABASE 'test',user 'federatedx',PASSWORD'');
 
CREATE TABLE t2 (c INT KEY,c2 BLOB) ENGINE=InnoDB;
 
CREATE TABLE t CONNECTION='srv/t2' ENGINE=FEDERATED;
 
SET autocommit=OFF;
 
INSERT INTO t VALUES (1);
 
CREATE TABLE t (a INT KEY,b CHAR(1)) ENGINE=FEDERATED;
 
INSERT INTO t (c) VALUES (1);

Leads to:

10.11.1 50c5743adc87e1cdec1431a02558f6540fe5a6d5 (Debug)

 
mysqld: /test/10.11_dbg/storage/federatedx/federatedx_io_mysql.cc:240: virtual int federatedx_io_mysql::savepoint_set(ulong): Assertion `sp > last_savepoint()' failed.

10.11.1 50c5743adc87e1cdec1431a02558f6540fe5a6d5 (Debug)

 
Core was generated by `/test/MD221022-mariadb-10.11.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 0x15537c1f9700 (LWP 431821))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x00001553a19ab859 in __GI_abort () at abort.c:79
 
#2  0x00001553a19ab729 in __assert_fail_base (fmt=0x1553a1b41588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x155398026585 "sp > last_savepoint()", file=0x155398026658 "/test/10.11_dbg/storage/federatedx/federatedx_io_mysql.cc", line=240, function=<optimized out>) at assert.c:92
 
#3  0x00001553a19bcfd6 in __GI___assert_fail (assertion=assertion@entry=0x155398026585 "sp > last_savepoint()", file=file@entry=0x155398026658 "/test/10.11_dbg/storage/federatedx/federatedx_io_mysql.cc", line=line@entry=240, function=function@entry=0x155398026698 "virtual int federatedx_io_mysql::savepoint_set(ulong)") at assert.c:101
 
#4  0x000015539801f118 in federatedx_io_mysql::savepoint_set (this=0x15530c043608, sp=1) at /test/10.11_dbg/storage/federatedx/federatedx_io_mysql.cc:240
 
#5  0x000015539801e5c0 in federatedx_txn::sp_acquire (this=0x15530c028e20, sp=sp@entry=0x15537c1f7728) at /test/10.11_dbg/storage/federatedx/federatedx_txn.cc:312
 
#6  0x000015539801e684 in federatedx_txn::txn_begin (this=<optimized out>) at /test/10.11_dbg/storage/federatedx/federatedx_txn.cc:228
 
#7  0x0000155398019815 in ha_federatedx::external_lock (this=0x15530c0409f0, thd=0x15530c000d48, lock_type=1) at /test/10.11_dbg/storage/federatedx/ha_federatedx.cc:3525
 
#8  0x000056446a7b1ce6 in handler::ha_external_lock (this=0x15530c0409f0, thd=thd@entry=0x15530c000d48, lock_type=lock_type@entry=1) at /test/10.11_dbg/sql/handler.cc:7095
 
#9  0x000056446a9143a8 in lock_external (count=1, tables=0x15530c014af8, thd=0x15530c000d48) at /test/10.11_dbg/sql/lock.cc:396
 
#10 mysql_lock_tables (thd=thd@entry=0x15530c000d48, sql_lock=sql_lock@entry=0x15530c014ac8, flags=flags@entry=0) at /test/10.11_dbg/sql/lock.cc:341
 
#11 0x000056446a91517b in mysql_lock_tables (thd=thd@entry=0x15530c000d48, tables=tables@entry=0x15530c014ac0, count=count@entry=1, flags=flags@entry=0) at /test/10.11_dbg/sql/lock.cc:304
 
#12 0x000056446a445af1 in lock_tables (thd=thd@entry=0x15530c000d48, tables=0x15530c013310, count=<optimized out>, flags=flags@entry=0) at /test/10.11_dbg/sql/sql_base.cc:5821
 
#13 0x000056446a447892 in open_and_lock_tables (thd=thd@entry=0x15530c000d48, options=<optimized out>, tables=<optimized out>, tables@entry=0x15530c013310, derived=derived@entry=true, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x15537c1f7ad0) at /test/10.11_dbg/sql/sql_base.cc:5581
 
#14 0x000056446a4889f5 in open_and_lock_tables (flags=0, derived=true, tables=0x15530c013310, thd=0x15530c000d48) at /test/10.11_dbg/sql/sql_base.h:510
 
#15 mysql_insert (thd=thd@entry=0x15530c000d48, table_list=0x15530c013310, fields=@0x15530c005e68: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x15530c013b48, last = 0x15530c013b48, elements = 1}, <No data fields>}, values_list=@0x15530c005eb0: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x15530c014078, last = 0x15530c014078, elements = 1}, <No data fields>}, update_fields=@0x15530c005e98: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x56446ba4eea0 <end_of_list>, last = 0x15530c005e98, elements = 0}, <No data fields>}, update_values=@0x15530c005e80: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x56446ba4eea0 <end_of_list>, last = 0x15530c005e80, elements = 0}, <No data fields>}, duplic=DUP_ERROR, ignore=false, result=0x0) at /test/10.11_dbg/sql/sql_insert.cc:758
 
#16 0x000056446a4cb51a in mysql_execute_command (thd=thd@entry=0x15530c000d48, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_parse.cc:4563
 
#17 0x000056446a4b7f90 in mysql_parse (thd=thd@entry=0x15530c000d48, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x15537c1f8300) at /test/10.11_dbg/sql/sql_parse.cc:8023
 
#18 0x000056446a4c54ac in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x15530c000d48, packet=packet@entry=0x15530c00af09 "INSERT INTO t (c) VALUES (1)", packet_length=packet_length@entry=28, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_class.h:1346
 
#19 0x000056446a4c78f4 in do_command (thd=0x15530c000d48, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407
 
#20 0x000056446a624067 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x56446c6c5f28, put_in_cache=put_in_cache@entry=true) at /test/10.11_dbg/sql/sql_connect.cc:1416
 
#21 0x000056446a624536 in handle_one_connection (arg=0x56446c6c5f28) at /test/10.11_dbg/sql/sql_connect.cc:1318
 
#22 0x00001553a1ebc609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#23 0x00001553a1aa8133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment by Alice Sherepa [ 2023-08-09 ]

I guess this is related:

mysqld: /10.4/storage/federatedx/ha_federatedx.cc:1689: int free_server(federatedx_txn*, FEDERATEDX_SERVER*): Assertion `server->io_count == 0' failed.
 
230809 15:29:45 [ERROR] mysqld got signal 6 ;
 
 
 
Server version: 10.4.31-MariaDB-debug-log source revision: 161ce045a71e306768d4609bdc35788fa5ea2a71
 
 
 
linux/raise.c:51(__GI_raise)[0x7f4388c7b8eb]
 
stdlib/abort.c:81(__GI_abort)[0x7f4388c66535]
 
intl/loadmsgcat.c:1177(_nl_load_domain)[0x7f4388c6640f]
 
/lib/x86_64-linux-gnu/libc.so.6(+0x301a2)[0x7f4388c741a2]
 
federatedx/ha_federatedx.cc:1691(free_server(federatedx_txn*, st_fedrated_server*))[0x7f43882a78cb]
 
federatedx/ha_federatedx.cc:1729(free_share(federatedx_txn*, st_federatedx_share*))[0x7f43882a7aff]
 
federatedx/ha_federatedx.cc:1857(ha_federatedx::close())[0x7f43882a8137]
 
sql/handler.cc:2891(handler::ha_close())[0x55fbb194f7e8]
 
sql/table.cc:4248(closefrm(TABLE*))[0x55fbb174243a]
 
sql/table_cache.cc:222(intern_close_table(TABLE*))[0x55fbb1870b35]
 
sql/table_cache.cc:333(tc_purge(bool))[0x55fbb1870f92]
 
sql/backup.cc:210(backup_flush(THD*))[0x55fbb187c394]
 
sql/backup.cc:113(run_backup_stage(THD*, backup_stages))[0x55fbb187c012]
 
sql/sql_parse.cc:5150(mysql_execute_command(THD*))[0x55fbb160dfa3]
 
sql/sql_parse.cc:8010(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x55fbb16176e0]
 
sql/sql_parse.cc:1860(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x55fbb1603a11]
 
sql/sql_parse.cc:1378(do_command(THD*))[0x55fbb160220e]
 
sql/sql_connect.cc:1420(do_handle_one_connection(CONNECT*))[0x55fbb1797061]
 
sql/sql_connect.cc:1325(handle_one_connection)[0x55fbb1796db0]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7fa3)[0x7f4389133fa3]
 
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f4388d3d06f]

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