Bug #87572 Assertion `thd->ha_data[ht_arg->slot].ha_ptr_backup == __null || (thd->is_binlog
Submitted: 29 Aug 2017 7:37 Modified: 22 Dec 2017 8:53
Reporter: Roel Van de Paar Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Replication Severity:S1 (Critical)
Version:5.7.19 OS:Any
Assigned to: CPU Architecture:Any

[29 Aug 2017 7:37] Roel Van de Paar
Description:
mysqld: /git/mysql-server_dbg/sql/handler.cc:1382: void trans_register_ha(THD*, bool, handlerton*, const ulonglong*): Assertion `thd->ha_data[ht_arg->slot].ha_ptr_backup == __null || (thd->is_binlog_applier() || thd->slave_thread)' failed.
04:47:46 UTC - mysqld got signal 6 ;

Core was generated by `/sda/MS250817-mysql-5.7.19-linux-x86_64-debug/bin/mysqld --no-defaults --basedi'.
Program terminated with signal 6, Aborted.
#0  0x00007fce08c47741 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  0x00007fce08c47741 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x0000000001836ef0 in my_write_core (sig=6) at /git/mysql-server_dbg/mysys/stacktrace.c:249
#2  0x0000000000e7d8b2 in handle_fatal_signal (sig=6) at /git/mysql-server_dbg/sql/signal_handler.cc:220
#3  <signal handler called>
#4  0x00007fce06fdb1d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007fce06fdc8c8 in __GI_abort () at abort.c:90
#6  0x00007fce06fd4146 in __assert_fail_base (fmt=0x7fce071253a8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", 
    assertion=assertion@entry=0x1d8c8c8 "thd->ha_data[ht_arg->slot].ha_ptr_backup == __null || (thd->is_binlog_applier() || thd->slave_thread)", file=file@entry=0x1d8c308 "/git/mysql-server_dbg/sql/handler.cc", line=line@entry=1382, 
    function=function@entry=0x1d8ed60 <trans_register_ha(THD*, bool, handlerton*, unsigned long long const*)::__PRETTY_FUNCTION__> "void trans_register_ha(THD*, bool, handlerton*, const ulonglong*)") at assert.c:92
#7  0x00007fce06fd41f2 in __GI___assert_fail (
    assertion=0x1d8c8c8 "thd->ha_data[ht_arg->slot].ha_ptr_backup == __null || (thd->is_binlog_applier() || thd->slave_thread)", 
    file=0x1d8c308 "/git/mysql-server_dbg/sql/handler.cc", line=1382, 
    function=0x1d8ed60 <trans_register_ha(THD*, bool, handlerton*, unsigned long long const*)::__PRETTY_FUNCTION__> "void trans_register_ha(THD*, bool, handlerton*, const ulonglong*)") at assert.c:101
#8  0x0000000000ef6e5b in trans_register_ha (thd=0x7fcdcac12000, all=true, ht_arg=0x7fce027f94a0, trxid=0x7fce09237058)
    at /git/mysql-server_dbg/sql/handler.cc:1381
#9  0x000000000196651f in innobase_register_trx (hton=0x7fce027f94a0, thd=0x7fcdcac12000, trx=0x7fcdf8000cf8)
    at /git/mysql-server_dbg/storage/innobase/handler/ha_innodb.cc:2894
#10 0x000000000197e748 in ha_innobase::external_lock (this=0x7fcdcac16c30, thd=0x7fcdcac12000, lock_type=0)
    at /git/mysql-server_dbg/storage/innobase/handler/ha_innodb.cc:15585
#11 0x0000000000f05bb4 in handler::ha_external_lock (this=0x7fcdcac16c30, thd=0x7fcdcac12000, lock_type=0)
    at /git/mysql-server_dbg/sql/handler.cc:7892
#12 0x00000000016b7121 in lock_external (thd=0x7fcdcac12000, tables=0x7fcdcb0fa978, count=1) at /git/mysql-server_dbg/sql/lock.cc:389
#13 0x00000000016b6e23 in mysql_lock_tables (thd=0x7fcdcac12000, tables=0x7fcdcad90b38, count=1, flags=0)
    at /git/mysql-server_dbg/sql/lock.cc:326
#14 0x0000000001481a73 in lock_tables (thd=0x7fcdcac12000, tables=0x7fcdcad902e8, count=1, flags=0)
    at /git/mysql-server_dbg/sql/sql_base.cc:6632
#15 0x0000000001550a10 in handle_query (thd=0x7fcdcac12000, lex=0x7fcdcac142f8, result=0x7fcdcad90930, added_options=0, 
    removed_options=0) at /git/mysql-server_dbg/sql/sql_select.cc:151
#16 0x0000000001506a7c in execute_sqlcom_select (thd=0x7fcdcac12000, all_tables=0x7fcdcad902e8)
    at /git/mysql-server_dbg/sql/sql_parse.cc:5158
#17 0x00000000015002fe in mysql_execute_command (thd=0x7fcdcac12000, first_level=true) at /git/mysql-server_dbg/sql/sql_parse.cc:2795
#18 0x0000000001507902 in mysql_parse (thd=0x7fcdcac12000, parser_state=0x7fce09238550)
    at /git/mysql-server_dbg/sql/sql_parse.cc:5574
#19 0x00000000014fd1d4 in dispatch_command (thd=0x7fcdcac12000, com_data=0x7fce09238cb0, command=COM_QUERY)
    at /git/mysql-server_dbg/sql/sql_parse.cc:1461
#20 0x00000000014fc0c6 in do_command (thd=0x7fcdcac12000) at /git/mysql-server_dbg/sql/sql_parse.cc:999
#21 0x000000000162c436 in handle_connection (arg=0x7fcdde397860)
    at /git/mysql-server_dbg/sql/conn_handler/connection_handler_per_thread.cc:300
#22 0x000000000186363b in pfs_spawn_thread (arg=0x7fcdef7e2120) at /git/mysql-server_dbg/storage/perfschema/pfs.cc:2188
#23 0x00007fce08c42dc5 in start_thread (arg=0x7fce09239700) at pthread_create.c:308
#24 0x00007fce0709d73d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

How to repeat:
The attached tarball (1503641168_bug_bundle.tar.gz) gives the testcase as an exact match of our system, including some handy utilities

$ vi 1503641168_mybase         # STEP1: Update the base path in this file (usually the only change required!). If you use a non-binary distribution, please update SOURCE_DIR location also
$ ./1503641168_init            # STEP2: Initializes the data dir
$ ./1503641168_start           # STEP3: Starts mysqld
$ ./1503641168_cl              # STEP4: To check mysqld is up
$ ./1503641168_run_pquery      # STEP5: Run the testcase with the pquery binary
$ ./1503641168_run             # OPTIONAL: Run the testcase with the mysql CLI (may not reproduce the issue, as the pquery binary was used for the original testcase reduction)
$ vi /dev/shm/1503641168/error.log.out  # STEP6: Verify the error log
$ ./1503641168_gdb             # OPTIONAL: Brings you to a gdb prompt with gdb attached to the used mysqld and attached to the generated core
$ ./1503641168_parse_core      # OPTIONAL: Creates 1503641168_STD.gdb and 1503641168_FULL.gdb; standard and full variables gdb stack traces

Suggested fix:
Seem related to pseudo_slave_mode
[29 Aug 2017 7:39] Roel Van de Paar
Tarball

Attachment: 1503641168_bug_bundle.tar.gz (application/gzip, text), 1.79 MiB.

[29 Aug 2017 7:51] MySQL Verification Team
Hello Roel,

Thank you for the report and test case.
Observed that 5.7.19 debug build is affected.

Thanks,
Umesh
[16 Nov 2017 9:59] Erlend Dahl
Duplicate of

Bug#80699 handle_fatal_signal (sig=6) in MYSQL_BIN_LOG::change_stage | sql/binlog.cc:8382
[16 Nov 2017 10:18] Roel Van de Paar
Bug 80699 has a completely different stack and a seemingly different testcase (though BINLOG command could be same). It is also a bug marked as security (whereas this one is not)? What version was this fixed in?
[17 Nov 2017 5:01] MySQL Verification Team
Bug#80699 was fixed in 5.7.20 and 8.0.3.
[17 Nov 2017 6:11] Roel Van de Paar
Umesh, thank you for confirming the fix version. My other comments remain unaddressed;

How was it established that both bugs are the same (with completely different stacks and potentially different testcases), and why is one marked security and not the other?
[17 Nov 2017 6:12] Roel Van de Paar
A bit more information would be appreciated
[29 Nov 2017 5:31] Roel Van de Paar
Erlend or Umesh, ping
[22 Dec 2017 8:53] Erlend Dahl
According to the responsible sustaining developer, the root cause for the two bugs is the same: setting pseudo_slave_mode inside a transaction. This is no longer possible starting from 5.7.20 and onwards.