[MDEV-22907] Assertion `(m_storage_engine_name.str != __null) == used_engine' failed in Sql_cmd_alter_table::execute on 2nd prepared statement OR stored procedure exec Created: 2020-06-16  Updated: 2023-04-27

Status: Open
Project: MariaDB Server
Component/s: Prepared Statements, Stored routines
Affects Version/s: 10.1, 10.2, 10.3, 10.4, 10.5, 10.6
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Dmitry Shulga
Resolution: Unresolved Votes: 0
Labels: affects-tests

Issue Links:
Relates
relates to MDEV-22546 Server hangs on 2nd execution of PS w... Open

 Description   

May be related to MDEV-22546, though the outcome (assert message vs hang) is different as are the versions affected.

SET SQL_MODE='';
 
SET @cmd="ALTER TABLE non.existing ENGINE=NDB";
 
PREPARE stmt FROM @cmd;
 
EXECUTE stmt;
 
EXECUTE stmt;

Leads to:

10.5.4 4080e3acefd7e58d88c2f3539fb6a0fb359cf057

 
mysqld: /test/10.5_dbg/sql/sql_alter.cc:393: virtual bool Sql_cmd_alter_table::execute(THD*): Assertion `(m_storage_engine_name.str != __null) == used_engine' failed.

10.5.4 4080e3acefd7e58d88c2f3539fb6a0fb359cf057

 
Core was generated by `/test/MD150620-mariadb-10.5.4-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
[Current thread is 1 (Thread 0x14edd0d0c700 (LWP 2682043))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
#1  0x000055ae46d134c6 in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
 
#2  0x000055ae464b5d60 in handle_fatal_signal (sig=6) at /test/10.5_dbg/sql/signal_handler.cc:330
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
#5  0x000014edd9470801 in __GI_abort () at abort.c:79
 
#6  0x000014edd946039a in __assert_fail_base (fmt=0x14edd95e77d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x55ae46ead170 "(m_storage_engine_name.str != __null) == used_engine", file=file@entry=0x55ae46ec8250 "/test/10.5_dbg/sql/sql_alter.cc", line=line@entry=393, function=function@entry=0x55ae46ec8520 <Sql_cmd_alter_table::execute(THD*)::__PRETTY_FUNCTION__> "virtual bool Sql_cmd_alter_table::execute(THD*)") at assert.c:92
 
#7  0x000014edd9460412 in __GI___assert_fail (assertion=assertion@entry=0x55ae46ead170 "(m_storage_engine_name.str != __null) == used_engine", file=file@entry=0x55ae46ec8250 "/test/10.5_dbg/sql/sql_alter.cc", line=line@entry=393, function=function@entry=0x55ae46ec8520 <Sql_cmd_alter_table::execute(THD*)::__PRETTY_FUNCTION__> "virtual bool Sql_cmd_alter_table::execute(THD*)") at assert.c:101
 
#8  0x000055ae463665d9 in Sql_cmd_alter_table::execute (this=0x14edb7482410, thd=0x14edb7415088) at /test/10.5_dbg/sql/sql_alter.cc:393
 
#9  0x000055ae46210860 in mysql_execute_command (thd=0x14edb7415088) at /test/10.5_dbg/sql/sql_parse.cc:5951
 
#10 0x000055ae4623140f in Prepared_statement::execute (this=this@entry=0x14edb7452088, expanded_query=expanded_query@entry=0x14edd0d0aab0, open_cursor=open_cursor@entry=false) at /test/10.5_dbg/sql/sql_prepare.cc:4786
 
#11 0x000055ae4623175c in Prepared_statement::execute_loop (this=this@entry=0x14edb7452088, expanded_query=expanded_query@entry=0x14edd0d0aab0, open_cursor=open_cursor@entry=false, packet=packet@entry=0x0, packet_end=packet_end@entry=0x0) at /test/10.5_dbg/sql/sql_prepare.cc:4275
 
#12 0x000055ae46231d4b in mysql_sql_stmt_execute (thd=thd@entry=0x14edb7415088) at /test/10.5_dbg/sql/sql_prepare.cc:3387
 
#13 0x000055ae4620b372 in mysql_execute_command (thd=thd@entry=0x14edb7415088) at /test/10.5_dbg/sql/sql_parse.cc:3955
 
#14 0x000055ae4621815c in mysql_parse (thd=thd@entry=0x14edb7415088, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14edd0d0b350, 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
 
#15 0x000055ae46204c60 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14edb7415088, packet=packet@entry=0x14edb7467089 "EXECUTE stmt", packet_length=packet_length@entry=12, 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:1874
 
#16 0x000055ae4620343a in do_command (thd=0x14edb7415088) at /test/10.5_dbg/sql/sql_parse.cc:1355
 
#17 0x000055ae4635ec47 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x14edba97a808, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1411
 
#18 0x000055ae4635f363 in handle_one_connection (arg=arg@entry=0x14edba97a808) at /test/10.5_dbg/sql/sql_connect.cc:1313
 
#19 0x000055ae467c0902 in pfs_spawn_thread (arg=0x14edd8046c88) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
 
#20 0x000014edda1536db in start_thread (arg=0x14edd0d0c700) at pthread_create.c:463
 
#21 0x000014edd955188f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.1.46 (dbg), 10.2.33 (dbg), 10.3.24 (dbg), 10.4.14 (dbg), 10.5.4 (dbg)

Bug confirmed not present in:
MariaDB: 10.1.46 (opt), 10.2.33 (opt), 10.3.24 (opt), 10.4.14 (opt), 10.5.4 (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 [ 2021-04-01 ] 

SET sql_mode='';
 
CREATE PROCEDURE p1 (IN i INT) ALTER TABLE t ENGINE=none;
 
CALL p1 (1);
 
CALL p1 (1);

Leads to:

10.6.0 609e8e38bb0e5c80a80c77c451b6e519f9aeb386 (Debug)

 
mysqld: /test/10.6_dbg/sql/sql_alter.cc:396: virtual bool Sql_cmd_alter_table::execute(THD*): Assertion `(m_storage_engine_name.str != __null) == used_engine' failed.

10.6.0 609e8e38bb0e5c80a80c77c451b6e519f9aeb386 (Debug)

 
Core was generated by `/test/MD020421-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
[Current thread is 1 (Thread 0x1456289a2700 (LWP 454018))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
#1  0x00005642b45eceed in my_write_core (sig=sig@entry=6) at /test/10.6_dbg/mysys/stacktrace.c:424
 
#2  0x00005642b3d8ba65 in handle_fatal_signal (sig=6) at /test/10.6_dbg/sql/signal_handler.cc:343
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#5  0x0000145631e07859 in __GI_abort () at abort.c:79
 
#6  0x0000145631e07729 in __assert_fail_base (fmt=0x145631f9d588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5642b4773508 "(m_storage_engine_name.str != __null) == used_engine", file=0x5642b4789a50 "/test/10.6_dbg/sql/sql_alter.cc", line=396, function=<optimized out>) at assert.c:92
 
#7  0x0000145631e18f36 in __GI___assert_fail (assertion=assertion@entry=0x5642b4773508 "(m_storage_engine_name.str != __null) == used_engine", file=file@entry=0x5642b4789a50 "/test/10.6_dbg/sql/sql_alter.cc", line=line@entry=396, function=function@entry=0x5642b4789a70 "virtual bool Sql_cmd_alter_table::execute(THD*)") at assert.c:101
 
#8  0x00005642b3c2a13b in Sql_cmd_alter_table::execute (this=0x1455dc021520, thd=0x1455dc000db8) at /test/10.6_dbg/sql/sql_alter.cc:396
 
#9  0x00005642b3ad0f69 in mysql_execute_command (thd=0x1455dc000db8) at /test/10.6_dbg/sql/sql_parse.cc:5973
 
#10 0x00005642b39ea5c9 in sp_instr_stmt::exec_core (this=0x1455dc021538, thd=<optimized out>, nextp=0x1456289a024c) at /test/10.6_dbg/sql/sp_head.cc:3770
 
#11 0x00005642b39f7d10 in sp_lex_keeper::reset_lex_and_exec_core (this=this@entry=0x1455dc021580, thd=thd@entry=0x1455dc000db8, nextp=nextp@entry=0x1456289a024c, open_tables=open_tables@entry=false, instr=instr@entry=0x1455dc021538) at /test/10.6_dbg/sql/sp_head.cc:3497
 
#12 0x00005642b39f88a5 in sp_instr_stmt::execute (this=0x1455dc021538, thd=0x1455dc000db8, nextp=0x1456289a024c) at /test/10.6_dbg/sql/sp_head.cc:3676
 
#13 0x00005642b39f0521 in sp_head::execute (this=this@entry=0x1455dc020030, thd=thd@entry=0x1455dc000db8, merge_da_on_success=merge_da_on_success@entry=true) at /test/10.6_dbg/sql/sp_head.cc:1437
 
#14 0x00005642b39f25a0 in sp_head::execute_procedure (this=0x1455dc020030, thd=thd@entry=0x1455dc000db8, args=0x1455dc005e70) at /test/10.6_dbg/sql/sp_head.cc:2451
 
#15 0x00005642b3abe0fa in do_execute_sp (thd=thd@entry=0x1455dc000db8, sp=sp@entry=0x1455dc020030) at /test/10.6_dbg/sql/sql_parse.cc:3007
 
#16 0x00005642b3ac3a76 in Sql_cmd_call::execute (this=0x1455dc013c50, thd=0x1455dc000db8) at /test/10.6_dbg/sql/sql_parse.cc:3253
 
#17 0x00005642b3ad0f69 in mysql_execute_command (thd=thd@entry=0x1455dc000db8) at /test/10.6_dbg/sql/sql_parse.cc:5973
 
#18 0x00005642b3ab78d0 in mysql_parse (thd=thd@entry=0x1455dc000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1456289a1410) at /test/10.6_dbg/sql/sql_parse.cc:8004
 
#19 0x00005642b3ac64d6 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1455dc000db8, packet=packet@entry=0x1455dc00b359 "CALL p1 (1)", packet_length=packet_length@entry=11, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:1331
 
#20 0x00005642b3ac98b1 in do_command (thd=0x1455dc000db8, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1399
 
#21 0x00005642b3c22b42 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5642b7087538, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
 
#22 0x00005642b3c23147 in handle_one_connection (arg=arg@entry=0x5642b7087538) at /test/10.6_dbg/sql/sql_connect.cc:1312
 
#23 0x00005642b40cfbef in pfs_spawn_thread (arg=0x5642b6fabc18) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
 
#24 0x0000145632315609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#25 0x0000145631f04293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.2.38 (dbg), 10.3.29 (dbg), 10.4.19 (dbg), 10.5.10 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.38 (opt), 10.3.29 (opt), 10.4.19 (opt), 10.5.10 (opt), 10.6.0 (dbg), 10.6.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.33 (dbg), 5.7.33 (opt), 8.0.23 (dbg), 8.0.23 (opt)

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

Issue is seen regularly in testing; a fix would be appreciated.
Please also fix MDEV-22546 at same time.

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

This bug can lead to smashed stacks:

Core was generated by `/test/MD060421-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --no-defaults --max_a'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  0x00001486bb691f08 in ?? ()
 
[Current thread is 1 (LWP 153787)]
 
(gdb) bt
 
#0  0x00001486bb691f08 in ?? ()
 
Backtrace stopped: Cannot access memory at address 0x1486b856f320

Which requires manual analysis for failed trials. Raised prio for affect_tests.

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

SET sql_mode='';
 
SET @c:="ALTER TABLE t ENGINE=none";
 
PREPARE s FROM @c;
 
EXECUTE s;
 
EXECUTE s;

Leads to:

10.6.0 f74704c7d963ddcd1109843a5861c6bd76409c8d (Debug)

 
mysqld: /test/10.6_dbg/sql/sql_alter.cc:396: virtual bool Sql_cmd_alter_table::execute(THD*): Assertion `(m_storage_engine_name.str != __null) == used_engine' failed.

10.6.0 f74704c7d963ddcd1109843a5861c6bd76409c8d (Debug)

 
Core was generated by `/test/MD120421-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
[Current thread is 1 (Thread 0x152f040b0700 (LWP 2684878))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
#1  0x00005557f28cdc9e in my_write_core (sig=sig@entry=6) at /test/10.6_dbg/mysys/stacktrace.c:424
 
#2  0x00005557f206cb07 in handle_fatal_signal (sig=6) at /test/10.6_dbg/sql/signal_handler.cc:343
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#5  0x0000152f1bd71859 in __GI_abort () at abort.c:79
 
#6  0x0000152f1bd71729 in __assert_fail_base (fmt=0x152f1bf07588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5557f2a546a0 "(m_storage_engine_name.str != __null) == used_engine", file=0x5557f2a6ac70 "/test/10.6_dbg/sql/sql_alter.cc", line=396, function=<optimized out>) at assert.c:92
 
#7  0x0000152f1bd82f36 in __GI___assert_fail (assertion=assertion@entry=0x5557f2a546a0 "(m_storage_engine_name.str != __null) == used_engine", file=file@entry=0x5557f2a6ac70 "/test/10.6_dbg/sql/sql_alter.cc", line=line@entry=396, function=function@entry=0x5557f2a6ac90 "virtual bool Sql_cmd_alter_table::execute(THD*)") at assert.c:101
 
#8  0x00005557f1f0a771 in Sql_cmd_alter_table::execute (this=0x152ec8020018, thd=0x152ec8000db8) at /test/10.6_dbg/sql/sql_alter.cc:396
 
#9  0x00005557f1db120d in mysql_execute_command (thd=0x152ec8000db8) at /test/10.6_dbg/sql/sql_parse.cc:5973
 
#10 0x00005557f1dc5295 in Prepared_statement::execute (this=this@entry=0x152ec801d828, expanded_query=expanded_query@entry=0x152f040aedd0, open_cursor=open_cursor@entry=false) at /test/10.6_dbg/sql/sql_prepare.cc:5040
 
#11 0x00005557f1dc55e3 in Prepared_statement::execute_loop (this=this@entry=0x152ec801d828, expanded_query=expanded_query@entry=0x152f040aedd0, open_cursor=open_cursor@entry=false, packet=packet@entry=0x0, packet_end=packet_end@entry=0x0) at /test/10.6_dbg/sql/sql_prepare.cc:4502
 
#12 0x00005557f1dc5b1a in mysql_sql_stmt_execute (thd=thd@entry=0x152ec8000db8) at /test/10.6_dbg/sql/sql_prepare.cc:3579
 
#13 0x00005557f1dab673 in mysql_execute_command (thd=thd@entry=0x152ec8000db8) at /test/10.6_dbg/sql/sql_parse.cc:3943
 
#14 0x00005557f1d97a02 in mysql_parse (thd=thd@entry=0x152ec8000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x152f040af410) at /test/10.6_dbg/sql/sql_parse.cc:8004
 
#15 0x00005557f1da6726 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x152ec8000db8, packet=packet@entry=0x152ec800b369 "EXECUTE s", packet_length=packet_length@entry=9, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:1331
 
#16 0x00005557f1da9ac7 in do_command (thd=0x152ec8000db8, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1399
 
#17 0x00005557f1f03176 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5557f49b33b8, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
 
#18 0x00005557f1f0377b in handle_one_connection (arg=arg@entry=0x5557f49b33b8) at /test/10.6_dbg/sql/sql_connect.cc:1312
 
#19 0x00005557f23b1253 in pfs_spawn_thread (arg=0x5557f48d7a88) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
 
#20 0x0000152f1c27f609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#21 0x0000152f1be6e293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.2.38 (dbg), 10.3.29 (dbg), 10.4.19 (dbg), 10.5.10 (dbg), 10.6.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.38 (opt), 10.3.29 (opt), 10.4.19 (opt), 10.5.10 (opt), 10.6.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.33 (dbg), 5.7.33 (opt), 8.0.23 (dbg), 8.0.23 (opt)

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

Interestingly, in 10.6 this is routed via Diagnostics_area::set_error_status frames:

(m_storage_engine_name.str != __null) == used_engine|SIGABRT|Diagnostics_area::set_error_status|THD::raise_condition|THD::raise_condition|my_message_sql

Whereas in other versions the actual frames immediate show:

(m_storage_engine_name.str != __null) == used_engine|SIGABRT|Sql_cmd_alter_table::execute|mysql_execute_command|Prepared_statement::execute|Prepared_statement::execute_loop

I have seen this elsewhere too. Will the Diagnostics_area::set_error_status routing be applicable for all asserts?

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