[MDEV-22768] Assertion `! is_set() || m_can_overwrite_status' failed in Diagnostics_area::set_error_status Created: 2020-06-01  Updated: 2023-11-28

Status: Stalled
Project: MariaDB Server
Component/s: Variables
Affects Version/s: 10.1, 10.2, 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10
Fix Version/s: 10.4, 10.5, 10.6, 10.11, 11.0

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

Issue Links:
Relates
relates to MDEV-27462 SET STATEMENT allows variables that c... Stalled

 Description   

--source include/have_log_bin.inc
--source include/have_innodb.inc
 
USE test;
SET SQL_MODE='';
SET AUTOCOMMIT=0;
CREATE TABLE t(c CHAR (0)) ENGINE=InnoDB;
SET STATEMENT gtid_domain_id=0 FOR INSERT INTO t VALUES(0),(0);
SET GLOBAL init_connect="SET @a=0";

Leads to:

10.5.4 8569dac1ec9f6853a0b2f3ea9bcbda67644ead24

mysqld: /test/10.5_dbg/sql/sql_error.cc:445: void Diagnostics_area::set_error_status(uint, const char*, const char*, const Sql_user_condition_identity&, const Sql_condition*): Assertion `! is_set() || m_can_overwrite_status' failed.

10.5.4 8569dac1ec9f6853a0b2f3ea9bcbda67644ead24

Core was generated by `/test/MD260520-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 0x1489f44f0700 (LWP 114766))]
(gdb) bt
(gdb) (gdb) #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
#1  0x0000559d77034d7a in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
#2  0x0000559d767da385 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  0x00001489f2c34801 in __GI_abort () at abort.c:79
#6  0x00001489f2c2439a in __assert_fail_base (fmt=0x1489f2dab7d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x559d771aa1d0 "! is_set() || m_can_overwrite_status", file=file@entry=0x559d771aa140 "/test/10.5_dbg/sql/sql_error.cc", line=line@entry=445, function=function@entry=0x559d771aabe0 <Diagnostics_area::set_error_status(unsigned int, char const*, char const*, Sql_user_condition_identity const&, Sql_condition const*)::__PRETTY_FUNCTION__> "void Diagnostics_area::set_error_status(uint, const char*, const char*, const Sql_user_condition_identity&, const Sql_condition*)") at assert.c:92
#7  0x00001489f2c24412 in __GI___assert_fail (assertion=assertion@entry=0x559d771aa1d0 "! is_set() || m_can_overwrite_status", file=file@entry=0x559d771aa140 "/test/10.5_dbg/sql/sql_error.cc", line=line@entry=445, function=function@entry=0x559d771aabe0 <Diagnostics_area::set_error_status(unsigned int, char const*, char const*, Sql_user_condition_identity const&, Sql_condition const*)::__PRETTY_FUNCTION__> "void Diagnostics_area::set_error_status(uint, const char*, const char*, const Sql_user_condition_identity&, const Sql_condition*)") at assert.c:101
#8  0x0000559d764e65ee in Diagnostics_area::set_error_status (this=this@entry=0x1489d201ab90, sql_errno=sql_errno@entry=1953, message=message@entry=0x1489f44eeab0 "Cannot modify @@session.gtid_domain_id or @@session.gtid_seq_no inside a transaction", sqlstate=sqlstate@entry=0x559d771cb8c8 "HY000", ucid=@0x1489f44eea08: {m_user_condition_value = 0x0}, error_condition=0x0) at /test/10.5_dbg/sql/sql_error.cc:445
#9  0x0000559d764c84e0 in THD::raise_condition (this=this@entry=0x1489d2015088, sql_errno=sql_errno@entry=1953, sqlstate=0x559d771cb8c8 "HY000", sqlstate@entry=0x0, level=<optimized out>, ucid=@0x1489f44eea08: {m_user_condition_value = 0x0}, msg=msg@entry=0x1489f44eeab0 "Cannot modify @@session.gtid_domain_id or @@session.gtid_seq_no inside a transaction") at /test/10.5_dbg/sql/sql_class.cc:1135
#10 0x0000559d7642c102 in THD::raise_condition (msg=0x1489f44eeab0 "Cannot modify @@session.gtid_domain_id or @@session.gtid_seq_no inside a transaction", level=<optimized out>, sqlstate=0x0, sql_errno=1953, this=0x1489d2015088) at /test/10.5_dbg/sql/sql_class.h:4504
#11 my_message_sql (error=1953, str=0x1489f44eeab0 "Cannot modify @@session.gtid_domain_id or @@session.gtid_seq_no inside a transaction", MyFlags=0) at /test/10.5_dbg/sql/mysqld.cc:3110
#12 0x0000559d7702975e in my_error (nr=nr@entry=1953, MyFlags=MyFlags@entry=0) at /test/10.5_dbg/mysys/my_error.c:125
#13 0x0000559d76698fac in error_if_in_trans_or_substatement (thd=<optimized out>, in_substatement_error=in_substatement_error@entry=1954, in_transaction_error=in_transaction_error@entry=1953) at /test/10.5_dbg/sql/sys_vars.cc:582
#14 0x0000559d7669901c in check_gtid_domain_id (self=<optimized out>, thd=<optimized out>, var=<optimized out>) at /test/10.5_dbg/sql/sys_vars.cc:1777
#15 0x0000559d76448e4a in sys_var::check (this=0x559d77dac760 <Sys_gtid_domain_id>, thd=thd@entry=0x1489d2015088, var=var@entry=0x1489d2051258) at /test/10.5_dbg/sql/set_var.cc:246
#16 0x0000559d76449eda in set_var::check (this=0x1489d2051258, thd=0x1489d2015088) at /test/10.5_dbg/sql/set_var.cc:811
#17 0x0000559d7644a606 in sql_set_variables (thd=0x1489d2015088, var_list=var_list@entry=0x1489d2019fe0, free=free@entry=false) at /test/10.5_dbg/sql/set_var.cc:739
#18 0x0000559d765075cd in LEX::restore_set_statement_var (this=0x1489d2018fd8) at /test/10.5_dbg/sql/sql_lex.cc:5720
#19 0x0000559d7652c365 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1489d2015088, packet=<optimized out>, packet@entry=0x1489d2067089 "", packet_length=<optimized out>, packet_length@entry=62, 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:2525
#20 0x0000559d7652831c in do_command (thd=0x1489d2015088) at /test/10.5_dbg/sql/sql_parse.cc:1355
#21 0x0000559d7668273f in do_handle_one_connection (connect=<optimized out>, connect@entry=0x1489d34453a8, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1411
#22 0x0000559d76682e5b in handle_one_connection (arg=arg@entry=0x1489d34453a8) at /test/10.5_dbg/sql/sql_connect.cc:1313
#23 0x0000559d76ae214e in pfs_spawn_thread (arg=0x1489f2045888) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
#24 0x00001489f39176db in start_thread (arg=0x1489f44f0700) at pthread_create.c:463
#25 0x00001489f2d1588f 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 Rucha Deodhar [ 2021-01-19 ]

Patch: https://github.com/MariaDB/server/commit/5d4853085b588b823242143fe31bc8e02882ee89

Comment by Oleksandr Byelkin [ 2021-01-25 ]

Please fix it as we agreed

Comment by Rucha Deodhar [ 2021-07-13 ]

Findings:
1. Some variables (default_master_connection, last_insert_id, log_slow_filter, log_slow_rate_limit, log_slow_verbosity, long_query_time, min_examined_row_limit, rand_seed1, rand_seed2, slow_query_log) mentioned under limitation can still be set. Others give error that the variable can't be set.
2. Asserts similar to one mentioned in the bug occurs when trying to set gtid_seq_no, binlog_format, binlog_direct, sql_log_bin (in addition to gtid_domain_id). However, no assert when the set statement is inside a stored procedure, it returns error as it should.

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

rucha174 Thank you for the analysis. Given your second remark, have a look at MDEV-25874 to see if there is any connection? Thanks

Comment by Rucha Deodhar [ 2021-07-23 ]

Hi Roel , Assertion in Diagnostics_area::set_error_status at DBUG_ASSERT(! is_set() || m_can_overwrite_status) occurs because we get error after OK or EOF is already sent. It can happen for any case for different reason where we have already sent EOF / OK but got an error later. So it is not really related. Only thing common is MDEV-25874 and this bug has assert in Diagnostics_area::set_error_status.

Comment by Oleksandr Byelkin [ 2022-01-04 ]

To sum up our discussion: we should issue an error if we are tryint to set one of the variables listed as unsupported in SET STATEMENT.

Comment by Rucha Deodhar [ 2022-01-10 ]

Closing issue because assertion can't be repeated anymore. Created another issue to disallow some variables that can be set in SET STATEMENT.
MDEV-27462

Comment by Roel Van de Paar [ 2022-01-31 ]

The issue readily reproduces at the CLI. rucha174 did you add InnoDB (MTR automatically uses MyISAM, whereas the server/client by default uses InnoDB)?

10.8.1 0c5d1342ae6b5ab3256848be7a83e5c3b1f21566 (Debug)

10.8.1-dbg>USE test;
Database changed
10.8.1-dbg>SET SQL_MODE='';
Query OK, 0 rows affected (0.000 sec)
10.8.1-dbg>SET AUTOCOMMIT=0;
Query OK, 0 rows affected (0.000 sec)
10.8.1-dbg>CREATE TABLE t(c CHAR (0));
Query OK, 0 rows affected (0.015 sec)
10.8.1-dbg>SET STATEMENT gtid_domain_id=0 FOR INSERT INTO t VALUES(0),(0);
Query OK, 2 rows affected, 2 warnings (0.006 sec)
Records: 2  Duplicates: 0  Warnings: 2
10.8.1-dbg>SET GLOBAL init_connect="SET @a=0";
ERROR 2013 (HY000): Lost connection to server during query

Comment by Roel Van de Paar [ 2022-01-31 ]

USE test;
SET SQL_MODE='';
SET AUTOCOMMIT=0;
CREATE TABLE t(c CHAR (0)) ENGINE=InnoDB;
SET STATEMENT gtid_domain_id=0 FOR INSERT INTO t VALUES(0),(0);
SET GLOBAL init_connect="SET @a=0";

Leads to:

10.8.1 0c5d1342ae6b5ab3256848be7a83e5c3b1f21566 (Debug)

mysqld: /test/10.8_dbg/sql/sql_error.cc:457: void Diagnostics_area::set_error_status(uint, const char*, const char*, const Sql_user_condition_identity&, const Sql_condition*): Assertion `! is_set() || m_can_overwrite_status' failed.

10.8.1 0c5d1342ae6b5ab3256848be7a83e5c3b1f21566 (Debug)

Core was generated by `/test/MD290122-mariadb-10.8.1-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 0x1492c4119700 (LWP 98805))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00001492ccd7b859 in __GI_abort () at abort.c:79
#2  0x00001492ccd7b729 in __assert_fail_base (fmt=0x1492ccf11588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55e403214e28 "! is_set() || m_can_overwrite_status", file=0x55e403214b98 "/test/10.8_dbg/sql/sql_error.cc", line=457, function=<optimized out>) at assert.c:92
#3  0x00001492ccd8cf36 in __GI___assert_fail (assertion=assertion@entry=0x55e403214e28 "! is_set() || m_can_overwrite_status", file=file@entry=0x55e403214b98 "/test/10.8_dbg/sql/sql_error.cc", line=line@entry=457, function=function@entry=0x55e403214da0 "void Diagnostics_area::set_error_status(uint, const char*, const char*, const Sql_user_condition_identity&, const Sql_condition*)") at assert.c:101
#4  0x000055e4024f1a3f in Diagnostics_area::set_error_status (this=this@entry=0x1491fc006d20, sql_errno=sql_errno@entry=1953, message=message@entry=0x1492c4117c50 "Cannot modify @@session.gtid_domain_id or @@session.gtid_seq_no inside a transaction", sqlstate=sqlstate@entry=0x55e4032358a8 "HY000", ucid=@0x1492c41179f0: {m_user_condition_value = 0x0}, error_condition=0x0) at /test/10.8_dbg/sql/sql_error.h:1019
#5  0x000055e4024cb02b in THD::raise_condition (this=this@entry=0x1491fc000db8, cond=cond@entry=0x1492c41179e0) at /test/10.8_dbg/sql/sql_class.cc:1121
#6  0x000055e4024028dc in THD::raise_condition (this=this@entry=0x1491fc000db8, sql_errno=sql_errno@entry=1953, sqlstate=sqlstate@entry=0x55e4031f2878 "", level=<optimized out>, msg=msg@entry=0x1492c4117c50 "Cannot modify @@session.gtid_domain_id or @@session.gtid_seq_no inside a transaction") at /test/10.8_dbg/sql/sql_class.h:4818
#7  0x000055e4023f4a6f in my_message_sql (error=1953, str=0x1492c4117c50 "Cannot modify @@session.gtid_domain_id or @@session.gtid_seq_no inside a transaction", MyFlags=0) at /test/10.8_dbg/sql/mysqld.cc:3279
#8  0x000055e403064836 in my_error (nr=nr@entry=1953, MyFlags=MyFlags@entry=0) at /test/10.8_dbg/mysys/my_error.c:124
#9  0x000055e4026dd320 in error_if_in_trans_or_substatement (thd=<optimized out>, in_substatement_error=in_substatement_error@entry=1954, in_transaction_error=in_transaction_error@entry=1953) at /test/10.8_dbg/sql/sys_vars.cc:581
#10 0x000055e4026dd39d in check_gtid_domain_id (self=<optimized out>, thd=<optimized out>, var=<optimized out>) at /test/10.8_dbg/sql/sys_vars.cc:1827
#11 0x000055e402446022 in sys_var::check (this=0x55e403bb1040 <Sys_gtid_domain_id>, thd=thd@entry=0x1491fc000db8, var=var@entry=0x1491fc025958) at /test/10.8_dbg/sql/set_var.cc:246
#12 0x000055e402447056 in set_var::check (this=0x1491fc025958, thd=0x1491fc000db8) at /test/10.8_dbg/sql/set_var.cc:810
#13 0x000055e402447766 in sql_set_variables (thd=0x1491fc000db8, var_list=var_list@entry=0x1491fc006110, free=free@entry=false) at /test/10.8_dbg/sql/set_var.cc:738
#14 0x000055e402513c5f in LEX::restore_set_statement_var (this=0x1491fc0050f0) at /test/10.8_dbg/sql/sql_lex.cc:5911
#15 0x000055e402548f80 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1491fc000db8, packet=<optimized out>, packet@entry=0x1491fc00b889 "", packet_length=packet_length@entry=62, blocking=blocking@entry=true) at /test/10.8_dbg/sql/sql_parse.cc:2468
#16 0x000055e402549e9a in do_command (thd=0x1491fc000db8, blocking=blocking@entry=true) at /test/10.8_dbg/sql/sql_parse.cc:1402
#17 0x000055e4026c5110 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55e405c21d38, put_in_cache=put_in_cache@entry=true) at /test/10.8_dbg/sql/sql_connect.cc:1418
#18 0x000055e4026c5715 in handle_one_connection (arg=arg@entry=0x55e405c21d38) at /test/10.8_dbg/sql/sql_connect.cc:1312
#19 0x000055e402b4ec8e in pfs_spawn_thread (arg=0x55e405b34e78) at /test/10.8_dbg/storage/perfschema/pfs.cc:2201
#20 0x00001492cd28a609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#21 0x00001492cce78293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.2.42 (dbg), 10.3.33 (dbg), 10.4.23 (dbg), 10.5.14 (dbg), 10.6.6 (dbg), 10.7.2 (dbg), 10.8.1 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.42 (opt), 10.3.33 (opt), 10.4.23 (opt), 10.5.14 (opt), 10.6.6 (opt), 10.7.2 (opt), 10.8.1 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.36 (dbg), 5.7.36 (opt), 8.0.27 (dbg), 8.0.27 (opt)

Comment by Roel Van de Paar [ 2022-01-31 ]

This bug was found to be masking other bugs (confirmed), so it was increased in prio and affect-tests tag was added

Comment by Rucha Deodhar [ 2022-02-01 ]

Roel , oh, right. sorry, my bad. Can repeat it now. But it is not repeatable after patch for MDEV-27462

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