MySQL Bugs: #85220: Assertion `(*thd)->get_transaction()->xid_state()-> has_state(XID_STATE::XA

Bug #85220	Assertion `(*thd)->get_transaction()->xid_state()-> has_state(XID_STATE::XA_...
Submitted:	28 Feb 2017 8:34	Modified:	4 May 2017 4:17
Reporter:	Roel Van de Paar	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S1 (Critical)
Version:	5.7.17	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
mysqld: /git/mysql-server_dbg/sql/rpl_gtid_persist.cc:180: bool Gtid_table_access_context::init(THD**, TABLE**, bool): Assertion `(*thd)->get_transaction()->xid_state()-> has_state(XID_STATE::XA_IDLE) || (*thd)->get_transaction()->xid_state()-> has_state(XID_STATE::XA_PREPARED)' failed.
07:09:32 UTC - mysqld got signal 6 ;

(gdb) bt
#0  0x00007f7f41b31741 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x0000000001826d71 in my_write_core (sig=6) at /git/mysql-server_dbg/mysys/stacktrace.c:249
#2  0x0000000000e75574 in handle_fatal_signal (sig=6) at /git/mysql-server_dbg/sql/signal_handler.cc:220
#3  <signal handler called>
#4  0x00007f7f3fec51d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007f7f3fec68c8 in __GI_abort () at abort.c:90
#6  0x00007f7f3febe146 in __assert_fail_base (fmt=0x7f7f4000f3a8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
    assertion=assertion@entry=0x201d350 "(*thd)->get_transaction()->xid_state()-> has_state(XID_STATE::XA_IDLE) || (*thd)->get_transaction()->xid_state()-> has_state(XID_STATE::XA_PREPARED)", file=file@entry=0x201d230 "/git/mysql-server_dbg/sql/rpl_gtid_persist.cc", line=line@entry=180,
    function=function@entry=0x201dc80 <Gtid_table_access_context::init(THD**, TABLE**, bool)::__PRETTY_FUNCTION__> "bool Gtid_table_access_context::init(THD**, TABLE**, bool)")
    at assert.c:92
#7  0x00007f7f3febe1f2 in __GI___assert_fail (
    assertion=0x201d350 "(*thd)->get_transaction()->xid_state()-> has_state(XID_STATE::XA_IDLE) || (*thd)->get_transaction()->xid_state()-> has_state(XID_STATE::XA_PREPARED)",
    file=0x201d230 "/git/mysql-server_dbg/sql/rpl_gtid_persist.cc", line=180,
    function=0x201dc80 <Gtid_table_access_context::init(THD**, TABLE**, bool)::__PRETTY_FUNCTION__> "bool Gtid_table_access_context::init(THD**, TABLE**, bool)") at assert.c:101
#8  0x000000000174e975 in Gtid_table_access_context::init (this=0x7f7f340652b0, thd=0x7f7f34065358, table=0x7f7f34065360, is_write=true)
    at /git/mysql-server_dbg/sql/rpl_gtid_persist.cc:177
#9  0x000000000174f6a0 in Gtid_table_persistor::save (this=0x3e7f2c0, gtid_set=0x7f7f34065410) at /git/mysql-server_dbg/sql/rpl_gtid_persist.cc:432
#10 0x0000000001749388 in Gtid_state::save (this=0x3eb6630, gtid_set=0x7f7f34065410) at /git/mysql-server_dbg/sql/rpl_gtid_state.cc:732
#11 0x000000000174952d in Gtid_state::save_gtids_of_last_binlog_into_table (this=0x3eb6630, on_rotation=true) at /git/mysql-server_dbg/sql/rpl_gtid_state.cc:771
#12 0x00000000017963ee in MYSQL_BIN_LOG::new_file_impl (this=0x2b5da40 <mysql_bin_log>, need_lock_log=false, extra_description_event=0x0)
    at /git/mysql-server_dbg/sql/binlog.cc:6634
#13 0x0000000001795e41 in MYSQL_BIN_LOG::new_file_without_locking (this=0x2b5da40 <mysql_bin_log>, extra_description_event=0x0) at /git/mysql-server_dbg/sql/binlog.cc:6519
#14 0x0000000001797a8b in MYSQL_BIN_LOG::rotate (this=0x2b5da40 <mysql_bin_log>, force_rotate=false, check_purge=0x7f7f340661af) at /git/mysql-server_dbg/sql/binlog.cc:7165
#15 0x000000000179c5ce in MYSQL_BIN_LOG::ordered_commit (this=0x2b5da40 <mysql_bin_log>, thd=0x7f7ecc0124c0, all=false, skip_commit=false)
    at /git/mysql-server_dbg/sql/binlog.cc:9180
#16 0x000000000179a5eb in MYSQL_BIN_LOG::commit (this=0x2b5da40 <mysql_bin_log>, thd=0x7f7ecc0124c0, all=false) at /git/mysql-server_dbg/sql/binlog.cc:8257
#17 0x0000000000eeef8f in ha_commit_trans (thd=0x7f7ecc0124c0, all=false, ignore_global_read_lock=false) at /git/mysql-server_dbg/sql/handler.cc:1796
#18 0x00000000015f35b9 in trans_commit_stmt (thd=0x7f7ecc0124c0) at /git/mysql-server_dbg/sql/transaction.cc:458
#19 0x00000000014f9f63 in mysql_execute_command (thd=0x7f7ecc0124c0, first_level=true) at /git/mysql-server_dbg/sql/sql_parse.cc:5043
#20 0x00000000014fb5f5 in mysql_parse (thd=0x7f7ecc0124c0, parser_state=0x7f7f34068590) at /git/mysql-server_dbg/sql/sql_parse.cc:5611
#21 0x00000000014f0c1d in dispatch_command (thd=0x7f7ecc0124c0, com_data=0x7f7f34068cf0, command=COM_QUERY) at /git/mysql-server_dbg/sql/sql_parse.cc:1461
#22 0x00000000014efa44 in do_command (thd=0x7f7ecc0124c0) at /git/mysql-server_dbg/sql/sql_parse.cc:999
#23 0x000000000161f9d0 in handle_connection (arg=0x49c6780) at /git/mysql-server_dbg/sql/conn_handler/connection_handler_per_thread.cc:300
#24 0x00000000018534f9 in pfs_spawn_thread (arg=0x49e5da0) at /git/mysql-server_dbg/storage/perfschema/pfs.cc:2188
#25 0x00007f7f41b2cdc5 in start_thread (arg=0x7f7f34069700) at pthread_create.c:308
#26 0x00007f7f3ff8773d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

How to repeat:
--source include/have_log_bin.inc
--source include/have_binlog_format_statement.inc
# --source include/have_gtid.inc
--source include/not_gtid_enabled.inc

SET SESSION binlog_direct_non_transactional_updates= ON;

SET GLOBAL gtid_mode= OFF_PERMISSIVE;
SET GLOBAL gtid_mode= ON_PERMISSIVE;

SET @saved_max_binlog_size= @@GLOBAL.max_binlog_size;
SET GLOBAL max_binlog_size= 4096;

SET binlog_direct_non_transactional_updates=ON;

CREATE TABLE t2 (a INT) ENGINE=MyISAM;

SHOW MASTER STATUS;

XA START '1';

INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);
INSERT INTO t2 VALUES (1);

XA END '1';
XA PREPARE '1';
XA COMMIT '1';

# If it does not crash, see if there has been no binlog rotation since the last
# SHOW MASTER STATUS, and add more INSERTs to cause it if needed
SHOW MASTER STATUS;

SET GLOBAL gtid_mode= ON_PERMISSIVE;
SET GLOBAL gtid_mode= OFF_PERMISSIVE;
SET GLOBAL gtid_mode= OFF;

SET GLOBAL max_binlog_size= @saved_max_binlog_size;

DROP TABLE t2;

Testcase & co-debugging credits to: Laurynas Biveinis

Update Severity to S2

Hello Roel,

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

Thanks,
Umesh

Posted by developer:
 
Hi,

I hit this assert too. The simple steps to hit this is as follows:-

mysql> set global max_binlog_size=4096;

mysql> CREATE TABLE t1 (c1 LONGBLOB) ENGINE=MyISAM;
Query OK, 0 rows affected (0.06 sec)

mysql> XA START 'xa1';
Query OK, 0 rows affected (0.00 sec)

mysql> insert into t1 values (repeat('a', 8000));
ERROR 2013 (HY000): Lost connection to MySQL server during query
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/tmp/mysqld1.sock' (111)
ERROR: 
Can't connect to the server

Looks like it happens when max_binlog_size is small and we try to insert data which exceeds max_binlog_size and makes binlog rotate, through XA transaction that cannot be rollbacked back.

If we try to insert data into InnoDB table, the transaction will rollback.

Thanks & Regards,
Narendra

Posted by developer:
 
Please investigate if related to BUG#25693396

See bug 86174