Bug #77521 InnoDB: Failing assertion: !trx_is_autocommit_non_locking(trx) in trx0trx.cc
Submitted: 28 Jun 2015 23:13 Modified: 8 Sep 2015 4:27
Reporter: Roel Van de Paar Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: DML Severity:S1 (Critical)
Version:5.7.7 RC, 5.7.8, 8.0.0 OS:Any
Assigned to: CPU Architecture:Any

[28 Jun 2015 23:13] Roel Van de Paar 
Description:
May be related to bug #77520

2015-06-28T23:06:27.652328Z 2 [Note] Changed GTID_MODE from OFF to OFF_PERMISSIVE.
2015-06-29 09:06:28 0x7f0b1b6b0700  InnoDB: Assertion failure in thread 139685681366784 in file trx0trx.cc line 1290
InnoDB: Failing assertion: !trx_is_autocommit_non_locking(trx)

+bt
#0  0x00007f0b1b0b7771 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x0000000000737304 in handle_fatal_signal (sig=6) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/sql/signal_handler.cc:220
#2  <signal handler called>
#3  0x00007f0b19cbb5c9 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#4  0x00007f0b19cbccd8 in __GI_abort () at abort.c:90
#5  0x0000000001016cbe in ut_dbg_assertion_failed (expr=0x14f7540 "!trx_is_autocommit_non_locking(trx)", file=<optimized out>, line=1290) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/storage/innobase/ut/ut0dbg.cc:67
#6  0x000000000100a648 in trx_assign_rseg (trx=0x7f0b0d400738) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/storage/innobase/trx/trx0trx.cc:1290
#7  0x0000000000f91b1a in row_insert_for_mysql_using_ins_graph (mysql_rec=<optimized out>, prebuilt=0x7f0b10fe4080) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/storage/innobase/row/row0mysql.cc:1665
#8  0x0000000000ed9920 in ha_innobase::write_row (this=0x7f0b12fa3820, record=0x7f0b12fa3b00 "\377\061\061\061\061\061\061\061\061-aaaa-2222-bbbb-", '0' <repeats 12 times>, "\001") at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/storage/innobase/handler/ha_innodb.cc:6807
#9  0x000000000077ac7f in handler::ha_write_row (this=0x7f0b12fa3820, buf=0x7f0b12fa3b00 "\377\061\061\061\061\061\061\061\061-aaaa-2222-bbbb-", '0' <repeats 12 times>, "\001") at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/sql/handler.cc:7518
#10 0x0000000000e119cd in Gtid_table_persistor::write_row (this=0x7f0b14fff070, table=0x7f0b193e1410, sid=0x7f0b1b6ae390 "11111111-aaaa-2222-bbbb-", '0' <repeats 12 times>, gno_start=1, gno_end=<optimized out>) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/sql/rpl_gtid_persist.cc:193
#11 0x0000000000e127e0 in Gtid_table_persistor::save (this=0x7f0b14fff070, thd=0x7f0a81818000, gtid=0x7f0a81819ee0) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/sql/rpl_gtid_persist.cc:312
#12 0x0000000000e0e9d2 in Gtid_state::save (this=<optimized out>, thd=0xd91) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/sql/rpl_gtid_state.cc:737
#13 0x000000000077d6aa in ha_commit_trans (thd=0x7f0a81818000, all=<optimized out>, ignore_global_read_lock=<optimized out>) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/sql/handler.cc:1553
#14 0x0000000000d3514e in trans_commit_stmt (thd=0xd30) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/sql/transaction.cc:395
#15 0x0000000000c86c2c in mysql_execute_command (thd=0x7f0a81818000) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/sql/sql_parse.cc:4591
#16 0x0000000000c89010 in mysql_parse (thd=0x7f0a81818000, parser_state=<optimized out>) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/sql/sql_parse.cc:5159
#17 0x0000000000c8a5d8 in dispatch_command (command=COM_QUERY, thd=0x7f0a81818000, packet=<optimized out>, packet_length=<optimized out>) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/sql/sql_parse.cc:1249
#18 0x0000000000d4fa14 in handle_connection (arg=<optimized out>) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/sql/conn_handler/connection_handler_per_thread.cc:298
#19 0x000000000113cbda in pfs_spawn_thread (arg=<optimized out>) at /export/home/pb2/build/sb_0-14853600-1427719770.96/mysql-5.7.7-rc/storage/perfschema/pfs.cc:2147
#20 0x00007f0b1b0b2df3 in start_thread (arg=0x7f0b1b6b0700) at pthread_create.c:308
#21 0x00007f0b19d7c1ad in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

How to repeat:
DROP DATABASE test;CREATE DATABASE test;USE test;
SET GLOBAL GTID_MODE=OFF_PERMISSIVE;
CREATE TABLE t1(c1 TEXT);
CREATE TABLE t2(c1 BINARY (1));
SET SESSION GTID_NEXT='11111111-AAAA-2222-BBBB-000000000000:1';
CREATE TABLE t1(a INT KEY,b CHAR (1),c TEXT);
select count(*)from t2;
[29 Jun 2015 5:37] MySQL Verification Team 
Hello Roel,

Thank you for the report and test case.
Observed that 5.7.8/5.8.0 release builds are affected.

Thanks,
Umesh
[29 Jun 2015 5:37] MySQL Verification Team 
// 5.7.8 (release build affected)

rm -rf bug
bin/mysql_install_db --insecure --basedir=/export/umesh/server/binaries/mysql-5.7.8 --datadir=/export/umesh/server/binaries/mysql-5.7.8/bug -v
bin/mysqld --basedir=/export/umesh/server/binaries/mysql-5.7.8 --datadir=/export/umesh/server/binaries/mysql-5.7.8/bug --sql_mode=ONLY_FULL_GROUP_BY --core-file --socket=/tmp/mysql_ushastry.sock  --port=15000 --log-error=/export/umesh/server/binaries/mysql-5.7.8/bug/log.err 2>&1 &

commit: 5646b91dc9980ceb88b41913304b8530a24538ab
date: 2015-06-26 15:14:51 +0200
build-date: 2015-06-26 18:02:46 +0200
short: 5646b91
branch: mysql-5.7

MySQL source 5.7.8

(gdb) bt
#0  0x00007f8b80f1c771 in pthread_kill () from /lib64/libpthread.so.0
#1  0x00000000007850b5 in handle_fatal_signal (sig=6) at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/signal_handler.cc:220
#2  <signal handler called>
#3  0x00007f8b7fb225c9 in raise () from /lib64/libc.so.6
#4  0x00007f8b7fb23cd8 in abort () from /lib64/libc.so.6
#5  0x0000000000757526 in ut_dbg_assertion_failed (expr=expr@entry=0x15a7868 "!trx_is_autocommit_non_locking(trx)",
    file=file@entry=0x15a7528 "/export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/storage/innobase/trx/trx0trx.cc", line=line@entry=1302)
    at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/storage/innobase/ut/ut0dbg.cc:67
#6  0x000000000105b887 in trx_assign_rseg (trx=0x7f8b76a99740) at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/storage/innobase/trx/trx0trx.cc:1302
#7  0x0000000000fca5c7 in row_insert_for_mysql_using_ins_graph (mysql_rec=mysql_rec@entry=0x7f8b10024af0 "\377\061\061\061\061\061\061\061\061-aaaa-2222-bbbb-", '0' <repeats 12 times>, "\001",
    prebuilt=prebuilt@entry=0x7f8b10025088) at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/storage/innobase/row/row0mysql.cc:1660
#8  0x0000000000fcd4c4 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x7f8b10024af0 "\377\061\061\061\061\061\061\061\061-aaaa-2222-bbbb-", '0' <repeats 12 times>, "\001",
    prebuilt=prebuilt@entry=0x7f8b10025088) at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/storage/innobase/row/row0mysql.cc:1795
#9  0x0000000000ef8a02 in ha_innobase::write_row (this=0x7f8b10024810, record=0x7f8b10024af0 "\377\061\061\061\061\061\061\061\061-aaaa-2222-bbbb-", '0' <repeats 12 times>, "\001")
    at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/storage/innobase/handler/ha_innodb.cc:6737
#10 0x00000000007cf64f in handler::ha_write_row (this=0x7f8b10024810, buf=0x7f8b10024af0 "\377\061\061\061\061\061\061\061\061-aaaa-2222-bbbb-", '0' <repeats 12 times>, "\001")
    at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/handler.cc:7519
#11 0x0000000000d72572 in Gtid_table_persistor::write_row (this=this@entry=0x30eeed0, table=0x7f8b10023e90, sid=sid@entry=0x7f8b53caa460 "11111111-aaaa-2222-bbbb-", '0' <repeats 12 times>,
    gno_start=1, gno_end=1) at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/rpl_gtid_persist.cc:193
#12 0x0000000000d7294a in Gtid_table_persistor::save (this=0x30eeed0, thd=thd@entry=0x7f8b10000b50, gtid=gtid@entry=0x7f8b10002ab8)
    at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/rpl_gtid_persist.cc:321
#13 0x0000000000d706f2 in Gtid_state::save (this=<optimized out>, thd=thd@entry=0x7f8b10000b50)
    at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/rpl_gtid_state.cc:748
#14 0x00000000007c8abd in ha_commit_trans (thd=thd@entry=0x7f8b10000b50, all=all@entry=false, ignore_global_read_lock=ignore_global_read_lock@entry=false)
    at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/handler.cc:1504
#15 0x0000000000c95350 in trans_commit_stmt (thd=thd@entry=0x7f8b10000b50) at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/transaction.cc:390
#16 0x0000000000bf722f in mysql_execute_command (thd=thd@entry=0x7f8b10000b50) at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/sql_parse.cc:4691
#17 0x0000000000bfa0e8 in mysql_parse (thd=thd@entry=0x7f8b10000b50, parser_state=parser_state@entry=0x7f8b53cab690)
    at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/sql_parse.cc:5253
#18 0x0000000000bfb5cf in dispatch_command (thd=thd@entry=0x7f8b10000b50, com_data=com_data@entry=0x7f8b53cabe00, command=COM_QUERY)
    at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/sql_parse.cc:1272
#19 0x0000000000bfc9af in do_command (thd=thd@entry=0x7f8b10000b50) at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/sql_parse.cc:852
#20 0x0000000000caf7a0 in handle_connection (arg=arg@entry=0x3a01b70)
    at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/sql/conn_handler/connection_handler_per_thread.cc:299
#21 0x0000000000e6deb3 in pfs_spawn_thread (arg=0x39028f0) at /export/home2/pb2/build/sb_0-15709687-1435335615.05/mysqlcom-pro-5.7.8-rc/storage/perfschema/pfs.cc:2178
#22 0x00007f8b80f17df3 in start_thread () from /lib64/libpthread.so.0
#23 0x00007f8b7fbe347d in clone () from /lib64/libc.so.6
(gdb)
[29 Jun 2015 5:37] MySQL Verification Team 
// 5.8.0

rm -rf bug
bin/mysql_install_db  --insecure --basedir=/export/umesh/server/binaries/mysql-5.8.0 --datadir=/export/umesh/server/binaries/mysql-5.8.0/bug -v
bin/mysqld --basedir=/export/umesh/server/binaries/mysql-5.8.0 --datadir=/export/umesh/server/binaries/mysql-5.8.0/bug --core-file --socket=/tmp/mysql_ushastry.sock  --port=15000 --log-error=/export/umesh/server/binaries/mysql-5.8.0/bug/log.err 2>&1 &

commit: c978540d4fa15613311479b8baf9766e01eb754c
date: 2015-06-26 15:18:34 +0200
build-date: 2015-06-26 17:02:29 +0200
short: c978540
branch: mysql-trunk

MySQL source 5.8.0

(gdb) bt
#0  0x00007f9f860db771 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000775fa5 in handle_fatal_signal (sig=6) at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/signal_handler.cc:221
#2  <signal handler called>
#3  0x00007f9f84ce15c9 in raise () from /lib64/libc.so.6
#4  0x00007f9f84ce2cd8 in abort () from /lib64/libc.so.6
#5  0x0000000000748fcb in ut_dbg_assertion_failed (expr=expr@entry=0x157a9e0 "!trx_is_autocommit_non_locking(trx)",
    file=file@entry=0x157a6a0 "/export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/storage/innobase/trx/trx0trx.cc", line=line@entry=1328)
    at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/storage/innobase/ut/ut0dbg.cc:67
#6  0x0000000000f8a087 in trx_assign_rseg (trx=0x7f9f77bff740) at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/storage/innobase/trx/trx0trx.cc:1328
#7  0x0000000000efd4dd in row_insert_for_mysql_using_ins_graph (mysql_rec=mysql_rec@entry=0x7f9f0c926dd0 "\377\061\061\061\061\061\061\061\061-aaaa-2222-bbbb-", '0' <repeats 12 times>, "\001",
    prebuilt=prebuilt@entry=0x7f9f0c927368) at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/storage/innobase/row/row0mysql.cc:1667
#8  0x0000000000f00214 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x7f9f0c926dd0 "\377\061\061\061\061\061\061\061\061-aaaa-2222-bbbb-", '0' <repeats 12 times>, "\001",
    prebuilt=prebuilt@entry=0x7f9f0c927368) at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/storage/innobase/row/row0mysql.cc:1802
#9  0x0000000000e2bf4a in ha_innobase::write_row (this=0x7f9f0c926af0, record=0x7f9f0c926dd0 "\377\061\061\061\061\061\061\061\061-aaaa-2222-bbbb-", '0' <repeats 12 times>, "\001")
    at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/storage/innobase/handler/ha_innodb.cc:6835
#10 0x00000000007c156f in handler::ha_write_row (this=0x7f9f0c926af0, buf=0x7f9f0c926dd0 "\377\061\061\061\061\061\061\061\061-aaaa-2222-bbbb-", '0' <repeats 12 times>, "\001")
    at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/handler.cc:7456
#11 0x0000000000d5cb62 in Gtid_table_persistor::write_row (this=this@entry=0x2b8b910, table=0x7f9f0c926170, sid=sid@entry=0x7f9f58e824d0 "11111111-aaaa-2222-bbbb-", '0' <repeats 12 times>,
    gno_start=1, gno_end=1) at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/rpl_gtid_persist.cc:195
#12 0x0000000000d5cf3a in Gtid_table_persistor::save (this=0x2b8b910, thd=thd@entry=0x7f9f0c000b50, gtid=gtid@entry=0x7f9f0c002ab0)
    at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/rpl_gtid_persist.cc:323
#13 0x0000000000d5ad02 in Gtid_state::save (this=<optimized out>, thd=thd@entry=0x7f9f0c000b50)
    at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/rpl_gtid_state.cc:749
#14 0x00000000007baa8d in ha_commit_trans (thd=thd@entry=0x7f9f0c000b50, all=all@entry=false, ignore_global_read_lock=ignore_global_read_lock@entry=false)
    at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/handler.cc:1441
#15 0x0000000000c7f470 in trans_commit_stmt (thd=thd@entry=0x7f9f0c000b50) at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/transaction.cc:392
#16 0x0000000000be148d in mysql_execute_command (thd=thd@entry=0x7f9f0c000b50) at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/sql_parse.cc:4623
#17 0x0000000000be4078 in mysql_parse (thd=thd@entry=0x7f9f0c000b50, parser_state=parser_state@entry=0x7f9f58e837c0)
    at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/sql_parse.cc:5183
#18 0x0000000000be5098 in dispatch_command (thd=thd@entry=0x7f9f0c000b50, com_data=com_data@entry=0x7f9f58e83e00, command=COM_QUERY)
    at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/sql_parse.cc:1237
#19 0x0000000000be60df in do_command (thd=thd@entry=0x7f9f0c000b50) at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/sql_parse.cc:815
#20 0x0000000000c99630 in handle_connection (arg=arg@entry=0x34a1e60)
    at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/sql/conn_handler/connection_handler_per_thread.cc:300
#21 0x00000000010e45a3 in pfs_spawn_thread (arg=0x3368850) at /export/home2/pb2/build/sb_0-15709159-1435331588.95/mysqlcom-pro-5.8.0-m17/storage/perfschema/pfs.cc:2200
#22 0x00007f9f860d6df3 in start_thread () from /lib64/libpthread.so.0
#23 0x00007f9f84da247d in clone () from /lib64/libc.so.6
(gdb)
[7 Sep 2015 16:15] Jon Stephens 
Documented fix as follows in the 5.7.9 and 5.8.0 changelogs:

    When a transaction consisting of a single statement with a
    specified GTID failed in autocommit mode, its GTID was not
    released when rolling it back when binary logging was disabled.
      

Closed.
[18 Jun 2016 21:26] Omer Barnir 
Posted by developer:
 
Reported version value updated to reflect release name change from 5.8 to 8.0