[MDEV-24534] Assertion `!is_current_stmt_binlog_format_row()' failed in THD::restore_stmt_binlog_format Created: 2021-01-06  Updated: 2023-04-27

Status: Open
Project: MariaDB Server
Component/s: Replication
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Andrei Elkin
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-14472 Assertion `is_current_stmt_binlog_for... Stalled
relates to MDEV-17814 Server crashes in is_current_stmt_bin... Open

 Description   

Seemingly different from MDEV-14472, MDEV-17814:

# mysqld options required for replay: --log-bin 
SET GLOBAL autocommit=0;
SET GLOBAL event_scheduler= ON;
SET timestamp=12345;
CREATE TABLE t1 (c1 INT ZEROFILL NULL);
CREATE EVENT e1 ON SCHEDULE AT current_timestamp + INTERVAL 1 DAY DO INSERT INTO t1 VALUES (1);
SELECT SLEEP (3);

Leads to:

10.6.0 9118fd360a3da0bba521caf2a35c424968235ac4 (Debug)

mysqld: /test/10.6_dbg/sql/sql_class.h:4360: void THD::restore_stmt_binlog_format(enum_binlog_format): Assertion `!is_current_stmt_binlog_format_row()' failed.

10.6.0 9118fd360a3da0bba521caf2a35c424968235ac4 (Debug)

Core was generated by `/test/MD010121-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 0x152c90664700 (LWP 1680884))]
(gdb) bt
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
#1  0x0000557e964840d7 in my_write_core (sig=sig@entry=6) at /test/10.6_dbg/mysys/stacktrace.c:424
#2  0x0000557e95c18ab1 in handle_fatal_signal (sig=6) at /test/10.6_dbg/sql/signal_handler.cc:330
#3  <signal handler called>
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#5  0x0000152c93303859 in __GI_abort () at abort.c:79
#6  0x0000152c93303729 in __assert_fail_base (fmt=0x152c93499588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x557e965d8130 "!is_current_stmt_binlog_format_row()", file=0x557e965c21e0 "/test/10.6_dbg/sql/sql_class.h", line=4360, function=<optimized out>) at assert.c:92
#7  0x0000152c93314f36 in __GI___assert_fail (assertion=assertion@entry=0x557e965d8130 "!is_current_stmt_binlog_format_row()", file=file@entry=0x557e965c21e0 "/test/10.6_dbg/sql/sql_class.h", line=line@entry=4360, function=function@entry=0x557e965d8158 "void THD::restore_stmt_binlog_format(enum_binlog_format)") at assert.c:101
#8  0x0000557e95a86486 in THD::restore_stmt_binlog_format (format=BINLOG_FORMAT_STMT, this=0x152c30004008) at /test/10.6_dbg/sql/sql_class.h:4360
#9  Events::drop_event (thd=thd@entry=0x152c30004008, dbname=dbname@entry=0x152c90663b88, name=name@entry=0x152c90663b98, if_exists=if_exists@entry=false) at /test/10.6_dbg/sql/events.cc:629
#10 0x0000557e95a843ea in Event_job_data::execute (this=this@entry=0x152c90663b40, thd=thd@entry=0x152c30004008, drop=<optimized out>) at /test/10.6_dbg/sql/event_data_objects.cc:1543
#11 0x0000557e95e4011d in Event_worker_thread::run (this=this@entry=0x152c90663ddf, thd=thd@entry=0x152c30004008, event=event@entry=0x152c30002230) at /test/10.6_dbg/sql/event_scheduler.cc:323
#12 0x0000557e95e40309 in event_worker_thread (arg=arg@entry=0x152c30002230) at /test/10.6_dbg/sql/event_scheduler.cc:268
#13 0x0000557e95f6388f in pfs_spawn_thread (arg=0x152c2c01b918) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
#14 0x0000152c93811609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x0000152c93400293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.2.37 (dbg), 10.3.28 (dbg), 10.4.18 (dbg), 10.5.9 (dbg), 10.6.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.37 (opt), 10.3.28 (opt), 10.4.18 (opt), 10.5.9 (opt), 10.6.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.50 (dbg), 5.6.50 (opt), 5.7.32 (dbg), 5.7.32 (opt), 8.0.22 (dbg), 8.0.22 (opt)

10.5 and 10.6 crash with the above stack on debug. 10.4 and earlier crash with this stack instead:

10.4.18 3454b5cf35a61e8f6cfab376638520dee4a50609 (Debug)

mysqld: /test/10.4_dbg/sql/sql_base.cc:897: void close_thread_tables(THD*): Assertion `thd->transaction.stmt.is_empty() || thd->in_sub_stmt || (thd->state_flags & Open_tables_state::BACKUPS_AVAIL)' failed.

10.4.18 3454b5cf35a61e8f6cfab376638520dee4a50609 (Debug)

Core was generated by `/test/MD010121-mariadb-10.4.18-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 0x151838085700 (LWP 1751357))]
(gdb) bt
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
#1  0x000055674b19eebd in my_write_core (sig=sig@entry=6) at /test/10.4_dbg/mysys/stacktrace.c:386
#2  0x000055674a8b5abf in handle_fatal_signal (sig=6) at /test/10.4_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  0x000015184d5f7859 in __GI_abort () at abort.c:79
#6  0x000015184d5f7729 in __assert_fail_base (fmt=0x15184d78d588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55674b268ec0 "thd->transaction.stmt.is_empty() || thd->in_sub_stmt || (thd->state_flags & Open_tables_state::BACKUPS_AVAIL)", file=0x55674b268770 "/test/10.4_dbg/sql/sql_base.cc", line=897, function=<optimized out>) at assert.c:92
#7  0x000015184d608f36 in __GI___assert_fail (assertion=assertion@entry=0x55674b268ec0 "thd->transaction.stmt.is_empty() || thd->in_sub_stmt || (thd->state_flags & Open_tables_state::BACKUPS_AVAIL)", file=file@entry=0x55674b268770 "/test/10.4_dbg/sql/sql_base.cc", line=line@entry=897, function=function@entry=0x55674b268ea0 "void close_thread_tables(THD*)") at assert.c:101
#8  0x000055674a555d67 in close_thread_tables (thd=thd@entry=0x1517d0003b10) at /test/10.4_dbg/sql/handler.h:1771
#9  0x000055674aacfe6c in Event_db_repository::drop_event (this=0x55674d0f1830, thd=thd@entry=0x1517d0003b10, db=db@entry=0x151838084d90, name=name@entry=0x151838084da0, drop_if_exists=drop_if_exists@entry=false) at /test/10.4_dbg/sql/event_db_repository.cc:923
#10 0x000055674a70865e in Events::drop_event (thd=thd@entry=0x1517d0003b10, dbname=dbname@entry=0x151838084d90, name=name@entry=0x151838084da0, if_exists=if_exists@entry=false) at /test/10.4_dbg/sql/events.cc:616
#11 0x000055674a7067cd in Event_job_data::execute (this=this@entry=0x151838084d40, thd=thd@entry=0x1517d0003b10, drop=<optimized out>) at /test/10.4_dbg/sql/event_data_objects.cc:1520
#12 0x000055674aaca5e1 in Event_worker_thread::run (this=this@entry=0x151838084e4f, thd=thd@entry=0x1517d0003b10, event=event@entry=0x1517d0001f70) at /test/10.4_dbg/sql/event_scheduler.cc:313
#13 0x000055674aaca7d8 in event_worker_thread (arg=0x1517d0001f70) at /test/10.4_dbg/sql/event_scheduler.cc:267
#14 0x000015184dbb4609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x000015184d6f4293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

And there are many bugs with a similar assert message to that one.



 Comments   
Comment by Roel Van de Paar [ 2021-01-06 ]

Unique bug id's

!is_current_stmt_binlog_format_row()|SIGABRT|THD::restore_stmt_binlog_format|Events::drop_event|Event_job_data::execute|Event_worker_thread::run
thd->transaction.stmt.is_empty() || thd->in_sub_stmt || (thd->state_flags & Open_tables_state::BACKUPS_AVAIL)|SIGABRT|close_thread_tables|Event_db_repository::drop_event|Events::drop_event|Event_job_data::execute

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