Core was generated by `/test/MD140222-mariadb-10.9.0-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 0x14bc3c125700 (LWP 4096750))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x000014bc5b1a5859 in __GI_abort () at abort.c:79
#2 0x000014bc5b1a5729 in __assert_fail_base (fmt=0x14bc5b33b588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x14bc5b6c362d "mutex->__data.__owner == 0", file=0x14bc5b6c35fa "../nptl/pthread_mutex_lock.c", line=81, function=<optimized out>) at assert.c:92
#3 0x000014bc5b1b6f36 in __GI___assert_fail (assertion=assertion@entry=0x14bc5b6c362d "mutex->__data.__owner == 0", file=file@entry=0x14bc5b6c35fa "../nptl/pthread_mutex_lock.c", line=line@entry=81, function=function@entry=0x14bc5b6c3790 <__PRETTY_FUNCTION__.10174> "__pthread_mutex_lock") at assert.c:101
#4 0x000014bc5b6b7164 in __GI___pthread_mutex_lock (mutex=mutex@entry=0x14bb7c05f5d0) at ../nptl/pthread_mutex_lock.c:81
#5 0x000055da414f4ccf in psi_mutex_lock (that=that@entry=0x14bb7c05f5d0, file=file@entry=0x14bc341ab2a0 "/test/10.9_opt/storage/spider/spd_db_conn.cc", line=line@entry=10616) at /test/10.9_opt/mysys/my_thr_init.c:489
#6 0x000014bc340ffa21 in inline_mysql_mutex_lock (src_file=0x14bc341ab2a0 "/test/10.9_opt/storage/spider/spd_db_conn.cc", src_line=10616, that=0x14bb7c05f5d0) at /test/10.9_opt/include/mysql/psi/mysql_thread.h:746
#7 spider_db_open_handler (spider=spider@entry=0x14bb7c023810, conn=0x14bb7c05f578, link_idx=link_idx@entry=0) at /test/10.9_opt/storage/spider/spd_db_conn.cc:10616
#8 0x000014bc3416a228 in ha_spider::rnd_handler_init (this=0x14bb7c023810) at /test/10.9_opt/storage/spider/ha_spider.cc:10732
#9 ha_spider::rnd_handler_init (this=0x14bb7c023810) at /test/10.9_opt/storage/spider/ha_spider.cc:10700
#10 0x000014bc34170e27 in ha_spider::rnd_next_internal (this=0x14bb7c023810, buf=0x14bb7c0233f8 "\377") at /test/10.9_opt/storage/spider/ha_spider.cc:5947
#11 0x000055da4188a777 in handler::ha_rnd_next (this=0x14bb7c023810, buf=0x14bb7c0233f8 "\377") at /test/10.9_opt/sql/handler.cc:3393
#12 0x000055da415f8959 in mysql_ha_read (thd=thd@entry=0x14bb7c000c58, tables=tables@entry=0x14bb7c010a08, 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.9_opt/sql/sql_handler.cc:923
#13 0x000055da4163f8d6 in mysql_execute_command (thd=0x14bb7c000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.9_opt/sql/sql_limit.h:87
#14 0x000055da4162d086 in mysql_parse (thd=0x14bb7c000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.9_opt/sql/sql_parse.cc:8027
#15 0x000055da41639235 in dispatch_command (command=COM_QUERY, thd=0x14bb7c000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.9_opt/sql/sql_class.h:1362
#16 0x000055da4163b427 in do_command (thd=0x14bb7c000c58, blocking=blocking@entry=true) at /test/10.9_opt/sql/sql_parse.cc:1402
#17 0x000055da4175ad77 in do_handle_one_connection (connect=<optimized out>, put_in_cache=true) at /test/10.9_opt/sql/sql_connect.cc:1418
#18 0x000055da4175b0bd in handle_one_connection (arg=arg@entry=0x55da450b0888) at /test/10.9_opt/sql/sql_connect.cc:1312
#19 0x000055da41ad47b1 in pfs_spawn_thread (arg=0x55da450459a8) at /test/10.9_opt/storage/perfschema/pfs.cc:2201
#20 0x000014bc5b6b4609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#21 0x000014bc5b2a2293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
at /test/10.9_dbg/storage/spider/spd_db_conn.cc:10613
[Current thread is 1 (Thread 0x1535fc167700 (LWP 3916172))]
(gdb) bt
#0 0x00001535cfedf107 in spider_db_open_handler (spider=spider@entry=0x1535b407c920, conn=0x1535b408d8d8, link_idx=link_idx@entry=0) at /test/10.9_dbg/storage/spider/spd_db_conn.cc:10613
#1 0x00001535cff40096 in ha_spider::rnd_handler_init (this=this@entry=0x1535b407c920) at /test/10.9_dbg/storage/spider/ha_spider.cc:10732
#2 0x00001535cff4a615 in ha_spider::rnd_next_internal (this=this@entry=0x1535b407c920, buf=buf@entry=0x1535b4030878 "\377") at /test/10.9_dbg/storage/spider/ha_spider.cc:5947
#3 0x00001535cff4b80e in ha_spider::rnd_next (this=0x1535b407c920, buf=0x1535b4030878 "\377") at /test/10.9_dbg/storage/spider/ha_spider.cc:6310
#4 0x0000561e51b2b041 in handler::ha_rnd_next (this=0x1535b407c920, buf=0x1535b4030878 "\377") at /test/10.9_dbg/sql/handler.cc:3393
#5 0x0000561e517c8788 in mysql_ha_read (thd=thd@entry=0x1535b4000db8, tables=tables@entry=0x1535b4013f28, 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.9_dbg/sql/sql_handler.cc:923
#6 0x0000561e518226d5 in mysql_execute_command (thd=thd@entry=0x1535b4000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.9_dbg/sql/sql_limit.h:87
#7 0x0000561e5180a315 in mysql_parse (thd=thd@entry=0x1535b4000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1535fc166400) at /test/10.9_dbg/sql/sql_parse.cc:8027
#8 0x0000561e51818fb1 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1535b4000db8, packet=packet@entry=0x1535b400b889 "", packet_length=packet_length@entry=19, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_class.h:1362
#9 0x0000561e5181c3f8 in do_command (thd=0x1535b4000db8, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_parse.cc:1402
#10 0x0000561e51996fc4 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x561e5509a888, put_in_cache=put_in_cache@entry=true) at /test/10.9_dbg/sql/sql_connect.cc:1418
#11 0x0000561e519975c9 in handle_one_connection (arg=arg@entry=0x561e5509a888) at /test/10.9_dbg/sql/sql_connect.cc:1312
#12 0x0000561e51e1dd67 in pfs_spawn_thread (arg=0x561e54fadc78) at /test/10.9_dbg/storage/perfschema/pfs.cc:2201
#13 0x000015361cf12609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#14 0x000015361cb00293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Core was generated by `/test/MD290122-mariadb-10.4.23-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x0000147678056456 in spider_check_and_set_trx_isolation (
conn=0x1476300611c8, need_mon=0x14763005fb68)
at /test/10.4_opt/storage/spider/spd_trx.cc:1593
[Current thread is 1 (Thread 0x147684058700 (LWP 3970406))]
(gdb) bt
#0 0x0000147678056456 in spider_check_and_set_trx_isolation (conn=0x1476300611c8, need_mon=0x14763005fb68) at /test/10.4_opt/storage/spider/spd_trx.cc:1593
#1 0x00001476780b900c in ha_spider::external_lock (this=0x147630058830, thd=0x147630000c48, lock_type=0) at /test/10.4_opt/storage/spider/ha_spider.cc:1370
#2 0x000055c8a7161a8d in handler::ha_external_lock (this=0x147630058830, thd=thd@entry=0x147630000c48, lock_type=lock_type@entry=0) at /test/10.4_opt/sql/handler.cc:6506
#3 0x000055c8a725d2d9 in lock_external (count=<optimized out>, tables=0x147630061d98, thd=0x147630000c48) at /test/10.4_opt/sql/lock.cc:393
#4 mysql_lock_tables (thd=thd@entry=0x147630000c48, sql_lock=0x147630061d68, flags=<optimized out>) at /test/10.4_opt/sql/lock.cc:338
#5 0x000055c8a6f0e6d6 in mysql_ha_read (thd=thd@entry=0x147630000c48, tables=tables@entry=0x147630010150, mode=RNEXT, 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.4_opt/sql/sql_handler.cc:819
#6 0x000055c8a6f4b081 in mysql_execute_command (thd=0x147630000c48) at /test/10.4_opt/sql/sql_parse.cc:5676
#7 0x000055c8a6f500b7 in mysql_parse (thd=0x147630000c48, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_parse.cc:7995
#8 0x000055c8a6f5272d in dispatch_command (command=COM_QUERY, thd=0x147630000c48, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_class.h:1201
#9 0x000055c8a6f54d9e in do_command (thd=0x147630000c48) at /test/10.4_opt/sql/sql_parse.cc:1373
#10 0x000055c8a704abbe in do_handle_one_connection (connect=connect@entry=0x55c8a93a0c08) at /test/10.4_opt/sql/sql_connect.cc:1420
#11 0x000055c8a704acef in handle_one_connection (arg=0x55c8a93a0c08) at /test/10.4_opt/sql/sql_connect.cc:1316
#12 0x000014768db38609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#13 0x000014768d726293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Core was generated by `/test/MD290122-mariadb-10.5.14-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 0x1527b4958700 (LWP 3916429))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00001527beda4859 in __GI_abort () at abort.c:79
#2 0x00001527beda4729 in __assert_fail_base (fmt=0x1527bef3a588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x1527bf2c262d "mutex->__data.__owner == 0", file=0x1527bf2c25fa "../nptl/pthread_mutex_lock.c", line=81, function=<optimized out>) at assert.c:92
#3 0x00001527bedb5f36 in __GI___assert_fail (assertion=assertion@entry=0x1527bf2c262d "mutex->__data.__owner == 0", file=file@entry=0x1527bf2c25fa "../nptl/pthread_mutex_lock.c", line=line@entry=81, function=function@entry=0x1527bf2c2790 <__PRETTY_FUNCTION__.10174> "__pthread_mutex_lock") at assert.c:101
#4 0x00001527bf2b6164 in __GI___pthread_mutex_lock (mutex=mutex@entry=0x15271c05c900) at ../nptl/pthread_mutex_lock.c:81
#5 0x00001527b41230d2 in inline_mysql_mutex_lock (src_file=0x1527b41b12a0 "/test/10.5_opt/storage/spider/spd_db_conn.cc", src_line=12442, that=<optimized out>) at /test/10.5_opt/include/mysql/psi/mysql_thread.h:752
#6 spider_db_open_handler (spider=spider@entry=0x15271c028f80, conn=0x15271c05c8a8, link_idx=link_idx@entry=0) at /test/10.5_opt/storage/spider/spd_db_conn.cc:12442
#7 0x00001527b4165728 in ha_spider::rnd_handler_init (this=0x15271c028f80) at /test/10.5_opt/storage/spider/ha_spider.cc:13654
#8 ha_spider::rnd_handler_init (this=0x15271c028f80) at /test/10.5_opt/storage/spider/ha_spider.cc:13620
#9 0x00001527b416c9a7 in ha_spider::rnd_next_internal (this=0x15271c028f80, buf=0x15271c024618 "\377") at /test/10.5_opt/storage/spider/ha_spider.cc:7448
#10 0x000055a4bc199fd7 in handler::ha_rnd_next (this=0x15271c028f80, buf=0x15271c024618 "\377") at /test/10.5_opt/sql/handler.cc:3080
#11 0x000055a4bbf3b897 in mysql_ha_read (thd=thd@entry=0x15271c000c58, tables=tables@entry=0x15271c010568, 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.5_opt/sql/sql_handler.cc:911
#12 0x000055a4bbf80cf1 in mysql_execute_command (thd=0x15271c000c58) at /test/10.5_opt/sql/sql_limit.h:71
#13 0x000055a4bbf6ebf3 in mysql_parse (thd=0x15271c000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.5_opt/sql/sql_parse.cc:8100
#14 0x000055a4bbf7ba0d in dispatch_command (command=COM_QUERY, thd=0x15271c000c58, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.5_opt/sql/sql_class.h:1290
#15 0x000055a4bbf7e1e2 in do_command (thd=0x15271c000c58) at /test/10.5_opt/sql/sql_parse.cc:1370
#16 0x000055a4bc085d41 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55a4bfe3f158, put_in_cache=put_in_cache@entry=true) at /test/10.5_opt/sql/sql_connect.cc:1418
#17 0x000055a4bc0861bd in handle_one_connection (arg=arg@entry=0x55a4bfe3f158) at /test/10.5_opt/sql/sql_connect.cc:1312
#18 0x000055a4bc41aec2 in pfs_spawn_thread (arg=0x55a4bfdad558) at /test/10.5_opt/storage/perfschema/pfs.cc:2201
#19 0x00001527bf2b3609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#20 0x00001527beea1293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
MDEV-29002ASAN errors in spider_conn_queue_and_merge_loop_check
Closed
MDEV-29962SIGSEGV in ha_spider::lock_tables on BEGIN after table lock
Closed
MDEV-31996Segfault when setting spider_delete_all_rows to 0 and delete all rows of a spider table, ASAN heap-use-after-free in spider_db_delete_all_rows
Closed
MDEV-32492SIGSEGV in spider_conn_first_link_idx and others on DELETE, INSERT and SELECT
Closed
MDEV-34849SIGSEGV in server_mysql_real_connect, spider_db_connect, __strcmp_evex and __strnlen_evex, ASAN heap-use-after-free in spider_db_connect on INSERT
Closed
split to
MDEV-34555SIGSEGV in spider_conn_queue_and_merge_loop_check, and ASAN: heap-use-after-free in spider_conn_reset_queue_loop_check
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_handler.cc:727
#7 0x0000563c1d09692d in mysql_execute_command (thd=0x7f4050009790) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:5331
is_com_multi=false, is_next_command=false) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:1827
#10 0x0000563c1d08a8e0 in do_command (thd=0x7f4050009790) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:1381
#11 0x0000563c1d1e707e in do_handle_one_connection (connect=0x563c20310090) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_connect.cc:1336
#12 0x0000563c1d1e6de6 in handle_one_connection (arg=0x563c20310090) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_connect.cc:1241
#13 0x00007f405e209450 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#14 0x00007f405dda9d53 in clone () from /lib/x86_64-linux-gnu/libc.so.6
(rr) up
#1 0x00007f402af15e3e in spider_check_and_set_trx_isolation (conn=0x7f40500a5280, need_mon=0x7f40500a4200)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_trx.cc:1544
1544 trx_isolation = thd_tx_isolation(conn->thd);
(rr) watch -l conn->thd
Hardware watchpoint 1: -location conn->thd
(rr) rc
Continuing.
Thread 2 received signal SIGSEGV, Segmentation fault.
0x0000563c1d041618 in thd_tx_isolation (thd=0x8f8f8f8f8f8f8f8f) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_class.cc:487
487 return (int) thd->tx_isolation;
(rr)
Continuing.
Thread 2 hit Hardware watchpoint 1: -location conn->thd
Old value = (THD *) 0x8f8f8f8f8f8f8f8f
New value = (THD *) 0x0
0x00007f405de15474 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
(rr) bt
#0 0x00007f405de15474 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#1 0x0000563c1da7d435 in free_memory (ptr=0x7f40500a5270) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/mysys/safemalloc.c:278
#2 0x0000563c1da7d0eb in sf_free (ptr=0x7f40500a5270) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/mysys/safemalloc.c:197
#3 0x0000563c1da6a3c9 in my_free (ptr=0x7f40500a5270) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/mysys/my_malloc.c:218
#4 0x00007f402af93f49 in spider_free_mem (trx=0x7f405007bd90, ptr=0x7f40500a5280, my_flags=0)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_malloc.cc:185
#5 0x00007f402af47c57 in spider_free_conn (conn=0x7f40500a5280) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_conn.cc:1108
#6 0x00007f402af46109 in spider_free_conn_from_trx (trx=0x7f405007bd90, conn=0x7f40500a5280, another=false, trx_free=false, roop_count=0x7f403c0a73e4)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_conn.cc:263
#7 0x00007f402af1085b in spider_free_trx_conn (trx=0x7f405007bd90, trx_free=false)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_trx.cc:114
#8 0x00007f402af1afe1 in spider_rollback (hton=0x7f405003de10, thd=0x7f4050009790, all=false)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_trx.cc:3451
#9 0x0000563c1d31aa33 in ha_rollback_trans (thd=0x7f4050009790, all=false) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/handler.cc:1708
#10 0x0000563c1d1fd606 in trans_rollback_stmt (thd=0x7f4050009790) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/transaction.cc:566
#11 0x0000563c1d0677e2 in mysql_ha_read (thd=0x7f4050009790, tables=0x7f4050019fc0, mode=RNEXT, keyname=0x0, key_expr=0xa5a5a5a5a5a5a5a5,
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_handler.cc:915
#12 0x0000563c1d09692d in mysql_execute_command (thd=0x7f4050009790) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:5331
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:1827
#15 0x0000563c1d08a8e0 in do_command (thd=0x7f4050009790) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:1381
#16 0x0000563c1d1e707e in do_handle_one_connection (connect=0x563c20310090) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_connect.cc:1336
#17 0x0000563c1d1e6de6 in handle_one_connection (arg=0x563c20310090) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_connect.cc:1241
#18 0x00007f405e209450 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#19 0x00007f405dda9d53 in clone () from /lib/x86_64-linux-gnu/libc.so.6
Nayuta Yanagisawa (Inactive)
added a comment - - edited use-after-free
Thread 2 received signal SIGSEGV, Segmentation fault.
[Switching to Thread 1619897.1620280]
0x0000563c1d041618 in thd_tx_isolation (thd=0x8f8f8f8f8f8f8f8f) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_class.cc:487
487 return (int) thd->tx_isolation;
(rr) bt
#0 0x0000563c1d041618 in thd_tx_isolation (thd=0x8f8f8f8f8f8f8f8f) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_class.cc:487
#1 0x00007f402af15e3e in spider_check_and_set_trx_isolation (conn=0x7f40500a5280, need_mon=0x7f40500a4200)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_trx.cc:1544
#2 0x00007f402afa2cff in ha_spider::external_lock (this=0x7f405009c0e8, thd=0x7f4050009790, lock_type=0)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/ha_spider.cc:1352
#3 0x0000563c1d32633d in handler::ha_external_lock (this=0x7f405009c0e8, thd=0x7f4050009790, lock_type=0)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/handler.cc:6044
#4 0x0000563c1d43616c in lock_external (thd=0x7f4050009790, tables=0x7f40500ade28, count=1)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/lock.cc:395
#5 0x0000563c1d435e63 in mysql_lock_tables (thd=0x7f4050009790, sql_lock=0x7f40500ade00, flags=8192)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/lock.cc:340
#6 0x0000563c1d066d3b in mysql_ha_read (thd=0x7f4050009790, tables=0x7f4050019fb8, mode=RNEXT, keyname=0x0, key_expr=0xa5a5a5a5a5a5a5a5,
ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_handler.cc:727
#7 0x0000563c1d09692d in mysql_execute_command (thd=0x7f4050009790) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:5331
#8 0x0000563c1d09db8c in mysql_parse (thd=0x7f4050009790, rawbuf=0x7f4050019e48 "HANDLER tbl_a READ NEXT", length=23, parser_state=0x7f403c0a8510, is_com_multi=false,
is_next_command=false) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:7793
#9 0x0000563c1d08bde0 in dispatch_command (command=COM_QUERY, thd=0x7f4050009790, packet=0x7f4050011661 "HANDLER tbl_a READ NEXT", packet_length=23,
is_com_multi=false, is_next_command=false) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:1827
#10 0x0000563c1d08a8e0 in do_command (thd=0x7f4050009790) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:1381
#11 0x0000563c1d1e707e in do_handle_one_connection (connect=0x563c20310090) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_connect.cc:1336
#12 0x0000563c1d1e6de6 in handle_one_connection (arg=0x563c20310090) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_connect.cc:1241
#13 0x00007f405e209450 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#14 0x00007f405dda9d53 in clone () from /lib/x86_64-linux-gnu/libc.so.6
(rr) up
#1 0x00007f402af15e3e in spider_check_and_set_trx_isolation (conn=0x7f40500a5280, need_mon=0x7f40500a4200)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_trx.cc:1544
1544 trx_isolation = thd_tx_isolation(conn->thd);
(rr) watch -l conn->thd
Hardware watchpoint 1: -location conn->thd
(rr) rc
Continuing.
Thread 2 received signal SIGSEGV, Segmentation fault.
0x0000563c1d041618 in thd_tx_isolation (thd=0x8f8f8f8f8f8f8f8f) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_class.cc:487
487 return (int) thd->tx_isolation;
(rr)
Continuing.
Thread 2 hit Hardware watchpoint 1: -location conn->thd
Old value = (THD *) 0x8f8f8f8f8f8f8f8f
New value = (THD *) 0x0
0x00007f405de15474 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
(rr) bt
#0 0x00007f405de15474 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#1 0x0000563c1da7d435 in free_memory (ptr=0x7f40500a5270) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/mysys/safemalloc.c:278
#2 0x0000563c1da7d0eb in sf_free (ptr=0x7f40500a5270) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/mysys/safemalloc.c:197
#3 0x0000563c1da6a3c9 in my_free (ptr=0x7f40500a5270) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/mysys/my_malloc.c:218
#4 0x00007f402af93f49 in spider_free_mem (trx=0x7f405007bd90, ptr=0x7f40500a5280, my_flags=0)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_malloc.cc:185
#5 0x00007f402af47c57 in spider_free_conn (conn=0x7f40500a5280) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_conn.cc:1108
#6 0x00007f402af46109 in spider_free_conn_from_trx (trx=0x7f405007bd90, conn=0x7f40500a5280, another=false, trx_free=false, roop_count=0x7f403c0a73e4)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_conn.cc:263
#7 0x00007f402af1085b in spider_free_trx_conn (trx=0x7f405007bd90, trx_free=false)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_trx.cc:114
#8 0x00007f402af1afe1 in spider_rollback (hton=0x7f405003de10, thd=0x7f4050009790, all=false)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/storage/spider/spd_trx.cc:3451
#9 0x0000563c1d31aa33 in ha_rollback_trans (thd=0x7f4050009790, all=false) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/handler.cc:1708
#10 0x0000563c1d1fd606 in trans_rollback_stmt (thd=0x7f4050009790) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/transaction.cc:566
#11 0x0000563c1d0677e2 in mysql_ha_read (thd=0x7f4050009790, tables=0x7f4050019fc0, mode=RNEXT, keyname=0x0, key_expr=0xa5a5a5a5a5a5a5a5,
ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_handler.cc:915
#12 0x0000563c1d09692d in mysql_execute_command (thd=0x7f4050009790) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:5331
#13 0x0000563c1d09db8c in mysql_parse (thd=0x7f4050009790, rawbuf=0x7f4050019e48 "HANDLER tbl_a READ FIRST", length=24, parser_state=0x7f403c0a8510, is_com_multi=false,
is_next_command=false) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:7793
#14 0x0000563c1d08bde0 in dispatch_command (command=COM_QUERY, thd=0x7f4050009790, packet=0x7f4050011661 "", packet_length=24, is_com_multi=false, is_next_command=false)
at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:1827
#15 0x0000563c1d08a8e0 in do_command (thd=0x7f4050009790) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_parse.cc:1381
#16 0x0000563c1d1e707e in do_handle_one_connection (connect=0x563c20310090) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_connect.cc:1336
#17 0x0000563c1d1e6de6 in handle_one_connection (arg=0x563c20310090) at /home/nayuta_mariadb/repo/mariadb-server/bb-10.2-MDEV-27902/sql/sql_connect.cc:1241
#18 0x00007f405e209450 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#19 0x00007f405dda9d53 in clone () from /lib/x86_64-linux-gnu/libc.so.6
dummy is redundant. The following is enough to reproduce the bug:
--disable_query_log
--disable_result_log
--source t/test_init.inc
--enable_result_log
--enable_query_log
--connection master_1
CREATEDATABASE auto_test_local;
USE auto_test_local;
CREATETABLE tbl_a (a INT) ENGINE=Spider;
HANDLER tbl_a OPEN;
--error ER_CONNECT_TO_FOREIGN_DATA_SOURCE
HANDLER tbl_a READFIRST;
--error ER_CONNECT_TO_FOREIGN_DATA_SOURCE
HANDLER tbl_a READNEXT;
DROPDATABASE auto_test_local;
--disable_query_log
--disable_result_log
--source test_deinit.inc
--enable_result_log
--enable_query_log
Nayuta Yanagisawa (Inactive)
added a comment - - edited dummy is redundant. The following is enough to reproduce the bug:
--disable_query_log
--disable_result_log
--source t/test_init.inc
--enable_result_log
--enable_query_log
--connection master_1
CREATE DATABASE auto_test_local;
USE auto_test_local;
CREATE TABLE tbl_a (a INT ) ENGINE=Spider;
HANDLER tbl_a OPEN ;
--error ER_CONNECT_TO_FOREIGN_DATA_SOURCE
HANDLER tbl_a READ FIRST ;
--error ER_CONNECT_TO_FOREIGN_DATA_SOURCE
HANDLER tbl_a READ NEXT ;
DROP DATABASE auto_test_local;
--disable_query_log
--disable_result_log
--source test_deinit.inc
--enable_result_log
--enable_query_log
ha_spider::conns is set at HANDLER tbl_a OPEN. The connections are freed at HANDLER tbl_a READ FIRST but ha_spider::conns is not cleared. This result in the use-after-free.
Nayuta Yanagisawa (Inactive)
added a comment - ha_spider::conns is set at HANDLER tbl_a OPEN . The connections are freed at HANDLER tbl_a READ FIRST but ha_spider::conns is not cleared. This result in the use-after-free.
Spider tries to close allocated connections at every handler statement execution but I doubt that this is a correct behavior. IMHO, the set of operations between HANDLER ... OPEN and HANDLER ... CLOSE correspond to a single SQL query. Thus, it seems to be natural that the Spider tries to close the connections only after HANDLER ... CLOSE.
Nayuta Yanagisawa (Inactive)
added a comment - - edited Spider tries to close allocated connections at every handler statement execution but I doubt that this is a correct behavior. IMHO, the set of operations between HANDLER ... OPEN and HANDLER ... CLOSE correspond to a single SQL query. Thus, it seems to be natural that the Spider tries to close the connections only after HANDLER ... CLOSE .
Only the last of these was previously known. That last one reproduces on 10.4 (opt+dbg), all the rest (1-3) is new on other versions. The main one ending in spider_db_open_handler happens on 10.6-10.9 after trying to shutdown the server when a thread is hanging in 'starting' state due to the testcase: the testcase [now?] seems to hang 10.6 to 10.9 optimized builds with odd looking process traces:
Core was generated by `/test/MD160322-mariadb-10.9.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 0x14a148079700 (LWP 2431706))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x000014a1508dd859 in __GI_abort () at abort.c:79
#2 0x0000560b08321da0 in safe_mutex_lock (mp=mp@entry=0x14a0c408e790, my_flags=my_flags@entry=0, file=file@entry=0x14a130199c88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", line=line@entry=10605) at /test/10.9_dbg/mysys/thr_mutex.c:245
#3 0x0000560b0831c2ec in psi_mutex_lock (that=that@entry=0x14a0c408e790, file=file@entry=0x14a130199c88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", line=line@entry=10605) at /test/10.9_dbg/mysys/my_thr_init.c:487
#4 0x000014a1300ca1b6 in inline_mysql_mutex_lock (src_line=10605, src_file=0x14a130199c88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", that=0x14a0c408e790) at /test/10.9_dbg/include/mysql/psi/mysql_thread.h:746
#5 spider_db_open_handler (spider=spider@entry=0x14a0c407d780, conn=0x14a0c408e738, link_idx=link_idx@entry=0) at /test/10.9_dbg/storage/spider/spd_db_conn.cc:10605
#6 0x000014a13012b1b4 in ha_spider::rnd_handler_init (this=this@entry=0x14a0c407d780) at /test/10.9_dbg/storage/spider/ha_spider.cc:10732
#7 0x000014a130135733 in ha_spider::rnd_next_internal (this=this@entry=0x14a0c407d780, buf=buf@entry=0x14a0c402f598 "\377") at /test/10.9_dbg/storage/spider/ha_spider.cc:5947
#8 0x000014a13013692c in ha_spider::rnd_next (this=0x14a0c407d780, buf=0x14a0c402f598 "\377") at /test/10.9_dbg/storage/spider/ha_spider.cc:6310
#9 0x0000560b07b0d2d9 in handler::ha_rnd_next (this=0x14a0c407d780, buf=0x14a0c402f598 "\377") at /test/10.9_dbg/sql/handler.cc:3398
#10 0x0000560b077aa8aa in mysql_ha_read (thd=thd@entry=0x14a0c4000db8, tables=tables@entry=0x14a0c4013f28, 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.9_dbg/sql/sql_handler.cc:923
#11 0x0000560b078047f7 in mysql_execute_command (thd=thd@entry=0x14a0c4000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.9_dbg/sql/sql_limit.h:87
#12 0x0000560b077ec437 in mysql_parse (thd=thd@entry=0x14a0c4000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14a148078400) at /test/10.9_dbg/sql/sql_parse.cc:8027
#13 0x0000560b077fb0d3 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14a0c4000db8, packet=packet@entry=0x14a0c400b889 "", packet_length=packet_length@entry=19, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_class.h:1362
#14 0x0000560b077fe51a in do_command (thd=0x14a0c4000db8, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_parse.cc:1402
#15 0x0000560b07979228 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x560b0b18a298, put_in_cache=put_in_cache@entry=true) at /test/10.9_dbg/sql/sql_connect.cc:1418
#16 0x0000560b0797982d in handle_one_connection (arg=arg@entry=0x560b0b18a298) at /test/10.9_dbg/sql/sql_connect.cc:1312
#17 0x0000560b07dfff23 in pfs_spawn_thread (arg=0x560b0b09d828) at /test/10.9_dbg/storage/perfschema/pfs.cc:2201
#18 0x000014a150dee609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#19 0x000014a1509da163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Core was generated by `/test/MD160322-mariadb-10.5.16-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 0x14fd84143700 (LWP 2430828))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x000014fd98ddd859 in __GI_abort () at abort.c:79
#2 0x000056459d41fd51 in safe_mutex_lock (mp=mp@entry=0x14fd3808f530, my_flags=my_flags@entry=0, file=file@entry=0x14fd75dacc28 "/test/10.5_dbg/storage/spider/spd_db_conn.cc", line=line@entry=12442) at /test/10.5_dbg/mysys/thr_mutex.c:245
#3 0x000014fd75cd3070 in inline_mysql_mutex_lock (src_line=12442, src_file=0x14fd75dacc28 "/test/10.5_dbg/storage/spider/spd_db_conn.cc", that=0x14fd3808f530) at /test/10.5_dbg/include/mysql/psi/mysql_thread.h:750
#4 spider_db_open_handler (spider=spider@entry=0x14fd3807e450, conn=0x14fd3808f4d8, link_idx=link_idx@entry=0) at /test/10.5_dbg/storage/spider/spd_db_conn.cc:12442
#5 0x000014fd75d3683e in ha_spider::rnd_handler_init (this=this@entry=0x14fd3807e450) at /test/10.5_dbg/storage/spider/ha_spider.cc:13660
#6 0x000014fd75d41312 in ha_spider::rnd_next_internal (this=this@entry=0x14fd3807e450, buf=buf@entry=0x14fd38030538 "\377") at /test/10.5_dbg/storage/spider/ha_spider.cc:7449
#7 0x000014fd75d42650 in ha_spider::rnd_next (this=0x14fd3807e450, buf=0x14fd38030538 "\377") at /test/10.5_dbg/storage/spider/ha_spider.cc:7818
#8 0x000056459cb72b49 in handler::ha_rnd_next (this=0x14fd3807e450, buf=0x14fd38030538 "\377") at /test/10.5_dbg/sql/handler.cc:3080
#9 0x000056459c8491c7 in mysql_ha_read (thd=thd@entry=0x14fd38000db8, tables=tables@entry=0x14fd38013e58, 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.5_dbg/sql/sql_handler.cc:911
#10 0x000056459c8a5446 in mysql_execute_command (thd=thd@entry=0x14fd38000db8) at /test/10.5_dbg/sql/sql_limit.h:71
#11 0x000056459c88bfe2 in mysql_parse (thd=thd@entry=0x14fd38000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14fd841423d0, 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:8100
#12 0x000056459c89b835 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14fd38000db8, packet=packet@entry=0x14fd3800b4a9 "", 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_class.h:1290
#13 0x000056459c89f0b1 in do_command (thd=0x14fd38000db8) at /test/10.5_dbg/sql/sql_parse.cc:1370
#14 0x000056459c9fbeb6 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5645a0e13818, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1418
#15 0x000056459c9fc5b9 in handle_one_connection (arg=arg@entry=0x5645a0e13818) at /test/10.5_dbg/sql/sql_connect.cc:1312
#16 0x000056459ceb5acb in pfs_spawn_thread (arg=0x5645a0d41938) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
#17 0x000014fd992ee609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#18 0x000014fd98eda163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
str=0x39 <error: Cannot access memory at address 0x39>, this=0xffffffff)
at /test/10.5_opt/include/m_ctype.h:776
[Current thread is 1 (Thread 0x14b7d8129700 (LWP 2430827))]
(gdb) bt
#0 0x0000564d969acb8b in charset_info_st::strntoull10rnd (error=0x14b7d8127a24, endptr=0x14b7d8127a28, unsigned_fl=0, length=33, str=0x39 <error: Cannot access memory at address 0x39>, this=0xffffffff) at /test/10.5_opt/include/m_ctype.h:776
#1 Field_num::get_int (this=this@entry=0x14b76405ca18, cs=0xffffffff, from=0x39 <error: Cannot access memory at address 0x39>, len=33, rnd=rnd@entry=0x14b7d8127a88, unsigned_max=unsigned_max@entry=4294967295, signed_min=-2147483648, signed_max=2147483647) at /test/10.5_opt/sql/field.cc:1742
#2 0x0000564d969acdf5 in Field_long::store (this=0x14b76405ca18, from=<optimized out>, len=<optimized out>, cs=<optimized out>) at /test/10.5_opt/sql/field.cc:4312
#3 0x000014b7c9f2aa6d in spider_db_errorno (conn=conn@entry=0x14b76405c9e8) at /test/10.5_opt/storage/spider/spd_db_conn.cc:758
#4 0x000014b7c9f3f108 in spider_db_open_handler (spider=spider@entry=0x14b764028f60, conn=0x14b76405c9e8, link_idx=link_idx@entry=0) at /test/10.5_opt/storage/spider/spd_db_conn.cc:12476
#5 0x000014b7c9f81748 in ha_spider::rnd_handler_init (this=0x14b764028f60) at /test/10.5_opt/storage/spider/ha_spider.cc:13660
#6 ha_spider::rnd_handler_init (this=0x14b764028f60) at /test/10.5_opt/storage/spider/ha_spider.cc:13626
#7 0x000014b7c9f889c7 in ha_spider::rnd_next_internal (this=0x14b764028f60, buf=0x14b764024638 "\377") at /test/10.5_opt/storage/spider/ha_spider.cc:7449
#8 0x0000564d969c01b7 in handler::ha_rnd_next (this=0x14b764028f60, buf=0x14b764024638 "\377") at /test/10.5_opt/sql/handler.cc:3080
#9 0x0000564d967619ef in mysql_ha_read (thd=thd@entry=0x14b764000c58, tables=tables@entry=0x14b764010568, 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.5_opt/sql/sql_handler.cc:911
#10 0x0000564d967a6eb1 in mysql_execute_command (thd=0x14b764000c58) at /test/10.5_opt/sql/sql_limit.h:71
#11 0x0000564d96794db3 in mysql_parse (thd=0x14b764000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.5_opt/sql/sql_parse.cc:8100
#12 0x0000564d967a1bcd in dispatch_command (command=COM_QUERY, thd=0x14b764000c58, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.5_opt/sql/sql_class.h:1290
#13 0x0000564d967a43a2 in do_command (thd=0x14b764000c58) at /test/10.5_opt/sql/sql_parse.cc:1370
#14 0x0000564d968abf31 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x564d9a4623d8, put_in_cache=put_in_cache@entry=true) at /test/10.5_opt/sql/sql_connect.cc:1418
#15 0x0000564d968ac3ad in handle_one_connection (arg=arg@entry=0x564d9a4623d8) at /test/10.5_opt/sql/sql_connect.cc:1312
#16 0x0000564d96c414f2 in pfs_spawn_thread (arg=0x564d9a3e3418) at /test/10.5_opt/storage/perfschema/pfs.cc:2201
#17 0x000014b7ed509609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#18 0x000014b7ed0f5163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Core was generated by `/test/MD160322-mariadb-10.4.25-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00001476e4116456 in spider_check_and_set_trx_isolation (
conn=0x1476ac0611c8, need_mon=0x1476ac05fb68)
at /test/10.4_opt/storage/spider/spd_trx.cc:1593
[Current thread is 1 (Thread 0x147708377700 (LWP 2430691))]
(gdb) bt
#0 0x00001476e4116456 in spider_check_and_set_trx_isolation (conn=0x1476ac0611c8, need_mon=0x1476ac05fb68) at /test/10.4_opt/storage/spider/spd_trx.cc:1593
#1 0x00001476e417904c in ha_spider::external_lock (this=0x1476ac058830, thd=0x1476ac000c48, lock_type=0) at /test/10.4_opt/storage/spider/ha_spider.cc:1371
#2 0x0000564855340ced in handler::ha_external_lock (this=0x1476ac058830, thd=thd@entry=0x1476ac000c48, lock_type=lock_type@entry=0) at /test/10.4_opt/sql/handler.cc:6509
#3 0x000056485543c459 in lock_external (count=<optimized out>, tables=0x1476ac061d98, thd=0x1476ac000c48) at /test/10.4_opt/sql/lock.cc:393
#4 mysql_lock_tables (thd=thd@entry=0x1476ac000c48, sql_lock=0x1476ac061d68, flags=<optimized out>) at /test/10.4_opt/sql/lock.cc:338
#5 0x00005648550ed876 in mysql_ha_read (thd=thd@entry=0x1476ac000c48, tables=tables@entry=0x1476ac010150, mode=RNEXT, 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.4_opt/sql/sql_handler.cc:819
#6 0x000056485512a221 in mysql_execute_command (thd=0x1476ac000c48) at /test/10.4_opt/sql/sql_parse.cc:5676
#7 0x000056485512f257 in mysql_parse (thd=0x1476ac000c48, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_parse.cc:7995
#8 0x00005648551318cd in dispatch_command (command=COM_QUERY, thd=0x1476ac000c48, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_class.h:1201
#9 0x0000564855133f3e in do_command (thd=0x1476ac000c48) at /test/10.4_opt/sql/sql_parse.cc:1373
#10 0x0000564855229d3e in do_handle_one_connection (connect=connect@entry=0x56485892ec18) at /test/10.4_opt/sql/sql_connect.cc:1420
#11 0x0000564855229e6f in handle_one_connection (arg=0x56485892ec18) at /test/10.4_opt/sql/sql_connect.cc:1316
#12 0x0000147709c53609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#13 0x000014770983f163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Given all the new findings, temporary re-increasing prio, feel free to re-lower if not deemed significant.
Roel Van de Paar
added a comment - - edited This slightly different testcase [now?] produces a whole set of new stacks + hangs:
INSTALL PLUGIN spider SONAME 'ha_spider.so' ;
CREATE TABLE t (c INT ) ENGINE=Spider;
HANDLER t OPEN ;
HANDLER t READ NEXT ;
SELECT * FROM t;
HANDLER t READ NEXT ;
UniqueID's seen:
SIGABRT|safe_mutex_lock|inline_mysql_mutex_lock|spider_db_open_handler|ha_spider::rnd_handler_init
SIGABRT|safe_mutex_lock|psi_mutex_lock|inline_mysql_mutex_lock|spider_db_open_handler
SIGSEGV|charset_info_st::strntoull10rnd|Field_num::get_int|Field_long::store|spider_db_errorno
SIGSEGV|spider_check_and_set_trx_isolation|ha_spider::external_lock|handler::ha_external_lock|lock_external
Only the last of these was previously known. That last one reproduces on 10.4 (opt+dbg), all the rest (1-3) is new on other versions. The main one ending in spider_db_open_handler happens on 10.6-10.9 after trying to shutdown the server when a thread is hanging in 'starting' state due to the testcase: the testcase [now?] seems to hang 10.6 to 10.9 optimized builds with odd looking process traces:
10.6.8 b2c81e06b042025663ea01fa98dac0ff536c7706 (Optimized)
MariaDB [test]> show processlist;
+----+-------------+-----------+------+---------+------+----------------------------------------------------+---------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+----+-------------+-----------+------+---------+------+----------------------------------------------------+---------------------+----------+
| 4 | root | localhost | test | Query | 362 | starting | HANDLER t READ NEXT | 0.000 |
| 5 | system user | | NULL | Sleep | 362 | Reset for next command | NULL | 0.000 |
| 6 | system user | | NULL | Daemon | NULL | Spider table background cardinality action handler | NULL | 0.000 |
| 7 | system user | | NULL | Daemon | NULL | Spider table background cardinality action handler | NULL | 0.000 |
| 8 | system user | | NULL | Daemon | NULL | Spider table background statistics action handler | NULL | 0.000 |
| 9 | system user | | NULL | Daemon | NULL | Spider table background statistics action handler | NULL | 0.000 |
| 10 | system user | | NULL | Daemon | NULL | Spider table background cardinality action handler | NULL | 0.000 |
| 11 | system user | | NULL | Daemon | NULL | Spider table background cardinality action handler | NULL | 0.000 |
| 12 | system user | | NULL | Daemon | NULL | Spider table background cardinality action handler | NULL | 0.000 |
| 13 | system user | | NULL | Daemon | NULL | Spider table background statistics action handler | NULL | 0.000 |
| 14 | system user | | NULL | Daemon | NULL | Spider table background cardinality action handler | NULL | 0.000 |
| 15 | system user | | NULL | Daemon | NULL | Spider table background cardinality action handler | NULL | 0.000 |
| 16 | system user | | NULL | Daemon | NULL | Spider table background statistics action handler | NULL | 0.000 |
| 17 | system user | | NULL | Daemon | NULL | Spider table background statistics action handler | NULL | 0.000 |
| 18 | system user | | NULL | Daemon | NULL | Spider table background statistics action handler | NULL | 0.000 |
| 19 | system user | | NULL | Daemon | NULL | Spider table background statistics action handler | NULL | 0.000 |
| 20 | system user | | NULL | Daemon | NULL | Spider table background cardinality action handler | NULL | 0.000 |
| 21 | system user | | NULL | Daemon | NULL | Spider table background cardinality action handler | NULL | 0.000 |
| 22 | system user | | NULL | Daemon | NULL | Spider table background cardinality action handler | NULL | 0.000 |
| 23 | system user | | NULL | Daemon | NULL | Spider table background statistics action handler | NULL | 0.000 |
| 24 | system user | | NULL | Daemon | NULL | Spider table background statistics action handler | NULL | 0.000 |
| 25 | root | localhost | test | Query | 0 | starting | show processlist | 0.000 |
+----+-------------+-----------+------+---------+------+----------------------------------------------------+---------------------+----------+
22 rows in set (0.000 sec)
The CLI does not hang when trying to connect.
Stacks:
10.9.0 5be92887c2caacb45af87b1131db952ce627e83a (Debug)
Core was generated by `/test/MD160322-mariadb-10.9.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 0x14a148079700 (LWP 2431706))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x000014a1508dd859 in __GI_abort () at abort.c:79
#2 0x0000560b08321da0 in safe_mutex_lock (mp=mp@entry=0x14a0c408e790, my_flags=my_flags@entry=0, file=file@entry=0x14a130199c88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", line=line@entry=10605) at /test/10.9_dbg/mysys/thr_mutex.c:245
#3 0x0000560b0831c2ec in psi_mutex_lock (that=that@entry=0x14a0c408e790, file=file@entry=0x14a130199c88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", line=line@entry=10605) at /test/10.9_dbg/mysys/my_thr_init.c:487
#4 0x000014a1300ca1b6 in inline_mysql_mutex_lock (src_line=10605, src_file=0x14a130199c88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", that=0x14a0c408e790) at /test/10.9_dbg/include/mysql/psi/mysql_thread.h:746
#5 spider_db_open_handler (spider=spider@entry=0x14a0c407d780, conn=0x14a0c408e738, link_idx=link_idx@entry=0) at /test/10.9_dbg/storage/spider/spd_db_conn.cc:10605
#6 0x000014a13012b1b4 in ha_spider::rnd_handler_init (this=this@entry=0x14a0c407d780) at /test/10.9_dbg/storage/spider/ha_spider.cc:10732
#7 0x000014a130135733 in ha_spider::rnd_next_internal (this=this@entry=0x14a0c407d780, buf=buf@entry=0x14a0c402f598 "\377") at /test/10.9_dbg/storage/spider/ha_spider.cc:5947
#8 0x000014a13013692c in ha_spider::rnd_next (this=0x14a0c407d780, buf=0x14a0c402f598 "\377") at /test/10.9_dbg/storage/spider/ha_spider.cc:6310
#9 0x0000560b07b0d2d9 in handler::ha_rnd_next (this=0x14a0c407d780, buf=0x14a0c402f598 "\377") at /test/10.9_dbg/sql/handler.cc:3398
#10 0x0000560b077aa8aa in mysql_ha_read (thd=thd@entry=0x14a0c4000db8, tables=tables@entry=0x14a0c4013f28, 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.9_dbg/sql/sql_handler.cc:923
#11 0x0000560b078047f7 in mysql_execute_command (thd=thd@entry=0x14a0c4000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.9_dbg/sql/sql_limit.h:87
#12 0x0000560b077ec437 in mysql_parse (thd=thd@entry=0x14a0c4000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14a148078400) at /test/10.9_dbg/sql/sql_parse.cc:8027
#13 0x0000560b077fb0d3 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14a0c4000db8, packet=packet@entry=0x14a0c400b889 "", packet_length=packet_length@entry=19, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_class.h:1362
#14 0x0000560b077fe51a in do_command (thd=0x14a0c4000db8, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_parse.cc:1402
#15 0x0000560b07979228 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x560b0b18a298, put_in_cache=put_in_cache@entry=true) at /test/10.9_dbg/sql/sql_connect.cc:1418
#16 0x0000560b0797982d in handle_one_connection (arg=arg@entry=0x560b0b18a298) at /test/10.9_dbg/sql/sql_connect.cc:1312
#17 0x0000560b07dfff23 in pfs_spawn_thread (arg=0x560b0b09d828) at /test/10.9_dbg/storage/perfschema/pfs.cc:2201
#18 0x000014a150dee609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#19 0x000014a1509da163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
10.5.16 73fee39ea62037780c59161507e89dd76c10b7a3 (Debug)
Core was generated by `/test/MD160322-mariadb-10.5.16-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 0x14fd84143700 (LWP 2430828))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x000014fd98ddd859 in __GI_abort () at abort.c:79
#2 0x000056459d41fd51 in safe_mutex_lock (mp=mp@entry=0x14fd3808f530, my_flags=my_flags@entry=0, file=file@entry=0x14fd75dacc28 "/test/10.5_dbg/storage/spider/spd_db_conn.cc", line=line@entry=12442) at /test/10.5_dbg/mysys/thr_mutex.c:245
#3 0x000014fd75cd3070 in inline_mysql_mutex_lock (src_line=12442, src_file=0x14fd75dacc28 "/test/10.5_dbg/storage/spider/spd_db_conn.cc", that=0x14fd3808f530) at /test/10.5_dbg/include/mysql/psi/mysql_thread.h:750
#4 spider_db_open_handler (spider=spider@entry=0x14fd3807e450, conn=0x14fd3808f4d8, link_idx=link_idx@entry=0) at /test/10.5_dbg/storage/spider/spd_db_conn.cc:12442
#5 0x000014fd75d3683e in ha_spider::rnd_handler_init (this=this@entry=0x14fd3807e450) at /test/10.5_dbg/storage/spider/ha_spider.cc:13660
#6 0x000014fd75d41312 in ha_spider::rnd_next_internal (this=this@entry=0x14fd3807e450, buf=buf@entry=0x14fd38030538 "\377") at /test/10.5_dbg/storage/spider/ha_spider.cc:7449
#7 0x000014fd75d42650 in ha_spider::rnd_next (this=0x14fd3807e450, buf=0x14fd38030538 "\377") at /test/10.5_dbg/storage/spider/ha_spider.cc:7818
#8 0x000056459cb72b49 in handler::ha_rnd_next (this=0x14fd3807e450, buf=0x14fd38030538 "\377") at /test/10.5_dbg/sql/handler.cc:3080
#9 0x000056459c8491c7 in mysql_ha_read (thd=thd@entry=0x14fd38000db8, tables=tables@entry=0x14fd38013e58, 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.5_dbg/sql/sql_handler.cc:911
#10 0x000056459c8a5446 in mysql_execute_command (thd=thd@entry=0x14fd38000db8) at /test/10.5_dbg/sql/sql_limit.h:71
#11 0x000056459c88bfe2 in mysql_parse (thd=thd@entry=0x14fd38000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14fd841423d0, 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:8100
#12 0x000056459c89b835 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14fd38000db8, packet=packet@entry=0x14fd3800b4a9 "", 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_class.h:1290
#13 0x000056459c89f0b1 in do_command (thd=0x14fd38000db8) at /test/10.5_dbg/sql/sql_parse.cc:1370
#14 0x000056459c9fbeb6 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5645a0e13818, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1418
#15 0x000056459c9fc5b9 in handle_one_connection (arg=arg@entry=0x5645a0e13818) at /test/10.5_dbg/sql/sql_connect.cc:1312
#16 0x000056459ceb5acb in pfs_spawn_thread (arg=0x5645a0d41938) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
#17 0x000014fd992ee609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#18 0x000014fd98eda163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
10.5.16 73fee39ea62037780c59161507e89dd76c10b7a3 (Optimized)
Core was generated by `/test/MD160322-mariadb-10.5.16-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x0000564d969acb8b in charset_info_st::strntoull10rnd (
error=0x14b7d8127a24, endptr=0x14b7d8127a28, unsigned_fl=0, length=33,
str=0x39 <error: Cannot access memory at address 0x39>, this=0xffffffff)
at /test/10.5_opt/include/m_ctype.h:776
[Current thread is 1 (Thread 0x14b7d8129700 (LWP 2430827))]
(gdb) bt
#0 0x0000564d969acb8b in charset_info_st::strntoull10rnd (error=0x14b7d8127a24, endptr=0x14b7d8127a28, unsigned_fl=0, length=33, str=0x39 <error: Cannot access memory at address 0x39>, this=0xffffffff) at /test/10.5_opt/include/m_ctype.h:776
#1 Field_num::get_int (this=this@entry=0x14b76405ca18, cs=0xffffffff, from=0x39 <error: Cannot access memory at address 0x39>, len=33, rnd=rnd@entry=0x14b7d8127a88, unsigned_max=unsigned_max@entry=4294967295, signed_min=-2147483648, signed_max=2147483647) at /test/10.5_opt/sql/field.cc:1742
#2 0x0000564d969acdf5 in Field_long::store (this=0x14b76405ca18, from=<optimized out>, len=<optimized out>, cs=<optimized out>) at /test/10.5_opt/sql/field.cc:4312
#3 0x000014b7c9f2aa6d in spider_db_errorno (conn=conn@entry=0x14b76405c9e8) at /test/10.5_opt/storage/spider/spd_db_conn.cc:758
#4 0x000014b7c9f3f108 in spider_db_open_handler (spider=spider@entry=0x14b764028f60, conn=0x14b76405c9e8, link_idx=link_idx@entry=0) at /test/10.5_opt/storage/spider/spd_db_conn.cc:12476
#5 0x000014b7c9f81748 in ha_spider::rnd_handler_init (this=0x14b764028f60) at /test/10.5_opt/storage/spider/ha_spider.cc:13660
#6 ha_spider::rnd_handler_init (this=0x14b764028f60) at /test/10.5_opt/storage/spider/ha_spider.cc:13626
#7 0x000014b7c9f889c7 in ha_spider::rnd_next_internal (this=0x14b764028f60, buf=0x14b764024638 "\377") at /test/10.5_opt/storage/spider/ha_spider.cc:7449
#8 0x0000564d969c01b7 in handler::ha_rnd_next (this=0x14b764028f60, buf=0x14b764024638 "\377") at /test/10.5_opt/sql/handler.cc:3080
#9 0x0000564d967619ef in mysql_ha_read (thd=thd@entry=0x14b764000c58, tables=tables@entry=0x14b764010568, 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.5_opt/sql/sql_handler.cc:911
#10 0x0000564d967a6eb1 in mysql_execute_command (thd=0x14b764000c58) at /test/10.5_opt/sql/sql_limit.h:71
#11 0x0000564d96794db3 in mysql_parse (thd=0x14b764000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.5_opt/sql/sql_parse.cc:8100
#12 0x0000564d967a1bcd in dispatch_command (command=COM_QUERY, thd=0x14b764000c58, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.5_opt/sql/sql_class.h:1290
#13 0x0000564d967a43a2 in do_command (thd=0x14b764000c58) at /test/10.5_opt/sql/sql_parse.cc:1370
#14 0x0000564d968abf31 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x564d9a4623d8, put_in_cache=put_in_cache@entry=true) at /test/10.5_opt/sql/sql_connect.cc:1418
#15 0x0000564d968ac3ad in handle_one_connection (arg=arg@entry=0x564d9a4623d8) at /test/10.5_opt/sql/sql_connect.cc:1312
#16 0x0000564d96c414f2 in pfs_spawn_thread (arg=0x564d9a3e3418) at /test/10.5_opt/storage/perfschema/pfs.cc:2201
#17 0x000014b7ed509609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#18 0x000014b7ed0f5163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
10.4.25 9c6135e81f29b3e3286d6b864c0fdafc2fea16ce (Optimized)
Core was generated by `/test/MD160322-mariadb-10.4.25-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00001476e4116456 in spider_check_and_set_trx_isolation (
conn=0x1476ac0611c8, need_mon=0x1476ac05fb68)
at /test/10.4_opt/storage/spider/spd_trx.cc:1593
[Current thread is 1 (Thread 0x147708377700 (LWP 2430691))]
(gdb) bt
#0 0x00001476e4116456 in spider_check_and_set_trx_isolation (conn=0x1476ac0611c8, need_mon=0x1476ac05fb68) at /test/10.4_opt/storage/spider/spd_trx.cc:1593
#1 0x00001476e417904c in ha_spider::external_lock (this=0x1476ac058830, thd=0x1476ac000c48, lock_type=0) at /test/10.4_opt/storage/spider/ha_spider.cc:1371
#2 0x0000564855340ced in handler::ha_external_lock (this=0x1476ac058830, thd=thd@entry=0x1476ac000c48, lock_type=lock_type@entry=0) at /test/10.4_opt/sql/handler.cc:6509
#3 0x000056485543c459 in lock_external (count=<optimized out>, tables=0x1476ac061d98, thd=0x1476ac000c48) at /test/10.4_opt/sql/lock.cc:393
#4 mysql_lock_tables (thd=thd@entry=0x1476ac000c48, sql_lock=0x1476ac061d68, flags=<optimized out>) at /test/10.4_opt/sql/lock.cc:338
#5 0x00005648550ed876 in mysql_ha_read (thd=thd@entry=0x1476ac000c48, tables=tables@entry=0x1476ac010150, mode=RNEXT, 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.4_opt/sql/sql_handler.cc:819
#6 0x000056485512a221 in mysql_execute_command (thd=0x1476ac000c48) at /test/10.4_opt/sql/sql_parse.cc:5676
#7 0x000056485512f257 in mysql_parse (thd=0x1476ac000c48, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_parse.cc:7995
#8 0x00005648551318cd in dispatch_command (command=COM_QUERY, thd=0x1476ac000c48, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_class.h:1201
#9 0x0000564855133f3e in do_command (thd=0x1476ac000c48) at /test/10.4_opt/sql/sql_parse.cc:1373
#10 0x0000564855229d3e in do_handle_one_connection (connect=connect@entry=0x56485892ec18) at /test/10.4_opt/sql/sql_connect.cc:1420
#11 0x0000564855229e6f in handle_one_connection (arg=0x56485892ec18) at /test/10.4_opt/sql/sql_connect.cc:1316
#12 0x0000147709c53609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#13 0x000014770983f163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Given all the new findings, temporary re-increasing prio, feel free to re-lower if not deemed significant.
Core was generated by `/test/MD050422-mariadb-10.9.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 0x153a40108700 (LWP 3116627))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x0000153a56577859 in __GI_abort () at abort.c:79
#2 0x000055b2a070f8cc in safe_mutex_lock (mp=mp@entry=0x153a0808de10, my_flags=my_flags@entry=0, file=file@entry=0x153a3299fc88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", line=line@entry=10605) at /test/10.9_dbg/mysys/thr_mutex.c:245
#3 0x000055b2a0709e18 in psi_mutex_lock (that=that@entry=0x153a0808de10, file=file@entry=0x153a3299fc88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", line=line@entry=10605) at /test/10.9_dbg/mysys/my_thr_init.c:487
#4 0x0000153a328d01b6 in inline_mysql_mutex_lock (src_line=10605, src_file=0x153a3299fc88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", that=0x153a0808de10) at /test/10.9_dbg/include/mysql/psi/mysql_thread.h:746
#5 spider_db_open_handler (spider=spider@entry=0x153a0802e5b0, conn=0x153a0808ddb8, link_idx=link_idx@entry=0) at /test/10.9_dbg/storage/spider/spd_db_conn.cc:10605
#6 0x0000153a329311b4 in ha_spider::rnd_handler_init (this=this@entry=0x153a0802e5b0) at /test/10.9_dbg/storage/spider/ha_spider.cc:10604
#7 0x0000153a3293b733 in ha_spider::rnd_next_internal (this=this@entry=0x153a0802e5b0, buf=buf@entry=0x153a08062888 "\377") at /test/10.9_dbg/storage/spider/ha_spider.cc:5867
#8 0x0000153a3293c92c in ha_spider::rnd_next (this=0x153a0802e5b0, buf=0x153a08062888 "\377") at /test/10.9_dbg/storage/spider/ha_spider.cc:6228
#9 0x000055b29fef8407 in handler::ha_rnd_next (this=0x153a0802e5b0, buf=0x153a08062888 "\377") at /test/10.9_dbg/sql/handler.cc:3398
#10 0x000055b29fb8fb3e in mysql_ha_read (thd=thd@entry=0x153a08000db8, tables=tables@entry=0x153a08013f28, 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.9_dbg/sql/sql_handler.cc:923
#11 0x000055b29fbea1c8 in mysql_execute_command (thd=thd@entry=0x153a08000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.9_dbg/sql/sql_limit.h:87
#12 0x000055b29fbd1e23 in mysql_parse (thd=thd@entry=0x153a08000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x153a40107400) at /test/10.9_dbg/sql/sql_parse.cc:8043
#13 0x000055b29fbe0a23 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x153a08000db8, packet=packet@entry=0x153a0800b889 "", packet_length=packet_length@entry=19, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_class.h:1362
#14 0x000055b29fbe3e74 in do_command (thd=0x153a08000db8, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_parse.cc:1407
#15 0x000055b29fd60d2a in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55b2a23f3ba8, put_in_cache=put_in_cache@entry=true) at /test/10.9_dbg/sql/sql_connect.cc:1418
#16 0x000055b29fd6132f in handle_one_connection (arg=arg@entry=0x55b2a23f3ba8) at /test/10.9_dbg/sql/sql_connect.cc:1312
#17 0x000055b2a01eb7a5 in pfs_spawn_thread (arg=0x55b2a23071c8) at /test/10.9_dbg/storage/perfschema/pfs.cc:2201
#18 0x0000153a56a88609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#19 0x0000153a56674163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Roel Van de Paar
added a comment - - edited Various new stacks found with this testcase:
INSTALL PLUGIN spider SONAME 'ha_spider.so' ;
CREATE TABLE t (i INT (1),v1 CHAR (1),v2 VARCHAR (1), KEY i (i), KEY v (v1,i)) ENGINE=Spider;
HANDLER t OPEN ;
HANDLER t READ next ;
SELECT * FROM t;
HANDLER t READ next ;
Leads to:
10.9.0 ef930dcad58ae6c3f334a32bd63e26c65fd66fa6 (Debug)
Core was generated by `/test/MD050422-mariadb-10.9.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 0x153a40108700 (LWP 3116627))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x0000153a56577859 in __GI_abort () at abort.c:79
#2 0x000055b2a070f8cc in safe_mutex_lock (mp=mp@entry=0x153a0808de10, my_flags=my_flags@entry=0, file=file@entry=0x153a3299fc88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", line=line@entry=10605) at /test/10.9_dbg/mysys/thr_mutex.c:245
#3 0x000055b2a0709e18 in psi_mutex_lock (that=that@entry=0x153a0808de10, file=file@entry=0x153a3299fc88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", line=line@entry=10605) at /test/10.9_dbg/mysys/my_thr_init.c:487
#4 0x0000153a328d01b6 in inline_mysql_mutex_lock (src_line=10605, src_file=0x153a3299fc88 "/test/10.9_dbg/storage/spider/spd_db_conn.cc", that=0x153a0808de10) at /test/10.9_dbg/include/mysql/psi/mysql_thread.h:746
#5 spider_db_open_handler (spider=spider@entry=0x153a0802e5b0, conn=0x153a0808ddb8, link_idx=link_idx@entry=0) at /test/10.9_dbg/storage/spider/spd_db_conn.cc:10605
#6 0x0000153a329311b4 in ha_spider::rnd_handler_init (this=this@entry=0x153a0802e5b0) at /test/10.9_dbg/storage/spider/ha_spider.cc:10604
#7 0x0000153a3293b733 in ha_spider::rnd_next_internal (this=this@entry=0x153a0802e5b0, buf=buf@entry=0x153a08062888 "\377") at /test/10.9_dbg/storage/spider/ha_spider.cc:5867
#8 0x0000153a3293c92c in ha_spider::rnd_next (this=0x153a0802e5b0, buf=0x153a08062888 "\377") at /test/10.9_dbg/storage/spider/ha_spider.cc:6228
#9 0x000055b29fef8407 in handler::ha_rnd_next (this=0x153a0802e5b0, buf=0x153a08062888 "\377") at /test/10.9_dbg/sql/handler.cc:3398
#10 0x000055b29fb8fb3e in mysql_ha_read (thd=thd@entry=0x153a08000db8, tables=tables@entry=0x153a08013f28, 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.9_dbg/sql/sql_handler.cc:923
#11 0x000055b29fbea1c8 in mysql_execute_command (thd=thd@entry=0x153a08000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.9_dbg/sql/sql_limit.h:87
#12 0x000055b29fbd1e23 in mysql_parse (thd=thd@entry=0x153a08000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x153a40107400) at /test/10.9_dbg/sql/sql_parse.cc:8043
#13 0x000055b29fbe0a23 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x153a08000db8, packet=packet@entry=0x153a0800b889 "", packet_length=packet_length@entry=19, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_class.h:1362
#14 0x000055b29fbe3e74 in do_command (thd=0x153a08000db8, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_parse.cc:1407
#15 0x000055b29fd60d2a in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55b2a23f3ba8, put_in_cache=put_in_cache@entry=true) at /test/10.9_dbg/sql/sql_connect.cc:1418
#16 0x000055b29fd6132f in handle_one_connection (arg=arg@entry=0x55b2a23f3ba8) at /test/10.9_dbg/sql/sql_connect.cc:1312
#17 0x000055b2a01eb7a5 in pfs_spawn_thread (arg=0x55b2a23071c8) at /test/10.9_dbg/storage/perfschema/pfs.cc:2201
#18 0x0000153a56a88609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#19 0x0000153a56674163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Bug confirmed present in:
MariaDB: 10.4.25 (dbg), 10.4.25 (opt), 10.5.16 (dbg), 10.5.16 (opt), 10.6.8 (dbg), 10.6.8 (opt), 10.7.4 (dbg), 10.7.4 (opt), 10.8.3 (dbg), 10.8.3 (opt), 10.9.0 (dbg), 10.9.0 (opt)
May affect 10.2 and 10.3 also.
Bug (or feature/syntax) confirmed not present in:
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.37 (dbg), 5.7.37 (opt), 8.0.28 (dbg), 8.0.28 (opt)
Stacks seen with this testcase:
SIGABRT|safe_mutex_lock|inline_mysql_mutex_lock|spider_db_open_handler|ha_spider::rnd_handler_init
SIGABRT|safe_mutex_lock|psi_mutex_lock|inline_mysql_mutex_lock|spider_db_open_handler
SIGSEGV|spider_check_and_set_trx_isolation|ha_spider::external_lock|handler::ha_external_lock|lock_external
SIGSEGV|spider_db_open_handler|ha_spider::rnd_handler_init|ha_spider::rnd_handler_init|ha_spider::rnd_next_internal
SIGSEGV's in spider_check_and_set_trx_isolation and spider_db_open_handler, __pthread_mutex_lock: Assertion `mutex->__data.__owner == 0' failed in psi_mutex_lock and inline_mysql_mutex_lock
SIGSEGV's in spider_check_and_set_trx_isolation and spider_db_open_handler, __pthread_mutex_lock: Assertion `mutex->__data.__owner == 0' failed in psi_mutex_lock and inline_mysql_mutex_lock, SIGABRT in safe_mutex_lock
SIGSEGV's in spider_check_and_set_trx_isolation and spider_db_open_handler, __pthread_mutex_lock: Assertion `mutex->__data.__owner == 0' failed in psi_mutex_lock and inline_mysql_mutex_lock, SIGABRT in safe_mutex_lock
SIGSEGV's in spider_check_and_set_trx_isolation and spider_db_open_handler, __pthread_mutex_lock: Assertion `mutex->__data.__owner == 0' failed in psi_mutex_lock and inline_mysql_mutex_lock, and SIGABRT in safe_mutex_lock
Core was generated by `/test/MD160322-mariadb-10.4.25-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x000014f82c0b5456 in spider_check_and_set_trx_isolation (
conn=0x14f7f40611c8, need_mon=0x14f7f405fb68)
at /test/10.4_opt/storage/spider/spd_trx.cc:1593
[Current thread is 1 (Thread 0x14f82c1d6700 (LWP 4132605))]
(gdb) bt
#0 0x000014f82c0b5456 in spider_check_and_set_trx_isolation (conn=0x14f7f40611c8, need_mon=0x14f7f405fb68) at /test/10.4_opt/storage/spider/spd_trx.cc:1593
#1 0x000014f82c11804c in ha_spider::external_lock (this=0x14f7f4058830, thd=0x14f7f4000c48, lock_type=0) at /test/10.4_opt/storage/spider/ha_spider.cc:1371
#2 0x0000559db529fced in handler::ha_external_lock (this=0x14f7f4058830, thd=thd@entry=0x14f7f4000c48, lock_type=lock_type@entry=0) at /test/10.4_opt/sql/handler.cc:6509
#3 0x0000559db539b459 in lock_external (count=<optimized out>, tables=0x14f7f4061d98, thd=0x14f7f4000c48) at /test/10.4_opt/sql/lock.cc:393
#4 mysql_lock_tables (thd=thd@entry=0x14f7f4000c48, sql_lock=0x14f7f4061d68, flags=<optimized out>) at /test/10.4_opt/sql/lock.cc:338
#5 0x0000559db504c876 in mysql_ha_read (thd=thd@entry=0x14f7f4000c48, tables=tables@entry=0x14f7f4010160, mode=RNEXT, keyname=0x14f7f4010830 "PRIMARY", key_expr=0x0, ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.4_opt/sql/sql_handler.cc:819
#6 0x0000559db5089221 in mysql_execute_command (thd=0x14f7f4000c48) at /test/10.4_opt/sql/sql_parse.cc:5676
#7 0x0000559db508e257 in mysql_parse (thd=0x14f7f4000c48, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_parse.cc:7995
#8 0x0000559db50908cd in dispatch_command (command=COM_QUERY, thd=0x14f7f4000c48, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_class.h:1201
#9 0x0000559db5092f3e in do_command (thd=0x14f7f4000c48) at /test/10.4_opt/sql/sql_parse.cc:1373
#10 0x0000559db5188d3e in do_handle_one_connection (connect=connect@entry=0x559db8e6bb98) at /test/10.4_opt/sql/sql_connect.cc:1420
#11 0x0000559db5188e6f in handle_one_connection (arg=0x559db8e6bb98) at /test/10.4_opt/sql/sql_connect.cc:1316
#12 0x000014f850fb6609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#13 0x000014f850ba2133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
need_mon=<optimized out>) at /test/10.4_dbg/storage/spider/spd_trx.cc:1593
[Current thread is 1 (Thread 0x149d08138700 (LWP 2912310))]
(gdb) bt
#0 spider_check_and_set_trx_isolation (conn=0x149cbc095120, need_mon=<optimized out>) at /test/10.4_dbg/storage/spider/spd_trx.cc:1593
#1 0x0000149cf8118e90 in ha_spider::external_lock (this=0x149cbc083588, thd=0x149cbc000d90, lock_type=0) at /test/10.4_dbg/storage/spider/ha_spider.cc:1371
#2 0x00005618ac5afe84 in handler::ha_external_lock (this=0x149cbc083588, thd=thd@entry=0x149cbc000d90, lock_type=lock_type@entry=0) at /test/10.4_dbg/sql/handler.cc:6509
#3 0x00005618ac70f6f6 in lock_external (count=1, tables=0x149cbc0ceee0, thd=0x149cbc000d90) at /test/10.4_dbg/sql/lock.cc:393
#4 mysql_lock_tables (thd=thd@entry=0x149cbc000d90, sql_lock=0x149cbc0ceeb0, flags=<optimized out>) at /test/10.4_dbg/sql/lock.cc:338
#5 0x00005618ac29d5ee in mysql_ha_read (thd=thd@entry=0x149cbc000d90, tables=tables@entry=0x149cbc0133a8, mode=RNEXT, keyname=0x149cbc013a78 "PRIMARY", key_expr=0xa5a5a5a5a5a5a5a5, ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.4_dbg/sql/sql_handler.cc:819
#6 0x00005618ac2ed793 in mysql_execute_command (thd=thd@entry=0x149cbc000d90) at /test/10.4_dbg/sql/sql_parse.cc:5676
#7 0x00005618ac2f1d01 in mysql_parse (thd=thd@entry=0x149cbc000d90, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x149d08137490, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_parse.cc:7995
#8 0x00005618ac2f475d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x149cbc000d90, packet=packet@entry=0x149cbc01a361 "HANDLER t READ `PRIMARY` NEXT", packet_length=packet_length@entry=29, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_class.h:1201
#9 0x00005618ac2f8050 in do_command (thd=0x149cbc000d90) at /test/10.4_dbg/sql/sql_parse.cc:1373
#10 0x00005618ac437457 in do_handle_one_connection (connect=connect@entry=0x5618affa6120) at /test/10.4_dbg/sql/sql_connect.cc:1420
#11 0x00005618ac437576 in handle_one_connection (arg=0x5618affa6120) at /test/10.4_dbg/sql/sql_connect.cc:1316
#12 0x0000149d1d50c609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#13 0x0000149d1d0f8133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Core was generated by `/test/MD160322-mariadb-10.4.25-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x0000145d55b75dd1 in ha_spider::external_lock (this=0x145d18057c50, thd=
0x145d18000c48, lock_type=0)
at /test/10.4_opt/storage/spider/ha_spider.cc:1403
[Current thread is 1 (Thread 0x145d640fd700 (LWP 111473))]
(gdb) bt
#0 0x0000145d55b75dd1 in ha_spider::external_lock (this=0x145d18057c50, thd=0x145d18000c48, lock_type=0) at /test/10.4_opt/storage/spider/ha_spider.cc:1403
#1 0x000055b216c8dced in handler::ha_external_lock (this=0x145d18057c50, thd=thd@entry=0x145d18000c48, lock_type=lock_type@entry=0) at /test/10.4_opt/sql/handler.cc:6509
#2 0x000055b216d89459 in lock_external (count=<optimized out>, tables=0x145d18082118, thd=0x145d18000c48) at /test/10.4_opt/sql/lock.cc:393
#3 mysql_lock_tables (thd=thd@entry=0x145d18000c48, sql_lock=0x145d180820e8, flags=<optimized out>) at /test/10.4_opt/sql/lock.cc:338
#4 0x000055b216a3a876 in mysql_ha_read (thd=thd@entry=0x145d18000c48, tables=tables@entry=0x145d18010160, mode=RNEXT, keyname=0x145d18010830 "PRIMARY", key_expr=0x0, ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.4_opt/sql/sql_handler.cc:819
#5 0x000055b216a77221 in mysql_execute_command (thd=0x145d18000c48) at /test/10.4_opt/sql/sql_parse.cc:5676
#6 0x000055b216a7c257 in mysql_parse (thd=0x145d18000c48, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_parse.cc:7995
#7 0x000055b216a7e8cd in dispatch_command (command=COM_QUERY, thd=0x145d18000c48, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_class.h:1201
#8 0x000055b216a80f3e in do_command (thd=0x145d18000c48) at /test/10.4_opt/sql/sql_parse.cc:1373
#9 0x000055b216b76d3e in do_handle_one_connection (connect=connect@entry=0x55b21a6b2ce8) at /test/10.4_opt/sql/sql_connect.cc:1420
#10 0x000055b216b76e6f in handle_one_connection (arg=0x55b21a6b2ce8) at /test/10.4_opt/sql/sql_connect.cc:1316
#11 0x0000145d7c4b5609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#12 0x0000145d7c0a1133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Roel Van de Paar
added a comment - A longer variant on the above testcase sometimes results in different stacks:
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE TABLE t (c INT ) ENGINE=Spider;
EXPLAIN SELECT * FROM t AS x,t AS y;
HANDLER t OPEN ;
SELECT * FROM t;
SELECT 1 + 18446744073709551615;
HANDLER t READ ` PRIMARY ` NEXT ;
Leads to:
10.4.25 9c6135e81f29b3e3286d6b864c0fdafc2fea16ce (Optimized)
Core was generated by `/test/MD160322-mariadb-10.4.25-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x0000145d55b75dd1 in ha_spider::external_lock (this=0x145d18057c50, thd=
0x145d18000c48, lock_type=0)
at /test/10.4_opt/storage/spider/ha_spider.cc:1403
[Current thread is 1 (Thread 0x145d640fd700 (LWP 111473))]
(gdb) bt
#0 0x0000145d55b75dd1 in ha_spider::external_lock (this=0x145d18057c50, thd=0x145d18000c48, lock_type=0) at /test/10.4_opt/storage/spider/ha_spider.cc:1403
#1 0x000055b216c8dced in handler::ha_external_lock (this=0x145d18057c50, thd=thd@entry=0x145d18000c48, lock_type=lock_type@entry=0) at /test/10.4_opt/sql/handler.cc:6509
#2 0x000055b216d89459 in lock_external (count=<optimized out>, tables=0x145d18082118, thd=0x145d18000c48) at /test/10.4_opt/sql/lock.cc:393
#3 mysql_lock_tables (thd=thd@entry=0x145d18000c48, sql_lock=0x145d180820e8, flags=<optimized out>) at /test/10.4_opt/sql/lock.cc:338
#4 0x000055b216a3a876 in mysql_ha_read (thd=thd@entry=0x145d18000c48, tables=tables@entry=0x145d18010160, mode=RNEXT, keyname=0x145d18010830 "PRIMARY", key_expr=0x0, ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.4_opt/sql/sql_handler.cc:819
#5 0x000055b216a77221 in mysql_execute_command (thd=0x145d18000c48) at /test/10.4_opt/sql/sql_parse.cc:5676
#6 0x000055b216a7c257 in mysql_parse (thd=0x145d18000c48, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_parse.cc:7995
#7 0x000055b216a7e8cd in dispatch_command (command=COM_QUERY, thd=0x145d18000c48, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_class.h:1201
#8 0x000055b216a80f3e in do_command (thd=0x145d18000c48) at /test/10.4_opt/sql/sql_parse.cc:1373
#9 0x000055b216b76d3e in do_handle_one_connection (connect=connect@entry=0x55b21a6b2ce8) at /test/10.4_opt/sql/sql_connect.cc:1420
#10 0x000055b216b76e6f in handle_one_connection (arg=0x55b21a6b2ce8) at /test/10.4_opt/sql/sql_connect.cc:1316
#11 0x0000145d7c4b5609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#12 0x0000145d7c0a1133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Bug confirmed present in:
MariaDB: 10.4.25 (dbg), 10.4.25 (opt)
Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.3.35 (dbg), 10.3.35 (opt), 10.5.16 (dbg), 10.5.16 (opt), 10.6.8 (dbg), 10.6.8 (opt), 10.7.4 (dbg), 10.7.4 (opt), 10.8.3 (dbg), 10.8.3 (opt), 10.9.0 (opt), 10.9.0 (dbg), 10.10.0 (dbg), 10.10.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.37 (dbg), 5.7.37 (opt), 8.0.28 (dbg), 8.0.28 (opt)
The UniqueID for this is
SIGSEGV|ha_spider::external_lock|handler::ha_external_lock|lock_external|mysql_lock_tables
Which was previously unseen.
SIGSEGV's in spider_check_and_set_trx_isolation and spider_db_open_handler, __pthread_mutex_lock: Assertion `mutex->__data.__owner == 0' failed in psi_mutex_lock and inline_mysql_mutex_lock, and SIGABRT in safe_mutex_lock
SIGSEGV's in spider_check_and_set_trx_isolation, spider_db_open_handler, and ha_spider::external_lock and __pthread_mutex_lock: Assertion `mutex->__data.__owner == 0' failed in psi_mutex_lock and inline_mysql_mutex_lock, and SIGABRT in safe_mutex_lock
[ The server fails earlier with the ASAN build. So, I now concentrate on the ASAN failure. The problem here is that the freed connection is still in {{trx->trx_conn_hash}}.
]
The cause of the heap-use-after-free is that a single connection is referenced from both trx->trx_conn_hash and spider->conns. spider_free_conn_from_trx() only removes the connection from the hash and then Spider access spider->conns (boom!).
Nayuta Yanagisawa (Inactive)
added a comment - - edited The cause of the heap-use-after-free is that a single connection is referenced from both trx->trx_conn_hash and spider->conns . spider_free_conn_from_trx() only removes the connection from the hash and then Spider access spider->conns (boom!).
Spider seems to implicitly assume that ha_spider is freed almost the same time as a running transaction ends. This is my guess but, based on the assumption, Spider tries to free connections at the end of transactions, i.e., at the call of spider_commit and spider_rollback.
The assumption seems to hold in most cases but in some cases not. The release of the storage engine's handler (ha_spider) is the responsibility of the server, so making strong assumptions arbitrarily, such as at what timing the handler will be released, will lead to problems.
Nayuta Yanagisawa (Inactive)
added a comment - - edited Spider seems to implicitly assume that ha_spider is freed almost the same time as a running transaction ends. This is my guess but, based on the assumption, Spider tries to free connections at the end of transactions, i.e., at the call of spider_commit and spider_rollback .
The assumption seems to hold in most cases but in some cases not. The release of the storage engine's handler (ha_spider) is the responsibility of the server, so making strong assumptions arbitrarily, such as at what timing the handler will be released, will lead to problems.
My current understanding is that the bug can be solved by placing connections only in SPIDER_TRX (not ha_spider) and matching the lifetime of the connections with SPIDER_TRX.
Nayuta Yanagisawa (Inactive)
added a comment - My current understanding is that the bug can be solved by placing connections only in SPIDER_TRX (not ha_spider) and matching the lifetime of the connections with SPIDER_TRX.
+ conn_hash_freed == TRUE means that elements of trx_conn_hash has been freed
+ and ha_spider::conns maintains freed connections. In such a case, we need
+ to call get_conn() or its wrapper functions before accessing data nodes.
+ */
+ bool conn_hash_freed;
+
ulonglong direct_update_count;
ulonglong direct_delete_count;
Note that the above diff is just for showing the idea of the fix and is still incomplete.
Nayuta Yanagisawa (Inactive)
added a comment - The above fix requires significant code changes. Another way to fix the bug would be like the following:
diff --git a/storage/spider/ha_spider.cc b/storage/spider/ha_spider.cc
index 533e308dc4e..9587a35365d 100644
--- a/storage/spider/ha_spider.cc
+++ b/storage/spider/ha_spider.cc
@@ -5977,6 +5977,13 @@ int ha_spider::rnd_next(
DBUG_RETURN(error_num);
use_pre_call = FALSE;
}
+
+ SPIDER_TRX *trx= this ->wide_handler->trx;
+ if (trx->conn_hash_freed &&
+ (error_num= spider_check_trx_and_get_conn(trx->thd, this , FALSE)))
+ {
+ DBUG_RETURN(error_num);
+ }
DBUG_RETURN(rnd_next_internal(buf));
}
diff --git a/storage/spider/spd_conn.cc b/storage/spider/spd_conn.cc
index 366a22ef8d2..5374fd15182 100644
--- a/storage/spider/spd_conn.cc
+++ b/storage/spider/spd_conn.cc
@@ -291,6 +291,8 @@ void spider_free_conn_from_trx(
spider_conn_clear_queue(conn);
conn->use_for_active_standby = FALSE;
conn->error_mode = 1;
+ trx->conn_hash_freed= !another;
+
if (
trx_free ||
(
diff --git a/storage/spider/spd_include.h b/storage/spider/spd_include.h
index 6df79e4e2c8..7c8299e783b 100644
--- a/storage/spider/spd_include.h
+++ b/storage/spider/spd_include.h
@@ -662,13 +662,19 @@ typedef struct st_spider_transaction
ulonglong trx_conn_adjustment;
uint locked_connections;
+ /*
+ conn_hash_freed == TRUE means that elements of trx_conn_hash has been freed
+ and ha_spider::conns maintains freed connections. In such a case, we need
+ to call get_conn() or its wrapper functions before accessing data nodes.
+ */
+ bool conn_hash_freed;
+
ulonglong direct_update_count;
ulonglong direct_delete_count;
Note that the above diff is just for showing the idea of the fix and is still incomplete.
Interesting new testcase which leads to all sorts of issues.
INSTALL PLUGIN Spider SONAME 'ha_spider.so';
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock', DATABASE'test', USER'Spider', PASSWORD'PWD123');
CREATETABLE t1 (a TEXT, b CHAR(255), c CHAR(4)) ENGINE=Spider COMMENT='WRAPPER "mysql", srv "srv", TABLE "t"';
CREATETABLE t2 SELECT f2 FROM (SELECTMAX(NOW()) f2 FROM t1) a;
SET SESSION tx_read_only=TRUE;
EXPLAIN SELECT * FROM t1,t1 AS t2 WHERE t1.x=t2.y;
HANDLER t1 OPEN;
HANDLER t1 READFIRST LIMIT 9;
SELECT * FROM t1 GROUPBY c1 COLLATE utf8mb4_slovenian_ci;
HANDLER t1 READFIRST;
SELECT SLEEP (3);
Summarizing the issues observed thus far:
1. Running this against a somewhat older build (19 August), results in a hang on the HANDLER t1 READ FIRST; query. Pressing CTRL+c twice in the client results in ERROR 2013 (HY000): Lost connection to server during query, however the server is not crashed. Still, it reports in the error log:
#4 0x00001524341361d9 in __pthread_tpp_change_priority (previous_prio=previous_prio@entry=-1, new_prio=new_prio@entry=0) at tpp.c:82
#5 0x000015243412bb09 in __pthread_mutex_lock_full (mutex=0x1523d80cf4d0) at ../nptl/pthread_mutex_lock.c:545
#6 0x000015243412c055 in __GI___pthread_mutex_lock (mutex=mutex@entry=0x1523d80cf4d0) at ../nptl/pthread_mutex_lock.c:73
#7 0x000056091b0d074e in safe_mutex_lock (mp=mp@entry=0x1523d80cf4d0, my_flags=my_flags@entry=0, file=file@entry=0x1524035cf920 "/test/10.11_dbg/storage/spider/ha_spider.cc", line=line@entry=5788) at /test/10.11_dbg/mysys/thr_mutex.c:238
#8 0x000015240356b860 in inline_mysql_mutex_lock (src_line=5788, src_file=0x1524035cf920 "/test/10.11_dbg/storage/spider/ha_spider.cc", that=0x1523d80cf4d0) at /test/10.11_dbg/include/mysql/psi/mysql_thread.h:750
#9 ha_spider::rnd_next_internal (this=this@entry=0x1523d802fee0, buf=buf@entry=0x1523d802fa58 "\377") at /test/10.11_dbg/storage/spider/ha_spider.cc:5788
#10 0x000015240356c046 in ha_spider::rnd_next (this=0x1523d802fee0, buf=0x1523d802fa58 "\377") at /test/10.11_dbg/storage/spider/ha_spider.cc:5965
#11 0x000056091a9919f0 in handler::ha_rnd_next (this=0x1523d802fee0, buf=0x1523d802fa58 "\377") at /test/10.11_dbg/sql/handler.cc:3415
#12 0x000056091a65629a in mysql_ha_read (thd=thd@entry=0x1523d8000db8, tables=tables@entry=0x1523d8013d88, 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.11_dbg/sql/sql_handler.cc:925
#13 0x000056091a6aad2f in mysql_execute_command (thd=thd@entry=0x1523d8000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_limit.h:87
#14 0x000056091a6944fa in mysql_parse (thd=thd@entry=0x1523d8000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x15241c099330) at /test/10.11_dbg/sql/sql_parse.cc:8035
#15 0x000056091a6a1ae2 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1523d8000db8, packet=packet@entry=0x1523d800b6e9 "", packet_length=packet_length@entry=21, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_class.h:1339
#16 0x000056091a6a41ec in do_command (thd=0x1523d8000db8, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407
#17 0x000056091a80683e in do_handle_one_connection (connect=<optimized out>, connect@entry=0x56091dda5358, put_in_cache=put_in_cache@entry=true) at /test/10.11_dbg/sql/sql_connect.cc:1418
#18 0x000056091a806d47 in handle_one_connection (arg=0x56091dda5358) at /test/10.11_dbg/sql/sql_connect.cc:1312
#19 0x0000152434129609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#20 0x0000152433d15133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
3. Furthermore, if we remove only GROUP BY c1 COLLATE utf8mb4_slovenian_ci, we get (using the same build) the crash from MENT-1519:
INSTALL PLUGIN Spider SONAME 'ha_spider.so';
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock', DATABASE'test', USER'Spider', PASSWORD'PWD123');
CREATETABLE t1 (a TEXT, b CHAR(255), c CHAR(4)) ENGINE=Spider COMMENT='WRAPPER "mysql", srv "srv", TABLE "t"';
CREATETABLE t2 SELECT f2 FROM (SELECTMAX(NOW()) f2 FROM t1) a;
SET SESSION tx_read_only=TRUE;
EXPLAIN SELECT * FROM t1,t1 AS t2 WHERE t1.x=t2.y;
4. Running the original testcase in this comment against a more recent debug build (15/9) also yields the MENT-1519 stacks instead of the new_prio assert. Also checked build as of today (19/9 @ 6ebdd3013a18b01dbecec76b870810329eb76586) with the same outcome.
5. Running the original testcase in this comment against all versions/build types (opt/dbg) made 10.8, 10.9 and 10.11 (all three in optimized builds) hang, but not 10.10. mysqladmin shutdown also hung when attempted on these builds.
6. Running the original testcase in this comment against all versions/build types (opt/dbg) yielded a long list of issues besides the hangs:
Roel Van de Paar
added a comment - - edited Interesting new testcase which leads to all sorts of issues.
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock' , DATABASE 'test' , USER 'Spider' , PASSWORD 'PWD123' );
CREATE TABLE t1 (a TEXT, b CHAR (255), c CHAR (4)) ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
CREATE TABLE t2 SELECT f2 FROM ( SELECT MAX (NOW()) f2 FROM t1) a;
SET SESSION tx_read_only= TRUE ;
EXPLAIN SELECT * FROM t1,t1 AS t2 WHERE t1.x=t2.y;
HANDLER t1 OPEN ;
HANDLER t1 READ FIRST LIMIT 9;
SELECT * FROM t1 GROUP BY c1 COLLATE utf8mb4_slovenian_ci;
HANDLER t1 READ FIRST ;
SELECT SLEEP (3);
Summarizing the issues observed thus far:
1. Running this against a somewhat older build (19 August), results in a hang on the HANDLER t1 READ FIRST; query. Pressing CTRL+c twice in the client results in ERROR 2013 (HY000): Lost connection to server during query , however the server is not crashed. Still, it reports in the error log:
10.11.0 bc563f1a4b0b38de3b41fd0f0d3d8b7f1aacbd8b (Debug)
Version: '10.11.0-MariaDB-debug' socket: '/test/MD190822-mariadb-10.11.0-linux-x86_64-dbg/socket.sock' port: 10973 MariaDB Server
2022-09-19 15:46:02 25 [Warning] Access denied for user 'Spider'@'localhost' (using password: YES)
2022-09-19 15:46:02 26 [Warning] Access denied for user 'Spider'@'localhost' (using password: YES)
2022-09-19 15:46:02 4 [ERROR] mysql_ha_read: Got error 12701 when reading table 't1'
2. Running this against a build from 31 August, results in a new assert and stack:
10.11.0 fe1f8f2c6b6f3b8e3383168225f9ae7853028947 (Debug)
mysqld: tpp.c:82: __pthread_tpp_change_priority: Assertion `new_prio == -1 || (new_prio >= fifo_min_prio && new_prio <= fifo_max_prio)' failed.
10.11.0 fe1f8f2c6b6f3b8e3383168225f9ae7853028947 (Debug)
Core was generated by `/test/MD310822-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 0x15241c09a700 (LWP 1260683))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x0000152433c18859 in __GI_abort () at abort.c:79
#2 0x0000152433c18729 in __assert_fail_base (fmt=0x152433dae588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x152434139120 "new_prio == -1 || (new_prio >= fifo_min_prio && new_prio <= fifo_max_prio)", file=0x152434139114 "tpp.c", line=82, function=<optimized out>) at assert.c:92
#3 0x0000152433c29fd6 in __GI___assert_fail (assertion=assertion@entry=0x152434139120 "new_prio == -1 || (new_prio >= fifo_min_prio && new_prio <= fifo_max_prio)", file=file@entry=0x152434139114 "tpp.c", line=line@entry=82, function=function@entry=0x1524341391d0 <__PRETTY_FUNCTION__.7875> "__pthread_tpp_change_priority") at assert.c:101
#4 0x00001524341361d9 in __pthread_tpp_change_priority (previous_prio=previous_prio@entry=-1, new_prio=new_prio@entry=0) at tpp.c:82
#5 0x000015243412bb09 in __pthread_mutex_lock_full (mutex=0x1523d80cf4d0) at ../nptl/pthread_mutex_lock.c:545
#6 0x000015243412c055 in __GI___pthread_mutex_lock (mutex=mutex@entry=0x1523d80cf4d0) at ../nptl/pthread_mutex_lock.c:73
#7 0x000056091b0d074e in safe_mutex_lock (mp=mp@entry=0x1523d80cf4d0, my_flags=my_flags@entry=0, file=file@entry=0x1524035cf920 "/test/10.11_dbg/storage/spider/ha_spider.cc", line=line@entry=5788) at /test/10.11_dbg/mysys/thr_mutex.c:238
#8 0x000015240356b860 in inline_mysql_mutex_lock (src_line=5788, src_file=0x1524035cf920 "/test/10.11_dbg/storage/spider/ha_spider.cc", that=0x1523d80cf4d0) at /test/10.11_dbg/include/mysql/psi/mysql_thread.h:750
#9 ha_spider::rnd_next_internal (this=this@entry=0x1523d802fee0, buf=buf@entry=0x1523d802fa58 "\377") at /test/10.11_dbg/storage/spider/ha_spider.cc:5788
#10 0x000015240356c046 in ha_spider::rnd_next (this=0x1523d802fee0, buf=0x1523d802fa58 "\377") at /test/10.11_dbg/storage/spider/ha_spider.cc:5965
#11 0x000056091a9919f0 in handler::ha_rnd_next (this=0x1523d802fee0, buf=0x1523d802fa58 "\377") at /test/10.11_dbg/sql/handler.cc:3415
#12 0x000056091a65629a in mysql_ha_read (thd=thd@entry=0x1523d8000db8, tables=tables@entry=0x1523d8013d88, 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.11_dbg/sql/sql_handler.cc:925
#13 0x000056091a6aad2f in mysql_execute_command (thd=thd@entry=0x1523d8000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_limit.h:87
#14 0x000056091a6944fa in mysql_parse (thd=thd@entry=0x1523d8000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x15241c099330) at /test/10.11_dbg/sql/sql_parse.cc:8035
#15 0x000056091a6a1ae2 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1523d8000db8, packet=packet@entry=0x1523d800b6e9 "", packet_length=packet_length@entry=21, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_class.h:1339
#16 0x000056091a6a41ec in do_command (thd=0x1523d8000db8, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407
#17 0x000056091a80683e in do_handle_one_connection (connect=<optimized out>, connect@entry=0x56091dda5358, put_in_cache=put_in_cache@entry=true) at /test/10.11_dbg/sql/sql_connect.cc:1418
#18 0x000056091a806d47 in handle_one_connection (arg=0x56091dda5358) at /test/10.11_dbg/sql/sql_connect.cc:1312
#19 0x0000152434129609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#20 0x0000152433d15133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
3. Furthermore, if we remove only GROUP BY c1 COLLATE utf8mb4_slovenian_ci , we get (using the same build) the crash from MENT-1519:
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock' , DATABASE 'test' , USER 'Spider' , PASSWORD 'PWD123' );
CREATE TABLE t1 (a TEXT, b CHAR (255), c CHAR (4)) ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
CREATE TABLE t2 SELECT f2 FROM ( SELECT MAX (NOW()) f2 FROM t1) a;
SET SESSION tx_read_only= TRUE ;
EXPLAIN SELECT * FROM t1,t1 AS t2 WHERE t1.x=t2.y;
HANDLER t1 OPEN ;
HANDLER t1 READ FIRST LIMIT 9;
SELECT * FROM t1; # Changed query
HANDLER t1 READ FIRST ;
SELECT SLEEP (3);
Leads to UniqueID:
SIGSEGV|ha_spider::rnd_next_internal|ha_spider::rnd_next|handler::ha_rnd_next|mysql_ha_read # MENT-1519
4. Running the original testcase in this comment against a more recent debug build (15/9) also yields the MENT-1519 stacks instead of the new_prio assert. Also checked build as of today (19/9 @ 6ebdd3013a18b01dbecec76b870810329eb76586) with the same outcome.
5. Running the original testcase in this comment against all versions/build types (opt/dbg) made 10.8, 10.9 and 10.11 (all three in optimized builds) hang, but not 10.10. mysqladmin shutdown also hung when attempted on these builds.
6. Running the original testcase in this comment against all versions/build types (opt/dbg) yielded a long list of issues besides the hangs:
SIGSEGV|__strlen_avx2|__vfprintf_internal|buffered_vfprintf|__vfprintf_internal
SIGSEGV|ha_spider::rnd_next_internal|ha_spider::rnd_next|handler::ha_rnd_next|mysql_ha_read
SIGSEGV|ha_spider::rnd_next_internal|handler::ha_rnd_next|mysql_ha_read|mysql_execute_command
SIGSEGV|spider_check_and_set_trx_isolation|ha_spider::external_lock|handler::ha_external_lock|lock_external
SIGSEGV|spider_db_open_handler|ha_spider::rnd_handler_init|ha_spider::rnd_handler_init|ha_spider::rnd_next_internal
SIGSEGV|spider_db_open_handler|ha_spider::rnd_handler_init|ha_spider::rnd_next_internal|ha_spider::rnd_next
new_prio == -1 || (new_prio >= fifo_min_prio && new_prio <= fifo_max_prio)|SIGABRT|__pthread_tpp_change_priority|__pthread_mutex_lock_full|__GI___pthread_mutex_lock|safe_mutex_lock
Of these, the following had not been observed before:
SIGSEGV|__strlen_avx2|__vfprintf_internal|buffered_vfprintf|__vfprintf_internal
SIGSEGV|ha_spider::rnd_next_internal|handler::ha_rnd_next|mysql_ha_read|mysql_execute_command
new_prio == -1 || (new_prio >= fifo_min_prio && new_prio <= fifo_max_prio)|SIGABRT|__pthread_tpp_change_priority|__pthread_mutex_lock_full|__GI___pthread_mutex_lock|safe_mutex_lock
SIGSEGV's in spider_check_and_set_trx_isolation, spider_db_open_handler, and ha_spider::external_lock and __pthread_mutex_lock: Assertion `mutex->__data.__owner == 0' failed in psi_mutex_lock and inline_mysql_mutex_lock, and SIGABRT in safe_mutex_lock
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock', DATABASE'test', USER'Spider', PASSWORD'PWD123');
CREATETABLE t1 (a INT, b CHAR(10), c CHAR(10), filler CHAR(10), PRIMARYKEY(a, b (2)), UNIQUEKEY(a, c (2))) CHARACTERSET ucs2 ENGINE=Spider COMMENT='WRAPPER "mysql", srv "srv", TABLE "t"';
at /test/10.11_dbg/storage/spider/ha_spider.cc:1445
[Current thread is 1 (Thread 0x148d70209700 (LWP 365878))]
(gdb) bt
#0 0x0000148d7012c164 in ha_spider::index_read_map_internal (this=this@entry=0x148d1802e6a0, buf=buf@entry=0x148d1802e288 "\377\066", key=key@entry=0x148d18013b78 "6", keypart_map=keypart_map@entry=1, find_flag=find_flag@entry=HA_READ_AFTER_KEY) at /test/10.11_dbg/storage/spider/ha_spider.cc:1445
#1 0x0000148d7012cd87 in ha_spider::index_read_map (this=0x148d1802e6a0, buf=0x148d1802e288 "\377\066", key=0x148d18013b78 "6", keypart_map=1, find_flag=HA_READ_AFTER_KEY) at /test/10.11_dbg/storage/spider/ha_spider.cc:1632
#2 0x0000559ed2126e41 in handler::ha_index_read_map (this=0x148d1802e6a0, buf=0x148d1802e288 "\377\066", key=key@entry=0x148d18013b78 "6", keypart_map=1, find_flag=find_flag@entry=HA_READ_AFTER_KEY) at /test/10.11_dbg/sql/handler.cc:3472
#3 0x0000559ed1de87c4 in mysql_ha_read (thd=thd@entry=0x148d18000d48, tables=tables@entry=0x148d18013348, mode=<optimized out>, keyname=0x148d18013a30 "a", key_expr=<optimized out>, ha_rkey_mode=HA_READ_AFTER_KEY, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.11_dbg/sql/sql_handler.cc:965
#4 0x0000559ed1e3d90e in mysql_execute_command (thd=thd@entry=0x148d18000d48, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_limit.h:87
#5 0x0000559ed1e2703c in mysql_parse (thd=thd@entry=0x148d18000d48, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x148d70208330) at /test/10.11_dbg/sql/sql_parse.cc:8037
#6 0x0000559ed1e3466d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x148d18000d48, packet=packet@entry=0x148d1800aed9 "", packet_length=packet_length@entry=23, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_class.h:1345
#7 0x0000559ed1e36d97 in do_command (thd=0x148d18000d48, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407
#8 0x0000559ed1f9afb9 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x559ed4921748, put_in_cache=put_in_cache@entry=true) at /test/10.11_dbg/sql/sql_connect.cc:1416
#9 0x0000559ed1f9b4c3 in handle_one_connection (arg=0x559ed4921748) at /test/10.11_dbg/sql/sql_connect.cc:1318
#10 0x0000148d89c84609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#11 0x0000148d89870133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
In all error logs: all versions 10.4-10.11, and in both build types dbg+opt, which looks understandable (ref MDEV-26543) given that no Spider user was defined?
Roel Van de Paar
added a comment - - edited Another testcase leading to additional stacks.
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock' , DATABASE 'test' , USER 'Spider' , PASSWORD 'PWD123' );
CREATE TABLE t1 (a INT , b CHAR (10), c CHAR (10), filler CHAR (10), PRIMARY KEY (a, b (2)), UNIQUE KEY (a, c (2))) CHARACTER SET ucs2 ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
HANDLER t1 OPEN ;
HANDLER t1 READ a> (54);
HANDLER t1 READ a> (54);
Leads to:
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 SIGSEGV, Segmentation fault.
#0 0x0000148d7012c164 in ha_spider::index_read_map_internal (
this=this@entry=0x148d1802e6a0, buf=buf@entry=0x148d1802e288 "\377\066",
key=key@entry=0x148d18013b78 "6", keypart_map=keypart_map@entry=1,
find_flag=find_flag@entry=HA_READ_AFTER_KEY)
at /test/10.11_dbg/storage/spider/ha_spider.cc:1445
[Current thread is 1 (Thread 0x148d70209700 (LWP 365878))]
(gdb) bt
#0 0x0000148d7012c164 in ha_spider::index_read_map_internal (this=this@entry=0x148d1802e6a0, buf=buf@entry=0x148d1802e288 "\377\066", key=key@entry=0x148d18013b78 "6", keypart_map=keypart_map@entry=1, find_flag=find_flag@entry=HA_READ_AFTER_KEY) at /test/10.11_dbg/storage/spider/ha_spider.cc:1445
#1 0x0000148d7012cd87 in ha_spider::index_read_map (this=0x148d1802e6a0, buf=0x148d1802e288 "\377\066", key=0x148d18013b78 "6", keypart_map=1, find_flag=HA_READ_AFTER_KEY) at /test/10.11_dbg/storage/spider/ha_spider.cc:1632
#2 0x0000559ed2126e41 in handler::ha_index_read_map (this=0x148d1802e6a0, buf=0x148d1802e288 "\377\066", key=key@entry=0x148d18013b78 "6", keypart_map=1, find_flag=find_flag@entry=HA_READ_AFTER_KEY) at /test/10.11_dbg/sql/handler.cc:3472
#3 0x0000559ed1de87c4 in mysql_ha_read (thd=thd@entry=0x148d18000d48, tables=tables@entry=0x148d18013348, mode=<optimized out>, keyname=0x148d18013a30 "a", key_expr=<optimized out>, ha_rkey_mode=HA_READ_AFTER_KEY, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.11_dbg/sql/sql_handler.cc:965
#4 0x0000559ed1e3d90e in mysql_execute_command (thd=thd@entry=0x148d18000d48, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_limit.h:87
#5 0x0000559ed1e2703c in mysql_parse (thd=thd@entry=0x148d18000d48, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x148d70208330) at /test/10.11_dbg/sql/sql_parse.cc:8037
#6 0x0000559ed1e3466d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x148d18000d48, packet=packet@entry=0x148d1800aed9 "", packet_length=packet_length@entry=23, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_class.h:1345
#7 0x0000559ed1e36d97 in do_command (thd=0x148d18000d48, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407
#8 0x0000559ed1f9afb9 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x559ed4921748, put_in_cache=put_in_cache@entry=true) at /test/10.11_dbg/sql/sql_connect.cc:1416
#9 0x0000559ed1f9b4c3 in handle_one_connection (arg=0x559ed4921748) at /test/10.11_dbg/sql/sql_connect.cc:1318
#10 0x0000148d89c84609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#11 0x0000148d89870133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Bug confirmed present in:
MariaDB: 10.4.27 (dbg), 10.4.27 (opt), 10.5.18 (dbg), 10.6.10 (dbg), 10.8.5 (dbg), 10.9.3 (dbg), 10.10.2 (dbg), 10.11.0 (dbg)
Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.3.37 (dbg), 10.3.37 (opt), 10.5.18 (opt), 10.6.10 (opt), 10.7.6 (dbg), 10.7.6 (opt), 10.8.5 (opt), 10.9.3 (opt), 10.10.2 (opt), 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)
UniqueID's observed with this testcase:
SIGSEGV|spider_check_and_set_trx_isolation|ha_spider::external_lock|handler::ha_external_lock|lock_external
SIGSEGV|ha_spider::index_read_map_internal|ha_spider::index_read_map|handler::ha_index_read_map|mysql_ha_read
SIGSEGV|spider_db_open_handler|ha_spider::index_handler_init|ha_spider::index_read_map_internal|ha_spider::index_read_map
Of which the last two are new, and the first one is associated with this bug and MENT-1519.
As a sidenote, this testcase also produces:
2022-09-20 18:45:34 4 [ERROR] mysql_ha_read: Got error 12701 when reading table 't1'
In all error logs: all versions 10.4-10.11, and in both build types dbg+opt, which looks understandable (ref MDEV-26543 ) given that no Spider user was defined?
at /test/10.11_opt/storage/spider/spd_db_conn.cc:834
[Current thread is 1 (Thread 0x14bf4873c700 (LWP 869025))]
(gdb) bt
#0 0x000014bf4863c287 in spider_db_set_names_internal (trx=<optimized out>, share=0x14bec8059198, conn=conn@entry=0x14bec80611d8, all_link_idx=0, need_mon=0x14bec805fac0) at /test/10.11_opt/storage/spider/spd_db_conn.cc:834
#1 0x000014bf4863c399 in spider_db_set_names (spider=spider@entry=0x14bec8026be0, conn=conn@entry=0x14bec80611d8, link_idx=link_idx@entry=0) at /test/10.11_opt/storage/spider/spd_db_conn.cc:857
#2 0x000014bf4868a122 in ha_spider::rnd_next_internal (this=0x14bec8026be0, buf=0x14bec80267c8 "\377") at /test/10.11_opt/storage/spider/ha_spider.cc:5797
#3 0x0000560982eb7bc6 in handler::ha_rnd_next (this=0x14bec8026be0, buf=0x14bec80267c8 "\377") at /test/10.11_opt/sql/handler.cc:3415
#4 0x0000560982c2c6f0 in mysql_ha_read (thd=thd@entry=0x14bec8000c58, tables=tables@entry=0x14bec8010978, 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.11_opt/sql/sql_handler.cc:925
#5 0x0000560982c726c2 in mysql_execute_command (thd=0x14bec8000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.11_opt/sql/sql_limit.h:87
#6 0x0000560982c61205 in mysql_parse (rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, thd=0x14bec8000c58) at /test/10.11_opt/sql/sql_parse.cc:8037
#8 0x0000560982c6cd6a in dispatch_command (command=COM_QUERY, thd=0x14bec8000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.11_opt/sql/sql_class.h:1345
#9 0x0000560982c6ecb2 in do_command (thd=0x14bec8000c58, blocking=blocking@entry=true) at /test/10.11_opt/sql/sql_parse.cc:1407
#10 0x0000560982d8817f in do_handle_one_connection (connect=<optimized out>, connect@entry=0x560984d01718, put_in_cache=put_in_cache@entry=true) at /test/10.11_opt/sql/sql_connect.cc:1416
#11 0x0000560982d8845d in handle_one_connection (arg=0x560984d01718) at /test/10.11_opt/sql/sql_connect.cc:1318
#12 0x000014bf6337f609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#13 0x000014bf62f6b133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
10.9.3 50c6090107d582a39e5be018c9fb4f40202210f9
Core was generated by `/test/tst2/bin/mysqld --no-defaults --core-file --basedir=/test/tst2 --tmpdir=/'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00001545c01064e5 in spider_db_query (conn=0x154544064068,
query=0x15454407d288 "handler `test`.`t` open as t00000",
at /test/10.9_opt/storage/spider/spd_db_conn.cc:669
[Current thread is 1 (Thread 0x1545cc09c700 (LWP 2731106))]
(gdb) bt
#0 0x00001545c01064e5 in spider_db_query (conn=0x154544064068, query=0x15454407d288 "handler `test`.`t` open as t00000", length=<optimized out>, quick_mode=<optimized out>, need_mon=<optimized out>) at /test/10.9_opt/storage/spider/spd_db_conn.cc:669
#1 0x00001545c0112e54 in spider_db_open_handler (spider=spider@entry=0x154544026790, conn=0x154544064068, link_idx=link_idx@entry=0) at /test/10.9_opt/storage/spider/spd_db_conn.cc:10621
#2 0x00001545c014f648 in ha_spider::rnd_handler_init (this=0x154544026790) at /test/10.9_opt/storage/spider/ha_spider.cc:10582
#3 ha_spider::rnd_handler_init (this=0x154544026790) at /test/10.9_opt/storage/spider/ha_spider.cc:10550
#4 0x00001545c0155dc7 in ha_spider::rnd_next_internal (this=0x154544026790, buf=0x154544026378 "\377") at /test/10.9_opt/storage/spider/ha_spider.cc:5850
#5 0x0000560f3f2e7076 in handler::ha_rnd_next (this=0x154544026790, buf=0x154544026378 "\377") at /test/10.9_opt/sql/handler.cc:3415
#6 0x0000560f3f05eb50 in mysql_ha_read (thd=thd@entry=0x154544000c58, tables=tables@entry=0x154544010848, 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.9_opt/sql/sql_handler.cc:925
#7 0x0000560f3f0a455b in mysql_execute_command (thd=0x154544000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.9_opt/sql/sql_limit.h:87
#8 0x0000560f3f093065 in mysql_parse (rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, thd=0x154544000c58) at /test/10.9_opt/sql/sql_parse.cc:8037
#10 0x0000560f3f09ebba in dispatch_command (command=COM_QUERY, thd=0x154544000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.9_opt/sql/sql_class.h:1370
#11 0x0000560f3f0a0b02 in do_command (thd=0x154544000c58, blocking=blocking@entry=true) at /test/10.9_opt/sql/sql_parse.cc:1407
#12 0x0000560f3f1b79af in do_handle_one_connection (connect=<optimized out>, connect@entry=0x560f411cd838, put_in_cache=put_in_cache@entry=true) at /test/10.9_opt/sql/sql_connect.cc:1416
#13 0x0000560f3f1b7c8d in handle_one_connection (arg=0x560f411cd838) at /test/10.9_opt/sql/sql_connect.cc:1318
#14 0x00001545e62d3609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x00001545e5ebf133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
This generates a lot of different stacks accross different versions:
Roel Van de Paar
added a comment - - edited Testcase may be very lightly sporadic.
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE USER Spider@localhost IDENTIFIED BY 'PWD123' ;
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock' , DATABASE 'test' , USER 'Spider' , PASSWORD 'PWD123' );
CREATE TABLE t1 (c INT ) ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
HANDLER t1 OPEN ;
HANDLER t1 READ NEXT ;
HANDLER t1 READ NEXT ;
Leads to:
10.11.0 6ebdd3013a18b01dbecec76b870810329eb76586 (Optimized)
Core was generated by `/test/MD190922-mariadb-10.11.0-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x000014bf4863c287 in spider_db_set_names_internal (trx=<optimized out>,
share=0x14bec8059198, conn=conn@entry=0x14bec80611d8, all_link_idx=0,
need_mon=0x14bec805fac0)
at /test/10.11_opt/storage/spider/spd_db_conn.cc:834
[Current thread is 1 (Thread 0x14bf4873c700 (LWP 869025))]
(gdb) bt
#0 0x000014bf4863c287 in spider_db_set_names_internal (trx=<optimized out>, share=0x14bec8059198, conn=conn@entry=0x14bec80611d8, all_link_idx=0, need_mon=0x14bec805fac0) at /test/10.11_opt/storage/spider/spd_db_conn.cc:834
#1 0x000014bf4863c399 in spider_db_set_names (spider=spider@entry=0x14bec8026be0, conn=conn@entry=0x14bec80611d8, link_idx=link_idx@entry=0) at /test/10.11_opt/storage/spider/spd_db_conn.cc:857
#2 0x000014bf4868a122 in ha_spider::rnd_next_internal (this=0x14bec8026be0, buf=0x14bec80267c8 "\377") at /test/10.11_opt/storage/spider/ha_spider.cc:5797
#3 0x0000560982eb7bc6 in handler::ha_rnd_next (this=0x14bec8026be0, buf=0x14bec80267c8 "\377") at /test/10.11_opt/sql/handler.cc:3415
#4 0x0000560982c2c6f0 in mysql_ha_read (thd=thd@entry=0x14bec8000c58, tables=tables@entry=0x14bec8010978, 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.11_opt/sql/sql_handler.cc:925
#5 0x0000560982c726c2 in mysql_execute_command (thd=0x14bec8000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.11_opt/sql/sql_limit.h:87
#6 0x0000560982c61205 in mysql_parse (rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, thd=0x14bec8000c58) at /test/10.11_opt/sql/sql_parse.cc:8037
#7 mysql_parse (thd=0x14bec8000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.11_opt/sql/sql_parse.cc:7959
#8 0x0000560982c6cd6a in dispatch_command (command=COM_QUERY, thd=0x14bec8000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.11_opt/sql/sql_class.h:1345
#9 0x0000560982c6ecb2 in do_command (thd=0x14bec8000c58, blocking=blocking@entry=true) at /test/10.11_opt/sql/sql_parse.cc:1407
#10 0x0000560982d8817f in do_handle_one_connection (connect=<optimized out>, connect@entry=0x560984d01718, put_in_cache=put_in_cache@entry=true) at /test/10.11_opt/sql/sql_connect.cc:1416
#11 0x0000560982d8845d in handle_one_connection (arg=0x560984d01718) at /test/10.11_opt/sql/sql_connect.cc:1318
#12 0x000014bf6337f609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#13 0x000014bf62f6b133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
10.9.3 50c6090107d582a39e5be018c9fb4f40202210f9
Core was generated by `/test/tst2/bin/mysqld --no-defaults --core-file --basedir=/test/tst2 --tmpdir=/'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00001545c01064e5 in spider_db_query (conn=0x154544064068,
query=0x15454407d288 "handler `test`.`t` open as t00000",
length=<optimized out>, quick_mode=<optimized out>,
need_mon=<optimized out>)
at /test/10.9_opt/storage/spider/spd_db_conn.cc:669
[Current thread is 1 (Thread 0x1545cc09c700 (LWP 2731106))]
(gdb) bt
#0 0x00001545c01064e5 in spider_db_query (conn=0x154544064068, query=0x15454407d288 "handler `test`.`t` open as t00000", length=<optimized out>, quick_mode=<optimized out>, need_mon=<optimized out>) at /test/10.9_opt/storage/spider/spd_db_conn.cc:669
#1 0x00001545c0112e54 in spider_db_open_handler (spider=spider@entry=0x154544026790, conn=0x154544064068, link_idx=link_idx@entry=0) at /test/10.9_opt/storage/spider/spd_db_conn.cc:10621
#2 0x00001545c014f648 in ha_spider::rnd_handler_init (this=0x154544026790) at /test/10.9_opt/storage/spider/ha_spider.cc:10582
#3 ha_spider::rnd_handler_init (this=0x154544026790) at /test/10.9_opt/storage/spider/ha_spider.cc:10550
#4 0x00001545c0155dc7 in ha_spider::rnd_next_internal (this=0x154544026790, buf=0x154544026378 "\377") at /test/10.9_opt/storage/spider/ha_spider.cc:5850
#5 0x0000560f3f2e7076 in handler::ha_rnd_next (this=0x154544026790, buf=0x154544026378 "\377") at /test/10.9_opt/sql/handler.cc:3415
#6 0x0000560f3f05eb50 in mysql_ha_read (thd=thd@entry=0x154544000c58, tables=tables@entry=0x154544010848, 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.9_opt/sql/sql_handler.cc:925
#7 0x0000560f3f0a455b in mysql_execute_command (thd=0x154544000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.9_opt/sql/sql_limit.h:87
#8 0x0000560f3f093065 in mysql_parse (rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, thd=0x154544000c58) at /test/10.9_opt/sql/sql_parse.cc:8037
#9 mysql_parse (thd=0x154544000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.9_opt/sql/sql_parse.cc:7959
#10 0x0000560f3f09ebba in dispatch_command (command=COM_QUERY, thd=0x154544000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.9_opt/sql/sql_class.h:1370
#11 0x0000560f3f0a0b02 in do_command (thd=0x154544000c58, blocking=blocking@entry=true) at /test/10.9_opt/sql/sql_parse.cc:1407
#12 0x0000560f3f1b79af in do_handle_one_connection (connect=<optimized out>, connect@entry=0x560f411cd838, put_in_cache=put_in_cache@entry=true) at /test/10.9_opt/sql/sql_connect.cc:1416
#13 0x0000560f3f1b7c8d in handle_one_connection (arg=0x560f411cd838) at /test/10.9_opt/sql/sql_connect.cc:1318
#14 0x00001545e62d3609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x00001545e5ebf133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
This generates a lot of different stacks accross different versions:
SIGSEGV|ha_spider::rnd_next_internal|ha_spider::rnd_next|handler::ha_rnd_next|mysql_ha_read
SIGSEGV|spider_check_and_set_trx_isolation|ha_spider::external_lock|handler::ha_external_lock|lock_external
SIGSEGV|spider_db_open_handler|ha_spider::rnd_handler_init|ha_spider::rnd_next_internal|ha_spider::rnd_next
SIGSEGV|spider_db_query|spider_db_open_handler|ha_spider::rnd_handler_init|ha_spider::rnd_handler_init
SIGSEGV|spider_db_set_names_internal|spider_db_set_names|ha_spider::rnd_next_internal|handler::ha_rnd_next
Out of these the following are new (full stacks shown above):
SIGSEGV|spider_db_query|spider_db_open_handler|ha_spider::rnd_handler_init|ha_spider::rnd_handler_init
SIGSEGV|spider_db_set_names_internal|spider_db_set_names|ha_spider::rnd_next_internal|handler::ha_rnd_next
Core was generated by `/test/MD190922-mariadb-10.11.0-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x000014edc406e760 in spider_db_conn_queue_action (conn=0x14ed3005ea28)
at /test/10.11_opt/storage/spider/spd_db_conn.cc:294
[Current thread is 1 (Thread 0x14edc4174700 (LWP 909220))]
(gdb) bt
#0 0x000014edc406e760 in spider_db_conn_queue_action (conn=0x14ed3005ea28) at /test/10.11_opt/storage/spider/spd_db_conn.cc:294
#1 0x000014edc4073fd0 in spider_db_before_query (conn=0x14ed3005ea28, need_mon=<optimized out>) at /test/10.11_opt/storage/spider/spd_db_conn.cc:586
#2 0x000014edc40741e2 in spider_db_set_names_internal (trx=0x14ed3003b6a8, share=0x14ed300565c8, conn=conn@entry=0x14ed3005ea28, all_link_idx=0, need_mon=0x14ed3005d368) at /test/10.11_opt/storage/spider/spd_db_conn.cc:813
#3 0x000014edc4074399 in spider_db_set_names (spider=spider@entry=0x14ed30023b60, conn=conn@entry=0x14ed3005ea28, link_idx=link_idx@entry=0) at /test/10.11_opt/storage/spider/spd_db_conn.cc:857
#4 0x000014edc40c2122 in ha_spider::rnd_next_internal (this=0x14ed30023b60, buf=0x14ed30023748 "\377") at /test/10.11_opt/storage/spider/ha_spider.cc:5797
#5 0x000055bac92b8bc6 in handler::ha_rnd_next (this=0x14ed30023b60, buf=0x14ed30023748 "\377") at /test/10.11_opt/sql/handler.cc:3415
#6 0x000055bac902d6f0 in mysql_ha_read (thd=thd@entry=0x14ed30000c58, tables=tables@entry=0x14ed30010978, 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.11_opt/sql/sql_handler.cc:925
#7 0x000055bac90736c2 in mysql_execute_command (thd=0x14ed30000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.11_opt/sql/sql_limit.h:87
#8 0x000055bac9062205 in mysql_parse (rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, thd=0x14ed30000c58) at /test/10.11_opt/sql/sql_parse.cc:8037
#10 0x000055bac906dd6a in dispatch_command (command=COM_QUERY, thd=0x14ed30000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.11_opt/sql/sql_class.h:1345
#11 0x000055bac906fcb2 in do_command (thd=0x14ed30000c58, blocking=blocking@entry=true) at /test/10.11_opt/sql/sql_parse.cc:1407
#12 0x000055bac918917f in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55bacc45a168, put_in_cache=put_in_cache@entry=true) at /test/10.11_opt/sql/sql_connect.cc:1416
#13 0x000055bac918945d in handle_one_connection (arg=0x55bacc45a168) at /test/10.11_opt/sql/sql_connect.cc:1318
#14 0x000014edeb020609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x000014edeac0c133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Roel Van de Paar
added a comment - The last testcase introduces (likely some corrupted) new UniqueID's/stacks:
SIGABRT|safe_mutex_lock|inline_mysql_mutex_lock|ha_spider::rnd_next_internal|ha_spider::rnd_next
SIGSEGV|charset_info_st::strntoull10rnd|Field_num::get_int|Field_long::store|spider_db_errorno
SIGSEGV|spider_conn_queue_and_merge_loop_check|spider_conn_reset_queue_loop_check|spider_reset_conn_setted_parameter|spider_db_connect
SIGSEGV|spider_db_conn_queue_action|spider_db_before_query|spider_db_set_names_internal|spider_db_set_names
SIGSEGV|spider_db_connect|spider_db_conn_queue_action|spider_db_before_query|spider_db_query
The 3rd last testcase above gives a similar result as the first one addressed in this comment; skipping.
Same for the one before that (both testcases listed in that comment); skipping.
Roel Van de Paar
added a comment - - edited This testcase (the client corrupting one) gives some interesting results on an ASAN build of 10.11 trunk:
10.11.0 ba875e939619baefb08936863a889830f595e426 (Debug, ASAN)
2022-10-01 16:44:05 0 [Note] /test/ASAN_MD011022-mariadb-10.11.0-linux-x86_64-dbg/bin/mysqld: ready for connections.
Version: '10.11.0-MariaDB-debug' socket: '/test/ASAN_MD011022-mariadb-10.11.0-linux-x86_64-dbg/socket.sock' port: 10153 MariaDB Server
2022-10-01 16:46:25 25 [Warning] Access denied for user ''@'localhost' (using password: YES)
2022-10-01 16:46:25 4 [ERROR] mysql_ha_read: Got error 12701 when reading table 't'
2022-10-01 16:46:25 26 [Warning] Access denied for user ''@'localhost' (using password: YES)
safe_mutex: Trying to lock uninitialized mutex at /test/10.11_dbg/storage/spider/ha_spider.cc, line 5788
<EOL>
10.11.0 ba875e939619baefb08936863a889830f595e426 (Optimized, ASAN)
2022-10-01 16:47:11 0 [Note] /test/ASAN_MD011022-mariadb-10.11.0-linux-x86_64-opt/bin/mysqld: ready for connections.
Version: '10.11.0-MariaDB' socket: '/test/ASAN_MD011022-mariadb-10.11.0-linux-x86_64-opt/socket.sock' port: 12753 MariaDB Server
2022-10-01 16:47:12 25 [Warning] Access denied for user ''@'localhost' (using password: YES)
2022-10-01 16:47:12 4 [ERROR] mysql_ha_read: Got error 12701 when reading table 't'
2022-10-01 16:47:12 26 [Warning] Access denied for user ''@'localhost' (using password: YES)
<EOL>
Especially the attempted uninitialized mutex lock looks interesting.
This testcase gives a different outcome:
10.11.0 ba875e939619baefb08936863a889830f595e426 (Debug, ASAN)
2022-10-01 16:50:40 0 [Note] /test/ASAN_MD011022-mariadb-10.11.0-linux-x86_64-dbg/bin/mysqld: ready for connections.
Version: '10.11.0-MariaDB-debug' socket: '/test/ASAN_MD011022-mariadb-10.11.0-linux-x86_64-dbg/socket.sock' port: 10153 MariaDB Server
2022-10-01 16:50:41 4 [ERROR] mysql_ha_read: Got error 1146 when reading table 't1'
<EOL>
10.11.0 ba875e939619baefb08936863a889830f595e426 (Debug, ASAN)
2022-10-01 16:50:39 0 [Note] /test/ASAN_MD011022-mariadb-10.11.0-linux-x86_64-opt/bin/mysqld: ready for connections.
Version: '10.11.0-MariaDB' socket: '/test/ASAN_MD011022-mariadb-10.11.0-linux-x86_64-opt/socket.sock' port: 12753 MariaDB Server
2022-10-01 16:50:40 4 [ERROR] mysql_ha_read: Got error 1146 when reading table 't1'
<EOL>
The 3rd last testcase above gives a similar result as the first one addressed in this comment; skipping.
Same for the one before that (both testcases listed in that comment); skipping.
at /test/10.11_dbg/storage/spider/ha_spider.cc:2190
[Current thread is 1 (Thread 0x14665812d700 (LWP 1411180))]
(gdb) bt
#0 0x000014664b96fc29 in ha_spider::index_first_internal (this=this@entry=0x1465fc072840, buf=buf@entry=0x1465fc072428 "\377") at /test/10.11_dbg/storage/spider/ha_spider.cc:2190
#1 0x000014664b9707c2 in ha_spider::index_first (this=0x1465fc072840, buf=0x1465fc072428 "\377") at /test/10.11_dbg/storage/spider/ha_spider.cc:2379
#2 0x0000558033799995 in handler::ha_index_first (this=0x1465fc072840, buf=0x1465fc072428 "\377") at /test/10.11_dbg/sql/handler.cc:3566
#3 0x000055803345abc2 in mysql_ha_read (thd=thd@entry=0x1465fc000d48, tables=tables@entry=0x1465fc013348, mode=<optimized out>, keyname=0x1465fc013a30 "b", key_expr=<optimized out>, ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.11_dbg/sql/sql_handler.cc:919
#4 0x00005580334af90e in mysql_execute_command (thd=thd@entry=0x1465fc000d48, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_limit.h:87
#5 0x000055803349903c in mysql_parse (thd=thd@entry=0x1465fc000d48, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14665812c330) at /test/10.11_dbg/sql/sql_parse.cc:8037
#6 0x00005580334a666d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1465fc000d48, packet=packet@entry=0x1465fc00aed9 "", packet_length=packet_length@entry=22, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_class.h:1345
#7 0x00005580334a8d97 in do_command (thd=0x1465fc000d48, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407
#8 0x000055803360cfb9 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x558036647cd8, put_in_cache=put_in_cache@entry=true) at /test/10.11_dbg/sql/sql_connect.cc:1416
#9 0x000055803360d4c3 in handle_one_connection (arg=0x558036647cd8) at /test/10.11_dbg/sql/sql_connect.cc:1318
#10 0x0000146685bf1609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#11 0x00001466857dd133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Roel Van de Paar
added a comment - - edited
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE USER Spider@localhost IDENTIFIED BY 'PWD123' ;
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock' , DATABASE 'test' , USER 'Spider' , PASSWORD 'PWD123' );
CREATE TABLE t1 (b INT , FOREIGN KEY (b) REFERENCES t1 (a)) ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
HANDLER t1 OPEN ;
HANDLER t1 READ b NEXT ;
HANDLER t1 READ b NEXT ;
Leads to:
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 SIGSEGV, Segmentation fault.
#0 0x000014664b96fc29 in ha_spider::index_first_internal (
this=this@entry=0x1465fc072840, buf=buf@entry=0x1465fc072428 "\377")
at /test/10.11_dbg/storage/spider/ha_spider.cc:2190
[Current thread is 1 (Thread 0x14665812d700 (LWP 1411180))]
(gdb) bt
#0 0x000014664b96fc29 in ha_spider::index_first_internal (this=this@entry=0x1465fc072840, buf=buf@entry=0x1465fc072428 "\377") at /test/10.11_dbg/storage/spider/ha_spider.cc:2190
#1 0x000014664b9707c2 in ha_spider::index_first (this=0x1465fc072840, buf=0x1465fc072428 "\377") at /test/10.11_dbg/storage/spider/ha_spider.cc:2379
#2 0x0000558033799995 in handler::ha_index_first (this=0x1465fc072840, buf=0x1465fc072428 "\377") at /test/10.11_dbg/sql/handler.cc:3566
#3 0x000055803345abc2 in mysql_ha_read (thd=thd@entry=0x1465fc000d48, tables=tables@entry=0x1465fc013348, mode=<optimized out>, keyname=0x1465fc013a30 "b", key_expr=<optimized out>, ha_rkey_mode=HA_READ_KEY_EXACT, cond=0x0, select_limit_cnt=1, offset_limit_cnt=0) at /test/10.11_dbg/sql/sql_handler.cc:919
#4 0x00005580334af90e in mysql_execute_command (thd=thd@entry=0x1465fc000d48, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_limit.h:87
#5 0x000055803349903c in mysql_parse (thd=thd@entry=0x1465fc000d48, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14665812c330) at /test/10.11_dbg/sql/sql_parse.cc:8037
#6 0x00005580334a666d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1465fc000d48, packet=packet@entry=0x1465fc00aed9 "", packet_length=packet_length@entry=22, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_class.h:1345
#7 0x00005580334a8d97 in do_command (thd=0x1465fc000d48, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407
#8 0x000055803360cfb9 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x558036647cd8, put_in_cache=put_in_cache@entry=true) at /test/10.11_dbg/sql/sql_connect.cc:1416
#9 0x000055803360d4c3 in handle_one_connection (arg=0x558036647cd8) at /test/10.11_dbg/sql/sql_connect.cc:1318
#10 0x0000146685bf1609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#11 0x00001466857dd133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Accross versions this testcase gives:
SIGSEGV|ha_spider::index_first_internal|ha_spider::index_first|handler::ha_index_first|mysql_ha_read
SIGSEGV|spider_check_and_set_trx_isolation|ha_spider::external_lock|handler::ha_external_lock|lock_external
SIGSEGV|spider_db_open_handler|ha_spider::index_handler_init|ha_spider::index_first_internal|ha_spider::index_first
SIGSEGV|spider_db_query|spider_db_open_handler|ha_spider::index_handler_init|ha_spider::index_handler_init
SIGSEGV|spider_db_set_names_internal|spider_db_set_names|ha_spider::index_first_internal|handler::ha_index_first
Which are all new stacks except the second one.
at /test/10.11_opt/storage/spider/spd_conn.cc:1222
1222 lcptr->flag = 0;
[Current thread is 1 (Thread 0x154af16e6700 (LWP 720616))]
(gdb) bt
#0 spider_conn_reset_queue_loop_check (conn=conn@entry=0x154aac06c938) at /test/10.11_opt/storage/spider/spd_conn.cc:1222
#1 0x0000154af15f42e3 in spider_reset_conn_setted_parameter (conn=conn@entry=0x154aac06c938, thd=thd@entry=0x154aac000c58) at /test/10.11_opt/storage/spider/spd_conn.cc:260
#2 0x0000154af15e0049 in spider_db_connect (share=share@entry=0x154aac07d398, conn=conn@entry=0x154aac06c938, link_idx=link_idx@entry=0) at /test/10.11_opt/storage/spider/spd_db_conn.cc:137
#3 0x0000154af15e036a in spider_db_ping_internal (share=0x154aac07d398, conn=conn@entry=0x154aac06c938, all_link_idx=0, need_mon=<optimized out>) at /test/10.11_opt/storage/spider/spd_db_conn.cc:191
#4 0x0000154af15e0438 in spider_db_ping (spider=<optimized out>, conn=conn@entry=0x154aac06c938, link_idx=<optimized out>) at /test/10.11_opt/storage/spider/spd_db_conn.cc:234
#5 0x0000154af15e0db2 in spider_db_conn_queue_action (conn=0x154aac06c938) at /test/10.11_opt/storage/spider/spd_db_conn.cc:277
#6 0x0000154af15e5fe0 in spider_db_before_query (conn=0x154aac06c938, need_mon=<optimized out>) at /test/10.11_opt/storage/spider/spd_db_conn.cc:586
#7 0x0000154af15e61f2 in spider_db_set_names_internal (trx=0x154aac03e7f8, share=0x154aac07d398, conn=conn@entry=0x154aac06c938, all_link_idx=0, need_mon=0x154aac084130) at /test/10.11_opt/storage/spider/spd_db_conn.cc:813
#8 0x0000154af15e63a9 in spider_db_set_names (spider=spider@entry=0x154aac088cd0, conn=conn@entry=0x154aac06c938, link_idx=link_idx@entry=0) at /test/10.11_opt/storage/spider/spd_db_conn.cc:857
#9 0x0000154af15ea481 in spider_db_bulk_insert (spider=spider@entry=0x154aac088cd0, table=0x154aac0884b8, copy_info=copy_info@entry=0x154aac0890c0, bulk_end=bulk_end@entry=false) at /test/10.11_opt/storage/spider/spd_db_conn.cc:5505
#10 0x0000154af163fa29 in ha_spider::write_row (this=0x154aac088cd0, buf=0x154aac0888b8 <incomplete sequence \375>) at /test/10.11_opt/storage/spider/ha_spider.cc:7997
#11 0x000055c2b8a3bbb0 in handler::ha_write_row (this=0x154aac088cd0, buf=0x154aac0888b8 <incomplete sequence \375>) at /test/10.11_opt/sql/handler.cc:7580
#12 0x000055c2b87ab75d in write_record (thd=thd@entry=0x154aac000c58, table=table@entry=0x154aac0884b8, info=info@entry=0x154af16e4af0, sink=sink@entry=0x0) at /test/10.11_opt/sql/sql_insert.cc:2191
#13 0x000055c2b87b2829 in mysql_insert (thd=thd@entry=0x154aac000c58, table_list=<optimized out>, fields=@0x154aac005bb8: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55c2b99746f0 <end_of_list>, last = 0x154aac005bb8, elements = 0}, <No data fields>}, values_list=@0x154aac005c00: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x154aac011570, last = 0x154aac011570, elements = 1}, <No data fields>}, update_fields=@0x154aac005be8: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55c2b99746f0 <end_of_list>, last = 0x154aac005be8, elements = 0}, <No data fields>}, update_values=@0x154aac005bd0: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55c2b99746f0 <end_of_list>, last = 0x154aac005bd0, elements = 0}, <No data fields>}, duplic=<optimized out>, ignore=<optimized out>, result=<optimized out>) at /test/10.11_opt/sql/sql_insert.cc:1146
#14 0x000055c2b87ed128 in mysql_execute_command (thd=0x154aac000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.11_opt/sql/sql_parse.cc:4563
#15 0x000055c2b87dd335 in mysql_parse (rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, thd=0x154aac000c58) at /test/10.11_opt/sql/sql_parse.cc:8023
#17 0x000055c2b87e90ea in dispatch_command (command=COM_QUERY, thd=0x154aac000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.11_opt/sql/sql_class.h:1346
#18 0x000055c2b87eaee2 in do_command (thd=0x154aac000c58, blocking=blocking@entry=true) at /test/10.11_opt/sql/sql_parse.cc:1407
#19 0x000055c2b8904fbf in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55c2bbc058d8, put_in_cache=put_in_cache@entry=true) at /test/10.11_opt/sql/sql_connect.cc:1416
#20 0x000055c2b890529d in handle_one_connection (arg=0x55c2bbc058d8) at /test/10.11_opt/sql/sql_connect.cc:1318
#21 0x0000154b0a927609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#22 0x0000154b0a513133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
#4 0x0000555baf602150 in Diagnostics_area::set_error_status (this=this@entry=0x555bb343e5c0, sql_errno=sql_errno@entry=6, message=message@entry=0x7ffdc3ca55f0 "Error on delete of '/tmp/#sql-temptable-3ad9a0-1-2.MAD' (Errcode: 2 \"No such file or directory\")", sqlstate=sqlstate@entry=0x555bb02208e8 "HY000", ucid=@0x7ffdc3ca53d0: {m_user_condition_value = 0x0}, error_condition=0x0) at /test/10.11_dbg/sql/sql_error.h:1026
#5 0x0000555baf5e1400 in THD::raise_condition (this=this@entry=0x555bb34386b8, cond=cond@entry=0x7ffdc3ca53c0) at /test/10.11_dbg/sql/sql_class.cc:1118
#6 0x0000555baf5300d4 in THD::raise_condition (this=this@entry=0x555bb34386b8, sql_errno=sql_errno@entry=6, sqlstate=sqlstate@entry=0x555bb01e8918 "", level=<optimized out>, msg=msg@entry=0x7ffdc3ca55f0 "Error on delete of '/tmp/#sql-temptable-3ad9a0-1-2.MAD' (Errcode: 2 \"No such file or directory\")") at /test/10.11_dbg/sql/sql_class.h:4875
#7 0x0000555baf524d2e in my_message_sql (error=6, str=0x7ffdc3ca55f0 "Error on delete of '/tmp/#sql-temptable-3ad9a0-1-2.MAD' (Errcode: 2 \"No such file or directory\")", MyFlags=4) at /test/10.11_dbg/sql/mysqld.cc:3329
#8 0x0000555bb0044b5a in my_error (nr=nr@entry=6, MyFlags=MyFlags@entry=4) at /test/10.11_dbg/mysys/my_error.c:124
#9 0x0000555bb0044810 in my_delete (name=name@entry=0x7ffdc3ca5b50 "/tmp/#sql-temptable-3ad9a0-1-2.MAD", MyFlags=MyFlags@entry=16) at /test/10.11_dbg/mysys/my_delete.c:53
#10 0x0000555bb004c14e in my_handler_delete_with_symlink (filename=0x7ffdc3ca5b50 "/tmp/#sql-temptable-3ad9a0-1-2.MAD", sync_dir=sync_dir@entry=16) at /test/10.11_dbg/mysys/my_symlink2.c:190
#11 0x0000555bafba241e in inline_mysql_file_delete_with_symlink (name=name@entry=0x555bb3488060 "/tmp/#sql-temptable-3ad9a0-1-2", ext=ext@entry=0x555bb03f0455 ".MAD", flags=flags@entry=16) at /test/10.11_dbg/include/mysql/psi/mysql_file.h:1396
#12 0x0000555bafba2476 in maria_delete_table_files (name=name@entry=0x555bb3488060 "/tmp/#sql-temptable-3ad9a0-1-2", temporary=temporary@entry=1 '\001', flags=flags@entry=16) at /test/10.11_dbg/storage/maria/ma_delete_table.c:103
#13 0x0000555bafb494b7 in ha_maria::drop_table (this=0x555bb3488920, name=0x555bb3488060 "/tmp/#sql-temptable-3ad9a0-1-2") at /test/10.11_dbg/storage/maria/ha_maria.cc:2810
#14 0x0000555baf9389ab in handler::ha_drop_table (this=0x555bb3488920, name=0x555bb3488060 "/tmp/#sql-temptable-3ad9a0-1-2") at /test/10.11_dbg/sql/handler.cc:5367
#15 0x0000555baf6b5288 in free_tmp_table (thd=thd@entry=0x555bb34386b8, entry=0x555bb3486f10) at /test/10.11_dbg/sql/sql_select.cc:21055
#16 0x0000555baf5c920c in close_thread_tables (thd=thd@entry=0x555bb34386b8) at /test/10.11_dbg/sql/sql_base.cc:880
#17 0x0000555baf5c94b3 in close_thread_tables_for_query (thd=thd@entry=0x555bb34386b8) at /test/10.11_dbg/sql/sql_base.cc:790
#18 0x0000555baf659c2b in mysql_execute_command (thd=thd@entry=0x555bb34386b8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_parse.cc:6063
#19 0x0000555baf641f90 in mysql_parse (thd=0x555bb34386b8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7ffdc3ca64a0) at /test/10.11_dbg/sql/sql_parse.cc:8023
#20 0x0000555baf64d359 in bootstrap (file=0x555bb144f7a0 <instrumented_stdin>) at /test/10.11_dbg/sql/sql_class.h:1343
#21 0x0000555baf52d45d in mysqld_main (argc=<optimized out>, argv=<optimized out>) at /test/10.11_dbg/sql/mysqld.cc:5860
#22 0x0000555baf521b86 in main (argc=<optimized out>, argv=<optimized out>) at /test/10.11_dbg/sql/main.cc:34
Roel Van de Paar
added a comment -
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE USER Spider@localhost IDENTIFIED BY 'PWD123' ;
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock' , DATABASE 'test' , USER 'Spider' , PASSWORD 'PWD123' );
CREATE TABLE t (c INT ) ENGINE=InnoDB;
CREATE TABLE t1 (a INT ) ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
CREATE TABLE t2 (c INT ) ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
XA START 'a' ;
SET GLOBAL init_connect= 'SET autocomit=0' ;
INSERT INTO t1 VALUES (0);
INSERT INTO t2 SELECT * FROM t2; # < ---- Debug builds crash here or on the next line
SELECT IF ( 'SELECT COUNT(*) FROM t1 WHERE a=""' REGEXP '^[a-zA-z_][a-zA-z_0-9]*:' , 1, 0);
INSERT INTO t2 VALUES (0); # < ---- Optimized builds crash here
Leads to:
10.11.1 50c5743adc87e1cdec1431a02558f6540fe5a6d5 (Optimized)
Core was generated by `/test/MD221022-mariadb-10.11.1-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 spider_conn_reset_queue_loop_check (conn=conn@entry=0x154aac06c938)
at /test/10.11_opt/storage/spider/spd_conn.cc:1222
1222 lcptr->flag = 0;
[Current thread is 1 (Thread 0x154af16e6700 (LWP 720616))]
(gdb) bt
#0 spider_conn_reset_queue_loop_check (conn=conn@entry=0x154aac06c938) at /test/10.11_opt/storage/spider/spd_conn.cc:1222
#1 0x0000154af15f42e3 in spider_reset_conn_setted_parameter (conn=conn@entry=0x154aac06c938, thd=thd@entry=0x154aac000c58) at /test/10.11_opt/storage/spider/spd_conn.cc:260
#2 0x0000154af15e0049 in spider_db_connect (share=share@entry=0x154aac07d398, conn=conn@entry=0x154aac06c938, link_idx=link_idx@entry=0) at /test/10.11_opt/storage/spider/spd_db_conn.cc:137
#3 0x0000154af15e036a in spider_db_ping_internal (share=0x154aac07d398, conn=conn@entry=0x154aac06c938, all_link_idx=0, need_mon=<optimized out>) at /test/10.11_opt/storage/spider/spd_db_conn.cc:191
#4 0x0000154af15e0438 in spider_db_ping (spider=<optimized out>, conn=conn@entry=0x154aac06c938, link_idx=<optimized out>) at /test/10.11_opt/storage/spider/spd_db_conn.cc:234
#5 0x0000154af15e0db2 in spider_db_conn_queue_action (conn=0x154aac06c938) at /test/10.11_opt/storage/spider/spd_db_conn.cc:277
#6 0x0000154af15e5fe0 in spider_db_before_query (conn=0x154aac06c938, need_mon=<optimized out>) at /test/10.11_opt/storage/spider/spd_db_conn.cc:586
#7 0x0000154af15e61f2 in spider_db_set_names_internal (trx=0x154aac03e7f8, share=0x154aac07d398, conn=conn@entry=0x154aac06c938, all_link_idx=0, need_mon=0x154aac084130) at /test/10.11_opt/storage/spider/spd_db_conn.cc:813
#8 0x0000154af15e63a9 in spider_db_set_names (spider=spider@entry=0x154aac088cd0, conn=conn@entry=0x154aac06c938, link_idx=link_idx@entry=0) at /test/10.11_opt/storage/spider/spd_db_conn.cc:857
#9 0x0000154af15ea481 in spider_db_bulk_insert (spider=spider@entry=0x154aac088cd0, table=0x154aac0884b8, copy_info=copy_info@entry=0x154aac0890c0, bulk_end=bulk_end@entry=false) at /test/10.11_opt/storage/spider/spd_db_conn.cc:5505
#10 0x0000154af163fa29 in ha_spider::write_row (this=0x154aac088cd0, buf=0x154aac0888b8 <incomplete sequence \375>) at /test/10.11_opt/storage/spider/ha_spider.cc:7997
#11 0x000055c2b8a3bbb0 in handler::ha_write_row (this=0x154aac088cd0, buf=0x154aac0888b8 <incomplete sequence \375>) at /test/10.11_opt/sql/handler.cc:7580
#12 0x000055c2b87ab75d in write_record (thd=thd@entry=0x154aac000c58, table=table@entry=0x154aac0884b8, info=info@entry=0x154af16e4af0, sink=sink@entry=0x0) at /test/10.11_opt/sql/sql_insert.cc:2191
#13 0x000055c2b87b2829 in mysql_insert (thd=thd@entry=0x154aac000c58, table_list=<optimized out>, fields=@0x154aac005bb8: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55c2b99746f0 <end_of_list>, last = 0x154aac005bb8, elements = 0}, <No data fields>}, values_list=@0x154aac005c00: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x154aac011570, last = 0x154aac011570, elements = 1}, <No data fields>}, update_fields=@0x154aac005be8: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55c2b99746f0 <end_of_list>, last = 0x154aac005be8, elements = 0}, <No data fields>}, update_values=@0x154aac005bd0: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55c2b99746f0 <end_of_list>, last = 0x154aac005bd0, elements = 0}, <No data fields>}, duplic=<optimized out>, ignore=<optimized out>, result=<optimized out>) at /test/10.11_opt/sql/sql_insert.cc:1146
#14 0x000055c2b87ed128 in mysql_execute_command (thd=0x154aac000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.11_opt/sql/sql_parse.cc:4563
#15 0x000055c2b87dd335 in mysql_parse (rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, thd=0x154aac000c58) at /test/10.11_opt/sql/sql_parse.cc:8023
#16 mysql_parse (thd=0x154aac000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.11_opt/sql/sql_parse.cc:7945
#17 0x000055c2b87e90ea in dispatch_command (command=COM_QUERY, thd=0x154aac000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.11_opt/sql/sql_class.h:1346
#18 0x000055c2b87eaee2 in do_command (thd=0x154aac000c58, blocking=blocking@entry=true) at /test/10.11_opt/sql/sql_parse.cc:1407
#19 0x000055c2b8904fbf in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55c2bbc058d8, put_in_cache=put_in_cache@entry=true) at /test/10.11_opt/sql/sql_connect.cc:1416
#20 0x000055c2b890529d in handle_one_connection (arg=0x55c2bbc058d8) at /test/10.11_opt/sql/sql_connect.cc:1318
#21 0x0000154b0a927609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#22 0x0000154b0a513133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
And
10.11.1 50c5743adc87e1cdec1431a02558f6540fe5a6d5 (Debug)
Core was generated by `/test/MD221022-mariadb-10.11.1-linux-x86_64-dbg/bin/mariadbd --no-defaults --lc'.
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 0x14631a2f5940 (LWP 3856800))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x000014631a4ce859 in __GI_abort () at abort.c:79
#2 0x000014631a4ce729 in __assert_fail_base (fmt=0x14631a664588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x555bb0203ed0 "! is_set() || m_can_overwrite_status", file=0x555bb0203c38 "/test/10.11_dbg/sql/sql_error.cc", line=457, function=<optimized out>) at assert.c:92
#3 0x000014631a4dffd6 in __GI___assert_fail (assertion=assertion@entry=0x555bb0203ed0 "! is_set() || m_can_overwrite_status", file=file@entry=0x555bb0203c38 "/test/10.11_dbg/sql/sql_error.cc", line=line@entry=457, function=function@entry=0x555bb0203e48 "void Diagnostics_area::set_error_status(uint, const char*, const char*, const Sql_user_condition_identity&, const Sql_condition*)") at assert.c:101
#4 0x0000555baf602150 in Diagnostics_area::set_error_status (this=this@entry=0x555bb343e5c0, sql_errno=sql_errno@entry=6, message=message@entry=0x7ffdc3ca55f0 "Error on delete of '/tmp/#sql-temptable-3ad9a0-1-2.MAD' (Errcode: 2 \"No such file or directory\")", sqlstate=sqlstate@entry=0x555bb02208e8 "HY000", ucid=@0x7ffdc3ca53d0: {m_user_condition_value = 0x0}, error_condition=0x0) at /test/10.11_dbg/sql/sql_error.h:1026
#5 0x0000555baf5e1400 in THD::raise_condition (this=this@entry=0x555bb34386b8, cond=cond@entry=0x7ffdc3ca53c0) at /test/10.11_dbg/sql/sql_class.cc:1118
#6 0x0000555baf5300d4 in THD::raise_condition (this=this@entry=0x555bb34386b8, sql_errno=sql_errno@entry=6, sqlstate=sqlstate@entry=0x555bb01e8918 "", level=<optimized out>, msg=msg@entry=0x7ffdc3ca55f0 "Error on delete of '/tmp/#sql-temptable-3ad9a0-1-2.MAD' (Errcode: 2 \"No such file or directory\")") at /test/10.11_dbg/sql/sql_class.h:4875
#7 0x0000555baf524d2e in my_message_sql (error=6, str=0x7ffdc3ca55f0 "Error on delete of '/tmp/#sql-temptable-3ad9a0-1-2.MAD' (Errcode: 2 \"No such file or directory\")", MyFlags=4) at /test/10.11_dbg/sql/mysqld.cc:3329
#8 0x0000555bb0044b5a in my_error (nr=nr@entry=6, MyFlags=MyFlags@entry=4) at /test/10.11_dbg/mysys/my_error.c:124
#9 0x0000555bb0044810 in my_delete (name=name@entry=0x7ffdc3ca5b50 "/tmp/#sql-temptable-3ad9a0-1-2.MAD", MyFlags=MyFlags@entry=16) at /test/10.11_dbg/mysys/my_delete.c:53
#10 0x0000555bb004c14e in my_handler_delete_with_symlink (filename=0x7ffdc3ca5b50 "/tmp/#sql-temptable-3ad9a0-1-2.MAD", sync_dir=sync_dir@entry=16) at /test/10.11_dbg/mysys/my_symlink2.c:190
#11 0x0000555bafba241e in inline_mysql_file_delete_with_symlink (name=name@entry=0x555bb3488060 "/tmp/#sql-temptable-3ad9a0-1-2", ext=ext@entry=0x555bb03f0455 ".MAD", flags=flags@entry=16) at /test/10.11_dbg/include/mysql/psi/mysql_file.h:1396
#12 0x0000555bafba2476 in maria_delete_table_files (name=name@entry=0x555bb3488060 "/tmp/#sql-temptable-3ad9a0-1-2", temporary=temporary@entry=1 '\001', flags=flags@entry=16) at /test/10.11_dbg/storage/maria/ma_delete_table.c:103
#13 0x0000555bafb494b7 in ha_maria::drop_table (this=0x555bb3488920, name=0x555bb3488060 "/tmp/#sql-temptable-3ad9a0-1-2") at /test/10.11_dbg/storage/maria/ha_maria.cc:2810
#14 0x0000555baf9389ab in handler::ha_drop_table (this=0x555bb3488920, name=0x555bb3488060 "/tmp/#sql-temptable-3ad9a0-1-2") at /test/10.11_dbg/sql/handler.cc:5367
#15 0x0000555baf6b5288 in free_tmp_table (thd=thd@entry=0x555bb34386b8, entry=0x555bb3486f10) at /test/10.11_dbg/sql/sql_select.cc:21055
#16 0x0000555baf5c920c in close_thread_tables (thd=thd@entry=0x555bb34386b8) at /test/10.11_dbg/sql/sql_base.cc:880
#17 0x0000555baf5c94b3 in close_thread_tables_for_query (thd=thd@entry=0x555bb34386b8) at /test/10.11_dbg/sql/sql_base.cc:790
#18 0x0000555baf659c2b in mysql_execute_command (thd=thd@entry=0x555bb34386b8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_parse.cc:6063
#19 0x0000555baf641f90 in mysql_parse (thd=0x555bb34386b8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7ffdc3ca64a0) at /test/10.11_dbg/sql/sql_parse.cc:8023
#20 0x0000555baf64d359 in bootstrap (file=0x555bb144f7a0 <instrumented_stdin>) at /test/10.11_dbg/sql/sql_class.h:1343
#21 0x0000555baf52d45d in mysqld_main (argc=<optimized out>, argv=<optimized out>) at /test/10.11_dbg/sql/mysqld.cc:5860
#22 0x0000555baf521b86 in main (argc=<optimized out>, argv=<optimized out>) at /test/10.11_dbg/sql/main.cc:34
Bug confirmed present in:
MariaDB: 10.5.18 (dbg), 10.5.18 (opt), 10.6.10 (dbg), 10.6.10 (opt), 10.7.6 (dbg), 10.7.6 (opt), 10.8.5 (dbg), 10.8.5 (opt), 10.9.3 (dbg), 10.9.3 (opt), 10.10.2 (dbg), 10.10.2 (opt), 10.11.1 (dbg), 10.11.1 (opt)
Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.3.37 (dbg), 10.3.37 (opt), 10.4.27 (dbg), 10.4.27 (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)
Also interesting is this testcase:
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE USER Spider@localhost IDENTIFIED BY 'PWD123' ;
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock' , DATABASE 'test' , USER 'Spider' , PASSWORD 'PWD123' );
CREATE TABLE t7 (a INT ) ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
CREATE TABLE t2 (column_name_1 INT , column_name_2 VARCHAR (52)) ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
XA START 'a' ;
SET GLOBAL init_connect= 'SET autocomit=0' ;
INSERT INTO t7 (c1) VALUES ( 'a' );
INSERT INTO t2 SELECT * FROM t2;
SELECT IF ( 'SELECT COUNT(*) FROM t1 WHERE a=""' , 1, 0);
INSERT INTO t2 VALUES (2,4);
Which produces, on 10.11 optimized:
10.11.1 50c5743adc87e1cdec1431a02558f6540fe5a6d5 (Optimized)
10.11.1-opt>INSERT INTO t7 (c1) VALUES ('a');
ERROR 1054 (42S22): Unknown column 'c1' in 'field list'
10.11.1-opt>INSERT INTO t2 SELECT * FROM t2;
ERROR 12701 (HY000): Remote MariaDB server has gone away
10.11.1-opt>SELECT IF('SELECT COUNT(*) FROM t1 WHERE a=""', 1, 0);
+------------------------------------------------+
| IF('SELECT COUNT(*) FROM t1 WHERE a=""', 1, 0) |
+------------------------------------------------+
| 0 |
+------------------------------------------------+
1 row in set, 1 warning (0.000 sec)
10.11.1-opt>INSERT INTO t2 VALUES (2,4);
ERROR 1160 (08S01): Got an error writing communication packets
UniqueID's seen for the first testcase in this comment:
SIGSEGV|spider_conn_queue_and_merge_loop_check|spider_conn_reset_queue_loop_check|spider_reset_conn_setted_parameter|spider_db_connect
SIGSEGV|spider_conn_reset_queue_loop_check|spider_reset_conn_setted_parameter|spider_db_connect|spider_db_ping_internal
Core was generated by `/test/MD090823-mariadb-10.4.31-linux-x86_64-opt/bin/mariadbd --no-defaults --co'.
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 0x1484440b1700 (LWP 1187826))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x000014845d184859 in __GI_abort () at abort.c:79
#2 0x000014845d184729 in __assert_fail_base (fmt=0x14845d31a588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x14845d6a462d "mutex->__data.__owner == 0", file=0x14845d6a45fa "../nptl/pthread_mutex_lock.c", line=81, function=<optimized out>) at assert.c:92
#3 0x000014845d195fd6 in __GI___assert_fail (assertion=assertion@entry=0x14845d6a462d "mutex->__data.__owner == 0", file=file@entry=0x14845d6a45fa "../nptl/pthread_mutex_lock.c", line=line@entry=81, function=function@entry=0x14845d6a4790 <__PRETTY_FUNCTION__.10174> "__pthread_mutex_lock") at assert.c:101
#4 0x000014845d698164 in __GI___pthread_mutex_lock (mutex=mutex@entry=0x14840007d760) at ../nptl/pthread_mutex_lock.c:81
#5 0x000014843e63db8f in inline_mysql_mutex_lock (that=0x14840007d760) at /test/10.4_opt/include/mysql/psi/mysql_thread.h:719
#6 ha_spider::rnd_next_internal (this=0x148400042180, buf=0x0) at /test/10.4_opt/storage/spider/ha_spider.cc:7914
#7 0x000014843e63df2a in ha_spider::pre_rnd_next (use_parallel=<optimized out>, this=0x148400042180) at /test/10.4_opt/storage/spider/ha_spider.cc:8068
#8 ha_spider::pre_rnd_next (this=0x148400042180, use_parallel=<optimized out>) at /test/10.4_opt/storage/spider/ha_spider.cc:8060
#9 0x000055623dee3e26 in ha_partition::handle_pre_scan (this=this@entry=0x148400041950, reverse_order=reverse_order@entry=false, use_parallel=true) at /test/10.4_opt/sql/ha_partition.cc:7435
#10 0x000055623dee4159 in ha_partition::rnd_next (this=0x148400041950, buf=0x14840002c190 "\377") at /test/10.4_opt/sql/ha_partition.cc:5196
#11 0x000055623dc9de20 in handler::ha_rnd_next (this=0x148400041950, buf=0x14840002c190 "\377") at /test/10.4_opt/sql/handler.cc:2905
#12 0x000055623dde1dd4 in rr_sequential (info=0x1484440ae390) at /test/10.4_opt/sql/records.h:71
#13 0x000055623ddf7c79 in READ_RECORD::read_record (this=0x1484440ae390) at /test/10.4_opt/sql/records.h:70
#15 0x000055623daa0bd0 in mysql_execute_command (thd=0x148400000c48) at /test/10.4_opt/sql/sql_parse.cc:4810
#16 0x000055623daa63e2 in mysql_parse (thd=0x148400000c48, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_parse.cc:8010
#17 0x000055623daa8e95 in dispatch_command (command=COM_QUERY, thd=0x148400000c48, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_class.h:1231
#18 0x000055623daaa6ef in do_command (thd=0x148400000c48) at /test/10.4_opt/sql/sql_parse.cc:1378
#19 0x000055623db97dde in do_handle_one_connection (connect=<optimized out>) at /test/10.4_opt/sql/sql_connect.cc:1420
#20 0x000055623db97e6d in handle_one_connection (arg=<optimized out>) at /test/10.4_opt/sql/sql_connect.cc:1324
#21 0x000014845d695609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#22 0x000014845d281133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Ramesh Sivaraman
added a comment - Following test case crashes the 10.4 build with a slightly different stack. The test case does not have HANDLER statement.
CREATE TEMPORARY TABLE ti (a INT );
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE TABLE t (c INT ,c2 INT ) engine=Spider PARTITION BY HASH (c) PARTITIONS 4 ;
UPDATE t SET a=((1));
LOCK TABLES t WRITE CONCURRENT;
LOAD DATA INFILE 'unkownfile.txt' IGNORE INTO TABLE t IGNORE 4 LINES;
DELETE FROM t;
Leads to
10.4.31 161ce045a71e306768d4609bdc35788fa5ea2a71 (Optimized)
mariadbd: ../nptl/pthread_mutex_lock.c:81: __pthread_mutex_lock: Assertion `mutex->__data.__owner == 0' failed.
10.4.31 161ce045a71e306768d4609bdc35788fa5ea2a71 (Optimized)
Core was generated by `/test/MD090823-mariadb-10.4.31-linux-x86_64-opt/bin/mariadbd --no-defaults --co'.
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 0x1484440b1700 (LWP 1187826))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x000014845d184859 in __GI_abort () at abort.c:79
#2 0x000014845d184729 in __assert_fail_base (fmt=0x14845d31a588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x14845d6a462d "mutex->__data.__owner == 0", file=0x14845d6a45fa "../nptl/pthread_mutex_lock.c", line=81, function=<optimized out>) at assert.c:92
#3 0x000014845d195fd6 in __GI___assert_fail (assertion=assertion@entry=0x14845d6a462d "mutex->__data.__owner == 0", file=file@entry=0x14845d6a45fa "../nptl/pthread_mutex_lock.c", line=line@entry=81, function=function@entry=0x14845d6a4790 <__PRETTY_FUNCTION__.10174> "__pthread_mutex_lock") at assert.c:101
#4 0x000014845d698164 in __GI___pthread_mutex_lock (mutex=mutex@entry=0x14840007d760) at ../nptl/pthread_mutex_lock.c:81
#5 0x000014843e63db8f in inline_mysql_mutex_lock (that=0x14840007d760) at /test/10.4_opt/include/mysql/psi/mysql_thread.h:719
#6 ha_spider::rnd_next_internal (this=0x148400042180, buf=0x0) at /test/10.4_opt/storage/spider/ha_spider.cc:7914
#7 0x000014843e63df2a in ha_spider::pre_rnd_next (use_parallel=<optimized out>, this=0x148400042180) at /test/10.4_opt/storage/spider/ha_spider.cc:8068
#8 ha_spider::pre_rnd_next (this=0x148400042180, use_parallel=<optimized out>) at /test/10.4_opt/storage/spider/ha_spider.cc:8060
#9 0x000055623dee3e26 in ha_partition::handle_pre_scan (this=this@entry=0x148400041950, reverse_order=reverse_order@entry=false, use_parallel=true) at /test/10.4_opt/sql/ha_partition.cc:7435
#10 0x000055623dee4159 in ha_partition::rnd_next (this=0x148400041950, buf=0x14840002c190 "\377") at /test/10.4_opt/sql/ha_partition.cc:5196
#11 0x000055623dc9de20 in handler::ha_rnd_next (this=0x148400041950, buf=0x14840002c190 "\377") at /test/10.4_opt/sql/handler.cc:2905
#12 0x000055623dde1dd4 in rr_sequential (info=0x1484440ae390) at /test/10.4_opt/sql/records.h:71
#13 0x000055623ddf7c79 in READ_RECORD::read_record (this=0x1484440ae390) at /test/10.4_opt/sql/records.h:70
#14 mysql_delete (thd=thd@entry=0x148400000c48, table_list=0x14840000ff70, conds=<optimized out>, order_list=order_list@entry=0x148400005308, limit=18446744073709551615, options=<optimized out>, result=0x0) at /test/10.4_opt/sql/sql_delete.cc:794
#15 0x000055623daa0bd0 in mysql_execute_command (thd=0x148400000c48) at /test/10.4_opt/sql/sql_parse.cc:4810
#16 0x000055623daa63e2 in mysql_parse (thd=0x148400000c48, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_parse.cc:8010
#17 0x000055623daa8e95 in dispatch_command (command=COM_QUERY, thd=0x148400000c48, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_class.h:1231
#18 0x000055623daaa6ef in do_command (thd=0x148400000c48) at /test/10.4_opt/sql/sql_parse.cc:1378
#19 0x000055623db97dde in do_handle_one_connection (connect=<optimized out>) at /test/10.4_opt/sql/sql_connect.cc:1420
#20 0x000055623db97e6d in handle_one_connection (arg=<optimized out>) at /test/10.4_opt/sql/sql_connect.cc:1324
#21 0x000014845d695609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#22 0x000014845d281133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Roel Van de Paar
added a comment - - edited The last testcase produces this ASAN on 10.4 only (dbg+opt):
10.4.31 ab10a675acb8198d4c772b807b81b50f97480d28 (Debug, UBASAN)
ASAN|heap-use-after-free|storage/spider/ha_spider.cc|ha_spider::rnd_next_internal|ha_spider::pre_rnd_next|ha_partition::handle_pre_scan|ha_partition::rnd_next
Roel Van de Paar
added a comment - - edited Found a large number of ASAN issues using some of the testcases already reported. For example:
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE USER Spider@localhost IDENTIFIED BY 'PWD123' ;
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock' , DATABASE 'test' , USER 'Spider' , PASSWORD 'PWD123' );
CREATE TABLE t1 (b INT , FOREIGN KEY (b) REFERENCES t1 (a)) ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
HANDLER t1 OPEN ;
HANDLER t1 READ b NEXT ;
HANDLER t1 READ b NEXT ;
Leads to (across versions and build types):
ASAN|heap-use-after-free|storage/spider/ha_spider.cc|ha_spider::external_lock|handler::ha_external_lock|lock_external|mysql_lock_tables
ASAN|heap-use-after-free|storage/spider/ha_spider.cc|ha_spider::index_first_internal|ha_spider::index_first|handler::ha_index_first|mysql_ha_read
ASAN|heap-use-after-free|storage/spider/ha_spider.cc|ha_spider::index_first_internal|handler::ha_index_first|mysql_ha_read|mysql_execute_command
ASAN|heap-use-after-free|storage/spider/ha_spider.cc|ha_spider::lock_tables|ha_spider::external_lock|handler::ha_external_lock|lock_external
ASAN|heap-use-after-free|storage/spider/spd_db_conn.cc|spider_db_open_handler|ha_spider::index_handler_init|ha_spider::index_first_internal|ha_spider::index_first
ASAN|heap-use-after-free|storage/spider/spd_db_conn.cc|spider_db_open_handler|ha_spider::index_handler_init|ha_spider::index_first_internal|handler::ha_index_first
Another testcase:
INSTALL PLUGIN spider SONAME 'ha_spider.so' ;
CREATE TABLE t (c INT ) ENGINE=Spider;
HANDLER t OPEN ;
HANDLER t READ next ;
dummy;
HANDLER t READ next ;
Gives these UniqueID's/stacks:
ASAN|heap-use-after-free|storage/spider/ha_spider.cc|ha_spider::external_lock|handler::ha_external_lock|lock_external|mysql_lock_tables
ASAN|heap-use-after-free|storage/spider/ha_spider.cc|ha_spider::lock_tables|ha_spider::external_lock|handler::ha_external_lock|lock_external
ASAN|heap-use-after-free|storage/spider/ha_spider.cc|ha_spider::rnd_next_internal|ha_spider::rnd_next|handler::ha_rnd_next|mysql_ha_read
ASAN|heap-use-after-free|storage/spider/ha_spider.cc|ha_spider::rnd_next_internal|handler::ha_rnd_next|mysql_ha_read|mysql_execute_command
ASAN|heap-use-after-free|storage/spider/spd_db_conn.cc|spider_db_open_handler|ha_spider::rnd_handler_init|ha_spider::rnd_next_internal|ha_spider::rnd_next
ASAN|heap-use-after-free|storage/spider/spd_db_conn.cc|spider_db_open_handler|ha_spider::rnd_handler_init|ha_spider::rnd_next_internal|handler::ha_rnd_next
The latter 4 are not listed above.
This 10.5+ testcase:
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE USER Spider@localhost IDENTIFIED BY 'PWD123' ;
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock' , DATABASE 'test' , USER 'Spider' , PASSWORD 'PWD123' );
CREATE TABLE t (c INT ) ENGINE=InnoDB;
CREATE TABLE t1 (a INT ) ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
CREATE TABLE t2 (c INT ) ENGINE=Spider COMMENT= 'WRAPPER "mysql", srv "srv", TABLE "t"' ;
XA START 'a' ;
SET GLOBAL init_connect= 'SET autocomit=0' ;
INSERT INTO t1 VALUES (0);
INSERT INTO t2 SELECT * FROM t2;
SELECT IF ( 'SELECT COUNT(*) FROM t1 WHERE a=""' REGEXP '^[a-zA-z_][a-zA-z_0-9]*:' , 1, 0);
INSERT INTO t2 VALUES (0);
produces only:
ASAN|heap-use-after-free|storage/spider/spd_conn.cc|spider_conn_queue_and_merge_loop_check|spider_conn_reset_queue_loop_check|spider_reset_conn_setted_parameter|spider_db_connect
Which looks very similar to MDEV-29002
MDEV-27902 Spider create conn on demand in rnd_next()
In 10.4 the testcase also reveals the same issue in MDEV-29962. We
make changes to external_lock() the same way as changes for MDEV-29962
for 10.5+.
For 11.0 see
c2863c66f58 upstream/bb-11.0-mdev-27902 MDEV-27902 Spider check trx and get conn in rnd_next()
Yuchen Pei
added a comment - Hi holyfoot , ptal thanks:
upstream/bb-10.4-mdev-27902 8d75a77f579c29a8ec78ee7d98b65226ebfea4b8
MDEV-27902 Spider create conn on demand in rnd_next()
In 10.4 the testcase also reveals the same issue in MDEV-29962. We
make changes to external_lock() the same way as changes for MDEV-29962
for 10.5+.
For 11.0 see
c2863c66f58 upstream/bb-11.0-mdev-27902 MDEV-27902 Spider check trx and get conn in rnd_next()
I cannot push this yet, as it causes a regression in 10.5 in the test spider/handler.ha.
It's because spider_check_trx_and_get_conn() "re"sets the first link
idx to 0, even though it should be 1. There should be a way to check
that the connection has been freed and only call the function when
that happens. I notice that Nayuta attempted something similar in a
previous comment, but his patch does not fix the test.
Yuchen Pei
added a comment - - edited I cannot push this yet, as it causes a regression in 10.5 in the test
spider/handler.ha .
It's because spider_check_trx_and_get_conn() "re"sets the first link
idx to 0, even though it should be 1. There should be a way to check
that the connection has been freed and only call the function when
that happens. I notice that Nayuta attempted something similar in a
previous comment, but his patch does not fix the test.
ha_spider::set_first_link_idx > spider_check_trx_and_get_conn > ha_spider::rnd_next > handler::ha_rnd_next > find_all_keys > filesort > create_sort_index > st_join_table::sort_table > join_init_read_record > sub_select > do_select > JOIN::exec_inner > JOIN::exec > mysql_select > handle_select > execute_sqlcom_select > mysql_execute_command > mysql_parse
This is a tricky one... I am not convinced Nayuta's solution would
work well. The reason his patch did not fix the test spider/handler.ha
at the statement {{SELECT a, b, date_format(c, '%Y-%m-%d %H:%i:%s')
FROM ta_l ORDER BY a;}} is because trx->conn_hash_freed was
flipped to true in a previous statement, and his patch did not revert
it to false when recreating connections in dml_init() during the
group by handler creation, and thus in rnd_next() because it is
assumed the connections associated with trx have been freed, spider_check_trx_and_get_conn() is called which sets the wrong first_link_idx for the ha_spider. We can flip trx->conn_hash_freed back to false during connection creation spider_get_conn(), which will fix this test. But does that mean we
should use trx->conn_hash_freed to guard every call to spider_check_trx_and_get_conn()? So I moved the guard inside the spider_check_trx_and_get_conn(), but it resulted in failures of
many tests, which is not helped if we add an extra guard checking the
cardinality of trx->trx_conn_hash. I suspect it is caused by trx->conn_hash_freed having default value false, but a newly
created trx should not have the mark that its connections have been
freed.
Taking a step back, we just want to recreate the conns when needed,
and conns are associated with trx (e.g. during rollback, we free conns
associated with the trx, given a handlerton), so why mutating the ha_spider at all? I don't have an answer due to the legacy
codebase, neither do I know how to separate out the conn creation part
for the same reason.
I also tried another simple idea, which is to call reset_first_link_ids() instead of set_first_link_ids(), but it
results in wrong results in spider/handler.ha.
Of course there are still openings from the current analysis to check,
but given the regression caused by the simple patch only affects high
availability which is deprecated and not widely used, and the original
bug in the ticket only affects handler statements which are also
rather obscure, I think we can put this ticket on the back burner for
now, and come back to it if there are no other more important bugs to
work on.
Yuchen Pei
added a comment - This is a tricky one... I am not convinced Nayuta's solution would
work well. The reason his patch did not fix the test spider/handler.ha
at the statement {{SELECT a, b, date_format(c, '%Y-%m-%d %H:%i:%s')
FROM ta_l ORDER BY a;}} is because trx->conn_hash_freed was
flipped to true in a previous statement, and his patch did not revert
it to false when recreating connections in dml_init() during the
group by handler creation, and thus in rnd_next() because it is
assumed the connections associated with trx have been freed,
spider_check_trx_and_get_conn() is called which sets the wrong
first_link_idx for the ha_spider . We can flip
trx->conn_hash_freed back to false during connection creation
spider_get_conn() , which will fix this test. But does that mean we
should use trx->conn_hash_freed to guard every call to
spider_check_trx_and_get_conn() ? So I moved the guard inside the
spider_check_trx_and_get_conn() , but it resulted in failures of
many tests, which is not helped if we add an extra guard checking the
cardinality of trx->trx_conn_hash . I suspect it is caused by
trx->conn_hash_freed having default value false, but a newly
created trx should not have the mark that its connections have been
freed.
Taking a step back, we just want to recreate the conns when needed,
and conns are associated with trx (e.g. during rollback, we free conns
associated with the trx, given a handlerton), so why mutating the
ha_spider at all? I don't have an answer due to the legacy
codebase, neither do I know how to separate out the conn creation part
for the same reason.
I also tried another simple idea, which is to call
reset_first_link_ids() instead of set_first_link_ids() , but it
results in wrong results in spider/handler.ha .
Of course there are still openings from the current analysis to check,
but given the regression caused by the simple patch only affects high
availability which is deprecated and not widely used, and the original
bug in the ticket only affects handler statements which are also
rather obscure, I think we can put this ticket on the back burner for
now, and come back to it if there are no other more important bugs to
work on.
Yuchen Pei
added a comment - Roel my initial patch fixes the heap-use-after-free issue but
causes a regression, see my previous comments:
https://jira.mariadb.org/browse/MDEV-27902?focusedCommentId=277229&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-277229
https://jira.mariadb.org/browse/MDEV-27902?focusedCommentId=277691&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-277691
CREATETABLE ti (a INT UNSIGNED,b INT,c BINARY (1),d BINARY (1),e CHAR(1),f BINARY (1),g BLOB,h BLOB,id INT,KEY(b)) ENGINE=Spider;
INSERTINTO t2 SELECT * FROM t2;
XA START 't2';
SETGLOBAL table_open_cache=-1;
INSERTINTO ti VALUES (+1,+1,'GuouFix9aU','npmQUXtICRhmUw9','fi7fNNixs2eaasF4dW4a3wSm7TnRKtSArEPz1cL4HxSf7',0,0,0,1);
INSERTINTO t2 VALUES (+1);
SELECT SLEEP (1);
INSERTINTO ti VALUES (+1,0,'j5PdMJaSyqZfK4UhINT8bTpIOyMkkl9jSiH1W1WOIioTzyn','9RdEWjrZb9','Uij6wOXbYGNsAKqhhsHlnHOWluciiRwyq','DdMOZMJwyCL5TXAuiwqXLXojWDYUlcxvkWfgwU2LoQeYQEvUTntf7nDFdLNfRUFZgpqddR1Hqq9Hl2MEnuNx8aiOu9s6bQIzw6uwCdM3rfJWSXobIkwhUXnq2aDLSXkTPwHu2VRqHPZ3Ufq1G',0,'E3',4);
Note that this is in spider_db_connect rather than in the earlier seen spider_conn_queue_and_merge_loop_check.
Roel Van de Paar
added a comment - An additional testcase:
SET sql_mode= '' ;
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
CREATE TABLE t2 (a INT ,b CHAR (1)) ENGINE=Spider;
CREATE TABLE ti (a INT UNSIGNED,b INT ,c BINARY (1),d BINARY (1),e CHAR (1),f BINARY (1),g BLOB,h BLOB,id INT , KEY (b)) ENGINE=Spider;
INSERT INTO t2 SELECT * FROM t2;
XA START 't2' ;
SET GLOBAL table_open_cache=-1;
INSERT INTO ti VALUES (+1,+1, 'GuouFix9aU' , 'npmQUXtICRhmUw9' , 'fi7fNNixs2eaasF4dW4a3wSm7TnRKtSArEPz1cL4HxSf7' ,0,0,0,1);
INSERT INTO t2 VALUES (+1);
SELECT SLEEP (1);
INSERT INTO ti VALUES (+1,0, 'j5PdMJaSyqZfK4UhINT8bTpIOyMkkl9jSiH1W1WOIioTzyn' , '9RdEWjrZb9' , 'Uij6wOXbYGNsAKqhhsHlnHOWluciiRwyq' , 'DdMOZMJwyCL5TXAuiwqXLXojWDYUlcxvkWfgwU2LoQeYQEvUTntf7nDFdLNfRUFZgpqddR1Hqq9Hl2MEnuNx8aiOu9s6bQIzw6uwCdM3rfJWSXobIkwhUXnq2aDLSXkTPwHu2VRqHPZ3Ufq1G' ,0, 'E3' ,4);
Which causes the following new ASAN UniqueID:
11.5.0 3f9182126c64bcec359bebe9ebad2a0e559b13e2 (Optimized, UBASAN)
ASAN|heap-use-after-free|storage/spider/spd_db_conn.cc|spider_db_connect|spider_db_conn_queue_action|spider_db_before_query|spider_db_set_names_internal
Note that this is in spider_db_connect rather than in the earlier seen spider_conn_queue_and_merge_loop_check.
Which was the same stack in the previous MDEV-28683, another locking related bug.
Additionally, this testcase produces a real interesting result on optimized builds (CLI replay). The last statement error shows as:
11.5.0-opt>INSERT INTO ti VALUES (+1,0,'j5PdMJaSyqZfK4UhINT8bTpIOyMkkl9jSiH1W1WOIioTzyn','9RdEWjrZb9','Uij6wOXbYGNsAKqhhsHlnHOWluciiRwyq','DdMOZMJwyCL5TXAuiwqXLXojWDYUlcxvkWfgwU2LoQeYQEvUTntf7nDFdLNfRUFZgpqddR1Hqq9Hl2MEnuNx8aiOu9s6bQIzw6uwCdM3rfJWSXobIkwhUXnq2aDLSXkTPwHu2VRqHPZ3Ufq1G',0,'E3',4);
ERROR 1429 (HY000): Unable to connect to foreign data source: localhos@
11.5.0-opt>INSERT INTO ti VALUES (+1,0,'j5PdMJaSyqZfK4UhINT8bTpIOyMkkl9jSiH1W1WOIioTzyn','9RdEWjrZb9','Uij6wOXbYGNsAKqhhsHlnHOWluciiRwyq','DdMOZMJwyCL5TXAuiwqXLXojWDYUlcxvkWfgwU2LoQeYQEvUTntf7nDFdLNfRUFZgpqddR1Hqq9Hl2MEnuNx8aiOu9s6bQIzw6uwCdM3rfJWSXobIkwhUXnq2aDLSXkTPwHu2VRqHPZ3Ufq1G',0,'E3',4);
ERROR 1429 (HY000): Unable to connect to foreign data source: localhos
Note the missing 't' in localhost, at times also replaced by '@'.
Roel Van de Paar
added a comment - The testcase in the previous comment, on 11.5 dbg leads to:
11.5.0 3f9182126c64bcec359bebe9ebad2a0e559b13e2 (Debug)
SIGSEGV|spider_db_connect|spider_db_conn_queue_action|spider_db_before_query|spider_db_set_names_internal
Which was the same stack in the previous MDEV-28683 , another locking related bug.
Additionally, this testcase produces a real interesting result on optimized builds (CLI replay). The last statement error shows as:
11.5.0 3f9182126c64bcec359bebe9ebad2a0e559b13e2 (Optimized)
11.5.0-opt>INSERT INTO ti VALUES (+1,0,'j5PdMJaSyqZfK4UhINT8bTpIOyMkkl9jSiH1W1WOIioTzyn','9RdEWjrZb9','Uij6wOXbYGNsAKqhhsHlnHOWluciiRwyq','DdMOZMJwyCL5TXAuiwqXLXojWDYUlcxvkWfgwU2LoQeYQEvUTntf7nDFdLNfRUFZgpqddR1Hqq9Hl2MEnuNx8aiOu9s6bQIzw6uwCdM3rfJWSXobIkwhUXnq2aDLSXkTPwHu2VRqHPZ3Ufq1G',0,'E3',4);
ERROR 1429 (HY000): Unable to connect to foreign data source: localhos@
Or
11.5.0 3f9182126c64bcec359bebe9ebad2a0e559b13e2 (Optimized)
11.5.0-opt>INSERT INTO ti VALUES (+1,0,'j5PdMJaSyqZfK4UhINT8bTpIOyMkkl9jSiH1W1WOIioTzyn','9RdEWjrZb9','Uij6wOXbYGNsAKqhhsHlnHOWluciiRwyq','DdMOZMJwyCL5TXAuiwqXLXojWDYUlcxvkWfgwU2LoQeYQEvUTntf7nDFdLNfRUFZgpqddR1Hqq9Hl2MEnuNx8aiOu9s6bQIzw6uwCdM3rfJWSXobIkwhUXnq2aDLSXkTPwHu2VRqHPZ3Ufq1G',0,'E3',4);
ERROR 1429 (HY000): Unable to connect to foreign data source: localhos
Note the missing 't' in localhost, at times also replaced by '@'.
The testcases are always similar, i.e. Spider load, two tables created, XA START, SLEEP (1 second), INSERT.
However, interestingly not all testcases set table_open_cache (two do not). Also interesting is that the testcases often are highly sporadic.
I have about 7 testcases in various states of reduction in case it is of interest (NTS: KEEP/MDEV-27902).
Roel Van de Paar
added a comment - I have been seeing the stack from this comment regularly in testing again, i.e.
11.2.5 a21e49cbcc5f4adb1a1b4970ceead6a85e968063 (Debug)
SIGSEGV|spider_db_connect|spider_db_conn_queue_action|spider_db_before_query|spider_db_set_names_internal
The testcases are always similar, i.e. Spider load, two tables created, XA START, SLEEP (1 second), INSERT.
However, interestingly not all testcases set table_open_cache (two do not). Also interesting is that the testcases often are highly sporadic.
I have about 7 testcases in various states of reduction in case it is of interest (NTS: KEEP/ MDEV-27902 ) .
ycp When you have a moment, another look at this one would be appreciated. It is possible that the HANDLER bug differs from the XA bug.
Also may be worthwhile to check if any connection with the previously fixed bugs MDEV-26546 and MDEV-28683.
Likely not connected with MDEV-32585 as no DEFAULT_GROUP was used.
Roel Van de Paar
added a comment - ycp When you have a moment, another look at this one would be appreciated. It is possible that the HANDLER bug differs from the XA bug.
Also may be worthwhile to check if any connection with the previously fixed bugs MDEV-26546 and MDEV-28683 .
Likely not connected with MDEV-32585 as no DEFAULT_GROUP was used.
I will consider the new testcases after my last comment later. I did a quick pass of the first of these cases and could not immediate reprod in my environment, so it will need a closer look. For now, I focus on fixing the previous cases.
I have a fix for the regression (see 42928183666922314fdab7c111c52ce7de659649 in the bb-10.5-ycp branch), but then when I apply my current MDEV-29962 fix, spider.spider_fixes and spider/handler.spider_fixes fails.
Yuchen Pei
added a comment - I will consider the new testcases after my last comment later. I did a quick pass of the first of these cases and could not immediate reprod in my environment, so it will need a closer look. For now, I focus on fixing the previous cases.
I have a fix for the regression (see 42928183666922314fdab7c111c52ce7de659649 in the bb-10.5-ycp branch), but then when I apply my current MDEV-29962 fix, spider.spider_fixes and spider/handler.spider_fixes fails.
#2 0x0000153ba8108926 in spider_db_connect (share=0x153b6c01d4f8, conn=conn@entry=0x153b6c0aec98, link_idx=0)at /test/11.2_opt/storage/spider/spd_db_conn.cc:143
#3 0x0000153ba8109570 in spider_db_conn_queue_action (conn=conn@entry=0x153b6c0aec98)at /test/11.2_opt/storage/spider/spd_db_conn.cc:256
#4 0x0000153ba810ea90 in spider_db_before_query (conn=0x153b6c0aec98, need_mon=<optimized out>)at /test/11.2_opt/storage/spider/spd_db_conn.cc:571
#5 0x0000153ba810ec92 in spider_db_set_names_internal (trx=0x153b6c1abc08, share=0x153b6c0ab3d8, conn=conn@entry=0x153b6c0aec98, all_link_idx=0, need_mon=0x558955715a38)at /test/11.2_opt/storage/spider/spd_db_conn.cc:799
#6 0x0000153ba810ee49 in spider_db_set_names (spider=spider@entry=0x153b6c05c850, conn=conn@entry=0x153b6c0aec98, link_idx=link_idx@entry=0)at /test/11.2_opt/storage/spider/spd_db_conn.cc:842
#7 0x0000153ba8112cf5 in spider_db_bulk_insert (spider=spider@entry=0x153b6c05c850, table=0x153b6c1b4308, copy_info=copy_info@entry=0x153b6c05cc88, bulk_end=bulk_end@entry=false)at /test/11.2_opt/storage/spider/spd_db_conn.cc:5437
#8 0x0000153ba8165167 in ha_spider::write_row (this=0x153b6c05c850, buf=0x153b6c17aac8 <incomplete sequence \373>)at /test/11.2_opt/storage/spider/ha_spider.cc:7818
#9 0x000055895287e638 in handler::ha_write_row (this=0x153b6c05c850, buf=0x153b6c17aac8 <incomplete sequence \373>)at /test/11.2_opt/sql/handler.cc:7934
#10 0x00005589525adfe2 in write_record (thd=thd@entry=0x153b6c000c68, table=table@entry=0x153b6c1b4308, info=info@entry=0x153bb40c5400, sink=sink@entry=0x0) at /test/11.2_opt/sql/sql_insert.cc:2268
#11 0x00005589525b7ef0 in mysql_insert (thd=thd@entry=0x153b6c000c68, table_list=<optimized out>, fields=@0x153b6c005f20: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x5589539a0bd0 <end_of_list>, last = 0x153b6c005f20, elements = 0}, <No data fields>}, values_list=@0x153b6c005f68: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x153b6c011960, last = 0x153b6c011960, elements = 1}, <No data fields>}, update_fields=@0x153b6c005f50: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x5589539a0bd0 <end_of_list>, last = 0x153b6c005f50, elements = 0}, <No data fields>}, update_values=@0x153b6c005f38: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x5589539a0bd0 <end_of_list>, last = 0x153b6c005f38, elements = 0}, <No data fields>}, duplic=DUP_ERROR, ignore=false, result=0x0)at /test/11.2_opt/sql/sql_insert.cc:1159
#12 0x00005589525ed833 in mysql_execute_command (thd=thd@entry=0x153b6c000c68, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false)at /test/11.2_opt/sql/sql_parse.cc:4489
#13 0x00005589525f17d6 in mysql_parse (thd=0x153b6c000c68, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/11.2_opt/sql/sql_parse.cc:7920
#14 0x00005589525f39a5 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x153b6c000c68, packet=packet@entry=0x153b6c008839 "INSERT INTO t2 VALUES (NULL,'b');", packet_length=packet_length@entry=33, blocking=blocking@entry=true)at /test/11.2_opt/sql/sql_parse.cc:1993
#15 0x00005589525f5e90 in do_command (thd=0x153b6c000c68, blocking=blocking@entry=true) at /test/11.2_opt/sql/sql_parse.cc:1407
#16 0x00005589527223af in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55895568fcb8, put_in_cache=put_in_cache@entry=true)at /test/11.2_opt/sql/sql_connect.cc:1439
#17 0x00005589527226fd in handle_one_connection (arg=arg@entry=0x55895568fcb8)at /test/11.2_opt/sql/sql_connect.cc:1341
#18 0x0000558952ace3f1 in pfs_spawn_thread (arg=0x5589556d48a8)at /test/11.2_opt/storage/perfschema/pfs.cc:2201
#19 0x0000153bbd297ada in start_thread (arg=<optimized out>)at ./nptl/pthread_create.c:444
#20 0x0000153bbd32847c in clone3 ()at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78
(Note the handler::ha_write_row involvement, even though HANDLER is not directly present in the SQL.)
As well as other stacks:
ycp Hi! If you think it would help, I can attempt to create an MTR testcase for the sporadic testcase in the last comment.
Roel Van de Paar
added a comment - ycp Hi! If you think it would help, I can attempt to create an MTR testcase for the sporadic testcase in the last comment.
a867186328f upstream/bb-10.5-mdev-27902 MDEV-27902 Spider check trx and get conn in rnd_next()
e58420987d9 MDEV-27902 Some Spider code documentation regarding first_link_idx and remote HANDLER commands
Yuchen Pei
added a comment - - edited Let's wrap up this issue. I'll take a look at the new testcases, and if they still reprod, get them in a new issue.
Hi holyfoot , ptal thanks
a867186328f upstream/bb-10.5-mdev-27902 MDEV-27902 Spider check trx and get conn in rnd_next()
e58420987d9 MDEV-27902 Some Spider code documentation regarding first_link_idx and remote HANDLER commands
I had a look at the new case with the help of Roel. The following test crashes at 11.2.5 a21e49cbcc5f4adb1a1b4970ceead6a85e968063, but no longer does at bb-10.5-ycp 3b51d6a4a5b8038d62b9bc60d755c50e44934c5c which contains the fix of this bug as well as MDEV-29962 etc.
INSTALL PLUGIN Spider SONAME 'ha_spider.so';
SET default_storage_engine=Spider;
CREATEDATABASE db1 CHARACTERSET utf8;
CREATETABLE db1.t1 (a INT, b INT);
HANDLER db1.t1 OPEN;
--error ER_BAD_TABLE_ERROR
DROPTABLE t1;
--error ER_CONNECT_TO_FOREIGN_DATA_SOURCE
HANDLER t1 READNEXT LIMIT 2;
--error ER_NO_SUCH_TABLE
SELECTCOUNT(*) FROM foo;
# crash site
--error ER_CONNECT_TO_FOREIGN_DATA_SOURCE
HANDLER t1 READNEXT;
Yuchen Pei
added a comment - I had a look at the new case with the help of Roel . The following test crashes at 11.2.5 a21e49cbcc5f4adb1a1b4970ceead6a85e968063, but no longer does at bb-10.5-ycp 3b51d6a4a5b8038d62b9bc60d755c50e44934c5c which contains the fix of this bug as well as MDEV-29962 etc.
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
SET default_storage_engine=Spider;
CREATE DATABASE db1 CHARACTER SET utf8;
CREATE TABLE db1.t1 (a INT , b INT );
HANDLER db1.t1 OPEN ;
--error ER_BAD_TABLE_ERROR
DROP TABLE t1;
--error ER_CONNECT_TO_FOREIGN_DATA_SOURCE
HANDLER t1 READ NEXT LIMIT 2;
--error ER_NO_SUCH_TABLE
SELECT COUNT (*) FROM foo;
# crash site
--error ER_CONNECT_TO_FOREIGN_DATA_SOURCE
HANDLER t1 READ NEXT ;
Still reproduces in bb-11.6-mdev-32492-27902-29962 and was split to MDEV-34555 (SIGSEGV in spider_conn_queue_and_merge_loop_check)
Roel Van de Paar
added a comment -
SIGSEGV|spider_conn_queue_and_merge_loop_check|spider_conn_reset_queue_loop_check|spider_reset_conn_setted_parameter|spider_db_connect
Still reproduces in bb-11.6-mdev-32492-27902-29962 and was split to MDEV-34555 (SIGSEGV in spider_conn_queue_and_merge_loop_check)
Thanks for the review - pushed the following to 10.5
696c2497fcc MDEV-27902 Spider check trx and get conn in rnd_next()
85a36958e35 MDEV-27902 Some Spider code documentation regarding first_link_idx and remote HANDLER commands
Yuchen Pei
added a comment - Thanks for the review - pushed the following to 10.5
696c2497fcc MDEV-27902 Spider check trx and get conn in rnd_next()
85a36958e35 MDEV-27902 Some Spider code documentation regarding first_link_idx and remote HANDLER commands
Roel Van de Paar
added a comment - The following additional stacks were observed during MENT-2070 testing:
INSTALL PLUGIN Spider SONAME 'ha_spider.so' ;
SET default_storage_engine=Spider;
CREATE TABLE t (c INT ,c1 CHAR (5),c3 DATE ) PARTITION BY HASH ( YEAR (c3));
SET SESSION profiling= ON ;
INSERT INTO t VALUES (1,1, '' );
CREATE TABLE t1 (id INT ) ENGINE=Spider;
XA START 'a' ;
SET GLOBAL table_open_cache=1;
INSERT INTO t1 VALUES (+1);
SELECT * FROM t;
SELECT SLEEP(1);
SELECT * FROM t1 WHERE id=2 OR id=5 OR id=9;
Leading to:
SIGSEGV|__strcmp_evex|spider_db_mbase::connect|spider_db_connect|spider_db_conn_queue_action
SIGSEGV|__strnlen_evex|process_str_arg|my_vsnprintf_ex|my_error
MTR test case
--echo #
--echo # MDEV-27902 SIGSEGV's in spider_check_and_set_trx_isolation and spider_db_open_handler, __pthread_mutex_lock:
--echo # Assertion `mutex->__data.__owner == 0' failed in psi_mutex_lock and inline_mysql_mutex_lock
--echo #
--disable_query_log
--disable_result_log
--source ../../t/test_init.inc
--enable_result_log
--enable_query_log
--connection master_1
--error ER_CONNECT_TO_FOREIGN_DATA_SOURCE
--error ER_PARSE_ERROR
dummy;
--error ER_CONNECT_TO_FOREIGN_DATA_SOURCE
--disable_query_log
--disable_result_log
--source ../../t/test_deinit.inc
--enable_result_log