[MDEV-32346] InnoDB: Failing assertion: sym_node->table != NULL in pars_retrieve_table_def on UPDATE Created: 2023-10-04  Updated: 2024-01-05

Status: Stalled
Project: MariaDB Server
Component/s: Full-text Search, Storage Engine - InnoDB
Affects Version/s: 10.4, 10.5, 10.6, 10.9, 10.10, 10.11, 11.0, 11.1, 11.2, 11.3
Fix Version/s: 10.4, 10.5, 10.6, 10.11, 11.0, 11.1

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Thirunarayanan Balathandayuthapani
Resolution: Unresolved Votes: 0
Labels: upstream-5.6, upstream-5.7, upstream-8.0

Issue Links:
Relates
relates to MDEV-25536 InnoDB: Failing assertion: sym_node->... Closed

 Description   

CREATE TABLE t1 (b INT,c TEXT,KEY(b),FULLTEXT (c)) ENGINE=InnoDB;
CREATE TABLE t (a INT KEY,b INT,c FLOAT,KEY b (b)) ENGINE=InnoDB;
INSERT INTO t VALUES (0,0,0);
ALTER TABLE t1 ADD CONSTRAINT FOREIGN KEY(b) REFERENCES t (a);
ALTER TABLE t1 DISCARD TABLESPACE;
UPDATE t JOIN (SELECT * FROM t) AS dt ON t.a=dt.a SET t.b=t.b +1;

Leads to:

11.3.0 905c3d61e18ae6222d0d195c43d335046eec65d9 (Optimized)

2023-10-04 10:46:34 0x15145c11d640  InnoDB: Assertion failure in file /test/11.3_opt/storage/innobase/pars/pars0pars.cc line 771
InnoDB: Failing assertion: sym_node->table != NULL

11.3.0 905c3d61e18ae6222d0d195c43d335046eec65d9 (Optimized)

Core was generated by `/test/MD270923-mariadb-11.3.0-linux-x86_64-opt/bin/mariadbd --no-defaults --cor'.
Program terminated with signal SIGABRT, Aborted.
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=23177188202048)
    at ./nptl/pthread_kill.c:44
[Current thread is 1 (Thread 0x15145c11d640 (LWP 1017980))]
(gdb) bt
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=23177188202048) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=6, threadid=23177188202048) at ./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=23177188202048, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
#3  0x0000151467642476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#4  0x00001514676287f3 in __GI_abort () at ./stdlib/abort.c:79
#5  0x00005625e36fcfcc in ut_dbg_assertion_failed (expr=expr@entry=0x5625e440f0f4 "sym_node->table != NULL", file=file@entry=0x5625e440eaa0 "/test/11.3_opt/storage/innobase/pars/pars0pars.cc", line=line@entry=771) at /test/11.3_opt/storage/innobase/ut/ut0dbg.cc:60
#6  0x00005625e36e650b in pars_retrieve_table_def (sym_node=0x1513b8108810) at /test/11.3_opt/storage/innobase/pars/pars0pars.cc:771
#7  pars_retrieve_table_def (sym_node=0x1513b8108810) at /test/11.3_opt/storage/innobase/pars/pars0pars.cc:753
#8  0x00005625e3e94993 in pars_retrieve_table_list_defs (sym_node=0x1513b8108810) at /test/11.3_opt/storage/innobase/pars/pars0pars.cc:792
#9  pars_select_statement (select_node=0x1513b8108728, table_list=0x1513b8108810, search_cond=0x1513b8108ad8, for_update=0x5625e4af93ac <pars_update_token>, lock_shared=0x0, order_by=0x0) at /test/11.3_opt/storage/innobase/pars/pars0pars.cc:923
#10 0x00005625e3fd73cd in yyparse () at /test/11.3_opt/storage/innobase/pars0grm.y:295
#11 0x00005625e3e9835a in pars_sql (info=info@entry=0x1513b80198a0, str=str@entry=0x1513b80802a8 "PROCEDURE P() IS\nDECLARE FUNCTION my_func;\nDECLARE CURSOR c IS SELECT value FROM $config_table WHERE key = 'synced_doc_id' FOR UPDATE;\nBEGIN\nOPEN c;\nWHILE 1 = 1 LOOP\n  FETCH c INTO my_func();\n  IF c %"...) at /test/11.3_opt/storage/innobase/pars/pars0pars.cc:1986
#12 0x00005625e3fc6039 in fts_parse_sql (fts_table=fts_table@entry=0x15145c11a8f0, info=info@entry=0x1513b80198a0, sql=sql@entry=0x5625e4425758 "DECLARE FUNCTION my_func;\nDECLARE CURSOR c IS SELECT value FROM $config_table WHERE key = 'synced_doc_id' FOR UPDATE;\nBEGIN\nOPEN c;\nWHILE 1 = 1 LOOP\n  FETCH c INTO my_func();\n  IF c % NOTFOUND THEN\n  "...) at /test/11.3_opt/storage/innobase/fts/fts0sql.cc:136
#13 0x00005625e3fb7ad6 in fts_cmp_set_sync_doc_id (table=0x1513b8066b80, cmp_doc_id=0, read_only=0, doc_id=0x15145c11ad88) at /test/11.3_opt/storage/innobase/fts/fts0fts.cc:2606
#14 0x00005625e3fb90cb in fts_init_doc_id (table=table@entry=0x1513b8066b80) at /test/11.3_opt/storage/innobase/fts/fts0fts.cc:4819
#15 0x00005625e3ec990d in init_fts_doc_id_for_ref (depth=0x15145c11ae08, table=0x1513b8017840) at /test/11.3_opt/storage/innobase/row/row0mysql.cc:1587
#16 row_update_for_mysql (prebuilt=0x1513b8036a10) at /test/11.3_opt/storage/innobase/row/row0mysql.cc:1635
#17 0x00005625e3e135b3 in ha_innobase::update_row (this=0x1513b8035d50, old_row=0x1513b8035948 <incomplete sequence \371>, new_row=0x1513b8035938 <incomplete sequence \371>) at /test/11.3_opt/storage/innobase/handler/ha_innodb.cc:8613
#18 0x00005625e3b0bcf2 in handler::ha_update_row (this=0x1513b8035d50, old_data=0x1513b8035948 <incomplete sequence \371>, new_data=0x1513b8035938 <incomplete sequence \371>) at /test/11.3_opt/sql/handler.cc:7902
#19 0x00005625e396657e in multi_update::do_updates (this=0x1513b802f780) at /test/11.3_opt/sql/sql_update.cc:2644
#20 0x00005625e3966eeb in multi_update::send_eof (this=0x1513b802f780) at /test/11.3_opt/sql/sql_update.cc:2758
#21 0x00005625e38fe2f1 in do_select (procedure=<optimized out>, join=0x1513b802f8a0) at /test/11.3_opt/sql/sql_select.cc:23017
#22 JOIN::exec_inner (this=0x1513b802f8a0) at /test/11.3_opt/sql/sql_select.cc:4941
#23 0x00005625e38fe79e in JOIN::exec (this=this@entry=0x1513b802f8a0) at /test/11.3_opt/sql/sql_select.cc:4718
#24 0x00005625e38fe8ca in Sql_cmd_dml::execute_inner (this=this@entry=0x1513b8014080, thd=thd@entry=0x1513b8000c68) at /test/11.3_opt/sql/sql_select.cc:33420
#25 0x00005625e39658f7 in Sql_cmd_update::execute_inner (this=0x1513b8014080, thd=0x1513b8000c68) at /test/11.3_opt/sql/sql_update.cc:3082
#26 0x00005625e38b6af1 in Sql_cmd_dml::execute (this=0x1513b8014080, thd=0x1513b8000c68) at /test/11.3_opt/sql/sql_select.cc:33357
#27 0x00005625e38801f0 in mysql_execute_command (thd=0x1513b8000c68, is_called_from_prepared_stmt=<optimized out>) at /test/11.3_opt/sql/sql_parse.cc:4370
#28 0x00005625e3881156 in mysql_parse (thd=0x1513b8000c68, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/11.3_opt/sql/sql_parse.cc:7744
#29 0x00005625e38838ed in dispatch_command (command=COM_QUERY, thd=0x1513b8000c68, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/11.3_opt/sql/sql_parse.cc:1990
#30 0x00005625e3885690 in do_command (thd=0x1513b8000c68, blocking=blocking@entry=true) at /test/11.3_opt/sql/sql_parse.cc:1406
#31 0x00005625e39ae3df in do_handle_one_connection (connect=<optimized out>, put_in_cache=true) at /test/11.3_opt/sql/sql_connect.cc:1445
#32 0x00005625e39ae72d in handle_one_connection (arg=arg@entry=0x5625e5e33358) at /test/11.3_opt/sql/sql_connect.cc:1347
#33 0x00005625e3d56da1 in pfs_spawn_thread (arg=0x5625e5e5ad88) at /test/11.3_opt/storage/perfschema/pfs.cc:2201
#34 0x0000151467694b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#35 0x0000151467726a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

11.3.0 905c3d61e18ae6222d0d195c43d335046eec65d9 (Debug)

2023-10-04 10:46:34 0x1489101fb640  InnoDB: Assertion failure in file /test/11.3_dbg/storage/innobase/pars/pars0pars.cc line 771
InnoDB: Failing assertion: sym_node->table != NULL

11.3.0 905c3d61e18ae6222d0d195c43d335046eec65d9 (Debug)

Core was generated by `/test/MD270923-mariadb-11.3.0-linux-x86_64-dbg/bin/mariadbd --no-defaults --cor'.
Program terminated with signal SIGABRT, Aborted.
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=22578913588800)
    at ./nptl/pthread_kill.c:44
[Current thread is 1 (Thread 0x1489101fb640 (LWP 1018914))]
(gdb) bt
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=22578913588800) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=6, threadid=22578913588800) at ./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=22578913588800, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
#3  0x0000148925a42476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#4  0x0000148925a287f3 in __GI_abort () at ./stdlib/abort.c:79
#5  0x00005581efd8b89c in ut_dbg_assertion_failed (expr=expr@entry=0x5581f0399654 "sym_node->table != NULL", file=file@entry=0x5581f0398ce8 "/test/11.3_dbg/storage/innobase/pars/pars0pars.cc", line=line@entry=771) at /test/11.3_dbg/storage/innobase/ut/ut0dbg.cc:60
#6  0x00005581efc7bdf9 in pars_retrieve_table_def (sym_node=sym_node@entry=0x148884139780) at /test/11.3_dbg/storage/innobase/pars/pars0pars.cc:771
#7  0x00005581efc7fbda in pars_retrieve_table_list_defs (sym_node=0x148884139780) at /test/11.3_dbg/storage/innobase/pars/pars0pars.cc:792
#8  pars_select_statement (select_node=0x148884139690, table_list=0x148884139780, search_cond=0x148884139a48, for_update=0x5581f0ac612c <pars_update_token>, lock_shared=0x0, order_by=0x0) at /test/11.3_dbg/storage/innobase/pars/pars0pars.cc:923
#9  0x00005581efeda2d4 in yyparse () at /test/11.3_dbg/storage/innobase/pars0grm.y:295
#10 0x00005581efc7e7a2 in pars_sql (info=info@entry=0x14888401e788, str=str@entry=0x148884026688 "PROCEDURE P() IS\nDECLARE FUNCTION my_func;\nDECLARE CURSOR c IS SELECT value FROM $config_table WHERE key = 'synced_doc_id' FOR UPDATE;\nBEGIN\nOPEN c;\nWHILE 1 = 1 LOOP\n  FETCH c INTO my_func();\n  IF c %"...) at /test/11.3_dbg/storage/innobase/pars/pars0pars.cc:1986
#11 0x00005581efeb5bff in fts_parse_sql (fts_table=fts_table@entry=0x1489101f8f10, info=info@entry=0x14888401e788, sql=sql@entry=0x5581f03e3c00 "DECLARE FUNCTION my_func;\nDECLARE CURSOR c IS SELECT value FROM $config_table WHERE key = 'synced_doc_id' FOR UPDATE;\nBEGIN\nOPEN c;\nWHILE 1 = 1 LOOP\n  FETCH c INTO my_func();\n  IF c % NOTFOUND THEN\n  "...) at /test/11.3_dbg/storage/innobase/fts/fts0sql.cc:136
#12 0x00005581efea07c5 in fts_cmp_set_sync_doc_id (table=table@entry=0x148884090628, cmp_doc_id=<optimized out>, cmp_doc_id@entry=0, read_only=read_only@entry=0, doc_id=doc_id@entry=0x1489101f93a8) at /test/11.3_dbg/storage/innobase/fts/fts0fts.cc:2606
#13 0x00005581efea102d in fts_init_doc_id (table=0x148884090628) at /test/11.3_dbg/storage/innobase/fts/fts0fts.cc:4819
#14 0x00005581efcdf9a5 in init_fts_doc_id_for_ref (table=table@entry=0x14888401cf08, depth=depth@entry=0x1489101f9438) at /test/11.3_dbg/storage/innobase/row/row0mysql.cc:1587
#15 0x00005581efce4bb0 in row_update_for_mysql (prebuilt=0x148884046088) at /test/11.3_dbg/storage/innobase/row/row0mysql.cc:1635
#16 0x00005581efb97d52 in ha_innobase::update_row (this=0x148884044910, old_row=0x148884044508 <incomplete sequence \371>, new_row=0x1488840444f8 <incomplete sequence \371>) at /test/11.3_dbg/storage/innobase/handler/ha_innodb.cc:8613
#17 0x00005581ef833c01 in handler::ha_update_row (this=0x148884044910, old_data=0x148884044508 <incomplete sequence \371>, new_data=0x1488840444f8 <incomplete sequence \371>) at /test/11.3_dbg/sql/handler.cc:7902
#18 0x00005581ef6361ac in multi_update::do_updates (this=this@entry=0x14888403bc40) at /test/11.3_dbg/sql/sql_update.cc:2644
#19 0x00005581ef636dea in multi_update::send_eof (this=0x14888403bc40) at /test/11.3_dbg/sql/sql_update.cc:2758
#20 0x00005581ef5b8f95 in do_select (procedure=<optimized out>, join=0x14888403bd60) at /test/11.3_dbg/sql/sql_select.cc:23017
#21 JOIN::exec_inner (this=this@entry=0x14888403bd60) at /test/11.3_dbg/sql/sql_select.cc:4941
#22 0x00005581ef5b93b2 in JOIN::exec (this=this@entry=0x14888403bd60) at /test/11.3_dbg/sql/sql_select.cc:4718
#23 0x00005581ef5b956a in Sql_cmd_dml::execute_inner (this=this@entry=0x148884016a70, thd=thd@entry=0x148884000d58) at /test/11.3_dbg/sql/sql_select.cc:33420
#24 0x00005581ef6354a6 in Sql_cmd_update::execute_inner (this=0x148884016a70, thd=0x148884000d58) at /test/11.3_dbg/sql/sql_update.cc:3082
#25 0x00005581ef567ecd in Sql_cmd_dml::execute (this=0x148884016a70, thd=0x148884000d58) at /test/11.3_dbg/sql/sql_select.cc:33357
#26 0x00005581ef52537c in mysql_execute_command (thd=thd@entry=0x148884000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/11.3_dbg/sql/sql_parse.cc:4370
#27 0x00005581ef52a5f7 in mysql_parse (thd=thd@entry=0x148884000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1489101fa1e0) at /test/11.3_dbg/sql/sql_parse.cc:7744
#28 0x00005581ef52c96d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x148884000d58, packet=packet@entry=0x14888400b189 "UPDATE t JOIN (SELECT * FROM t) AS dt ON t.a=dt.a SET t.b=t.b +1", packet_length=packet_length@entry=64, blocking=blocking@entry=true) at /test/11.3_dbg/sql/sql_class.h:247
#29 0x00005581ef52ea8d in do_command (thd=0x148884000d58, blocking=blocking@entry=true) at /test/11.3_dbg/sql/sql_parse.cc:1406
#30 0x00005581ef68ecb5 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5581f3793778, put_in_cache=put_in_cache@entry=true) at /test/11.3_dbg/sql/sql_connect.cc:1445
#31 0x00005581ef68efaa in handle_one_connection (arg=arg@entry=0x5581f3793778) at /test/11.3_dbg/sql/sql_connect.cc:1347
#32 0x00005581efad120a in pfs_spawn_thread (arg=0x5581f374ba78) at /test/11.3_dbg/storage/perfschema/pfs.cc:2201
#33 0x0000148925a94b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#34 0x0000148925b26a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Bug confirmed present in:
MariaDB: 10.4.32 (dbg), 10.4.32 (opt), 10.5.23 (dbg), 10.5.23 (opt), 10.6.16 (dbg), 10.6.16 (opt), 10.9.8 (dbg), 10.9.8 (opt), 10.10.7 (dbg), 10.10.7 (opt), 10.11.6 (dbg), 10.11.6 (opt), 11.0.4 (dbg), 11.0.4 (opt), 11.1.3 (dbg), 11.1.3 (opt), 11.2.2 (dbg), 11.2.2 (opt), 11.3.0 (dbg), 11.3.0 (opt)
MySQL: 5.6.51 (dbg), 5.6.51 (opt), 5.7.40 (dbg), 8.0.33 (dbg), 8.0.33 (opt)

Bug (or feature/syntax) confirmed not present in:
MySQL: 5.5.62 (dbg), 5.5.62 (opt)



 Comments   
Comment by Roel Van de Paar [ 2023-10-04 ]

All UniqueID's/stacks observed across versions and build types (opt/dbg)

SIGABRT|my_server_abort|my_abort|ut_dbg_assertion_failed|pars_retrieve_table_def
sym_node->table != NULL|SIGABRT|pars_retrieve_table_def|pars_retrieve_table_list_defs|pars_select_statement|yyparse
sym_node->table != NULL|SIGABRT|ut_dbg_assertion_failed|pars_retrieve_table_def|pars_retrieve_table_def|pars_retrieve_table_list_defs
sym_node->table != NULL|SIGABRT|ut_dbg_assertion_failed|pars_retrieve_table_def|pars_retrieve_table_list_defs|pars_select_statement

Comment by Marko Mäkelä [ 2023-10-04 ]

I see several problems here:

  1. ALTER TABLE…DISCARD TABLESPACE is being allowed to break a FOREIGN KEY constraint even though SET foreign_key_checks=0 has not been executed.
  2. The preparation for FULLTEXT INDEX maintenance is actually unnecessary here: there is no CASCADE or SET NULL action that would cause fulltext-indexed columns (or the PRIMARY KEY of a child table) to be modified.
  3. The preparation results in an assertion failure because it fails to check if the tablespace had been discarded.

Here is a little simpler test case:

--source include/have_innodb.inc
CREATE TABLE t (a INT PRIMARY KEY) ENGINE=InnoDB;
CREATE TABLE t1 (b INT,c TEXT,FOREIGN KEY(b) REFERENCES t(a),FULLTEXT (c))
ENGINE=InnoDB;
INSERT INTO t SET a=1;
ALTER TABLE t1 DISCARD TABLESPACE;
UPDATE t SET a=2;
DROP TABLE t1,t;

Comment by Marko Mäkelä [ 2023-10-04 ]

Roel, your unique stacks are by no means unique to this bug. The differentiator would be the call stack leading to the entry point to the InnoDB SQL parser (pars_sql()):

ut_dbg_assertion_failed
pars_retrieve_table_def
pars_retrieve_table_list_defs
pars_select_statement
yyparse
pars_sql
fts_parse_sql
fts_cmp_set_sync_doc_id
fts_init_doc_id
init_fts_doc_id_for_ref
row_update_for_mysql
ha_innobase::update_row

Comment by Roel Van de Paar [ 2023-10-05 ]

marko I see, thanks. Thankfully the 4-frame ID's include the assert message which is generally quite unique (this particular one had been seen previously in MDEV-25536 but was remarked when that ticket was resolved). An original design decision was to use 4 frames to balance uniqueness vs [over-]granularity leading to too many stack differentiation's (and thus much resulting debug work per ticket, lost ROI) which has worked well so far, except on a few edge cases.

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