error log :
230202 09:30:23 Executing FLUSH NO_WRITE_TO_BINLOG BINARY LOGS
xtrabackup: Unknown error 1158
Error: failed to execute query ‘FLUSH NO_WRITE_TO_BINLOG BINARY LOGS’: 2013 (HY000) Lost connection to MySQL server during query
mysql8.0 variables：
wait_timeout=30
interactive_timeout=28800
mysql has not been restarted,backup for more than 8 hours;I wonder if the mysql connection is over interactive_timeout.
Hi @pangbin
xtrabackup is not an interactive session, so its connection should be closed after wait_timeout. However, xtrabackup sets wait timeout to its maximum value of 2147483.
Do you have any other process that look for long running idle connections and kills it, like pt-kill ?
Hello Marcelo,
I am facing exactly the same error, after the files are backed up, we have about 1.2 million tables copied, I get the above error from MySQL 8.0.33
and xtrabackup image: percona/percona-xtrabackup:latest
When I look inside the container I see even after the error is triggered, and the backup exec command is terminated, inside the mysql, the lock remains and I see this query statement continue being processed, A select from table spaces that list the tables …
The variables timeouts are default, and we do not pass 8 hours of interactive.
What should I do? please help?
Are you using the PXB inside the docker container ? Can you please confirm the exact version ?
xtrabackup --version
Ideally if the backup process completed it should be close in few intervals and shouldn’t be affected by interactive_timeout. Might be you hit with some bug thingy but not sure at the moment.
xtrabackup --user sbtest_user --password xxx --backup --target-dir=/home/vagrant/backups/
2023-11-22T07:54:41.793451-00:00 0 [Note] [MY-011825] [Xtrabackup] Transaction log of lsn (24404660652) to (24404660682) was copied.
2023-11-22T07:54:42.105068-00:00 0 [Note] [MY-011825] [Xtrabackup] completed OK!
| 246611 | sbtest_user | localhost | NULL | Sleep | 18 | | NULL | 17478 | 178 | 1092 |
mysql> show processlist;
+--------+-----------------+-----------------+------+---------+---------+------------------------+------------------+------------+-----------+---------------+
| Id | User | Host | db | Command | Time | State | Info | Time_ms | Rows_sent | Rows_examined |
+--------+-----------------+-----------------+------+---------+---------+------------------------+------------------+------------+-----------+---------------+
| 5 | event_scheduler | localhost | NULL | Daemon | 2323801 | Waiting on empty queue | NULL | 2323801305 | 0 | 0 |
| 208290 | pmm | localhost:40758 | NULL | Sleep | 0 | | NULL | 364 | 44 | 50 |
| 246581 | root | localhost | NULL | Query | 0 | init | show processlist | 0 | 0 | 0 |
| 246613 | pmm | localhost:58266 | NULL | Sleep | 1 | | NULL | 596 | 543 | 543 |
| 246614 | pmm | localhost:58290 | NULL | Sleep | 1 | | NULL | 590 | 0 | 0 |
| 246615 | pmm | localhost:58302 | NULL | Sleep | 1 | | NULL | 594 | 75 | 316 |
+--------+-----------------+-----------------+------+---------+---------+------------------------+------------------+------------+-----------+---------------+
mysql> select @@global.interactive_timeout;
+------------------------------+
| @@global.interactive_timeout |
+------------------------------+
| 28800 |
+------------------------------+
1 row in set (0.00 sec)
mysql> SELECT @@global.wait_timeout;
+-----------------------+
| @@global.wait_timeout |
+-----------------------+
| 30 |
+-----------------------+
1 row in set (0.00 sec)
Is that you doing backups on the PXC instance or a normal setup ? Is that reproducible or you just faced a one time issue ?
Can you please share the complete backup log file along with the database/mysql error logs as well for a review ?
Do you have the output of SHOW ENGINE INNODB STATUS\G resembling the issue duration ?
Lastly, please share the backup command also to have a quick look over there.
Hi @anil.joshi ,
We are using PXB in docker container , xtrabackup version 8.0.33-28 based on MySQL server 8.0.33 Linux (x86_64) (revision id: b3a3c3dd) .
We are running this command:
xtrabackup --user=user --password=password --host=host --port=3306 --backup --strict --slave-info --safe-slave-backup --safe-slave-backup-timeout=300 --check-privileges=1 --ftwrl-wait-timeout=100 --ftwrl-wait-query-type=all --kill-long-queries-timeout=50 --target-dir=/backups/up1 --parallel=8 --lock-ddl --no-lock 2>/backup.log
select @@global.interactive_timeout;
31536000
SELECT @@global.wait_timeout;
28800
We are running the command on Replica.
The amount of table we get when PXB runs "
SELECT T2.PATH, T2.NAME, T1.SPACE_TYPE FROM INFORMATION_SCHEMA.INNODB_TABLESPACES T1 JOIN INFORMATION_SCHEMA.INNODB_TABLESPACES_BRIEF T2 USING (SPACE) WHERE T1.SPACE_TYPE = ‘Single’ && T1.ROW_FORMAT != 'Undo’UNION SELECT T2.PATH, SUBSTRING_INDEX(SUBSTRING_INDEX(T2.PATH, ‘/’, -1), ‘.’, 1) NAME, T1.SPACE_TYPE FROM INFORMATION_SCHEMA .INNODB_TABLESPACES T1 JOIN INFORMATION_SCHEMA .INNODB_TABLESPACES_BRIEF T2 USING (SPACE) WHERE T1.SPACE_TYPE = ‘General’ && T1.ROW_FORMAT != ‘Undo’
"
is over 1.2 million rows
show variables like ‘%open_files_limit%’; == 1,048,576
show full processlist;
±------±-----------------±----------------±---------±--------±------±-----------------------±----------------------+
| Id | User | Host | db | Command | Time | State | Info |
±------±-----------------±----------------±---------±--------±------±-----------------------±----------------------+
| 5 | event_scheduler | localhost | NULL | Daemon | 81986 | Waiting on empty queue | NULL |
| 152 | root | localhost | appwrite | Sleep | 81605 | | NULL |
| 16181 | root | localhost | appwrite | Sleep | 41825 | | NULL |
| 27711 | root | localhost | appwrite | Sleep | 26284 | | NULL |
| 46418 | appwrite_backups | 10.0.8.23:37360 | NULL | Sleep | 1496 | | NULL |
| 47039 | root | localhost | appwrite | Query | 0 | init | show full processlist |
±------±-----------------±----------------±---------±--------±------±-----------------------±----------------------+
6 rows in set (0.00 sec)
2023-11-22T18:19:49.371305-00:00 0 [Note] [MY-011825] [Xtrabackup] recognized client arguments: --user=user --password=* --host=host --port=3306 --backup=1 --strict=1 --slave-info=1 --safe-slave-backup=1 --safe-slave-backup-timeout=300 --check-privileges=1 --target-dir=/backups/back1 --parallel=8 --lock-ddl=1
xtrabackup version 8.0.33-28 based on MySQL server 8.0.33 Linux (x86_64) (revision id: b3a3c3dd)
2023-11-22T18:19:49.375085-00:00 0 [Note] [MY-011825] [Xtrabackup] perl binary not found. Skipping the version check
2023-11-22T18:19:49.375149-00:00 0 [Note] [MY-011825] [Xtrabackup] Connecting to MySQL server host: host, user: user, password: set, port: 3306, socket: not set
2023-11-22T18:19:49.389427-00:00 0 [Note] [MY-011825] [Xtrabackup] Using server version 8.0.33
2023-11-22T18:19:52.094618-00:00 0 [Note] [MY-011825] [Xtrabackup] Slave open temp tables: 0
2023-11-22T18:19:52.098375-00:00 0 [Note] [MY-011825] [Xtrabackup] Slave is safe to backup.
2023-11-22T18:19:52.098628-00:00 0 [Note] [MY-011825] [Xtrabackup] Executing LOCK INSTANCE FOR BACKUP …
2023-11-22T18:19:52.101945-00:00 0 [Note] [MY-011825] [Xtrabackup] uses posix_fadvise().
2023-11-22T18:19:52.101994-00:00 0 [Note] [MY-011825] [Xtrabackup] cd to /var/lib/mysql/
2023-11-22T18:19:52.102011-00:00 0 [Note] [MY-011825] [Xtrabackup] open files limit requested 0, set to 1048576
2023-11-22T18:20:07.147226-00:00 0 [Note] [MY-011825] [Xtrabackup] using the following InnoDB configuration:
2023-11-22T18:20:07.147314-00:00 0 [Note] [MY-011825] [Xtrabackup] innodb_data_home_dir = .
2023-11-22T18:20:07.147326-00:00 0 [Note] [MY-011825] [Xtrabackup] innodb_data_file_path = ibdata1:12M:autoextend
2023-11-22T18:20:07.148161-00:00 0 [Note] [MY-011825] [Xtrabackup] innodb_log_group_home_dir = ./
2023-11-22T18:20:07.148227-00:00 0 [Note] [MY-011825] [Xtrabackup] innodb_log_files_in_group = 2
2023-11-22T18:20:07.148255-00:00 0 [Note] [MY-011825] [Xtrabackup] innodb_log_file_size = 50331648
2023-11-22T18:20:07.152628-00:00 0 [Note] [MY-011825] [Xtrabackup] inititialize_service_handles suceeded
2023-11-22T18:20:09.566487-00:00 0 [Note] [MY-011825] [Xtrabackup] Connecting to MySQL server host: host, user: user, password: set, port: 3306, socket: not set
2023-11-22T18:20:09.572851-00:00 0 [Note] [MY-011825] [Xtrabackup] Redo Log Archiving is not set up.
2023-11-22T18:20:09.669006-00:00 1 [Note] [MY-011825] [Xtrabackup] >> log scanned up to (46995286792)
2023-11-22T18:20:10.669296-00:00 1 [Note] [MY-011825] [Xtrabackup] >> log scanned up to (46995286792)
2023-11-22T18:20:11.669657-00:00 1 [Note] [MY-011825] [Xtrabackup] >> log scanned up to (46995286792)
2023-11-22T18:20:12.670072-00:00 1 [Note] [MY-011825] [Xtrabackup] >> log scanned up to (46995286792)
2023-11-22T18:20:13.670504-00:00 1 [Note] [MY-011825] [Xtrabackup] >> log scanned up to (46995286792)
2023-11-22T18:20:14.670922-00:00 1 [Note] [MY-011825] [Xtrabackup] >> log scanned up to (46995286792)
2023-11-22T18:20:15.671272-00:00 1 [Note] [MY-011825] [Xtrabackup] >> log scanned up to (46995286792)
2023-11-22T18:20:16.671629-00:00 1 [Note] [MY-011825] [Xtrabackup] >> log scanned up to (46995286792)
2023-11-22T18:20:17.671966-00:00 1 [Note] [MY-011825] [Xtrabackup] >> log scanned up to (46995286792)
2023-11-22T18:20:18.672304-00:00 1 [Note] [MY-011825] [Xtrabackup] >> log scanned up to (46995286792)
…
tail -n 10 backup.log
2023-11-22T18:50:33.208651-00:00 14 [Note] [MY-011825] [Xtrabackup] Copying mysql/general_log_213.sdi to /backups/db_fra1_self_hosted_0_2/v1/christy2/mysql/general_log_213.sdi
2023-11-22T18:50:33.208678-00:00 10 [Note] [MY-011825] [Xtrabackup] Copying mysql/general_log.CSV to /backups/db_fra1_self_hosted_0_2/v1/christy2/mysql/general_log.CSV
2023-11-22T18:50:33.208726-00:00 10 [Note] [MY-011825] [Xtrabackup] Done: Copying mysql/general_log.CSV to /backups/db_fra1_self_hosted_0_2/v1/christy2/mysql/general_log.CSV
2023-11-22T18:50:33.209795-00:00 15 [Note] [MY-011825] [Xtrabackup] Done: Copying mysql/general_log.CSM to /backups/db_fra1_self_hosted_0_2/v1/christy2/mysql/general_log.CSM
2023-11-22T18:50:33.209803-00:00 14 [Note] [MY-011825] [Xtrabackup] Done: Copying mysql/general_log_213.sdi to /backups/db_fra1_self_hosted_0_2/v1/christy2/mysql/general_log_213.sdi
2023-11-22T18:50:33.209805-00:00 16 [Note] [MY-011825] [Xtrabackup] Done: Copying mysql/slow_log_214.sdi to /backups/db_fra1_self_hosted_0_2/v1/christy2/mysql/slow_log_214.sdi
2023-11-22T18:50:33.247351-00:00 0 [Note] [MY-011825] [Xtrabackup] Finished backing up non-InnoDB tables and files
2023-11-22T18:50:33.247490-00:00 0 [Note] [MY-011825] [Xtrabackup] Executing FLUSH NO_WRITE_TO_BINLOG BINARY LOGS
xtrabackup: Unknown error 1158
2023-11-22T18:50:33.250430-00:00 0 [ERROR] [MY-011825] [Xtrabackup] failed to execute query ‘FLUSH NO_WRITE_TO_BINLOG BINARY LOGS’ : 2013 (HY000) Lost connection to MySQL server during query
Hi, we would really appreciate if we can get some insights / help on this issue. We’ve spent a lot of time searching online and trying various xtrabackup --options but none of them have helped so far.
We’ve also increased the system ulimit ( open files ) to well over 2M but that did not give us any fruitful results either.
Thanks for the details. While checking it further we noticed some close matching bug reports:- [PXB-2639] xtrabackup and wait_timeout - Percona JIRA & [PS-6916] MySQL 8.0.16-7 crash on centos 7 - Percona JIRA however the behaviour not reproduced.
The PXB can have max wait timeout(24 days) while doing backups.
xb_mysql_query(connection, "SET SESSION wait_timeout=2147483", false, true);
It appears to be happening with long running backups more specifically exceeding wait_timeout. How frequently you are getting that error ? Is there any particular time period when you observe the error ?
By any chance, did you observe anything in the mysql error logs if any crash or something happens. Can you pls share the same for a review ?
Did you also check if anything like pt-kill or any such cron scheduled which could kill the long running process on database ?
Are you doing the backups locally or using some NFS/ Streaming etc ? Did you see anything suspicious in the kernel/os logs ?
Thank you for your reply!
We have increased wait_timeout to max allowed by MySQL , this had no affect.
We are getting this error on EVERY iteration we run a backup.
We see nothing special in MySQL error logs.
We’re doing backups locally. We have MySQL and Xtrabackup running on docker containers on the same host. They are on the same network and share a volume that contains the /var/lib/mysql folder
Unanswered | Unsolved | Solved
MySQL, InnoDB, MariaDB and MongoDB are trademarks of their respective owners.
Copyright © 2006 - 2021 Percona LLC. All rights reserved.