Bug #76958 Events+RPL: void close_thread_tables(THD*): Assertion `thd->get_transaction()
Submitted: 6 May 2015 16:03 Modified: 21 May 2015 14:13
Reporter: Matthias Leich Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: DDL Severity:S2 (Serious)
Version:5.7.8-rc-debug-log OS:Any
Assigned to: CPU Architecture:Any

[6 May 2015 16:03] Matthias Leich
Description:
Assert found during RQG testing
- in mysql-trunk (MySQL 5.8) 2015-05
- in mysql-5.7 ~ 2015-04-23
compiled with debug.

Logging: ./mtr  --mysqld=--binlog_format=row rpl_ml009
MySQL Version 5.7.8
Using binlog format 'row'
...
==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------
....
main.rpl_ml009                           [ fail ]
...
mysqld: <tree>/sql/sql_base.cc:1562: void close_thread_tables(THD*): Assertion `thd->get_transaction()->is_empty(Transaction_ctx::STMT) || thd->in_sub_stmt || (thd->state_flags & Open_tables_state::BACKUPS_AVAIL)' failed.
15:48:28 UTC - mysqld got signal 6 ;
...
Thread 1 (Thread 0x7f741c8cb700 (LWP 4282)):
#0  0x00007f74365e88ac in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000001903831 in my_write_core (sig=6) at <tree>/mysys/stacktrace.c:247
#2  0x0000000000f4d090 in handle_fatal_signal (sig=6) at <tree>/sql/signal_handler.cc:220
#3  <signal handler called>
#4  0x00007f7435296925 in raise () from /lib64/libc.so.6
#5  0x00007f7435298105 in abort () from /lib64/libc.so.6
#6  0x00007f743528fa4e in __assert_fail_base () from /lib64/libc.so.6
#7  0x00007f743528fb10 in __assert_fail () from /lib64/libc.so.6
#8  0x0000000001560fe4 in close_thread_tables (thd=0x7f73b00160d0) at <tree>/sql/sql_base.cc:1562
#9  0x0000000001814f6b in Event_db_repository::drop_event (this=0x47f3bb0, thd=0x7f73b00160d0, db=..., name=..., drop_if_exists=false) at <tree>/sql/event_db_repository.cc:930
#10 0x0000000001818dce in Event_queue::recalculate_activation_times (this=0x4882770, thd=0x7f73b00160d0) at <tree>/sql/event_queue.cc:431
#11 0x000000000181cf23 in Event_scheduler::run (this=0x4882880, thd=0x7f73b00160d0) at <tree>/sql/event_scheduler.cc:505
#12 0x000000000181c4aa in event_scheduler_thread (arg=0x7f73b00117f0) at <tree>/sql/event_scheduler.cc:241
#13 0x0000000001cc8b19 in pfs_spawn_thread (arg=0x7f73b0011f40) at <tree>/storage/perfschema/pfs.cc:2147
#14 0x00007f74365e39d1 in start_thread () from /lib64/libpthread.so.0
#15 0x00007f743534cb6d in clone () from /lib64/libc.so.6

The problem was not reproducible on MySQL 5.6 ~ 2015-02.

How to repeat:
=== rpl_ml009.test ===
--source include/master-slave.inc
--disable_abort_on_error
--disable_query_log
--disable_result_log
let $run= 100000;
while ($run)
{
   # ~ no assert CREATE EVENT e1 ON SCHEDULE EVERY 1 SECOND STARTS NOW()
   #   ON COMPLETION NOT PRESERVE DO SELECT * FROM t1_base_S1 LIMIT 1;
   CREATE EVENT e1 ON SCHEDULE EVERY 1 SECOND
   STARTS NOW() ENDS NOW() + INTERVAL 1 SECOND
   ON COMPLETION NOT PRESERVE DO SET @aux = 1;
   SET GLOBAL EVENT_SCHEDULER = OFF;
   SET GLOBAL EVENT_SCHEDULER = ON;
   dec $run;
}
DROP EVENT e1;
SET GLOBAL EVENT_SCHEDULER = OFF;
--source include/rpl_end.inc
[21 May 2015 14:13] Paul DuBois
Noted in 5.7.8, 5.8.0 changelogs.

With row-based binary logging, automatic dropping of a scheduled
event that had reached the end of its lifetime could raise an
assertion.