Segfaults during table altering

[Alex Kazeko]

Hello,

Mysql (5.6.21-70.0-log) crashed during altering table (adding a column to InnoDB table). At that point of time mysql had a few thousands CPM. Server has 32Gb RAM. According to other monitoring graphs: CPU, free RAM, LA and Disk IO were fine. Disk IO (ssd) jumped up to 50%.

Is there anything else I can provide to help debugging this issue?

--------------

12:23:48 UTC - mysqld got signal 11 ;
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.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

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

Thread pointer: 0x7f21416ea000
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 = 7f21d833bd00 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0x8be13c]
/usr/sbin/mysqld(handle_fatal_signal+0x461)[0x6512a1]
/lib64/libpthread.so.0[0x3de880f710]
/usr/sbin/mysqld(_ZN7handler5cloneEPKcP11st_mem_root+0x1f)[0x5988bf]
/usr/sbin/mysqld[0x8cd641]
/usr/sbin/mysqld[0x7084ed]
/usr/sbin/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x2d2)[0x710722]
/usr/sbin/mysqld(_ZN4JOIN14prepare_resultEPP4ListI4ItemE+0xa5)[0x6f1cc5]
/usr/sbin/mysqld(_ZN4JOIN4execEv+0xac)[0x6adc1c]
/usr/sbin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_P10SQL_I_ListI8st_orderESB_S7_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x275)[0x6f6465]
/usr/sbin/mysqld(_Z13handle_selectP3THDP13select_resultm+0x165)[0x6f6cc5]
/usr/sbin/mysqld[0x55af40]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x378f)[0x6d28ef]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x5c8)[0x6d61c8]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xfb7)[0x6d78e7]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x162)[0x6a5822]
/usr/sbin/mysqld(handle_one_connection+0x40)[0x6a5910]
/usr/sbin/mysqld(pfs_spawn_thread+0x143)[0xac8973]
/lib64/libpthread.so.0[0x3de88079d1]
/lib64/libc.so.6(clone+0x6d)[0x3de84e89dd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f21a6a84010): is an invalid pointer
Connection ID (thread ID): 416475209
Status: NOT_KILLED

You may download the Percona Server operations manual by visiting
http://www.percona.com/software/percona-server/. You may find information
in the manual which will help you identify the cause of the crash.
150128 06:23:49 mysqld_safe Number of processes running now: 0
150128 06:23:49 mysqld_safe mysqld restarted

.
.
.
.

InnoDB: Doing recovery: scanned up to log sequence number 2519791100928
InnoDB: Doing recovery: scanned up to log sequence number 2519794668882
InnoDB: Transaction 65621207762 was in the XA prepared state.
InnoDB: 10 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 9 row operations to undo
InnoDB: Trx id counter is 65621208064
2015-01-28 06:25:57 32213 [Note] InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Last MySQL binlog file position 0 1578134, file name mysql-bin.113389
2015-01-28 06:27:28 32213 [Note] InnoDB: 128 rollback segment(s) are active.
InnoDB: Starting in background the rollback of uncommitted transactions
2015-01-28 06:27:28 7fd0643ff700 InnoDB: Rolling back trx with id 65621207701, 1 rows to undo
2015-01-28 06:27:28 32213 [Note] InnoDB: Waiting for purge to start
2015-01-28 06:27:28 32213 [Note] InnoDB: Rollback of trx with id 65621207701 completed
2015-01-28 06:27:28 7fd0643ff700 InnoDB: Rolling back trx with id 65621207638, 1 rows to undo
2015-01-28 06:27:28 32213 [Note] InnoDB: Rollback of trx with id 65621207638 completed
2015-01-28 06:27:28 7fd0643ff700 InnoDB: Rolling back trx with id 65621207595, 1 rows to undo
2015-01-28 06:27:28 32213 [Note] InnoDB: Rollback of trx with id 65621207595 completed
2015-01-28 06:27:28 7fd0643ff700 InnoDB: Rolling back trx with id 65621207578, 1 rows to undo
2015-01-28 06:27:28 32213 [Note] InnoDB: Rollback of trx with id 65621207578 completed
2015-01-28 06:27:28 7fd0643ff700 InnoDB: Rolling back trx with id 65621207525, 1 rows to undo
2015-01-28 06:27:28 32213 [Note] InnoDB: Rollback of trx with id 65621207525 completed
2015-01-28 06:27:28 7fd0643ff700 InnoDB: Rolling back trx with id 65621207458, 1 rows to undo
2015-01-28 06:27:28 32213 [Note] InnoDB: Rollback of trx with id 65621207458 completed
2015-01-28 06:27:28 7fd0643ff700 InnoDB: Rolling back trx with id 65621207114, 1 rows to undo
2015-01-28 06:27:28 32213 [Note] InnoDB: Rollback of trx with id 65621207114 completed
2015-01-28 06:27:28 7fd0643ff700 InnoDB: Rolling back trx with id 65621206595, 1 rows to undo
2015-01-28 06:27:28 32213 [Note] InnoDB: Rollback of trx with id 65621206595 completed
2015-01-28 06:27:28 7fd0643ff700 InnoDB: Rolling back trx with id 65621205557, 1 rows to undo
2015-01-28 06:27:28 32213 [Note] InnoDB: Rollback of trx with id 65621205557 completed
2015-01-28 06:27:28 7fd0643ff700 InnoDB: Rollback of non-prepared transactions completed
2015-01-28 06:27:28 32213 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.21-70.0 started; log sequence number 2519794668882
2015-01-28 06:27:28 32213 [Note] Recovering after a crash using mysql-bin
2015-01-28 06:27:28 32213 [Note] Starting crash recovery...
2015-01-28 06:27:28 7fd6dcc9a820 InnoDB: Starting recovery for XA transactions...
2015-01-28 06:27:28 7fd6dcc9a820 InnoDB: Transaction 65621207762 in prepared state after recovery
2015-01-28 06:27:28 7fd6dcc9a820 InnoDB: Transaction contains changes to 1 rows
2015-01-28 06:27:28 7fd6dcc9a820 InnoDB: 1 transactions in prepared state after recovery
2015-01-28 06:27:28 32213 [Note] Found 1 prepared transaction(s) in InnoDB
2015-01-28 06:27:28 32213 [Note] Crash recovery finished.

[Laurynas Biveinis (laurynas-biveinis)]

This looks similar to bug 1294190. Was there a INFORMATION_SCHEMA.GLOBAL_TEMPORARY_TABLES query going on in parallel at the time of ALTER TABLE? If so, please try upgrading to 5.6.22-71.0.

[Alex Kazeko (alexandr-temp)]

Laurynas,

Just wanted to comment we were executing "select * from information_schema.GLOBAL_TEMPORARY_TABLES \G" during the migration, but you were first :)

So yes, it seems that's the same issue. Thanks!

[Laurynas Biveinis (laurynas-biveinis)]

OK, marking as a duplicate of bug 1294190 for now. Please re-open if the crash occurs after you upgrade, without a GLOBAL_TEMP_TABLES query, or if you have any other reason to believe it's not the same issue. Thanks!