Bug #76844 handle_fatal_signal (sig=6) in trx_commit_low | trx/trx0trx.cc:1365
Submitted: 27 Apr 2015 5:50 Modified: 27 Apr 2015 6:52
Reporter: Ramesh Sivaraman Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: DML Severity:S3 (Non-critical)
Version:5.6.23, 5.6.25 OS:Linux (CentOS 7)
Assigned to: CPU Architecture:Any
Tags: debug

[27 Apr 2015 5:50] Ramesh Sivaraman
Description:
2015-04-27 01:47:55 7f27e3fb9700  InnoDB: Assertion failure in thread 139809305368320 in file trx0trx.cc line 1365
InnoDB: We intentionally generate a memory trap.

GDB info

#0  0x00007f9586a0e771 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x0000000000a980a6 in my_write_core (sig=6) at /sda/mysql-server-5.6/mysys/stacktrace.c:422
#2  0x00000000007277f0 in handle_fatal_signal (sig=6) at /sda/mysql-server-5.6/sql/signal_handler.cc:230
#3  <signal handler called>
#4  0x00007f958581a5d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007f958581bcc8 in __GI_abort () at abort.c:90
#6  0x0000000000cf4dd7 in trx_commit_low (trx=0x7f95688c7478, mtr=0x7f9586fc4270) at /sda/mysql-server-5.6/storage/innobase/trx/trx0trx.cc:1365
#7  0x0000000000cf4e9a in trx_commit (trx=0x7f95688c7478) at /sda/mysql-server-5.6/storage/innobase/trx/trx0trx.cc:1417
#8  0x0000000000cf56aa in trx_commit_for_mysql (trx=0x7f95688c7478) at /sda/mysql-server-5.6/storage/innobase/trx/trx0trx.cc:1635
#9  0x0000000000b78b9a in innobase_commit_low (trx=0x7f95688c7478) at /sda/mysql-server-5.6/storage/innobase/handler/ha_innodb.cc:3412
#10 0x0000000000b78f0c in innobase_commit (hton=0x7f95807f9c80, thd=0x7f95763ee000, commit_trx=false) at /sda/mysql-server-5.6/storage/innobase/handler/ha_innodb.cc:3560
#11 0x0000000000639141 in ha_commit_low (thd=0x7f95763ee000, all=false, run_after_commit=true) at /sda/mysql-server-5.6/sql/handler.cc:1493
#12 0x0000000000711cba in TC_LOG_DUMMY::commit (this=0x17f2768 <tc_log_dummy>, thd=0x7f95763ee000, all=false) at /sda/mysql-server-5.6/sql/log.h:115
#13 0x0000000000638f85 in ha_commit_trans (thd=0x7f95763ee000, all=false, ignore_global_read_lock=false) at /sda/mysql-server-5.6/sql/handler.cc:1436
#14 0x000000000089fcb0 in trans_commit_stmt (thd=0x7f95763ee000) at /sda/mysql-server-5.6/sql/transaction.cc:434
#15 0x00000000007da2ae in mysql_execute_command (thd=0x7f95763ee000) at /sda/mysql-server-5.6/sql/sql_parse.cc:5006
#16 0x00000000007dd54a in mysql_parse (thd=0x7f95763ee000, rawbuf=0x7f956881f010 "UPDATE t1 SET a=1000", length=20, parser_state=0x7f9586fc5e70) at /sda/mysql-server-5.6/sql/sql_parse.cc:6357
#17 0x00000000007d06bc in dispatch_command (command=COM_QUERY, thd=0x7f95763ee000, packet=0x7f956f7e1001 "UPDATE t1 SET a=1000", packet_length=20) at /sda/mysql-server-5.6/sql/sql_parse.cc:1332
#18 0x00000000007cf7ab in do_command (thd=0x7f95763ee000) at /sda/mysql-server-5.6/sql/sql_parse.cc:1034
#19 0x0000000000797b3d in do_handle_one_connection (thd_arg=0x7f95763ee000) at /sda/mysql-server-5.6/sql/sql_connect.cc:982
#20 0x0000000000797626 in handle_one_connection (arg=0x7f95763ee000) at /sda/mysql-server-5.6/sql/sql_connect.cc:898
#21 0x0000000000b5d7f0 in pfs_spawn_thread (arg=0x7f95813fe600) at /sda/mysql-server-5.6/storage/perfschema/pfs.cc:1860
#22 0x00007f9586a09df5 in start_thread (arg=0x7f9586fc7700) at pthread_create.c:308
#23 0x00007f95858db1ad in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

How to repeat:
Testcase

DROP DATABASE test;CREATE DATABASE test;USE test;
CREATE TABLE t1(a int,b int,c int,primary key(a,b)) partition by list (a) partitions 3 (partition x1 values in (1,2,9,4) tablespace ts1,partition x2 values in (3,11,5,7) tablespace ts2,partition x3 values in (16,8,5+19,70-43) tablespace ts3);
ALTER TABLE t1 CHANGE COLUMN b b2 INT;
DROP TABLE t1;
create TABLE t1(utf8mb4 char(1)character set utf8mb4);
EXPLAIN SELECT * FROM t1;
drop TABLE t1;
CREATE TABLE t1(c1 INT);
REPLACE t1 SET c1=0;
INSERT INTO t1 VALUES(1);
INSERT INTO t1 VALUES(1);
DELETE FROM t1;
insert INTO t1 values(STR_TO_DATE('31.10.2004 15.30 abc','%d.%m.%Y %H.%i'));
SELECT * FROM t1;
DROP TABLE t1;
CREATE TABLE t1(c1 DECIMAL,c2 CHAR(1),c3 INT(1),c4 CHAR(1) KEY,c5 DECIMAL UNIQUE KEY,c6 NUMERIC(10,8) DEFAULT 3.141592);
INSERT INTO t1 VALUES();
DROP TABLE t1;
CREATE TABLE t1(a CHAR (1),FULLTEXT(a)) ENGINE=InnoDB;
INSERT INTO t1 VALUES("REVOKE ALL PRIVILEGES on function to user with table locked");
INSERT INTO t1 VALUES();
delete FROM t1;
set global innodb_trx_rseg_n_slots_debug=1;
INSERT INTO t1 VALUES(1);
INSERT INTO t1 SELECT * FROM t1;
ALTER TABLE t1 ADD c2 INT;
INSERT INTO t1 VALUES();
INSERT INTO t1 VALUES();
INSERT INTO t1 VALUES(1);
INSERT INTO t1 VALUES(1),(1),(1);
INSERT INTO t1 VALUES();
CREATE TABLE t5(a int,b00 int,b01 int,b02 int,b03 int,b04 int,b05 int,b06 int,b07 int,b08 int,b90 int,b10 int,b11 int,b12 int,b13 int,b14 int,b15 int,b16 int,b17 int,b18 int,b19 int,b20 int,b21 int,b22 int,b23 int,b24 int,b25 int,b26 int,b27 int,b28 int,b29 int,b30 int,b31 int,b32 int)ENGINE=INNODB;
INSERT INTO t1 VALUES();
INSERT INTO t1 VALUES();
CREATE TABLE t6(a BINARY(1));
INSERT INTO t1 VALUES('aaa15');
INSERT INTO t1 VALUES();
UPDATE t1 SET a=1000;

 The attached tarball gives the testcase as an exact match of our
system,
  including some handy utilities

  $ vi {epoch}_mybase # Update base path in this file (the only change
  required!). For non-binary (i.e.
non-tarball/non-build-binary-distribution) distributions please update
SOURCE_DIR location also.
  $ ./{epoch}_init # Initializes the data dir
  $ ./{epoch}_start # Starts mysqld
  $ ./{epoch}_cl # To check mysqld is up
  $ ./{epoch}_run # Run the testcase with pquery binary(produces
  output)
  $ vi /dev/shm/{epoch}/error.log.out # Verify the error log
  $ ./{epoch}_gdb # Brings you to a gdb prompt attached to correct
  mysqld
  & generated core
  $ ./{epoch}_parse_core # Create {epoch}_STD.gdb and
{epoch}_FULL.gdb;
  standard and full var gdb stack traces
  etc.
[27 Apr 2015 5:51] Ramesh Sivaraman
Testcase bundle

Attachment: 1430110811_bug_bundle.tar.gz (application/gzip, text), 998.73 KiB.

[27 Apr 2015 6:52] MySQL Verification Team
Hello Ramesh Sivaraman ,

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

Thanks,
Umesh
[27 Apr 2015 6:53] MySQL Verification Team
// start up
scripts/mysql_install_db --basedir=/export/umesh/server/binaries/mysql-5.6.25 --datadir=/export/umesh/server/binaries/mysql-5.6.25/76844
bin/mysqld-debug  --no-defaults --basedir=/export/umesh/server/binaries/mysql-5.6.25 --datadir=/export/umesh/server/binaries/mysql-5.6.25/76844 --core-file --socket=/tmp/mysql_ushastry.sock  --port=15000 --log-error=/export/umesh/server/binaries/mysql-5.6.25/76844/log.err --innodb_file_per_table=1 --innodb_flush_method=O_DIRECT --log-bin=binlog --binlog_format=MIXED --event-scheduler=ON --maximum-bulk_insert_buffer_size=1M --maximum-join_buffer_size=1M --maximum-max_heap_table_size=1M --maximum-max_join_size=1M --maximum-myisam_max_sort_file_size=1M --maximum-myisam_mmap_size=1M --maximum-myisam_sort_buffer_size=1M --maximum-optimizer_trace_max_mem_size=1M --maximum-preload_buffer_size=1M --maximum-query_alloc_block_size=1M --maximum-query_prealloc_size=1M --maximum-range_alloc_block_size=1M --maximum-read_buffer_size=1M --maximum-read_rnd_buffer_size=1M --maximum-sort_buffer_size=1M --maximum-tmp_table_size=1M --maximum-transaction_alloc_block_size=1M --maximum-transaction_prealloc_size=1M --log-output=none --sql_mode=ONLY_FULL_GROUP_BY 2>&1 &

Build used:

date: 2015-04-24 13:39:44 +0200
build-date: 2015-04-24 14:11:29 +0200
short: 3776da9
branch: mysql-5.6

MySQL source 5.6.25

// extract from error log

Version: '5.6.25-enterprise-commercial-advanced-debug-log'  socket: '/tmp/mysql_ushastry.sock'  port: 15000  MySQL Enterprise Server - Advanced Edition Debug (Commercial)
2015-04-27 08:44:35 10010 [Note] Event Scheduler: scheduler thread started with id 1
2015-04-27 08:44:53 7fbcfc1e9700  InnoDB: Warning: cannot find a free slot for an undo log. Do you have too
InnoDB: many active transactions running concurrently?
2015-04-27 08:44:53 7fbcea1fc700 InnoDB: FTS Optimize Removing table test/#sql-271a_2
2015-04-27 08:44:54 7fbcfc1e9700  InnoDB: Warning: cannot find a free slot for an undo log. Do you have too
InnoDB: many active transactions running concurrently?
2015-04-27 08:44:54 7fbcfc1e9700  InnoDB: Assertion failure in thread 140449660442368 in file trx0trx.cc line 1364

(gdb) bt
#0  0x00007fbd26972771 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000ae1813 in my_write_core (sig=6) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/mysys/stacktrace.c:422
#2  0x00000000007460b6 in handle_fatal_signal (sig=6) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/signal_handler.cc:230
#3  <signal handler called>
#4  0x00007fbd255785c9 in raise () from /lib64/libc.so.6
#5  0x00007fbd25579cd8 in abort () from /lib64/libc.so.6
#6  0x0000000000d11cdd in trx_commit_low (trx=0x7fbcd0031248, mtr=0x7fbcfc1e52c0) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/storage/innobase/trx/trx0trx.cc:1364
#7  0x0000000000d11d88 in trx_commit (trx=0x7fbcd0031248) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/storage/innobase/trx/trx0trx.cc:1416
#8  0x0000000000d11e4f in trx_commit_for_mysql (trx=0x7fbcd0031248) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/storage/innobase/trx/trx0trx.cc:1634
#9  0x0000000000ba26fc in innobase_commit_low (trx=0x7fbcd0031248) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/storage/innobase/handler/ha_innodb.cc:3400
#10 0x0000000000bacfd7 in innobase_commit (hton=0x2465a00, thd=0x2b84960, commit_trx=false)
    at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/storage/innobase/handler/ha_innodb.cc:3548
#11 0x00000000006548cb in ha_commit_low (thd=0x2b84960, all=false, run_after_commit=false) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/handler.cc:1493
#12 0x0000000000a67853 in MYSQL_BIN_LOG::process_commit_stage_queue (this=0x1937740 <mysql_bin_log>, thd=0x2b84960, first=0x2b84960)
    at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/binlog.cc:6650
#13 0x0000000000a72ab2 in MYSQL_BIN_LOG::ordered_commit (this=0x1937740 <mysql_bin_log>, thd=0x2b84960, all=false, skip_commit=false)
    at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/binlog.cc:7057
#14 0x0000000000a75cb4 in MYSQL_BIN_LOG::commit (this=0x1937740 <mysql_bin_log>, thd=0x2b84960, all=false)
    at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/binlog.cc:6476
#15 0x0000000000654f16 in ha_commit_trans (thd=0x2b84960, all=false, ignore_global_read_lock=false) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/handler.cc:1436
#16 0x00000000008c956e in trans_commit_stmt (thd=0x2b84960) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/transaction.cc:434
#17 0x0000000000801dfc in mysql_execute_command (thd=0x2b84960) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/sql_parse.cc:5037
#18 0x000000000080250a in mysql_parse (thd=0x2b84960, rawbuf=0x7fbcd0004fd0 "UPDATE t1 SET a=1000", length=20, parser_state=0x7fbcfc1e8700)
    at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/sql_parse.cc:6386
#19 0x000000000080412e in dispatch_command (command=COM_QUERY, thd=0x2b84960, packet=0x2c69b01 "UPDATE t1 SET a=1000", packet_length=20)
    at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/sql_parse.cc:1340
#20 0x00000000008059ba in do_command (thd=0x2b84960) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/sql_parse.cc:1037
#21 0x00000000007bb3ed in do_handle_one_connection (thd_arg=0x2b84960) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/sql_connect.cc:982
#22 0x00000000007bb4b3 in handle_one_connection (arg=0x2b84960) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/sql/sql_connect.cc:898
#23 0x0000000000b932f4 in pfs_spawn_thread (arg=0x2bda420) at /export/home/pb2/build/sb_0-15116597-1429882237.93/mysqlcom-pro-5.6.25/storage/perfschema/pfs.cc:1860
#24 0x00007fbd2696ddf3 in start_thread () from /lib64/libpthread.so.0
#25 0x00007fbd2563947d in clone () from /lib64/libc.so.6
(gdb)