Bug #88255 m_thd->get_transaction()->is_empty(Transaction_ctx::STMT) etc. Assertion
Submitted: 27 Oct 2017 21:34 Modified: 13 Dec 2017 2:15
Reporter: Roel Van de Paar Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: DML Severity:S6 (Debug Builds)
Version:8.0.3 RC OS:Any
Assigned to: CPU Architecture:Any
Tags: debug, event scheduler

[27 Oct 2017 21:34] Roel Van de Paar
Description:
2017-10-27T21:03:01.255520Z 0 [Note] /sda/MS201017-mysql-8.0.3-rc-linux-x86_64-debug/bin/mysqld: ready for connections. Version: '8.0.3-rc-debug-log'  socket: '/sda/MS201017-mysql-8.0.3-rc-linux-x86_64-debug/socket.sock'  port: 16654  MySQL Community Server (GPL)
2017-10-27T21:03:36.420183Z 4 [Note] Event Scheduler: Last execution of test.e1. Dropping.
2017-10-27T21:03:36.463457Z 8 [Note] Event Scheduler: Dropping test.e1
mysqld: /git/mysql-server_dbg/sql/sql_class.h:4389: Disable_autocommit_guard::Disable_autocommit_guard(THD*): Assertion `m_thd->get_transaction()->is_empty(Transaction_ctx::STMT) && m_thd->get_transaction()->is_empty(Transaction_ctx::SESSION)' failed.
21:03:36 UTC - mysqld got signal 6 ;

Core was generated by `/sda/MS201017-mysql-8.0.3-rc-linux-x86_64-debug/bin/mysqld --no-defaults --sql_'.
Program terminated with signal 6, Aborted.
#0  0x00007f1d803039b1 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
61	  val = INTERNAL_SYSCALL (tgkill, err, 3, THREAD_GETMEM (THREAD_SELF, pid),
(gdb) bt
#0  0x00007f1d803039b1 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x000000000369e428 in my_write_core (sig=6) at /git/mysql-server_dbg/mysys/stacktrace.cc:291
#2  0x000000000286b8f6 in handle_fatal_signal (sig=6) at /git/mysql-server_dbg/sql/signal_handler.cc:234
#3  <signal handler called>
#4  0x00007f1d7e61b1f7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007f1d7e61c8e8 in __GI_abort () at abort.c:90
#6  0x00007f1d7e614266 in __assert_fail_base (fmt=0x7f1d7e766e68 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", 
    assertion=assertion@entry=0x3d1ce90 "m_thd->get_transaction()->is_empty(Transaction_ctx::STMT) && m_thd->get_transaction()->is_empty(Transaction_ctx::SESSION)", file=file@entry=0x3d1ce68 "/git/mysql-server_dbg/sql/sql_class.h", line=line@entry=4389, 
    function=function@entry=0x3d24a40 <Disable_autocommit_guard::Disable_autocommit_guard(THD*)::__PRETTY_FUNCTION__> "Disable_autocommit_guard::Disable_autocommit_guard(THD*)") at assert.c:92
#7  0x00007f1d7e614312 in __GI___assert_fail (
    assertion=0x3d1ce90 "m_thd->get_transaction()->is_empty(Transaction_ctx::STMT) && m_thd->get_transaction()->is_empty(Transaction_ctx::SESSION)", file=0x3d1ce68 "/git/mysql-server_dbg/sql/sql_class.h", line=4389, 
    function=0x3d24a40 <Disable_autocommit_guard::Disable_autocommit_guard(THD*)::__PRETTY_FUNCTION__> "Disable_autocommit_guard::Disable_autocommit_guard(THD*)") at assert.c:101
#8  0x0000000002380e23 in Disable_autocommit_guard::Disable_autocommit_guard (this=0x7f1d808625b0, thd=0x7f1d3ed05000)
    at /git/mysql-server_dbg/sql/sql_class.h:4388
#9  0x0000000002865ad7 in Event_job_data::execute (this=0x7f1d808627b0, thd=0x7f1d3ed05000, drop=true)
    at /git/mysql-server_dbg/sql/event_data_objects.cc:1291
#10 0x0000000002c68b3c in Event_worker_thread::run (this=0x7f1d80862c6f, thd=0x7f1d3ed05000, event=0x7f1d6c715040)
    at /git/mysql-server_dbg/sql/event_scheduler.cc:418
#11 0x0000000002c6870e in event_worker_thread (arg=0x7f1d6c715040) at /git/mysql-server_dbg/sql/event_scheduler.cc:328
#12 0x00000000036ec54d in pfs_spawn_thread (arg=0x7f1d38589120) at /git/mysql-server_dbg/storage/perfschema/pfs.cc:2985
#13 0x00007f1d802fee25 in start_thread (arg=0x7f1d80863700) at pthread_create.c:308
#14 0x00007f1d7e6de34d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

How to repeat:
CREATE DATABASE test;
USE test;
CREATE TABLE t1(_userid CHAR (1)KEY) ENGINE=InnoDB;
SET @@global.autocommit=0;
SET @@session.TIMESTAMP=200;
CREATE EVENT e1 ON SCHEDULE AT CURRENT_TIMESTAMP + INTERVAL 1 DAY DO INSERT INTO t1 VALUES(1);
SELECT SLEEP(3);  # Just to pause 3 seconds (i.e. this query is not effectively required to trigger crash, just a pause is needed. Will show as "Lost connection to MySQL server during query")
[27 Oct 2017 23:00] MySQL Verification Team
Thank you for the bug report.

2017-10-27T22:55:25.475302Z 0 [Note] [003874] Server socket created on IP: '::'.
2017-10-27T22:55:25.586754Z 4 [Note] [003674] Event Scheduler: scheduler thread started with id 4
2017-10-27T22:55:25.587050Z 0 [NOTE] [001408] /home/miguel/dbs/8.0/bin/mysqld: ready for connections. Version: '8.0.4-rc-debug-log'  socket: '/tmp/mysql80.sock'  port: 3380  Source distribution 2017-OCT-18
2017-10-27T22:57:31.488789Z 4 [Note] [003667] Event Scheduler: Last execution of test.e1. Dropping.
2017-10-27T22:57:31.602715Z 9 [Note] [004073] Event Scheduler: Dropping test.e1
mysqld: /home/miguel/build/2017OCT18/mysql-8.0/sql/sql_class.h:4403: Disable_autocommit_guard::Disable_autocommit_guard(THD*): Assertion `m_thd->get_transaction()->is_empty(Transaction_ctx::STMT) && m_thd->get_transaction()->is_empty(Transaction_ctx::SESSION)' failed.
22:57:31 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=3
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68147 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7fabfc00d7c0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7fac70258d3f thread_stack 0x46000
/home/miguel/dbs/8.0/bin/mysqld(my_print_stacktrace+0x43) [0x3821815]
/home/miguel/dbs/8.0/bin/mysqld(handle_fatal_signal+0x3f5) [0x2adaf80]
/lib64/libpthread.so.0(+0xf5e0) [0x7fac7a5b25e0]
/lib64/libc.so.6(gsignal+0x37) [0x7fac78fa41f7]
/lib64/libc.so.6(abort+0x148) [0x7fac78fa58e8]
/lib64/libc.so.6(+0x2e266) [0x7fac78f9d266]
/lib64/libc.so.6(+0x2e312) [0x7fac78f9d312]
/home/miguel/dbs/8.0/bin/mysqld(Disable_autocommit_guard::Disable_autocommit_guard(THD*)+0xb1) [0x266fd0d]
/home/miguel/dbs/8.0/bin/mysqld(Event_job_data::execute(THD*, bool)+0x8a1) [0x2ad5c7f]
/home/miguel/dbs/8.0/bin/mysqld(Event_worker_thread::run(THD*, Event_queue_element_for_exec*)+0x422) [0x2e937e4]
/home/miguel/dbs/8.0/bin/mysqld() [0x2e933b6]
/home/miguel/dbs/8.0/bin/mysqld() [0x3cec963]
/lib64/libpthread.so.0(+0x7e25) [0x7fac7a5aae25]
/lib64/libc.so.6(clone+0x6d) [0x7fac7906734d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7fabec0417a0): DROP EVENT IF EXISTS`test`.`e1`
Connection ID (thread ID): 9
Status: NOT_KILLED

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
miguel@tikal:~/dbs $
[13 Dec 2017 2:15] Paul DuBois
Posted by developer:
 
Noted in 8.0.4, 9.0.0.

An Event Scheduler event for which global autocommit was disabled at
event expiration time caused an assertion to be raised.