LOCK BINLOG FOR BACKUP then SHOW MASTER STATUS causes deadlock and mysqld segfault

Bug #1414051 reported by mrahm
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC
New
Undecided
Unassigned

Bug Description

Network map: "percona1", "percona2", 3, 4, and 5 are machines on a PXC cluster. "percona-slave" is running async replication off percona1. all 6 machines have binlogs enabled.

Versions on all 6 machines: Ubuntu 14.04 using " http://repo.percona.com/apt trusty" repo.
Mysql: "Server version: 5.6.21-70.1-56-log Percona XtraDB Cluster (GPL), Release rel70.1, Revision 938, WSREP version 25.8, wsrep_25.8.r4150"
innobackupex: $ innobackupex --version
InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oy
$ xtrabackup --help
xtrabackup version 2.2.8 based on MySQL server 5.6.22 Linux (x86_64) (revision id: )

Package versions:
ii percona-toolkit 2.2.12 all Advanced MySQL and system command-line tools
ii percona-xtrabackup 2.2.8-5059-1.trusty amd64 Open source backup tool for InnoDB and XtraDB
ii percona-xtradb-cluster-56 5.6.21-25.8-938.trusty amd64 Percona XtraDB Cluster with Galera
ii percona-xtradb-cluster-client-5.6 5.6.21-25.8-938.trusty amd64 Percona XtraDB Cluster database client binaries
ii percona-xtradb-cluster-common-5.6 5.6.21-25.8-938.trusty amd64 Percona XtraDB Cluster database common files (e.g. /etc/mysql/my.cnf)
ii percona-xtradb-cluster-galera-3 3.8.3390.trusty amd64 Metapackage for latest version of galera3.
ii percona-xtradb-cluster-galera-3.x 3.8.3390.trusty amd64 Galera components of Percona XtraDB Cluster
ii percona-xtradb-cluster-server-5.6 5.6.21-25.8-938.trusty amd64 Percona XtraDB Cluster database server binaries
ii qpress 11-1.trusty amd64 A portable file archiver using QuickLZ

Almost all of our tables are innodb, there are 3-4 memory tables.

Bug circumstances:
At 2am a cron entry kicks off an innobackupex on percona2. None of the other machines have scheduled processes at this time, but they are serving DB traffic. The command is something like this:

/usr/bin/innobackupex --no-timestamp -user=root -password=xxxxxxxxxxx --rsync --compress --compress-threads=4 --parallel=4 /mnt/mysqlvolume1/backup/2015-01-23-09-24-18

When it fails, we get this from innobackupex:
--
 150123 02:06:03 innobackupex: Finished backing up non-InnoDB tables and files
150123 02:06:03 innobackupex: Executing LOCK BINLOG FOR BACKUP...
DBD::mysql::db selectrow_hashref failed: Deadlock found when trying to get lock; try restarting transaction at /usr/bin/innobackupex line 3026.
innobackupex: got a fatal error with the following stacktrace: at /usr/bin/innobackupex line 3039.
        main::mysql_query('HASH(0x2f19a80)', 'SHOW MASTER STATUS') called at /usr/bin/innobackupex line 3054
        main::get_mysql_master_status('HASH(0x2f19a80)') called at /usr/bin/innobackupex line 3082
        main::write_binlog_info('HASH(0x2f19a80)') called at /usr/bin/innobackupex line 2018
        main::backup() called at /usr/bin/innobackupex line 1592
innobackupex: Error:
Error executing 'SHOW MASTER STATUS': DBD::mysql::db selectrow_hashref failed: Deadlock found when trying to get lock; try restarting transaction at /usr/bin/innobackupex line 3026.
150123 02:06:03 innobackupex: Waiting for ibbackup (pid=10713) to finish
--

And the server process dies.
Looking in /var/log/mysql/error.log:
--
08:06:03 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 XtraDB Cluster better by reporting any
bugs at https://bugs.launchpad.net/percona-xtradb-cluster

key_buffer_size=25165824
read_buffer_size=131072
max_used_connections=51
max_threads=202
thread_count=32
connection_count=23
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 105196 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7016ec0
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...
*** Error in `/usr/sbin/mysqld': malloc(): smallbin double linked list corrupted: 0x00007f7f9428e0d0 ***
Fatal signal 6 while backtracing
150123 02:06:04 mysqld_safe Number of processes running now: 0
150123 02:06:04 mysqld_safe WSREP: not restarting wsrep node automatically
150123 02:06:04 mysqld_safe mysqld from pid file /var/lib/mysql/percona2.pid ended
--

Sometimes it works, but sometimes it doesn't. Our failure rate is about 50%. I don't have a stack trace to resolve. I don't have a core file, either, but I just read the relevant page and I'll try to update this report with one. Attached my.cnf.redacted.

Revision history for this message
mrahm (matt-reishus) wrote :
summary: - LOCK BINLOCK FOR BACKUP then SHOW MASTER STATUS causes deadlock and
+ LOCK BINLOG FOR BACKUP then SHOW MASTER STATUS causes deadlock and
mysqld segfault
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.