percona xtrabackup not reflecting --ftwrl-wait-timeout parameter value

Bug #1566315 reported by Muhammad Irfan on 2016-04-05
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona XtraBackup moved to https://jira.percona.com/projects/PXB
Status tracked in 2.4
2.3
Fix Released
High
Sergei Glushchenko
2.4
Fix Released
High
Sergei Glushchenko

Bug Description

When I try to use --ftwrl-wait-timeout paremeter innobackupex program not obeying it. It doesn't wait for long running queries SELECT to finish before acquiring FTWRL and all subsequent queries stuck with "Waiting for global read lock" instead waiting --ftwrl-wait-timeout=value before giving up.

mysql [localhost] {msandbox} ((none)) > SHOW VARIABLES LIKE '%version%';
+-------------------------+------------------------------+
| Variable_name | Value |
+-------------------------+------------------------------+
| innodb_version | 5.6.19 |
| protocol_version | 10 |
| slave_type_conversions | |
| version | 5.6.19-log |
| version_comment | MySQL Community Server (GPL) |
| version_compile_machine | x86_64 |
| version_compile_os | linux-glibc2.5 |
+-------------------------+------------------------------+

innobackupex version 2.3.3 based on MySQL server 5.6.24 Linux (x86_64) (revision id: 525ca7d)

# innobackupex --user=msandbox --password=msandbox --socket=/tmp/mysql_sandbox15619.sock --compress --compress-threads=2 --parallel=2 --ftwrl-wait-timeout=180 --no-timestamp /home/mirfan/backups/
160405 08:42:18 innobackupex: Starting the backup operation

IMPORTANT: Please check that the backup run completes successfully.
           At the end of a successful backup run innobackupex
           prints "completed OK!".

160405 08:42:18 version_check Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_group=xtrabackup;mysql_socket=/tmp/mysql_sandbox15619.sock' as 'msandbox' (using password: YES).
160405 08:42:18 version_check Connected to MySQL server
160405 08:42:18 version_check Executing a version check against the server...
160405 08:42:18 version_check Done.
160405 08:42:18 Connecting to MySQL server host: localhost, user: msandbox, password: set, port: 0, socket: /tmp/mysql_sandbox15619.sock
Using server version 5.6.19-log
innobackupex version 2.3.4 based on MySQL server 5.6.24 Linux (x86_64) (revision id: e80c779)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /home/przemyslaw.malkowski/sandboxes/oracle5.6.19/data/
xtrabackup: open files limit requested 0, set to 1024
xtrabackup: using the following InnoDB configuration:
xtrabackup: innodb_data_home_dir = ./
xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 2
xtrabackup: innodb_log_file_size = 50331648
160405 08:42:18 >> log scanned up to (4365748825)
xtrabackup: Generating a list of tablespaces
xtrabackup: Starting 2 threads for parallel data files transfer
160405 08:42:18 [01] Compressing ./ibdata1 to /home/mirfan/backups/ibdata1.qp
160405 08:42:24 >> log scanned up to (4365748825)
160405 08:42:24 [01] ...done
160405 08:42:44 [02] Compressing ./mysql/slave_relay_log_info.ibd to /home/mirfan/backups/mysql/slave_relay_log_info.ibd.qp
160405 08:42:44 [02] ...done
160405 08:42:44 >> log scanned up to (4365748825)
160405 08:43:00 >> log scanned up to (4365748825)
160405 08:43:00 [01] ...done
160405 08:43:00 Waiting 180 seconds for queries running longer than 60 seconds to finish
160405 08:43:00 Executing FLUSH TABLES WITH READ LOCK...

Instead waiting 180 seconds as per "--ftwrl-wait-timeout=180" before acquiring FTWRL all coming queries on mysql instance stuck with "Waiting for global read lock". Workaround for this problem is to use "--ftwrl-wait-query=all" which look likes changed to "update" from default "all" during rename of this parameter from "--lock-wait-query"

# innobackupex --user=msandbox --password=msandbox --socket=/tmp/mysql_sandbox15619.sock --compress --compress-threads=2 --parallel=2 --ftwrl-wait-timeout=300 --ftwrl-wait-query=all --no-timestamp /home/mirfan/backups/
Warning: Using unique option prefix ftwrl-wait-query instead of ftwrl-wait-query-type is deprecated and will be removed in a future release. Please use the full name instead.
160405 08:53:25 innobackupex: Starting the backup operation

IMPORTANT: Please check that the backup run completes successfully.
           At the end of a successful backup run innobackupex
           prints "completed OK!".

160405 08:53:25 version_check Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_group=xtrabackup;mysql_socket=/tmp/mysql_sandbox15619.sock' as 'msandbox' (using password: YES).
160405 08:53:25 version_check Connected to MySQL server
160405 08:53:25 version_check Executing a version check against the server...
160405 08:53:25 version_check Done.
160405 08:53:25 Connecting to MySQL server host: localhost, user: msandbox, password: set, port: 0, socket: /tmp/mysql_sandbox15619.sock
Using server version 5.6.19-log
innobackupex version 2.3.4 based on MySQL server 5.6.24 Linux (x86_64) (revision id: e80c779)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /home/mirfan/sandboxes/oracle5.6.19/data/
xtrabackup: open files limit requested 0, set to 1024
xtrabackup: using the following InnoDB configuration:
xtrabackup: innodb_data_home_dir = ./
xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 2
xtrabackup: innodb_log_file_size = 50331648
160405 08:53:25 >> log scanned up to (4365748825)
xtrabackup: Generating a list of tablespaces
xtrabackup: Starting 2 threads for parallel data files transfer
160405 08:53:25 [01] Compressing ./ibdata1 to /home/mirfan/backups/ibdata1.qp
160405 08:53:28 >> log scanned up to (4365748825)
160405 08:53:32 [01] ...done
160405 08:53:50 [02] Compressing ./mysql/innodb_index_stats.ibd to /home/mirfan/backups/mysql/innodb_index_stats.ibd.qp
160405 08:53:51 [02] ...done
160405 08:53:54 >> log scanned up to (4365748825)
160405 08:54:07 [01] ...done
160405 08:54:07 Waiting 300 seconds for queries running longer than 60 seconds to finish
160405 08:54:07 Waiting for query 18 (duration 228 sec): SELECT SLEEP(1000)160405 08:54:08 >> log scanned up to (4365748825)
160405 08:54:08 Waiting for query 18 (duration 229 sec): SELECT SLEEP(1000)160405 08:54:09 >> log scanned up to (4365748825)
160405 08:54:09 Waiting for query 18 (duration 230 sec): SELECT SLEEP(1000)160405 08:54:10 >> log scanned up to (4365748825)
160405 08:54:10 Waiting for query 18 (duration 231 sec): SELECT SLEEP(1000)160405 08:54:11 >> log scanned up to (4365748825)
160405 08:54:11 Waiting for query 18 (duration 232 sec): SELECT SLEEP(1000)160405 08:54:12 >> log scanned up to (4365748825)
160405 08:54:12 Waiting for query 18 (duration 233 sec): SELECT SLEEP(1000)160405 08:54:13 >> log scanned up to (4365748825)
160405 08:54:13 Waiting for query 18 (duration 234 sec): SELECT SLEEP(1000)160405 08:54:14 >> log scanned up to (4365748825)
160405 08:54:14 Waiting for query 18 (duration 235 sec): SELECT SLEEP(1000)160405 08:54:15 >> log scanned up to (4365748825)
160405 08:54:15 Waiting for query 18 (duration 236 sec): SELECT SLEEP(1000)160405 08:54:16 >> log scanned up to (4365748825)
160405 08:59:08 Unable to obtain lock. Please try again later.

As soon as I used --ftwrl-wait-query=all innobackupex works as expected.

tags: added: i67718
Changed in percona-xtrabackup:
status: New → Confirmed

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXB-472

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers