[MDEV-22421] Galera assertion !wsrep_has_changes(thd) || (thd->lex->sql_command == SQLCOM_CREATE_TABLE && !thd->is_current_stmt_binlog_format_row()) Created: 2020-04-30  Updated: 2021-07-29  Resolved: 2021-07-28

Status: Closed
Project: MariaDB Server
Component/s: Galera
Affects Version/s: None
Fix Version/s: 10.4.21, 10.5.12, 10.6.4

Type: Bug Priority: Major
Reporter: Jan Lindström (Inactive) Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: None

Attachments: File galera_stress.zz     File galera_stress_kill.yy     File nohup.out     File rungalera22.sh    
Issue Links:
Relates
relates to MDEV-21697 Galera assertion !wsrep_has_changes(t... Closed

 Description   

How to repeat: randgen

mysqld: /home/jan/mysql/10.4-kill/sql/wsrep_trans_observer.h:509: void wsrep_commit_empty(THD*, bool): Assertion `!wsrep_has_changes(thd) || (thd->lex->sql_command == SQLCOM_CREATE_TABLE && !thd->is_current_stmt_binlog_format_row())' failed.
 
200430  7:54:17 [ERROR] mysqld got signal 6 ;
 
../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
# 2020-04-30T07:54:32 [655979] 
# 2020-04-30T07:54:32 [655979] Thread 1 (Thread 0x7f5818f64700 (LWP 656341)):
 
# 2020-04-30T07:54:32 [655979] #0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
# 2020-04-30T07:54:32 [655979] #1  0x0000559ceb151bb1 in my_write_core (sig=6) at /home/jan/mysql/10.4-kill/mysys/stacktrace.c:481
 
# 2020-04-30T07:54:32 [655979] #2  0x0000559cea8a46f3 in handle_fatal_signal (sig=6) at /home/jan/mysql/10.4-kill/sql/signal_handler.cc:343
 
# 2020-04-30T07:54:32 [655979] #3  <signal handler called>
 
# 2020-04-30T07:54:32 [655979] #4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
# 2020-04-30T07:54:32 [655979] #5  0x00007f584e0da859 in __GI_abort () at abort.c:79
 
# 2020-04-30T07:54:32 [655979] #6  0x00007f584e0da729 in __assert_fail_base (fmt=0x7f584e270588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x559ceb3cf280 "!wsrep_has_changes(thd) || (thd->lex->sql_command == SQLCOM_CREATE_TABLE && !thd->is_current_stmt_binlog_format_row())", file=0x559ceb3ceee0 "/home/jan/mysql/10.4-kill/sql/wsrep_trans_observer.h", line=509, function=<optimized out>) at assert.c:92
 
# 2020-04-30T07:54:32 [655979] #7  0x00007f584e0ebf36 in __GI___assert_fail (assertion=0x559ceb3cf280 "!wsrep_has_changes(thd) || (thd->lex->sql_command == SQLCOM_CREATE_TABLE && !thd->is_current_stmt_binlog_format_row())", file=0x559ceb3ceee0 "/home/jan/mysql/10.4-kill/sql/wsrep_trans_observer.h", line=509, function=0x559ceb3cf2f8 "void wsrep_commit_empty(THD*, bool)") at assert.c:101
 
# 2020-04-30T07:54:32 [655979] #8  0x0000559cea8a69fa in wsrep_commit_empty (thd=0x7f5780000d90, all=true) at /home/jan/mysql/10.4-kill/sql/wsrep_trans_observer.h:509
 
# 2020-04-30T07:54:32 [655979] #9  0x0000559cea8a96dc in ha_commit_trans (thd=0x7f5780000d90, all=true) at /home/jan/mysql/10.4-kill/sql/handler.cc:1462
 
# 2020-04-30T07:54:32 [655979] #10 0x0000559cea6e3c9b in trans_commit_implicit (thd=0x7f5780000d90) at /home/jan/mysql/10.4-kill/sql/transaction.cc:301
 
# 2020-04-30T07:54:32 [655979] #11 0x0000559cea54fe6a in mysql_execute_command (thd=0x7f5780000d90) at /home/jan/mysql/10.4-kill/sql/sql_parse.cc:6201
 
# 2020-04-30T07:54:32 [655979] #12 0x0000559cea554b83 in mysql_parse (thd=0x7f5780000d90, rawbuf=0x7f5780011f68 "OPTIMIZE TABLE `table10000_innodb_int` /* QNO 1000 CON_ID 24 */", length=63, parser_state=0x7f5818f63520, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4-kill/sql/sql_parse.cc:7900
 
# 2020-04-30T07:54:32 [655979] #13 0x0000559cea554275 in wsrep_mysql_parse (thd=0x7f5780000d90, rawbuf=0x7f5780011f68 "OPTIMIZE TABLE `table10000_innodb_int` /* QNO 1000 CON_ID 24 */", length=63, parser_state=0x7f5818f63520, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4-kill/sql/sql_parse.cc:7704
 
# 2020-04-30T07:54:32 [655979] #14 0x0000559cea541009 in dispatch_command (command=COM_QUERY, thd=0x7f5780000d90, packet=0x7f5780008691 "OPTIMIZE TABLE `table10000_innodb_int` /* QNO 1000 CON_ID 24 */ ", packet_length=64, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4-kill/sql/sql_parse.cc:1827
 
# 2020-04-30T07:54:32 [655979] #15 0x0000559cea53f976 in do_command (thd=0x7f5780000d90) at /home/jan/mysql/10.4-kill/sql/sql_parse.cc:1359
 
# 2020-04-30T07:54:32 [655979] #16 0x0000559cea6cacd1 in do_handle_one_connection (connect=0x559cedca24b0) at /home/jan/mysql/10.4-kill/sql/sql_connect.cc:1412
 
# 2020-04-30T07:54:32 [655979] #17 0x0000559cea6caa1a in handle_one_connection (arg=0x559cedca24b0) at /home/jan/mysql/10.4-kill/sql/sql_connect.cc:1316
 
# 2020-04-30T07:54:32 [655979] #18 0x00007f584ea19609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
# 2020-04-30T07:54:32 [655979] #19 0x00007f584e1d7103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
# 2020-04-30T07:54:32 [655979] Test completed with failure status STATUS_SERVER_CRASHED (101)
 
# 2020-04-30T07:54:32 [655979] GenTest exited with exit status STATUS_SERVER_CRASHED (101)



 Comments   
Comment by Jan Lindström (Inactive) [ 2020-04-30 ] 

# 2020-04-30T08:07:21 [657143] Thread 1 (Thread 0x7fa71d846700 (LWP 657503)):
 
# 2020-04-30T08:07:21 [657143] #0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
# 2020-04-30T08:07:21 [657143] #1  0x000055f2b47bbbb1 in my_write_core (sig=6) at /home/jan/mysql/10.4-kill/mysys/stacktrace.c:481
 
# 2020-04-30T08:07:21 [657143] #2  0x000055f2b3f0e6f3 in handle_fatal_signal (sig=6) at /home/jan/mysql/10.4-kill/sql/signal_handler.cc:343
 
# 2020-04-30T08:07:21 [657143] #3  <signal handler called>
 
# 2020-04-30T08:07:21 [657143] #4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
# 2020-04-30T08:07:21 [657143] #5  0x00007fa752982859 in __GI_abort () at abort.c:79
 
# 2020-04-30T08:07:21 [657143] #6  0x00007fa752982729 in __assert_fail_base (fmt=0x7fa752b18588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55f2b4a39280 "!wsrep_has_changes(thd) || (thd->lex->sql_command == SQLCOM_CREATE_TABLE && !thd->is_current_stmt_binlog_format_row())", file=0x55f2b4a38ee0 "/home/jan/mysql/10.4-kill/sql/wsrep_trans_observer.h", line=509, function=<optimized out>) at assert.c:92
 
# 2020-04-30T08:07:21 [657143] #7  0x00007fa752993f36 in __GI___assert_fail (assertion=0x55f2b4a39280 "!wsrep_has_changes(thd) || (thd->lex->sql_command == SQLCOM_CREATE_TABLE && !thd->is_current_stmt_binlog_format_row())", file=0x55f2b4a38ee0 "/home/jan/mysql/10.4-kill/sql/wsrep_trans_observer.h", line=509, function=0x55f2b4a392f8 "void wsrep_commit_empty(THD*, bool)") at assert.c:101
 
# 2020-04-30T08:07:21 [657143] #8  0x000055f2b3f109fa in wsrep_commit_empty (thd=0x7fa684000d90, all=true) at /home/jan/mysql/10.4-kill/sql/wsrep_trans_observer.h:509
 
# 2020-04-30T08:07:21 [657143] #9  0x000055f2b3f136dc in ha_commit_trans (thd=0x7fa684000d90, all=true) at /home/jan/mysql/10.4-kill/sql/handler.cc:1462
 
# 2020-04-30T08:07:21 [657143] #10 0x000055f2b3d4dc9b in trans_commit_implicit (thd=0x7fa684000d90) at /home/jan/mysql/10.4-kill/sql/transaction.cc:301
 
# 2020-04-30T08:07:21 [657143] #11 0x000055f2b3bb9e6a in mysql_execute_command (thd=0x7fa684000d90) at /home/jan/mysql/10.4-kill/sql/sql_parse.cc:6201
 
# 2020-04-30T08:07:21 [657143] #12 0x000055f2b3bbeb83 in mysql_parse (thd=0x7fa684000d90, rawbuf=0x7fa684011f68 "ALTER TABLE `table1_innodb_key_pk_parts_2_int_autoinc` ADD COLUMN IF NOT EXISTS galera_tmp int /* QNO 926 CON_ID 24 */", length=118, parser_state=0x7fa71d845520, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4-kill/sql/sql_parse.cc:7900
 
# 2020-04-30T08:07:21 [657143] #13 0x000055f2b3bbe275 in wsrep_mysql_parse (thd=0x7fa684000d90, rawbuf=0x7fa684011f68 "ALTER TABLE `table1_innodb_key_pk_parts_2_int_autoinc` ADD COLUMN IF NOT EXISTS galera_tmp int /* QNO 926 CON_ID 24 */", length=118, parser_state=0x7fa71d845520, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4-kill/sql/sql_parse.cc:7704
 
# 2020-04-30T08:07:21 [657143] #14 0x000055f2b3bab009 in dispatch_command (command=COM_QUERY, thd=0x7fa684000d90, packet=0x7fa684008691 "ALTER TABLE `table1_innodb_key_pk_parts_2_int_autoinc` ADD COLUMN IF NOT EXISTS galera_tmp int /* QNO 926 CON_ID 24 */ ", packet_length=119, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4-kill/sql/sql_parse.cc:1827
 
# 2020-04-30T08:07:21 [657143] #15 0x000055f2b3ba9976 in do_command (thd=0x7fa684000d90) at /home/jan/mysql/10.4-kill/sql/sql_parse.cc:1359
 
# 2020-04-30T08:07:21 [657143] #16 0x000055f2b3d34cd1 in do_handle_one_connection (connect=0x55f2b79d74b0) at /home/jan/mysql/10.4-kill/sql/sql_connect.cc:1412
 
# 2020-04-30T08:07:21 [657143] #17 0x000055f2b3d34a1a in handle_one_connection (arg=0x55f2b79d74b0) at /home/jan/mysql/10.4-kill/sql/sql_connect.cc:1316
 
# 2020-04-30T08:07:21 [657143] #18 0x00007fa7532c1609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
# 2020-04-30T08:07:21 [657143] #19 0x00007fa752a7f103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment by Ramesh Sivaraman [ 2021-06-04 ]

Found similar assertion with slightly different frames. 

SET @@local.sql_mode='no_field_options';
 
CREATE OR REPLACE TABLE t (a INT AS (b + 1), b INT, ROW_START BIGINT UNSIGNED AS ROW START INVISIBLE, ROW_END BIGINT UNSIGNED AS ROW END INVISIBLE, PERIOD FOR SYSTEM_TIME(ROW_START, ROW_END)) WITH SYSTEM VERSIONING ENGINE=InnoDB;
 
CREATE OR REPLACE TABLE t1 LIKE t;
 
INSERT IGNORE INTO t1 VALUES (1,1);
 
UPDATE t1 SET a=5 WHERE a !=3;

10.4.20 b2bb747f8cf56cf01dc571ffd8be195b95f0c0e8 (Debug)

 
mysqld: /test/10.4_dbg/sql/wsrep_trans_observer.h:532: void wsrep_commit_empty(THD*, bool): Assertion `!wsrep_has_changes(thd) || (thd->lex->sql_command == SQLCOM_CREATE_TABLE && !thd->is_current_stmt_binlog_format_row())' failed.

10.4.20 b2bb747f8cf56cf01dc571ffd8be195b95f0c0e8 (Debug)

 
Core was generated by `/test/GAL_MD120521-mariadb-10.4.20-linux-x86_64-dbg/bin/mysqld --defaults-file='.
 
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 0x147f193ed700 (LWP 3047135))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
#1  0x00005587eb8e84bd in my_write_core (sig=sig@entry=6) at /test/10.4_dbg/mysys/stacktrace.c:386
 
#2  0x00005587eaff0360 in handle_fatal_signal (sig=6) at /test/10.4_dbg/sql/signal_handler.cc:356
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#5  0x0000147f5ddb3859 in __GI_abort () at abort.c:79
 
#6  0x0000147f5ddb3729 in __assert_fail_base (fmt=0x147f5df49588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5587eb9c5360 "!wsrep_has_changes(thd) || (thd->lex->sql_command == SQLCOM_CREATE_TABLE && !thd->is_current_stmt_binlog_format_row())", file=0x5587eb9a9210 "/test/10.4_dbg/sql/wsrep_trans_observer.h", line=532, function=<optimized out>) at assert.c:92
 
#7  0x0000147f5ddc4f36 in __GI___assert_fail (assertion=assertion@entry=0x5587eb9c5360 "!wsrep_has_changes(thd) || (thd->lex->sql_command == SQLCOM_CREATE_TABLE && !thd->is_current_stmt_binlog_format_row())", file=file@entry=0x5587eb9a9210 "/test/10.4_dbg/sql/wsrep_trans_observer.h", line=line@entry=532, function=function@entry=0x5587eb9c53d8 "void wsrep_commit_empty(THD*, bool)") at assert.c:101
 
#8  0x00005587ead21819 in wsrep_commit_empty (all=true, thd=0x147ed4000d90) at /test/10.4_dbg/sql/sql_class.h:2534
 
#9  mysql_execute_command (thd=thd@entry=0x147ed4000d90) at /test/10.4_dbg/sql/sql_parse.cc:6346
 
#10 0x00005587ead22b9c in mysql_parse (thd=thd@entry=0x147ed4000d90, rawbuf=rawbuf@entry=0x147ed4013238 "UPDATE t1 SET a=5 WHERE a !=3", length=length@entry=29, parser_state=parser_state@entry=0x147f193ec490, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_parse.cc:7995
 
#11 0x00005587ead23c51 in wsrep_mysql_parse (thd=thd@entry=0x147ed4000d90, rawbuf=0x147ed4013238 "UPDATE t1 SET a=5 WHERE a !=3", length=29, parser_state=parser_state@entry=0x147f193ec490, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_parse.cc:7799
 
#12 0x00005587ead255ba in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x147ed4000d90, packet=packet@entry=0x147ed401b671 "UPDATE t1 SET a=5 WHERE a !=3", packet_length=packet_length@entry=29, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_class.h:1184
 
#13 0x00005587ead28e46 in do_command (thd=0x147ed4000d90) at /test/10.4_dbg/sql/sql_parse.cc:1373
 
#14 0x00005587eae640bd in do_handle_one_connection (connect=connect@entry=0x5587ef6f50e0) at /test/10.4_dbg/sql/sql_connect.cc:1412
 
#15 0x00005587eae641dc in handle_one_connection (arg=0x5587ef6f50e0) at /test/10.4_dbg/sql/sql_connect.cc:1316
 
#16 0x0000147f5e2c1609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#17 0x0000147f5deb0293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

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