[MDEV-23208] SIGSEGV in TABLE_LIST::print on SHOW FUNCTION CODE *and* Assertion `s' failed in TABLE::versioned on SHOW FUNCTION CODE Created: 2020-07-18  Updated: 2023-06-22

Status: Open
Project: MariaDB Server
Component/s: Data Definition - Temporary
Affects Version/s: 10.3, 10.4, 10.5, 11.1, 11.2
Fix Version/s: 10.4, 10.5, 11.1, 11.2

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Oleksandr Byelkin
Resolution: Unresolved Votes: 0
Labels: not-10.1, not-10.2, regression

Issue Links:
Relates
relates to MDEV-25784 Server crashes in Table_function_json... Confirmed

 Description   

USE test;
SET SQL_MODE='';
CREATE FUNCTION f(z INT) RETURNS INT READS SQL DATA RETURN (SELECT x FROM t WHERE x = z);
CREATE TEMPORARY TABLE t (c INT) ENGINE=InnoDB;
SELECT f('a');
DROP TEMPORARY TABLES t;
SHOW FUNCTION CODE f;

Leads to:

10.5.5 30e7a0a866dce530d8328c6d614e48d39a264f9b

Core was generated by `/test/MD140720-mariadb-10.5.5-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=11)
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
[Current thread is 1 (Thread 0x153fb7541700 (LWP 1691430))]
(gdb) bt
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
#1  0x000056063413d4d7 in my_write_core (sig=sig@entry=11) at /test/10.5_dbg/mysys/stacktrace.c:518
#2  0x00005606338f79ba in handle_fatal_signal (sig=11) at /test/10.5_dbg/sql/signal_handler.cc:330
#3  <signal handler called>
#4  TABLE_LIST::print (this=0x153f92c90568, thd=thd@entry=0x153f92c15088, eliminated_tables=eliminated_tables@entry=0, str=str@entry=0x153fb753f2a0, query_type=query_type@entry=QT_ITEM_ORIGINAL_FUNC_NULLIF) at /test/10.5_dbg/sql/sql_select.cc:27553
#5  0x00005606336a8876 in print_table_array (query_type=QT_ITEM_ORIGINAL_FUNC_NULLIF, end=0x153f92c742e8, table=0x153f92c742e0, str=0x153fb753f2a0, eliminated_tables=0, thd=0x153f92c15088) at /test/10.5_dbg/sql/sql_select.cc:27243
#6  print_join (thd=thd@entry=0x153f92c15088, eliminated_tables=0, str=str@entry=0x153fb753f2a0, tables=0x153f92c90130, query_type=query_type@entry=QT_ITEM_ORIGINAL_FUNC_NULLIF) at /test/10.5_dbg/sql/sql_select.cc:27399
#7  0x00005606336a8e23 in st_select_lex::print (this=0x153f92c8ff68, thd=thd@entry=0x153f92c15088, str=str@entry=0x153fb753f2a0, query_type=query_type@entry=QT_ITEM_ORIGINAL_FUNC_NULLIF) at /test/10.5_dbg/sql/sql_select.cc:27699
#8  0x00005606339e4696 in subselect_single_select_engine::print (this=0x153f92c91030, str=0x153fb753f2a0, query_type=QT_ITEM_ORIGINAL_FUNC_NULLIF) at /test/10.5_dbg/sql/item_subselect.cc:4478
#9  0x00005606339e4c03 in Item_subselect::print (this=0x153f92c90e88, str=0x153fb753f2a0, query_type=QT_ITEM_ORIGINAL_FUNC_NULLIF) at /test/10.5_dbg/sql/item_subselect.cc:1038
#10 0x000056063357fd83 in sp_instr_freturn::print (this=0x153f92c8dea0, str=0x153fb753f2a0) at /test/10.5_dbg/sql/sp_head.cc:4203
#11 0x000056063358a50e in sp_head::show_routine_code (this=0x153f92c8f0a0, thd=thd@entry=0x153f92c15088) at /test/10.5_dbg/sql/sp_head.cc:3385
#12 0x00005606336505e5 in mysql_execute_command (thd=thd@entry=0x153f92c15088) at /test/10.5_dbg/sql/sql_parse.cc:5728
#13 0x0000560633658752 in mysql_parse (thd=thd@entry=0x153f92c15088, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x153fb7540350, 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:7993
#14 0x0000560633645204 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x153f92c15088, packet=packet@entry=0x153f92c67089 "", packet_length=packet_length@entry=20, 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:1866
#15 0x00005606336439de in do_command (thd=0x153f92c15088) at /test/10.5_dbg/sql/sql_parse.cc:1347
#16 0x000056063379fc3b in do_handle_one_connection (connect=<optimized out>, connect@entry=0x153f964c7808, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1411
#17 0x00005606337a0357 in handle_one_connection (arg=arg@entry=0x153f964c7808) at /test/10.5_dbg/sql/sql_connect.cc:1313
#18 0x0000560633c03ca8 in pfs_spawn_thread (arg=0x153fb4446508) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
#19 0x0000153fb64ba6db in start_thread (arg=0x153fb7541700) at pthread_create.c:463
#20 0x0000153fb58b8a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.3.24 (dbg), 10.4.15 (dbg), 10.5.5 (dbg)

Bug confirmed not present in:
MariaDB: 10.1.46 (dbg), 10.1.46 (opt), 10.2.33 (dbg), 10.2.33 (opt), 10.3.24 (opt), 10.4.14 (dbg), 10.4.14 (opt), 10.5.5 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.47 (dbg), 5.6.47 (opt), 5.7.29 (dbg), 5.7.29 (opt), 8.0.19 (dbg), 8.0.19 (opt)



 Comments   
Comment by Roel Van de Paar [ 2020-09-09 ]

DROP DATABASE test;
CREATE DATABASE test;
USE test;
SET INNODB_DEFAULT_ENCRYPTION_KEY_ID=99;
CREATE TABLE t(c INT) ENGINE=InnoDB;
CREATE FUNCTION f() RETURNS INT RETURN (SELECT * FROM t);
SELECT f();
ALTER TABLE t ADD COLUMN d INT;
SHOW FUNCTION CODE f;

Also reproduces the issue (seemingly deterministic) on 10.5, and highly sporadically on 10.4, both with the same Unique Bug ID. However, 10.4 also has an assert being triggered (hard to hit), ref next comment

Comment by Roel Van de Paar [ 2020-09-09 ]

This testcase:

set innodb_default_encryption_key_id = 99;
USE test;
CREATE TABLE t1(c1 VARBINARY(30) NOT NULL, INDEX i1 (c1));
select SQL_CALC_FOUND_ROWS b,count(*) as c FROM t1  group by b order by c desc limit 1;
CREATE FUNCTION f1 () RETURNS int RETURN (SELECT COUNT(*) FROM t1 );
DROP TABLE IF EXISTS t1;
create TABLE t1 (c1 int) engine=InnoDB pack_keys=0;
INSERT INTO t VALUES (-2954245530716247387,3303582,'Fs0j8Aoxn9zWAkm4hJx8IMXQLF3KIryMiFyvWj','A0OosL','nY05l6MK6PKBLwvYA1vDzAjBzkjHxaOmzEPi4VMMwalMVQqZrFI2F12E2idYFD','Ryw','R','O',7);
select test.f1();
ALTER TABLE `t1` ADD COLUMN `b` INT;
SHOW FUNCTION CODE f1; ;
SELECT SLEEP(3);

Can at times (highly sporadically and may require the C-API i.e. pquery) produce the assertion below.

10.4.15 eae968f62d285de97ed607c87bc131cd863d5d03

mysqld: /test/10.4_dbg/sql/table.h:1680: bool TABLE::versioned() const: Assertion `s' failed.

10.4.15 eae968f62d285de97ed607c87bc131cd863d5d03

Core was generated by `/test/MD110820-mariadb-10.4.15-linux-x86_64-dbg/bin/mysqld --no-defaults --max_'.
Program terminated with signal SIGABRT, Aborted.
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
[Current thread is 1 (Thread 0x147dc40b2700 (LWP 1029395))]
(gdb) bt
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
#1  0x00005581112a18a6 in my_write_core (sig=sig@entry=6) at /test/10.4_dbg/mysys/stacktrace.c:482
#2  0x0000558110a1dcdc in handle_fatal_signal (sig=6) at /test/10.4_dbg/sql/signal_handler.cc:343
#3  <signal handler called>
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#5  0x0000147dcdbf88b1 in __GI_abort () at abort.c:79
#6  0x0000147dcdbe842a in __assert_fail_base (fmt=0x147dcdd6fa38 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x55811167aba5 "s", file=file@entry=0x55811137b959 "/test/10.4_dbg/sql/table.h", line=line@entry=1680, function=function@entry=0x5581113a4d30 <_ZZNK5TABLE9versionedEvE19__PRETTY_FUNCTION__> "bool TABLE::versioned() const") at assert.c:92
#7  0x0000147dcdbe84a2 in __GI___assert_fail (assertion=assertion@entry=0x55811167aba5 "s", file=file@entry=0x55811137b959 "/test/10.4_dbg/sql/table.h", line=line@entry=1680, function=function@entry=0x5581113a4d30 <_ZZNK5TABLE9versionedEvE19__PRETTY_FUNCTION__> "bool TABLE::versioned() const") at assert.c:101
#8  0x00005581107d6562 in TABLE::versioned (this=0x147d5c5f0fc0) at /test/10.4_dbg/sql/table.h:1680
#9  TABLE_LIST::print (this=0x147d5c61d168, thd=thd@entry=0x147d5c000d50, eliminated_tables=eliminated_tables@entry=0, str=str@entry=0x147dc40ae9b0, query_type=query_type@entry=QT_ITEM_ORIGINAL_FUNC_NULLIF) at /test/10.4_dbg/sql/sql_select.cc:27360
#10 0x00005581107d6ab4 in print_table_array (query_type=QT_ITEM_ORIGINAL_FUNC_NULLIF, end=0x147d5c6bf390, table=0x147d5c6bf388, str=0x147dc40ae9b0, eliminated_tables=0, thd=0x147d5c000d50) at /test/10.4_dbg/sql/sql_select.cc:27050
#11 print_join (thd=thd@entry=0x147d5c000d50, eliminated_tables=0, str=str@entry=0x147dc40ae9b0, tables=0x147d5c61cc88, query_type=query_type@entry=QT_ITEM_ORIGINAL_FUNC_NULLIF) at /test/10.4_dbg/sql/sql_select.cc:27206
#12 0x00005581107d705e in st_select_lex::print (this=this@entry=0x147d5c61cac8, thd=0x147d5c000d50, str=str@entry=0x147dc40ae9b0, query_type=query_type@entry=QT_ITEM_ORIGINAL_FUNC_NULLIF) at /test/10.4_dbg/sql/sql_select.cc:27506
#13 0x0000558110b076da in subselect_single_select_engine::print (this=0x147d5c61d9d0, str=0x147dc40ae9b0, query_type=QT_ITEM_ORIGINAL_FUNC_NULLIF) at /test/10.4_dbg/sql/item_subselect.cc:4457
#14 0x0000558110b07c39 in Item_subselect::print (this=0x147d5c61d848, str=0x147dc40ae9b0, query_type=QT_ITEM_ORIGINAL_FUNC_NULLIF) at /test/10.4_dbg/sql/item_subselect.cc:1002
#15 0x00005581106a271a in sp_instr_freturn::print (this=0x147d5c61da10, str=0x147dc40ae9b0) at /test/10.4_dbg/sql/sp_head.cc:4112
#16 0x00005581106aca8a in sp_head::show_routine_code (this=0x147d5c61bdf8, thd=thd@entry=0x147d5c000d50) at /test/10.4_dbg/sql/sp_head.cc:3312
#17 0x0000558110772221 in mysql_execute_command (thd=thd@entry=0x147d5c000d50) at /test/10.4_dbg/sql/sql_parse.cc:5888
#18 0x0000558110775090 in mysql_parse (thd=thd@entry=0x147d5c000d50, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x147dc40b1470, 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:7896
#19 0x0000558110777920 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x147d5c000d50, packet=packet@entry=0x147d5cd3d361 "", packet_length=packet_length@entry=22, 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:1834
#20 0x000055811077b35b in do_command (thd=0x147d5c000d50) at /test/10.4_dbg/sql/sql_parse.cc:1352
#21 0x00005581108a78b6 in do_handle_one_connection (connect=connect@entry=0x558114a66560) at /test/10.4_dbg/sql/sql_connect.cc:1412
#22 0x00005581108a79d6 in handle_one_connection (arg=arg@entry=0x558114a66560) at /test/10.4_dbg/sql/sql_connect.cc:1316
#23 0x00005581111b4898 in pfs_spawn_thread (arg=0x558114974440) at /test/10.4_dbg/storage/perfschema/pfs.cc:1869
#24 0x0000147dceb5f6db in start_thread (arg=0x147dc40b2700) at pthread_create.c:463
#25 0x0000147dcdcd9a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment by Roel Van de Paar [ 2020-09-09 ]

# mysqld options in use during reduction: --sql_mode=ONLY_FULL_GROUP_BY --log-output=none --performance-schema --performance-schema-instrument='%=on' --default-tmp-storage-engine=MyISAM --innodb_file_per_table=1 --innodb_flush_method=O_DIRECT
USE test;
CREATE TEMPORARY TABLE t1 ( i int) ;
CREATE TABLE ti (a SMALLINT UNSIGNED NOT NULL, b BIGINT UNSIGNED, c BINARY(94), d VARCHAR(56), e VARBINARY(95) NOT NULL, f VARCHAR(58) NOT NULL, g LONGBLOB, h TINYBLOB NOT NULL, id BIGINT NOT NULL, KEY(b), KEY(e), PRIMARY KEY(id)) ;
CREATE TABLE  t2  (a BINARY(246));
CREATE TABLE t1 (a INT, b VARCHAR(20)) ;
create function f1() returns int deterministic return (select max(a) from  t4 );
CREATE TABLE  t4  (f1 INTEGER, PRIMARY KEY (f1)) ;
DROP TABLE t1;
SET @@global.table_open_cache = FALSE;
SELECT f1();
call mtr.add_suppression("Plugin keyring_vault reported");
SELECT EVENT_ID, EVENT_NAME, TIMER_WAIT FROM performance_schema.events_waits_history WHERE EVENT_NAME LIKE 'abcdefghijklmnopqrstuvwxyz';
UPDATE t1 SET field1 = 'abcdefghijklmnopqrstuvwxyz' WHERE field2 = 'abcdefghijklmnopqrstuvwxyz';
INSERT INTO ti VALUES (17667088284071814827,115,'abcdefghijklmnopqrstuvwxyz','abcdefghijklmnopqrstuvwxyz','abcdefghijklmnopqrstuvwxyz','abcdefghijklmnopqrstuvwxyz','abcdefghijklmnopqrstuvwxyz','abcdefghijklmnopqrstuvwxyz',10);
SELECT * FROM performance_schema.hosts;
INSERT INTO  t2  VALUES (-1340711133,14018,'abcdefghijklmnopqrstuvwxyz','abcdefghijklmnopqrstuvwxyz','abcdefghijklmnopqrstuvwxyz','abcdefghijklmnopqrstuvwxyz','abcdefghijklmnopqrstuvwxyz','abcdefghijklmnopqrstuvwxyz',4);
select * from t1 A, t1 B where B.rowkey=A.a;
show function code f1; ;

Will produce the issue better on 10.4. It is also capable of producing the 's' assert, but may need high frequency for this as well as replay via the C-API/pquery. While it can likely be reduced further, I am not confident the 's' assert can then still be produced with the same.

Comment by Ramesh Sivaraman [ 2023-06-22 ]

Found similar stack on UBSAN debug build.

CREATE FUNCTION f0() RETURNS INT RETURN (SELECT * FROM t);
CREATE TABLE t (a INT);
CREATE TABLE t2 SELECT f0();
DROP TABLE IF EXISTS t;
SHOW FUNCTION f0;

11.2.0 acb02f646ebbd8b100c30621b92dcc0e2e4db7b3 (Debug, UBASAN)

==3332064==ERROR: AddressSanitizer: heap-use-after-free on address 0x619000074998 at pc 0x55ce9f30a582 bp 0x151ed1b83ae0 sp 0x151ed1b83ad0
READ of size 8 at 0x619000074998 thread T22
    #0 0x55ce9f30a581 in TABLE::versioned() const /test/mtest/MDEV-5816/11.1_dbg_san/sql/table.h:1844
    #1 0x55ce9f30a581 in TABLE_LIST::print(THD*, unsigned long long, String*, enum_query_type) /test/mtest/MDEV-5816/11.1_dbg_san/sql/sql_select.cc:30721
    #2 0x55ce9f30c3c3 in print_table_array /test/mtest/MDEV-5816/11.1_dbg_san/sql/sql_select.cc:30403
    #3 0x55ce9f30c3c3 in print_join /test/mtest/MDEV-5816/11.1_dbg_san/sql/sql_select.cc:30559
    #4 0x55ce9f312f73 in st_select_lex::print(THD*, String*, enum_query_type) /test/mtest/MDEV-5816/11.1_dbg_san/sql/sql_select.cc:31072
    #5 0x55cea13f9958 in subselect_single_select_engine::print(String*, enum_query_type) /test/mtest/MDEV-5816/11.1_dbg_san/sql/item_subselect.cc:4668
    #6 0x55cea141cda9 in Item_subselect::print(String*, enum_query_type) /test/mtest/MDEV-5816/11.1_dbg_san/sql/item_subselect.cc:1081
    #7 0x55ce9ff262e8 in sp_instr_freturn::print(String*) /test/mtest/MDEV-5816/11.1_dbg_san/sql/sp_instr.cc:1402
    #8 0x55ce9e95fdb3 in sp_head::show_routine_code(THD*) /test/mtest/MDEV-5816/11.1_dbg_san/sql/sp_head.cc:3341
    #9 0x55ce9efa58f9 in mysql_execute_command(THD*, bool) /test/mtest/MDEV-5816/11.1_dbg_san/sql/sql_parse.cc:5543
    #10 0x55ce9eef2d8f in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/mtest/MDEV-5816/11.1_dbg_san/sql/sql_parse.cc:7769
    #11 0x55ce9ef60edc in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/mtest/MDEV-5816/11.1_dbg_san/sql/sql_parse.cc:1892
    #12 0x55ce9ef72804 in do_command(THD*, bool) /test/mtest/MDEV-5816/11.1_dbg_san/sql/sql_parse.cc:1405
    #13 0x55ce9fa11c11 in do_handle_one_connection(CONNECT*, bool) /test/mtest/MDEV-5816/11.1_dbg_san/sql/sql_connect.cc:1416
    #14 0x55ce9fa1438b in handle_one_connection /test/mtest/MDEV-5816/11.1_dbg_san/sql/sql_connect.cc:1318
    #15 0x151ef5dd0608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
    #16 0x151ef5045132 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x11f132)

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