[MDEV-33195] Assertion `!is_set() || (m_status == DA_OK_BULK && is_bulk_op())' failed in Diagnostics_area::set_ok_status on UPDATE Created: 2024-01-07  Updated: 2024-01-15  Resolved: 2024-01-15

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - Spider
Affects Version/s: N/A
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: Roel Van de Paar Assignee: Unassigned
Resolution: Fixed Votes: 0
Labels: regression-11.4

Issue Links:
Problem/Incident
is caused by MDEV-28861 Spider: Deprecate table options by CO... Closed
Relates

 Description    

INSTALL PLUGIN spider SONAME 'ha_spider.so';
 
CREATE TABLE t2(a INT,c DATE);
 
CREATE TABLE t1(a INT,c DATE,KEY (a)) ENGINE=Spider COMMENT='table "t2"' CONNECTION='socket "../socket.sock"';
 
DROP TABLE mysql.spider_table_crd;
 
UPDATE t1 SET c=':1:1' WHERE a>1;

Leads to:

bb-11.4-mdev-28861 f93c20081a8a505ac502850ec02630f95673dfba (Debug)

 
mariadbd: /test/bb-11.4-mdev-28861_dbg/sql/sql_error.cc:335: void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*): Assertion `!is_set() || (m_status == DA_OK_BULK && is_bulk_op())' failed.

bb-11.4-mdev-28861 f93c20081a8a505ac502850ec02630f95673dfba (Debug)

 
Core was generated by `/test/MDEV-28861_MD301223-mariadb-11.4.0-linux-x86_64-dbg/bin/mariadbd --no-def'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=22627834652224)
 
    at ./nptl/pthread_kill.c:44
 
[Current thread is 1 (Thread 0x1494740be640 (LWP 523746))]
 
(gdb) bt
 
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=22627834652224) at ./nptl/pthread_kill.c:44
 
#1  __pthread_kill_internal (signo=6, threadid=22627834652224) at ./nptl/pthread_kill.c:78
 
#2  __GI___pthread_kill (threadid=22627834652224, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
 
#3  0x000014948c842476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
 
#4  0x000014948c8287f3 in __GI_abort () at ./stdlib/abort.c:79
 
#5  0x000014948c82871b in __assert_fail_base (fmt=0x14948c9dd130 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x556bbb5d1cc8 "!is_set() || (m_status == DA_OK_BULK && is_bulk_op())", file=0x556bbb5d1b98 "/test/bb-11.4-mdev-28861_dbg/sql/sql_error.cc", line=335, function=<optimized out>) at ./assert/assert.c:92
 
#6  0x000014948c839e96 in __GI___assert_fail (assertion=0x556bbb5d1cc8 "!is_set() || (m_status == DA_OK_BULK && is_bulk_op())", file=0x556bbb5d1b98 "/test/bb-11.4-mdev-28861_dbg/sql/sql_error.cc", line=335, function=0x556bbb5d1d00 "void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*)") at ./assert/assert.c:101
 
#7  0x0000556bba9824bf in Diagnostics_area::set_ok_status (this=0x149438006e60, affected_rows=0, last_insert_id=last_insert_id@entry=0, message=message@entry=0x1494740bc860 "Rows matched: 0  Changed: 0  Warnings: 6") at /test/bb-11.4-mdev-28861_dbg/sql/sql_error.cc:335
 
#8  0x0000556bbaae3b31 in my_ok (message=0x1494740bc860 "Rows matched: 0  Changed: 0  Warnings: 6", id=0, affected_rows_arg=<optimized out>, thd=0x149438000d58) at /test/bb-11.4-mdev-28861_dbg/sql/sql_class.h:5864
 
#9  Sql_cmd_update::update_single_table (this=<optimized out>, thd=0x149438000d58) at /test/bb-11.4-mdev-28861_dbg/sql/sql_update.cc:1254
 
#10 0x0000556bbaae40ac in Sql_cmd_update::execute_inner (this=0x149438013ee8, thd=0x149438000d58) at /test/bb-11.4-mdev-28861_dbg/sql/sql_update.cc:3077
 
#11 0x0000556bbaa11f4b in Sql_cmd_dml::execute (this=0x149438013ee8, thd=0x149438000d58) at /test/bb-11.4-mdev-28861_dbg/sql/sql_select.cc:33415
 
#12 0x0000556bba9cf194 in mysql_execute_command (thd=thd@entry=0x149438000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/bb-11.4-mdev-28861_dbg/sql/sql_parse.cc:4373
 
#13 0x0000556bba9d4455 in mysql_parse (thd=thd@entry=0x149438000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1494740bd1e0) at /test/bb-11.4-mdev-28861_dbg/sql/sql_parse.cc:7748
 
#14 0x0000556bba9d67cb in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x149438000d58, packet=packet@entry=0x14943800b1c9 "UPDATE t1 SET c=':1:1' WHERE a>1", packet_length=packet_length@entry=32, blocking=blocking@entry=true) at /test/bb-11.4-mdev-28861_dbg/sql/sql_class.h:253
 
#15 0x0000556bba9d88f0 in do_command (thd=0x149438000d58, blocking=blocking@entry=true) at /test/bb-11.4-mdev-28861_dbg/sql/sql_parse.cc:1406
 
#16 0x0000556bbab3d835 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x556bbdf393c8, put_in_cache=put_in_cache@entry=true) at /test/bb-11.4-mdev-28861_dbg/sql/sql_connect.cc:1418
 
#17 0x0000556bbab3db2a in handle_one_connection (arg=arg@entry=0x556bbdf393c8) at /test/bb-11.4-mdev-28861_dbg/sql/sql_connect.cc:1320
 
#18 0x0000556bbaf8266e in pfs_spawn_thread (arg=0x556bbdec2f48) at /test/bb-11.4-mdev-28861_dbg/storage/perfschema/pfs.cc:2201
 
#19 0x000014948c894ac3 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
 
#20 0x000014948c926660 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Bug confirmed present in:
MariaDB: 11.4.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.4.33 (dbg), 10.4.33 (opt), 10.5.24 (dbg), 10.5.24 (opt), 10.6.17 (dbg), 10.6.17 (opt), 10.11.7 (dbg), 10.11.7 (opt), 11.0.5 (dbg), 11.0.5 (opt), 11.1.4 (dbg), 11.1.4 (opt), 11.2.3 (dbg), 11.2.3 (opt), 11.3.2 (dbg), 11.3.2 (opt), 11.4.0 (opt)

 Comments   
Comment by Roel Van de Paar [ 2024-01-07 ]

Alike to MDEV-33191 this test is not reproducible in MTR:

--let $SOCKET=`SELECT @@global.socket`
 
INSTALL PLUGIN spider SONAME 'ha_spider.so';
 
CREATE TABLE t2(a INT,c DATE);
 
eval CREATE TABLE t1(a INT,c DATE,KEY (a)) ENGINE=Spider COMMENT='table "t2"' CONNECTION='socket "$SOCKET"';
 
DROP TABLE mysql.spider_table_crd;
 
UPDATE t1 SET c=':1:1' WHERE a>1;

Leads to:

bb-11.4-mdev-28861 f93c20081a8a505ac502850ec02630f95673dfba (Debug)

 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[01] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
INSTALL PLUGIN spider SONAME 'ha_spider.so';
 
CREATE TABLE t2(a INT,c DATE);
 
CREATE TABLE t1(a INT,c DATE,KEY (a)) ENGINE=Spider COMMENT='table "t2"' CONNECTION='socket "/test/MDEV-28861_MD301223-mariadb-11.4.0-linux-x86_64-dbg/mariadb-test/var/tmp/mysqld.1.sock"';
 
Warnings:
 
Warning	138	Spider table params in COMMENT or CONNECTION strings have been deprecated and will be removed in a future release. Please use table options instead.
 
Warning	138	Spider table params in COMMENT or CONNECTION strings have been deprecated and will be removed in a future release. Please use table options instead.
 
DROP TABLE mysql.spider_table_crd;
 
UPDATE t1 SET c=':1:1' WHERE a>1;
 
main.test                                [ fail ]
 
        Test ended at 2024-01-08 07:27:25
 
 
 
CURRENT_TEST: main.test
 
mysqltest: At line 6: query 'UPDATE t1 SET c=':1:1' WHERE a>1' failed: <Unknown> (12720): Host:localhost and Socket:/test/MDEV-28861_MD301223-mariadb-11.4.0-linux-x86_64-dbg/mariadb-test/var/tmp/mysqld.1.sock aim self server. Please change spider_same_server_link parameter if this link is required.

Comment by Roel Van de Paar [ 2024-01-07 ]

Additional stack with:

INSTALL PLUGIN Spider SONAME 'ha_spider.so';
 
CREATE SERVER s FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock');
 
CREATE TABLE t1 (c INT);
 
CREATE TABLE t2 (c INT) ENGINE=Spider COMMENT='WRAPPER "mysql",SRV "s",TABLE "t1"';
 
INSERT INTO t2 VALUES (1);
 
DROP TABLE IF EXISTS mysql.spider_table_sts;
 
ALTER TABLE t2 ENGINE=Spider;

Leads to:

bb-11.4-mdev-28861 f93c20081a8a505ac502850ec02630f95673dfba (Debug)

 
mariadbd: /test/bb-11.4-mdev-28861_dbg/sql/sql_error.cc:335: void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*): Assertion `!is_set() || (m_status == DA_OK_BULK && is_bulk_op())' failed.

bb-11.4-mdev-28861 f93c20081a8a505ac502850ec02630f95673dfba (Debug)

 
Core was generated by `/test/MDEV-28861_MD301223-mariadb-11.4.0-linux-x86_64-dbg/bin/mariadbd --no-def'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=22938481583680)
 
    at ./nptl/pthread_kill.c:44
 
[Current thread is 1 (Thread 0x14dcc80be640 (LWP 506810))]
 
(gdb) bt
 
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=22938481583680) at ./nptl/pthread_kill.c:44
 
#1  __pthread_kill_internal (signo=6, threadid=22938481583680) at ./nptl/pthread_kill.c:78
 
#2  __GI___pthread_kill (threadid=22938481583680, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
 
#3  0x000014dcdf042476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
 
#4  0x000014dcdf0287f3 in __GI_abort () at ./stdlib/abort.c:79
 
#5  0x000014dcdf02871b in __assert_fail_base (fmt=0x14dcdf1dd130 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x562a03b17cc8 "!is_set() || (m_status == DA_OK_BULK && is_bulk_op())", file=0x562a03b17b98 "/test/bb-11.4-mdev-28861_dbg/sql/sql_error.cc", line=335, function=<optimized out>) at ./assert/assert.c:92
 
#6  0x000014dcdf039e96 in __GI___assert_fail (assertion=0x562a03b17cc8 "!is_set() || (m_status == DA_OK_BULK && is_bulk_op())", file=0x562a03b17b98 "/test/bb-11.4-mdev-28861_dbg/sql/sql_error.cc", line=335, function=0x562a03b17d00 "void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*)") at ./assert/assert.c:101
 
#7  0x0000562a02ec84bf in Diagnostics_area::set_ok_status (this=0x14dc94006e60, affected_rows=0, last_insert_id=last_insert_id@entry=0, message=message@entry=0x14dcc80b9bf0 "Records: 0  Duplicates: 0  Warnings: 6") at /test/bb-11.4-mdev-28861_dbg/sql/sql_error.cc:335
 
#8  0x0000562a02eb76f2 in my_ok (message=0x14dcc80b9bf0 "Records: 0  Duplicates: 0  Warnings: 6", id=0, affected_rows_arg=<optimized out>, thd=0x14dc94000d58) at /test/bb-11.4-mdev-28861_dbg/sql/sql_class.h:4578
 
#9  THD::my_ok_with_recreate_info (this=this@entry=0x14dc94000d58, info=@0x14dcc80bbfa0: {m_records_copied = 0, m_records_duplicate = 0}, warn_count=<optimized out>) at /test/bb-11.4-mdev-28861_dbg/sql/sql_class.cc:8356
 
#10 0x0000562a030075d0 in mysql_alter_table (thd=thd@entry=0x14dc94000d58, new_db=<optimized out>, new_name=new_name@entry=0x14dc94005ef8, create_info=create_info@entry=0x14dcc80bc130, table_list=<optimized out>, table_list@entry=0x14dc940135e0, recreate_info=recreate_info@entry=0x14dcc80bbfa0, alter_info=<optimized out>, order_num=<optimized out>, order=<optimized out>, ignore=<optimized out>, if_exists=<optimized out>) at /test/bb-11.4-mdev-28861_dbg/sql/sql_table.cc:11632
 
#11 0x0000562a0308ac83 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x14dc94000d58) at /test/bb-11.4-mdev-28861_dbg/sql/sql_alter.cc:698
 
#12 0x0000562a02f190ca in mysql_execute_command (thd=thd@entry=0x14dc94000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/bb-11.4-mdev-28861_dbg/sql/sql_parse.cc:5738
 
#13 0x0000562a02f1a455 in mysql_parse (thd=thd@entry=0x14dc94000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14dcc80bd1e0) at /test/bb-11.4-mdev-28861_dbg/sql/sql_parse.cc:7748
 
#14 0x0000562a02f1c7cb in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14dc94000d58, packet=packet@entry=0x14dc9400b1c9 "ALTER TABLE t2 ENGINE=Spider", packet_length=packet_length@entry=28, blocking=blocking@entry=true) at /test/bb-11.4-mdev-28861_dbg/sql/sql_class.h:253
 
#15 0x0000562a02f1e8f0 in do_command (thd=0x14dc94000d58, blocking=blocking@entry=true) at /test/bb-11.4-mdev-28861_dbg/sql/sql_parse.cc:1406
 
#16 0x0000562a03083835 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x562a06d0ca28, put_in_cache=put_in_cache@entry=true) at /test/bb-11.4-mdev-28861_dbg/sql/sql_connect.cc:1418
 
#17 0x0000562a03083b2a in handle_one_connection (arg=arg@entry=0x562a06d0ca28) at /test/bb-11.4-mdev-28861_dbg/sql/sql_connect.cc:1320
 
#18 0x0000562a034c866e in pfs_spawn_thread (arg=0x562a06c965a8) at /test/bb-11.4-mdev-28861_dbg/storage/perfschema/pfs.cc:2201
 
#19 0x000014dcdf094ac3 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
 
#20 0x000014dcdf126660 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Comment by Yuchen Pei [ 2024-01-08 ]

The case in the description, with the usual modification for mtr
(see below) passes in main 11.4
7ee16b1e2978d6b73377d9a5bf7d9fd83c841f92, WITHOUT MDEV-28861. It
also passes (i.e. I cannot reprod) at the commit WITH MDEV-28861
(f93c20081a8a505ac502850ec02630f95673dfba) in the description.

The passing does not go without errors, of course, as the crd table
has been dropped:

UPDATE t1 SET c=':1:1' WHERE a>1;
 
Warnings:
 
Warning	138	Spider table params in COMMENT or CONNECTION strings have been deprecated and will be removed in a future release. Please use table options instead.
 
Warning	138	Spider table params in COMMENT or CONNECTION strings have been deprecated and will be removed in a future release. Please use table options instead.
 
Error	1146	Table 'mysql.spider_table_crd' doesn't exist
 
Error	12524	Can't open system table mysql.spider_table_crd
 
Error	1146	Table 'mysql.spider_table_crd' doesn't exist
 
Error	12524	Can't open system table mysql.spider_table_crd
 

--disable_query_log
 
--disable_result_log
 
--source ../../t/test_init.inc
 
--enable_result_log
 
--enable_query_log
 
evalp CREATE SERVER srv FOREIGN DATA WRAPPER mysql
 
OPTIONS (SOCKET "$MASTER_1_MYSOCK", DATABASE 'test',user 'root');
 
CREATE TABLE t2(a INT,c DATE);
 
CREATE TABLE t1(a INT,c DATE,KEY (a)) ENGINE=Spider COMMENT='table "t2"' CONNECTION='srv "srv"';
 
DROP TABLE mysql.spider_table_crd;
 
UPDATE t1 SET c=':1:1' WHERE a>1;
 
drop server srv;
 
 
 
--disable_query_log
 
--disable_result_log
 
--source ../../t/test_deinit.inc
 
--enable_result_log
 
--enable_query_log

Trying the other testcase with the assertion failure in comment[1]
at f93c20081a8a505ac502850ec02630f95673dfba, I also get a
[ pass ], thus cannot reprod either. It shows similar errors as
the above case but with the sts table instead of the crd table.

[1] https://jira.mariadb.org/browse/MDEV-33195?focusedCommentId=277773&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-277773

--disable_query_log
 
--disable_result_log
 
--source ../../t/test_init.inc
 
--enable_result_log
 
--enable_query_log
 
evalp CREATE SERVER srv FOREIGN DATA WRAPPER mysql
 
OPTIONS (SOCKET "$MASTER_1_MYSOCK", DATABASE 'test',user 'root');
 
CREATE TABLE t1 (c INT);
 
CREATE TABLE t2 (c INT) ENGINE=Spider COMMENT='WRAPPER "mysql",SRV "srv",TABLE "t1"';
 
INSERT INTO t2 VALUES (1);
 
DROP TABLE IF EXISTS mysql.spider_table_sts;
 
ALTER TABLE t2 ENGINE=Spider;
 
drop server srv;
 
--disable_query_log
 
--disable_result_log
 
--source ../../t/test_deinit.inc
 
--enable_result_log
 
--enable_query_log

Comment by Roel Van de Paar [ 2024-01-08 ]

Yes, as noted, the issue does not reproduce in MTR. Did you try the CLI?

Comment by Yuchen Pei [ 2024-01-09 ]

Roel, you are right about it being reproducible in the client but not with mtr. I could reproduce at both f93c20081a8a505ac502850ec02630f95673dfba and its parent 6b2287fff23fbdc362499501c562f01d0d2db52e.

However, I could not reproduce at the current 11.4 c0c1c80346b926ea1358aa512374d72d513299b0, or cherry picked MDEV-28861 patch on top, incorporating serg's patch 154fef3c058dbf0bcedbbc4fb51a3b6b4f59b7d3.

Here's my case:

INSTALL SONAME 'ha_spider';
 
set spider_same_server_link=on;
 
CREATE TABLE t2(a INT,c DATE);
 
CREATE TABLE t1(a INT,c DATE,KEY (a)) ENGINE=Spider COMMENT='socket "/home/ycp/source/mariadb-server/11.4/build/mysql-test/var/tmp/mysqld.1.sock", user "root", table "t2"';
 
DROP TABLE mysql.spider_table_crd;
 
UPDATE t1 SET c=':1:1' WHERE a>1;

The last statement got me MariaDB [test]> ERROR 2026 (HY000): TLS/SSL error: unexpected eof while reading, but the .err file shows the same assertion failure.

Roel can you please check the current 11.4 patch? Thanks

d7a46958bff * upstream/bb-11.4-mdev-28861 MDEV-28861 Deprecate spider table options by comment/connection

Comment by Roel Van de Paar [ 2024-01-15 ]

ycp Hi!
1) Result on c0c1c80346b926ea1358aa512374d72d513299b0 is confirmed as expected.
2) MDEV-28861 patch on top of trunk 11.4 not being reproducible is unexpected, recheck in #4 below. It would be interesting to know why it is fixed in the latest revision.
3) TSL/SSL error in CLI is expected: previously this would customarily show as "ERROR 2006 (HY000): Server has gone away" (and this almost always indicated a crash), however as of 11.3+ SSL is enabled by default and SSL errors seem to be hit earlier than "Server has gone away".
4) bb-11.4-mdev-28861 at d7a46958bffab80ff29646e98262471b4c879a04 (Jan 2, last commit) confirmed no longer reproduces the issue. Closing ticket. (Please ensure that this is the version that is pushed.)

Comment by Roel Van de Paar [ 2024-01-15 ]

Fixed as per last comment in d7a46958bffab80ff29646e98262471b4c879a04.

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