[MDEV-25460] Assertion `!is_set() || (m_status == DA_OK_BULK && is_bulk_op())' failed in Diagnostics_area::set_ok_status in my_ok from mysql_sql_stmt_prepare Created: 2021-04-20  Updated: 2023-04-08  Resolved: 2021-12-28

Status: Closed
Project: MariaDB Server
Component/s: Prepared Statements
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6, 10.7
Fix Version/s: 10.2.42, 10.3.33, 10.4.23, 10.5.14, 10.6.6, 10.7.2

Type: Bug Priority: Critical
Reporter: Roel Van de Paar Assignee: Rucha Deodhar
Resolution: Fixed Votes: 0
Labels: affects-tests

Issue Links:
Issue split
split to MDEV-31026 MDEV-25460 Split: Assertion `! is_set... Confirmed
Relates
relates to MDEV-22712 Assertion `!is_set() || (m_status == ... Closed
relates to MDEV-22058 Assertion `!is_set() || (m_status == ... Closed

 Description   

Ref MDEV-22058

CREATE TEMPORARY TABLE a (c INT) ENGINE=InnoDB;
 
CREATE TABLE b (c INT) ENGINE=InnoDB;
 
PREPARE s FROM 'SET STATEMENT binlog_format=ROW FOR SELECT * FROM b';

Leads to:

10.6.0 609e8e38bb0e5c80a80c77c451b6e519f9aeb386 (Debug)

 
mysqld: /test/10.6_dbg/sql/sql_error.cc:334: void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*): Assertion `!is_set() || (m_status == DA_OK_BULK && is_bulk_op())' failed.

10.6.0 609e8e38bb0e5c80a80c77c451b6e519f9aeb386 (Debug)

 
Core was generated by `/test/MD060421-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 0x148558098700 (LWP 422807))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
#1  0x0000557334aa8eed in my_write_core (sig=sig@entry=6) at /test/10.6_dbg/mysys/stacktrace.c:424
 
#2  0x0000557334247a65 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  0x00001485588ff859 in __GI_abort () at abort.c:79
 
#6  0x00001485588ff729 in __assert_fail_base (fmt=0x148558a95588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x557334c0f370 "!is_set() || (m_status == DA_OK_BULK && is_bulk_op())", file=0x557334c0f250 "/test/10.6_dbg/sql/sql_error.cc", line=334, function=<optimized out>) at assert.c:92
 
#7  0x0000148558910f36 in __GI___assert_fail (assertion=assertion@entry=0x557334c0f370 "!is_set() || (m_status == DA_OK_BULK && is_bulk_op())", file=file@entry=0x557334c0f250 "/test/10.6_dbg/sql/sql_error.cc", line=line@entry=334, function=function@entry=0x557334c0f3a8 "void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*)") at assert.c:101
 
#8  0x0000557333f2d4cb in Diagnostics_area::set_ok_status (this=0x1484f0006ab0, affected_rows=affected_rows@entry=0, last_insert_id=last_insert_id@entry=0, message=message@entry=0x557334c1db18 "Statement prepared") at /test/10.6_dbg/sql/sql_error.h:1017
 
#9  0x0000557333fa35c5 in my_ok (message=0x557334c1db18 "Statement prepared", id=0, affected_rows_arg=0, thd=0x1484f0000db8) at /test/10.6_dbg/sql/sql_class.h:5486
 
#10 mysql_sql_stmt_prepare (thd=thd@entry=0x1484f0000db8) at /test/10.6_dbg/sql/sql_prepare.cc:2938
 
#11 0x0000557333f87440 in mysql_execute_command (thd=thd@entry=0x1484f0000db8) at /test/10.6_dbg/sql/sql_parse.cc:3938
 
#12 0x0000557333f738d0 in mysql_parse (thd=thd@entry=0x1484f0000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x148558097410) at /test/10.6_dbg/sql/sql_parse.cc:8004
 
#13 0x0000557333f824d6 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1484f0000db8, packet=packet@entry=0x1484f000b359 "pREPARE s FROM 'SET STATEMENT binlog_format=ROW FOR SELECT * FROM b'", packet_length=packet_length@entry=68, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:1331
 
#14 0x0000557333f858b1 in do_command (thd=0x1484f0000db8, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1399
 
#15 0x00005573340deb42 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5573364606b8, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
 
#16 0x00005573340df147 in handle_one_connection (arg=arg@entry=0x5573364606b8) at /test/10.6_dbg/sql/sql_connect.cc:1312
 
#17 0x000055733458bbef in pfs_spawn_thread (arg=0x557336384cd8) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
 
#18 0x0000148558e0d609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#19 0x00001485589fc293 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)

Issue also confirmed present in a3e3225cd3b816d47621e749e21a71b6a864a96a (10.6, debug, build 15 April 2021)

 Comments   
Comment by Sergei Golubchik [ 2021-04-20 ]

What error do you see in non-debug builds?

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

10.6.0 a3e3225cd3b816d47621e749e21a71b6a864a96a (Optimized)

 
10.6.0-opt>PREPARE s FROM 'SET STATEMENT binlog_format=ROW FOR SELECT * FROM b';
 
ERROR 1559 (HY000): Cannot switch out of the row-based binary log format when the session has open temporary tables

Comment by Elena Stepanova [ 2021-04-22 ]

IMO this should be treated for the non-debug error. It clearly doesn't belong there, and when the error is gone, the diagnostics area failure will disappear anyway.

Comment by Sergei Golubchik [ 2021-04-22 ]

rucha174, it seems that this error "Cannot switch out of the row-based binary log format when the session has open temporary tables" is wrong here. An assertion in Diagnostics_area still needs to be fixed, but after you find out where the return value is ignored, please, try to create a test case for that line but with a different error message.

Comment by Elena Stepanova [ 2021-04-22 ]

Once the diagnostics area bug is fixed, it would be good to spawn another report for the wrong handling of binlog_format in SET STATEMENT, so that's it's not forgotten. It's a valid use case, but it seems to work in a very odd and buggy way – there are more different errors and even diagnostics area assertions around it, for example one can easily get a failure in set_error_status instead:

--source include/have_innodb.inc
 
 
 
CREATE TABLE t (c INT) ENGINE=InnoDB;
 
SET AUTOCOMMIT= 0;
 
SET STATEMENT binlog_format=ROW FOR INSERT INTO t VALUES (1);

So, I'm afraid any regression test based on binlog_format will be contaminated, it would be better to come up with a different variable (if SET STATEMENT remains important after the analysis).

Comment by Roel Van de Paar [ 2021-08-29 ] 

# mysqld options required for replay:  --debug-assert=0  (or --skip-debug-assert)
 
CREATE TEMPORARY TABLE t (c INT);
 
PREPARE s FROM 'SET STATEMENT binlog_format=ROW FOR SELECT 1';

Leads to:

10.7.0 05e29e177df243b700392b797e26cae43fd3181e (Debug)

 
Core was generated by `/test/MD280821-mariadb-10.7.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 0x14d884623700 (LWP 2753254))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x000014d8871e1859 in __GI_abort () at abort.c:79
 
#2  0x000055af2d930be7 in DbugExit (why=why@entry=0x14d8846219b0 "missing DBUG_RETURN or DBUG_VOID_RETURN macro in function \"set_ok_status\"\n") at /test/10.7_dbg/dbug/dbug.c:2046
 
#3  0x000055af2d932b98 in _db_return_ (_stack_frame_=_stack_frame_@entry=0x14d884621c00) at /test/10.7_dbg/dbug/dbug.c:1213
 
#4  0x000055af2cdc8a69 in Diagnostics_area::set_ok_status (this=0x14d840006c30, affected_rows=affected_rows@entry=0, last_insert_id=last_insert_id@entry=0, message=message@entry=0x55af2daaf7ce "Statement prepared") at /test/10.7_dbg/sql/sql_error.cc:361
 
#5  0x000055af2ce502c1 in my_ok (message=0x55af2daaf7ce "Statement prepared", id=0, affected_rows_arg=0, thd=0x14d840000db8) at /test/10.7_dbg/sql/sql_class.h:5553
 
#6  mysql_sql_stmt_prepare (thd=thd@entry=0x14d840000db8) at /test/10.7_dbg/sql/sql_prepare.cc:3036
 
#7  0x000055af2ce226c8 in mysql_execute_command (thd=thd@entry=0x14d840000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.7_dbg/sql/sql_parse.cc:3957
 
#8  0x000055af2ce0eb83 in mysql_parse (thd=thd@entry=0x14d840000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14d884622400) at /test/10.7_dbg/sql/sql_parse.cc:8030
 
#9  0x000055af2ce1d788 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14d840000db8, packet=packet@entry=0x14d84000b739 "PREPARE s FROM 'SET STATEMENT binlog_format=ROW FOR SELECT 1'", packet_length=packet_length@entry=61, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_class.h:1358
 
#10 0x000055af2ce20b90 in do_command (thd=0x14d840000db8, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_parse.cc:1404
 
#11 0x000055af2cf96f2e in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55af2f914f48, put_in_cache=put_in_cache@entry=true) at /test/10.7_dbg/sql/sql_connect.cc:1418
 
#12 0x000055af2cf97533 in handle_one_connection (arg=arg@entry=0x55af2f914f48) at /test/10.7_dbg/sql/sql_connect.cc:1312
 
#13 0x000055af2d400586 in pfs_spawn_thread (arg=0x55af2f83dae8) at /test/10.7_dbg/storage/perfschema/pfs.cc:2201
 
#14 0x000014d8876f0609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#15 0x000014d8872de293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.3.32 (dbg), 10.4.22 (dbg), 10.5.13 (dbg), 10.6.5 (dbg), 10.7.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.41 (dbg), 10.2.41 (opt), 10.3.32 (opt), 10.4.22 (opt), 10.5.13 (opt), 10.6.5 (opt), 10.7.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.35 (dbg), 5.7.35 (opt), 8.0.26 (dbg), 8.0.26 (opt)

Comment by Rucha Deodhar [ 2021-12-20 ]

Patch: https://github.com/MariaDB/server/commit/0f2b7bc3337441794979945192ea0aa7ca12bef7

Comment by Oleksandr Byelkin [ 2021-12-21 ]

OK to push

Comment by Roel Van de Paar [ 2023-04-08 ]

Created MDEV-31026 for the earlier additional testcase by Elena.

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