Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.3.36, 10.4.26, 10.5.17, 10.6.9, 10.7.5, 10.8.4, 10.9.2, 10.10.1
-
Fedora 35, macOS 10.13.6, RHEL 7.x
Description
Recent MariaDB Community Server (10.5.17) built from GitHub code does not allow to use --compress option with mariabackup. For example:
[openxs@fc35 maria10.5]$ bin/mariabackup --user=openxs --backup --compress --parallel=4 --target-dir=/tmp/backup/
|
[00] 2022-07-06 11:38:15 Connecting to MySQL server host: localhost, user: openxs, password: not set, port: not set, socket: not set
|
[00] 2022-07-06 11:38:15 Using server version 10.5.17-MariaDB
|
[00] 2022-07-06 11:38:15 Warning: option 'datadir' has different values:
|
'/var/lib/mysql' in defaults file
|
'/home/openxs/dbs/maria10.5/data/' in SHOW VARIABLES
|
bin/mariabackup based on MariaDB server 10.5.17-MariaDB Linux (x86_64)
|
[00] 2022-07-06 11:38:15 uses posix_fadvise().
|
[00] 2022-07-06 11:38:15 cd to /home/openxs/dbs/maria10.5/data/
|
[00] 2022-07-06 11:38:15 open files limit requested 0, set to 100000
|
[00] 2022-07-06 11:38:15 mariabackup: using the following InnoDB configuration:
|
[00] 2022-07-06 11:38:15 innodb_data_home_dir =
|
[00] 2022-07-06 11:38:15 innodb_data_file_path = ibdata1:12M:autoextend
|
[00] 2022-07-06 11:38:15 innodb_log_group_home_dir = ./
|
[00] 2022-07-06 11:38:15 InnoDB: Using Linux native AIO
|
2022-07-06 11:38:15 0 [Note] InnoDB: Number of pools: 1
|
It hangs this way indefinitely with the following content in the target directory:
^C
|
[openxs@fc35 maria10.5]$ ls -l /tmp/backup/*
|
-rw-r-----. 1 openxs openxs 0 Jul 6 11:38 /tmp/backup/ib_logfile0.qp
|
[openxs@fc35 maria10.5]$
|
This build is affected:
[openxs@fc35 server]$ git log -1
|
commit 0fca5068a88e9baee2ba06914885e80ca6c330ad (HEAD -> 10.5, origin/bb-10.5-serg, origin/10.5)
|
Author: Sergei Golubchik <serg@mariadb.org>
|
Date: Mon Jul 4 20:20:20 2022 +0200
|
|
MDEV-28234 Change maturity of plugins for July 2022 Releases
|
|
mysql_json: GAMMA -> STABLE
|
while this older one worked perfectly:
[openxs@fc35 server]$ git log -1
|
commit ea40c75c2793f15e57482a0b374ab48b81b8e3ac (HEAD -> 10.5, origin/10.5)
|
Merge: a0e4853eff0 99c8aed00d8
|
Author: Marko Mäkelä <marko.makela@mariadb.com>
|
Date: Wed May 25 14:24:51 2022 +0300
|
|
Merge 10.4 into 10.5
|
So, we have some recent enough regression introduced here. Tested on both Fedora 35 and macOS 10.13.6.
Attachments
Issue Links
- is caused by
-
MDEV-28689 Two improper locking bugs in the method compress_write
-
- Closed
-
- is duplicated by
-
MDEV-29372 mariabackup runs into a repeated loop InnoDB: Read redo log up to LSN when doing full backup
-
- Closed
-
Activity
I made a fix, but I could not believe my eyes: mariabackup --backup --compress --parallel=15 would only consume 2% of one CPU. I repeated the same performance with
git checkout mariadb-10.8.3 extra/mariabackup/ds_compress.cc
|
Maybe this is because my test case involves one huge table and an idle server. With multiple tables and concurrent write workload, it could look different.
It turns out that compress_write() may be called from at least 2 threads. I added some logic for "allocating" worker thread slots, so that concurrent compress_write() will not step on each other’s toes.
I tested a little more. It turns out that the parameter --parallel affects the maximum number of concurrent calls to compress_write(), a.k.a. the producer side. By default, the value is 1, so there will be one data-file copying thread and one log-copying thread that may submit compression jobs. The test mariabackup.compress_qpress that we have in the source tree is too small; there apparently were no concurrent calls to compress_write(). When cleaning up the code in MDEV-28689, I did not realize that there may indeed be multiple concurrent callers of compress_write().
The parameter --compress-threads specifies the number of threads that actually compress data.
I modified the test case to insert 10×1M rows in parallel and to use a 2-gigabyte buffer pool and log file size. With compress_qpress.opt and compress_qpress.test
, the 10.8 mariadbd would consume about 25 CPU seconds in a couple of seconds (using 8 to 10 CPU cores), and then the mariabackup would crawl, consuming about 2% of a single CPU. The entire test would complete in 190 seconds when I am running it on persistent storage. On /dev/shm the performance is about the same.
To ensure that there is no performance regression, I repeated the experiment with
git checkout mariadb-10.8.3 extra/mariabackup/ds_compress.cc
|
and got similar performance:
mariadb-10.8.3 |
mariabackup.compress_qpress [ pass ] 189161
|
I repeated the experiment without any compress option. Both with parallel=1 and parallel=10, mariabackup would typically consume only 0.7% of CPU, and the test would still complete in 187 or 190 seconds. I think that implementing MDEV-14992 would greatly improve backup performance. This test should really consume at most 10 to 20 seconds.
Current 10.5.18 from GitHub does seem to hang:
Yuliyas-Air:maria10.5 Valerii$ bin/mariabackup --user=Valerii --backup --compress --parallel=4 --target-dir=/tmp/backup/
|
[00] 2022-08-19 10:19:37 Connecting to MySQL server host: localhost, user: Valerii, password: not set, port: not set, socket: not set
|
[00] 2022-08-19 10:19:37 Using server version 10.5.18-MariaDB
|
bin/mariabackup based on MariaDB server 10.5.18-MariaDB osx10.13 (x86_64)
|
[00] 2022-08-19 10:19:37 cd to /Users/Valerii/dbs/maria10.5/data/
|
[00] 2022-08-19 10:19:37 open files limit requested 0, set to 256
|
[00] 2022-08-19 10:19:37 mariabackup: using the following InnoDB configuration:
|
[00] 2022-08-19 10:19:37 innodb_data_home_dir =
|
[00] 2022-08-19 10:19:37 innodb_data_file_path = ibdata1:12M:autoextend
|
[00] 2022-08-19 10:19:37 innodb_log_group_home_dir = ./
|
2022-08-19 10:19:37 0 [Note] InnoDB: Number of pools: 1
|
[00] 2022-08-19 10:19:37 mariabackup: Generating a list of tablespaces
|
[00] 2022-08-19 10:19:37 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:37 mariabackup: Starting 4 threads for parallel data files transfer
|
[01] 2022-08-19 10:19:37 Compressing ibdata1 to /tmp/backup/ibdata1.qp
|
[02] 2022-08-19 10:19:37 Compressing ./sbtest/sbtest4.ibd to /tmp/backup/sbtest/sbtest4.ibd.qp
|
[04] 2022-08-19 10:19:37 Compressing ./sbtest/sbtest7.ibd to /tmp/backup/sbtest/sbtest7.ibd.qp
|
[03] 2022-08-19 10:19:37 Compressing ./sbtest/sbtest5.ibd to /tmp/backup/sbtest/sbtest5.ibd.qp
|
[00] 2022-08-19 10:19:38 >> log scanned up to (2823374571)
|
[01] 2022-08-19 10:19:39 ...done
|
[01] 2022-08-19 10:19:39 Compressing ./sbtest/sbtest6.ibd to /tmp/backup/sbtest/sbtest6.ibd.qp
|
[00] 2022-08-19 10:19:39 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:40 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:41 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:42 >> log scanned up to (2823374571)
|
[04] 2022-08-19 10:19:42 ...done
|
[04] 2022-08-19 10:19:42 Compressing ./sbtest/sbtest2.ibd to /tmp/backup/sbtest/sbtest2.ibd.qp
|
[03] 2022-08-19 10:19:42 ...done
|
[03] 2022-08-19 10:19:42 Compressing ./sbtest/sbtest10.ibd to /tmp/backup/sbtest/sbtest10.ibd.qp
|
[02] 2022-08-19 10:19:42 ...done
|
[02] 2022-08-19 10:19:43 Compressing ./sbtest/sbtest3.ibd to /tmp/backup/sbtest/sbtest3.ibd.qp
|
[00] 2022-08-19 10:19:43 >> log scanned up to (2823374571)
|
[01] 2022-08-19 10:19:44 ...done
|
[01] 2022-08-19 10:19:44 Compressing ./sbtest/sbtest1.ibd to /tmp/backup/sbtest/sbtest1.ibd.qp
|
[00] 2022-08-19 10:19:44 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:45 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:46 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:47 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:48 >> log scanned up to (2823374571)
|
[03] 2022-08-19 10:19:49 ...done
|
[03] 2022-08-19 10:19:49 Compressing ./sbtest/sbtest8.ibd to /tmp/backup/sbtest/sbtest8.ibd.qp
|
[04] 2022-08-19 10:19:49 ...done
|
[04] 2022-08-19 10:19:49 Compressing ./sbtest/sbtest9.ibd to /tmp/backup/sbtest/sbtest9.ibd.qp
|
[02] 2022-08-19 10:19:49 ...done
|
[02] 2022-08-19 10:19:49 Compressing ./mysql/innodb_index_stats.ibd to /tmp/backup/mysql/innodb_index_stats.ibd.qp
|
[02] 2022-08-19 10:19:49 ...done
|
[02] 2022-08-19 10:19:49 Compressing ./mysql/innodb_table_stats.ibd to /tmp/backup/mysql/innodb_table_stats.ibd.qp
|
[02] 2022-08-19 10:19:49 ...done
|
[02] 2022-08-19 10:19:49 Compressing ./mysql/gtid_slave_pos.ibd to /tmp/backup/mysql/gtid_slave_pos.ibd.qp
|
[02] 2022-08-19 10:19:49 ...done
|
[02] 2022-08-19 10:19:49 Compressing ./mysql/transaction_registry.ibd to /tmp/backup/mysql/transaction_registry.ibd.qp
|
[02] 2022-08-19 10:19:49 ...done
|
[00] 2022-08-19 10:19:49 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:50 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:51 >> log scanned up to (2823374571)
|
2022-08-19 10:19:52 0 [Note] InnoDB: Read redo log up to LSN=2823374848
|
[00] 2022-08-19 10:19:52 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:53 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:54 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:55 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:56 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:57 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:58 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:19:59 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:00 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:01 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:02 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:03 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:04 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:05 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:06 >> log scanned up to (2823374571)
|
2022-08-19 10:20:07 0 [Note] InnoDB: Read redo log up to LSN=2823374848
|
[00] 2022-08-19 10:20:07 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:08 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:09 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:10 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:11 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:12 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:13 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:14 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:15 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:16 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:17 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:18 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:19 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:20 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:21 >> log scanned up to (2823374571)
|
2022-08-19 10:20:22 0 [Note] InnoDB: Read redo log up to LSN=2823374848
|
[00] 2022-08-19 10:20:22 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:23 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:24 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:25 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:26 >> log scanned up to (2823374571)
|
[00] 2022-08-19 10:20:27 >> log scanned up to (2823374571)
|
^C
|
Yuliyas-Air:maria10.5 Valerii$
|
This is on a fresh installation with the following 10 sysbench tables created:
Yuliyas-Air:maria10.5 Valerii$ cd ~/git/sysbench
|
Yuliyas-Air:sysbench Valerii$ src/sysbench --tables=10 --table-size=1000000 --threads=4 --mysql-user=Valerii --mysql-socket=/tmp/mysql.sock --mysql-db=sbtest oltp_write_only prepare
|
sysbench 1.1.0-df89d34 (using bundled LuaJIT 2.1.0-beta3)
|
|
Initializing worker threads...
|
|
Creating table 'sbtest1'...Creating table 'sbtest4'...Creating table 'sbtest3'...
|
Creating table 'sbtest2'...
|
|
|
Inserting 1000000 records into 'sbtest4'Inserting 1000000 records into 'sbtest3'
|
|
Inserting 1000000 records into 'sbtest2'
|
Inserting 1000000 records into 'sbtest1'
|
Creating a secondary index on 'sbtest4'...
|
Creating a secondary index on 'sbtest1'...
|
Creating a secondary index on 'sbtest2'...
|
Creating a secondary index on 'sbtest3'...
|
Creating table 'sbtest8'...
|
Inserting 1000000 records into 'sbtest8'
|
Creating table 'sbtest5'...
|
Inserting 1000000 records into 'sbtest5'
|
Creating table 'sbtest6'...
|
Inserting 1000000 records into 'sbtest6'
|
Creating table 'sbtest7'...
|
Inserting 1000000 records into 'sbtest7'
|
Creating a secondary index on 'sbtest8'...
|
Creating a secondary index on 'sbtest6'...
|
Creating a secondary index on 'sbtest5'...
|
Creating a secondary index on 'sbtest7'...
|
Creating table 'sbtest10'...
|
Inserting 1000000 records into 'sbtest10'
|
Creating table 'sbtest9'...
|
Inserting 1000000 records into 'sbtest9'
|
Creating a secondary index on 'sbtest9'...
|
Creating a secondary index on 'sbtest10'...
|
|
Now with this commit:
Yuliyas-Air:server Valerii$ git log -1
|
commit 8b9043c6220b67a342ad4f5b8c70975e04410f91 (HEAD -> bb-10.8-MDEV-29043, origin/bb-10.8-MDEV-29043)
|
Author: Marko Mäkelä <marko.makela@mariadb.com>
|
Date: Thu Aug 18 17:39:46 2022 +0300
|
|
MDEV-29043 mariabackup --compress hangs
|
|
compress_write(): Fix a race condition between threads that would
|
use the same worker thread object. Make thd->data_avail contain the
|
thread identifier of the submitter, and add thd->avail_cond to
|
notify other compress_write() threads that are waiting for a slot.
|
the same test completes in a reasonable time:
Yuliyas-Air:sysbench Valerii$ src/sysbench --tables=10 --table-size=1000000 --threads=4 --mysql-user=Valerii --mysql-socket=/tmp/mysql.sock --mysql-db=sbtest oltp_write_only prepare
|
sysbench 1.1.0-df89d34 (using bundled LuaJIT 2.1.0-beta3)
|
|
Initializing worker threads...
|
|
Creating table 'sbtest1'...Creating table 'sbtest2'...Creating table 'sbtest4'...
|
|
|
Creating table 'sbtest3'...
|
Inserting 1000000 records into 'sbtest4'
|
Inserting 1000000 records into 'sbtest1'
|
Inserting 1000000 records into 'sbtest2'
|
Inserting 1000000 records into 'sbtest3'
|
Creating a secondary index on 'sbtest2'...
|
Creating a secondary index on 'sbtest1'...
|
Creating a secondary index on 'sbtest3'...
|
Creating a secondary index on 'sbtest4'...
|
Creating table 'sbtest6'...
|
Inserting 1000000 records into 'sbtest6'
|
Creating table 'sbtest5'...
|
Creating table 'sbtest7'...
|
Inserting 1000000 records into 'sbtest5'
|
Inserting 1000000 records into 'sbtest7'
|
Creating table 'sbtest8'...
|
Inserting 1000000 records into 'sbtest8'
|
Creating a secondary index on 'sbtest6'...
|
Creating a secondary index on 'sbtest5'...
|
Creating a secondary index on 'sbtest7'...
|
Creating a secondary index on 'sbtest8'...
|
Creating table 'sbtest10'...
|
Inserting 1000000 records into 'sbtest10'
|
Creating table 'sbtest9'...
|
Inserting 1000000 records into 'sbtest9'
|
Creating a secondary index on 'sbtest10'...
|
Creating a secondary index on 'sbtest9'...
|
Yuliyas-Air:sysbench Valerii$ cd -
|
/Users/Valerii/dbs/maria10.8
|
Yuliyas-Air:maria10.8 Valerii$ rm -rf /tmp/backup/
|
Yuliyas-Air:maria10.8 Valerii$ bin/mariabackup --user=Valerii --backup --compress --parallel=4 --target-dir=/tmp/backup/
|
[00] 2022-08-19 10:53:25 Connecting to MariaDB server host: localhost, user: Valerii, password: not set, port: not set, socket: not set
|
[00] 2022-08-19 10:53:25 Using server version 10.8.5-MariaDB
|
bin/mariabackup based on MariaDB server 10.8.5-MariaDB osx10.13 (x86_64)
|
[00] 2022-08-19 10:53:25 cd to /Users/Valerii/dbs/maria10.8/data/
|
[00] 2022-08-19 10:53:25 open files limit requested 0, set to 256
|
[00] 2022-08-19 10:53:25 mariabackup: using the following InnoDB configuration:
|
[00] 2022-08-19 10:53:25 innodb_data_home_dir =
|
[00] 2022-08-19 10:53:25 innodb_data_file_path = ibdata1:12M:autoextend
|
[00] 2022-08-19 10:53:25 innodb_log_group_home_dir = ./
|
2022-08-19 10:53:25 0 [Note] InnoDB: Number of transaction pools: 1
|
[00] 2022-08-19 10:53:25 mariabackup: Generating a list of tablespaces
|
[00] 2022-08-19 10:53:25 >> log scanned up to (2853106862)
|
[00] 2022-08-19 10:53:25 mariabackup: Starting 4 threads for parallel data files transfer
|
[00] 2022-08-19 10:53:25 >> log scanned up to (2855203825)
|
[01] 2022-08-19 10:53:25 Compressing ibdata1 to /tmp/backup/ibdata1.qp
|
[03] 2022-08-19 10:53:25 Compressing ./sbtest/sbtest5.ibd to /tmp/backup/sbtest/sbtest5.ibd.qp
|
[04] 2022-08-19 10:53:25 Compressing ./sbtest/sbtest7.ibd to /tmp/backup/sbtest/sbtest7.ibd.qp
|
[02] 2022-08-19 10:53:25 Compressing ./sbtest/sbtest4.ibd to /tmp/backup/sbtest/sbtest4.ibd.qp
|
[00] 2022-08-19 10:53:26 >> log scanned up to (2855834768)
|
[00] 2022-08-19 10:53:27 >> log scanned up to (2855834768)
|
[01] 2022-08-19 10:53:28 ...done
|
[01] 2022-08-19 10:53:28 Compressing ./sbtest/sbtest6.ibd to /tmp/backup/sbtest/sbtest6.ibd.qp
|
[00] 2022-08-19 10:53:28 >> log scanned up to (2855834768)
|
[00] 2022-08-19 10:53:29 >> log scanned up to (2855834768)
|
[03] 2022-08-19 10:53:30 ...done
|
[03] 2022-08-19 10:53:30 Compressing ./sbtest/sbtest2.ibd to /tmp/backup/sbtest/sbtest2.ibd.qp
|
[04] 2022-08-19 10:53:30 ...done
|
[04] 2022-08-19 10:53:30 Compressing ./sbtest/sbtest10.ibd to /tmp/backup/sbtest/sbtest10.ibd.qp
|
[00] 2022-08-19 10:53:30 >> log scanned up to (2855834768)
|
[02] 2022-08-19 10:53:31 ...done
|
[02] 2022-08-19 10:53:31 Compressing ./sbtest/sbtest3.ibd to /tmp/backup/sbtest/sbtest3.ibd.qp
|
[00] 2022-08-19 10:53:31 >> log scanned up to (2855834768)
|
[00] 2022-08-19 10:53:32 >> log scanned up to (2855834768)
|
[00] 2022-08-19 10:53:33 >> log scanned up to (2855834768)
|
[01] 2022-08-19 10:53:34 ...done
|
[01] 2022-08-19 10:53:34 Compressing ./sbtest/sbtest1.ibd to /tmp/backup/sbtest/sbtest1.ibd.qp
|
[00] 2022-08-19 10:53:34 >> log scanned up to (2855834768)
|
[00] 2022-08-19 10:53:35 >> log scanned up to (2855834768)
|
[04] 2022-08-19 10:53:36 ...done
|
[04] 2022-08-19 10:53:36 Compressing ./sbtest/sbtest8.ibd to /tmp/backup/sbtest/sbtest8.ibd.qp
|
[03] 2022-08-19 10:53:36 ...done
|
[03] 2022-08-19 10:53:36 Compressing ./sbtest/sbtest9.ibd to /tmp/backup/sbtest/sbtest9.ibd.qp
|
[00] 2022-08-19 10:53:36 >> log scanned up to (2855834768)
|
[02] 2022-08-19 10:53:37 ...done
|
[02] 2022-08-19 10:53:37 Compressing ./mysql/innodb_index_stats.ibd to /tmp/backup/mysql/innodb_index_stats.ibd.qp
|
[02] 2022-08-19 10:53:37 ...done
|
[02] 2022-08-19 10:53:37 Compressing ./mysql/innodb_table_stats.ibd to /tmp/backup/mysql/innodb_table_stats.ibd.qp
|
[02] 2022-08-19 10:53:37 ...done
|
[02] 2022-08-19 10:53:37 Compressing ./mysql/gtid_slave_pos.ibd to /tmp/backup/mysql/gtid_slave_pos.ibd.qp
|
[02] 2022-08-19 10:53:37 ...done
|
[02] 2022-08-19 10:53:37 Compressing ./mysql/transaction_registry.ibd to /tmp/backup/mysql/transaction_registry.ibd.qp
|
[02] 2022-08-19 10:53:37 ...done
|
[00] 2022-08-19 10:53:37 >> log scanned up to (2855834768)
|
[00] 2022-08-19 10:53:38 >> log scanned up to (2855834768)
|
[01] 2022-08-19 10:53:38 ...done
|
[03] 2022-08-19 10:53:39 ...done
|
[04] 2022-08-19 10:53:39 ...done
|
[00] 2022-08-19 10:53:39 >> log scanned up to (2855834768)
|
[00] 2022-08-19 10:53:40 Acquiring BACKUP LOCKS...
|
[00] 2022-08-19 10:53:40 Starting to backup non-InnoDB tables and files
|
[01] 2022-08-19 10:53:40 Compressing ./test/db.opt to /tmp/backup/test/db.opt.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sbtest/sbtest4.frm to /tmp/backup/sbtest/sbtest4.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sbtest/sbtest5.frm to /tmp/backup/sbtest/sbtest5.frm.qp
|
[00] 2022-08-19 10:53:40 >> log scanned up to (2855834768)
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sbtest/sbtest7.frm to /tmp/backup/sbtest/sbtest7.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sbtest/sbtest6.frm to /tmp/backup/sbtest/sbtest6.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sbtest/sbtest2.frm to /tmp/backup/sbtest/sbtest2.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sbtest/sbtest10.frm to /tmp/backup/sbtest/sbtest10.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sbtest/sbtest3.frm to /tmp/backup/sbtest/sbtest3.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sbtest/sbtest1.frm to /tmp/backup/sbtest/sbtest1.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sbtest/db.opt to /tmp/backup/sbtest/db.opt.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sbtest/sbtest8.frm to /tmp/backup/sbtest/sbtest8.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sbtest/sbtest9.frm to /tmp/backup/sbtest/sbtest9.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/latest_file_io.frm to /tmp/backup/sys/latest_file_io.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/statements_with_temp_tables.frm to /tmp/backup/sys/statements_with_temp_tables.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/waits_by_user_by_latency.frm to /tmp/backup/sys/waits_by_user_by_latency.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/user_summary_by_file_io.frm to /tmp/backup/sys/user_summary_by_file_io.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/x@0024memory_by_user_by_current_bytes.frm to /tmp/backup/sys/x@0024memory_by_user_by_current_bytes.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/schema_table_lock_waits.frm to /tmp/backup/sys/schema_table_lock_waits.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/x@0024memory_global_by_current_bytes.frm to /tmp/backup/sys/x@0024memory_global_by_current_bytes.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/user_summary_by_file_io_type.frm to /tmp/backup/sys/user_summary_by_file_io_type.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/io_global_by_file_by_bytes.frm to /tmp/backup/sys/io_global_by_file_by_bytes.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/x@0024user_summary_by_file_io_type.frm to /tmp/backup/sys/x@0024user_summary_by_file_io_type.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/statement_analysis.frm to /tmp/backup/sys/statement_analysis.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/wait_classes_global_by_latency.frm to /tmp/backup/sys/wait_classes_global_by_latency.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/x@0024processlist.frm to /tmp/backup/sys/x@0024processlist.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/x@0024io_global_by_file_by_bytes.frm to /tmp/backup/sys/x@0024io_global_by_file_by_bytes.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/schema_auto_increment_columns.frm to /tmp/backup/sys/schema_auto_increment_columns.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/x@0024memory_global_total.frm to /tmp/backup/sys/x@0024memory_global_total.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/x@0024schema_table_statistics_with_buffer.frm to /tmp/backup/sys/x@0024schema_table_statistics_with_buffer.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/waits_by_host_by_latency.frm to /tmp/backup/sys/waits_by_host_by_latency.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:40 Compressing ./sys/x@0024io_by_thread_by_latency.frm to /tmp/backup/sys/x@0024io_by_thread_by_latency.frm.qp
|
[01] 2022-08-19 10:53:40 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/processlist.frm to /tmp/backup/sys/processlist.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/session_ssl_status.frm to /tmp/backup/sys/session_ssl_status.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024schema_tables_with_full_table_scans.frm to /tmp/backup/sys/x@0024schema_tables_with_full_table_scans.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/host_summary_by_file_io_type.frm to /tmp/backup/sys/host_summary_by_file_io_type.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024host_summary_by_file_io_type.frm to /tmp/backup/sys/x@0024host_summary_by_file_io_type.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/metrics.frm to /tmp/backup/sys/metrics.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/memory_by_user_by_current_bytes.frm to /tmp/backup/sys/memory_by_user_by_current_bytes.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024waits_by_user_by_latency.frm to /tmp/backup/sys/x@0024waits_by_user_by_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/schema_redundant_indexes.frm to /tmp/backup/sys/schema_redundant_indexes.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/schema_unused_indexes.frm to /tmp/backup/sys/schema_unused_indexes.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/io_by_thread_by_latency.frm to /tmp/backup/sys/io_by_thread_by_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024statements_with_full_table_scans.frm to /tmp/backup/sys/x@0024statements_with_full_table_scans.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/db.opt to /tmp/backup/sys/db.opt.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024host_summary_by_statement_type.frm to /tmp/backup/sys/x@0024host_summary_by_statement_type.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/version.frm to /tmp/backup/sys/version.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024user_summary_by_stages.frm to /tmp/backup/sys/x@0024user_summary_by_stages.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/sys_config.MAD to /tmp/backup/sys/sys_config.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024waits_by_host_by_latency.frm to /tmp/backup/sys/x@0024waits_by_host_by_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/sys_config.frm to /tmp/backup/sys/sys_config.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024host_summary_by_stages.frm to /tmp/backup/sys/x@0024host_summary_by_stages.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024user_summary_by_file_io.frm to /tmp/backup/sys/x@0024user_summary_by_file_io.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024schema_table_lock_waits.frm to /tmp/backup/sys/x@0024schema_table_lock_waits.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024user_summary_by_statement_type.frm to /tmp/backup/sys/x@0024user_summary_by_statement_type.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024wait_classes_global_by_latency.frm to /tmp/backup/sys/x@0024wait_classes_global_by_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/schema_tables_with_full_table_scans.frm to /tmp/backup/sys/schema_tables_with_full_table_scans.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/statements_with_sorting.frm to /tmp/backup/sys/statements_with_sorting.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/memory_global_total.frm to /tmp/backup/sys/memory_global_total.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/schema_table_statistics_with_buffer.frm to /tmp/backup/sys/schema_table_statistics_with_buffer.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024memory_by_host_by_current_bytes.frm to /tmp/backup/sys/x@0024memory_by_host_by_current_bytes.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024statements_with_runtimes_in_95th_percentile.frm to /tmp/backup/sys/x@0024statements_with_runtimes_in_95th_percentile.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024user_summary.frm to /tmp/backup/sys/x@0024user_summary.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024ps_digest_95th_percentile_by_avg_us.frm to /tmp/backup/sys/x@0024ps_digest_95th_percentile_by_avg_us.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/user_summary_by_statement_latency.frm to /tmp/backup/sys/user_summary_by_statement_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024schema_table_statistics.frm to /tmp/backup/sys/x@0024schema_table_statistics.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/user_summary.frm to /tmp/backup/sys/user_summary.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024user_summary_by_statement_latency.frm to /tmp/backup/sys/x@0024user_summary_by_statement_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024latest_file_io.frm to /tmp/backup/sys/x@0024latest_file_io.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024wait_classes_global_by_avg_latency.frm to /tmp/backup/sys/x@0024wait_classes_global_by_avg_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024ps_digest_avg_latency_distribution.frm to /tmp/backup/sys/x@0024ps_digest_avg_latency_distribution.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/memory_global_by_current_bytes.frm to /tmp/backup/sys/memory_global_by_current_bytes.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024schema_flattened_keys.frm to /tmp/backup/sys/x@0024schema_flattened_keys.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/statements_with_full_table_scans.frm to /tmp/backup/sys/statements_with_full_table_scans.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024schema_index_statistics.frm to /tmp/backup/sys/x@0024schema_index_statistics.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024session.frm to /tmp/backup/sys/x@0024session.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/waits_global_by_latency.frm to /tmp/backup/sys/waits_global_by_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024innodb_buffer_stats_by_table.frm to /tmp/backup/sys/x@0024innodb_buffer_stats_by_table.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/session.frm to /tmp/backup/sys/session.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/innodb_buffer_stats_by_table.frm to /tmp/backup/sys/innodb_buffer_stats_by_table.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/schema_object_overview.frm to /tmp/backup/sys/schema_object_overview.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024host_summary_by_file_io.frm to /tmp/backup/sys/x@0024host_summary_by_file_io.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/statements_with_errors_or_warnings.frm to /tmp/backup/sys/statements_with_errors_or_warnings.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/memory_by_host_by_current_bytes.frm to /tmp/backup/sys/memory_by_host_by_current_bytes.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024io_global_by_wait_by_latency.frm to /tmp/backup/sys/x@0024io_global_by_wait_by_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/io_global_by_wait_by_latency.frm to /tmp/backup/sys/io_global_by_wait_by_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024statements_with_errors_or_warnings.frm to /tmp/backup/sys/x@0024statements_with_errors_or_warnings.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/host_summary_by_statement_type.frm to /tmp/backup/sys/host_summary_by_statement_type.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/host_summary_by_file_io.frm to /tmp/backup/sys/host_summary_by_file_io.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024io_global_by_wait_by_bytes.frm to /tmp/backup/sys/x@0024io_global_by_wait_by_bytes.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024host_summary_by_statement_latency.frm to /tmp/backup/sys/x@0024host_summary_by_statement_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/statements_with_runtimes_in_95th_percentile.frm to /tmp/backup/sys/statements_with_runtimes_in_95th_percentile.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/user_summary_by_stages.frm to /tmp/backup/sys/user_summary_by_stages.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/innodb_buffer_stats_by_schema.frm to /tmp/backup/sys/innodb_buffer_stats_by_schema.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024ps_schema_table_statistics_io.frm to /tmp/backup/sys/x@0024ps_schema_table_statistics_io.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/schema_index_statistics.frm to /tmp/backup/sys/schema_index_statistics.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/host_summary_by_stages.frm to /tmp/backup/sys/host_summary_by_stages.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024waits_global_by_latency.frm to /tmp/backup/sys/x@0024waits_global_by_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/host_summary_by_statement_latency.frm to /tmp/backup/sys/host_summary_by_statement_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/io_global_by_wait_by_bytes.frm to /tmp/backup/sys/io_global_by_wait_by_bytes.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/innodb_lock_waits.frm to /tmp/backup/sys/innodb_lock_waits.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/wait_classes_global_by_avg_latency.frm to /tmp/backup/sys/wait_classes_global_by_avg_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/host_summary.frm to /tmp/backup/sys/host_summary.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/schema_table_statistics.frm to /tmp/backup/sys/schema_table_statistics.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/io_global_by_file_by_latency.frm to /tmp/backup/sys/io_global_by_file_by_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/user_summary_by_statement_type.frm to /tmp/backup/sys/user_summary_by_statement_type.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024host_summary.frm to /tmp/backup/sys/x@0024host_summary.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/sys_config.MAI to /tmp/backup/sys/sys_config.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024io_global_by_file_by_latency.frm to /tmp/backup/sys/x@0024io_global_by_file_by_latency.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024innodb_lock_waits.frm to /tmp/backup/sys/x@0024innodb_lock_waits.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024memory_by_thread_by_current_bytes.frm to /tmp/backup/sys/x@0024memory_by_thread_by_current_bytes.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024innodb_buffer_stats_by_schema.frm to /tmp/backup/sys/x@0024innodb_buffer_stats_by_schema.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/ps_check_lost_instrumentation.frm to /tmp/backup/sys/ps_check_lost_instrumentation.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024statements_with_sorting.frm to /tmp/backup/sys/x@0024statements_with_sorting.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024statements_with_temp_tables.frm to /tmp/backup/sys/x@0024statements_with_temp_tables.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/memory_by_thread_by_current_bytes.frm to /tmp/backup/sys/memory_by_thread_by_current_bytes.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./sys/x@0024statement_analysis.frm to /tmp/backup/sys/x@0024statement_analysis.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/index_stats.frm to /tmp/backup/mysql/index_stats.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_transition.MAI to /tmp/backup/mysql/time_zone_transition.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/index_stats.MAD to /tmp/backup/mysql/index_stats.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_transition_type.MAD to /tmp/backup/mysql/time_zone_transition_type.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/table_stats.frm to /tmp/backup/mysql/table_stats.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/columns_priv.MAD to /tmp/backup/mysql/columns_priv.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/slow_log.frm to /tmp/backup/mysql/slow_log.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/columns_priv.frm to /tmp/backup/mysql/columns_priv.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_transition_type.frm to /tmp/backup/mysql/time_zone_transition_type.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/table_stats.MAD to /tmp/backup/mysql/table_stats.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/tables_priv.frm to /tmp/backup/mysql/tables_priv.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_category.MAI to /tmp/backup/mysql/help_category.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/func.MAD to /tmp/backup/mysql/func.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/column_stats.MAD to /tmp/backup/mysql/column_stats.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/plugin.MAI to /tmp/backup/mysql/plugin.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/column_stats.frm to /tmp/backup/mysql/column_stats.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/func.frm to /tmp/backup/mysql/func.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/innodb_index_stats.frm to /tmp/backup/mysql/innodb_index_stats.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/tables_priv.MAD to /tmp/backup/mysql/tables_priv.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_relation.MAI to /tmp/backup/mysql/help_relation.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/slow_log.CSM to /tmp/backup/mysql/slow_log.CSM.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/slow_log.CSV to /tmp/backup/mysql/slow_log.CSV.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/innodb_table_stats.frm to /tmp/backup/mysql/innodb_table_stats.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/proxies_priv.MAI to /tmp/backup/mysql/proxies_priv.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/roles_mapping.MAI to /tmp/backup/mysql/roles_mapping.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone.MAI to /tmp/backup/mysql/time_zone.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/proc.MAD to /tmp/backup/mysql/proc.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_name.MAI to /tmp/backup/mysql/time_zone_name.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/gtid_slave_pos.frm to /tmp/backup/mysql/gtid_slave_pos.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/db.opt to /tmp/backup/mysql/db.opt.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/proc.frm to /tmp/backup/mysql/proc.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_keyword.MAI to /tmp/backup/mysql/help_keyword.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/servers.MAI to /tmp/backup/mysql/servers.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_leap_second.frm to /tmp/backup/mysql/time_zone_leap_second.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/global_priv.MAD to /tmp/backup/mysql/global_priv.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/procs_priv.MAD to /tmp/backup/mysql/procs_priv.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/db.frm to /tmp/backup/mysql/db.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_topic.MAD to /tmp/backup/mysql/help_topic.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_topic.frm to /tmp/backup/mysql/help_topic.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/procs_priv.frm to /tmp/backup/mysql/procs_priv.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/db.MAD to /tmp/backup/mysql/db.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/global_priv.frm to /tmp/backup/mysql/global_priv.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/event.MAI to /tmp/backup/mysql/event.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_leap_second.MAD to /tmp/backup/mysql/time_zone_leap_second.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/transaction_registry.frm to /tmp/backup/mysql/transaction_registry.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/index_stats.MAI to /tmp/backup/mysql/index_stats.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_transition.frm to /tmp/backup/mysql/time_zone_transition.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_transition.MAD to /tmp/backup/mysql/time_zone_transition.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/table_stats.MAI to /tmp/backup/mysql/table_stats.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/columns_priv.MAI to /tmp/backup/mysql/columns_priv.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_transition_type.MAI to /tmp/backup/mysql/time_zone_transition_type.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/user.frm to /tmp/backup/mysql/user.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_relation.MAD to /tmp/backup/mysql/help_relation.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/tables_priv.MAI to /tmp/backup/mysql/tables_priv.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_category.frm to /tmp/backup/mysql/help_category.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/plugin.MAD to /tmp/backup/mysql/plugin.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/plugin.frm to /tmp/backup/mysql/plugin.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/column_stats.MAI to /tmp/backup/mysql/column_stats.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/func.MAI to /tmp/backup/mysql/func.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_category.MAD to /tmp/backup/mysql/help_category.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_relation.frm to /tmp/backup/mysql/help_relation.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/roles_mapping.MAD to /tmp/backup/mysql/roles_mapping.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/proxies_priv.MAD to /tmp/backup/mysql/proxies_priv.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/proxies_priv.frm to /tmp/backup/mysql/proxies_priv.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/roles_mapping.frm to /tmp/backup/mysql/roles_mapping.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone.MAD to /tmp/backup/mysql/time_zone.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone.frm to /tmp/backup/mysql/time_zone.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/servers.MAD to /tmp/backup/mysql/servers.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_keyword.MAD to /tmp/backup/mysql/help_keyword.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_name.frm to /tmp/backup/mysql/time_zone_name.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/general_log.frm to /tmp/backup/mysql/general_log.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_name.MAD to /tmp/backup/mysql/time_zone_name.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/proc.MAI to /tmp/backup/mysql/proc.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/servers.frm to /tmp/backup/mysql/servers.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_keyword.frm to /tmp/backup/mysql/help_keyword.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/time_zone_leap_second.MAI to /tmp/backup/mysql/time_zone_leap_second.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/event.MAD to /tmp/backup/mysql/event.MAD.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/db.MAI to /tmp/backup/mysql/db.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/help_topic.MAI to /tmp/backup/mysql/help_topic.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/procs_priv.MAI to /tmp/backup/mysql/procs_priv.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/global_priv.MAI to /tmp/backup/mysql/global_priv.MAI.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/event.frm to /tmp/backup/mysql/event.frm.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/general_log.CSV to /tmp/backup/mysql/general_log.CSV.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./mysql/general_log.CSM to /tmp/backup/mysql/general_log.CSM.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./performance_schema/db.opt to /tmp/backup/performance_schema/db.opt.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[00] 2022-08-19 10:53:41 Finished backing up non-InnoDB tables and files
|
[01] 2022-08-19 10:53:41 Compressing ./aria_log_control to /tmp/backup/aria_log_control.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[01] 2022-08-19 10:53:41 Compressing ./aria_log.00000001 to /tmp/backup/aria_log.00000001.qp
|
[01] 2022-08-19 10:53:41 ...done
|
[00] 2022-08-19 10:53:41 Waiting for log copy thread to read lsn 2855834768
|
[00] 2022-08-19 10:53:41 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
|
[00] 2022-08-19 10:53:41 mariabackup: The latest check point (for incremental): '2851019284'
|
mariabackup: Stopping log copying thread.[00] 2022-08-19 10:53:41 >> log scanned up to (2855834768)
|
|
[00] 2022-08-19 10:53:41 >> log scanned up to (2855834768)
|
[00] 2022-08-19 10:53:41 Executing BACKUP STAGE END
|
[00] 2022-08-19 10:53:41 All tables unlocked
|
[00] 2022-08-19 10:53:41 Backup created in directory '/tmp/backup/'
|
[00] 2022-08-19 10:53:41 Compressing backup-my.cnf
|
[00] 2022-08-19 10:53:41 ...done
|
[00] 2022-08-19 10:53:41 Compressing xtrabackup_info
|
[00] 2022-08-19 10:53:41 ...done
|
[00] 2022-08-19 10:53:41 Redo log (from LSN 2851019284 to 2855834768) was copied.
|
[00] 2022-08-19 10:53:41 completed OK!
|
Yuliyas-Air:maria10.8 Valerii$
|
I am able to reproduce the hang on 10.8 with this test:
diff --git a/mysql-test/suite/mariabackup/compress_qpress.opt b/mysql-test/suite/mariabackup/compress_qpress.opt
new file mode 100644
index 00000000000..16b4f1c994c
--- /dev/null
+++ b/mysql-test/suite/mariabackup/compress_qpress.opt
@@ -0,0 +1 @@
+--innodb-log-file-size=2g --innodb-buffer-pool-size=2g
diff --git a/mysql-test/suite/mariabackup/compress_qpress.test b/mysql-test/suite/mariabackup/compress_qpress.test
index f86efe44e5d..72f8ba5362e 100644
--- a/mysql-test/suite/mariabackup/compress_qpress.test
+++ b/mysql-test/suite/mariabackup/compress_qpress.test
@@ -1,13 +1,15 @@
-CREATE TABLE t(i INT) ENGINE INNODB;
-INSERT INTO t VALUES(1);
+--source include/have_sequence.inc
+CREATE TABLE t(i INT PRIMARY KEY) ENGINE INNODB;
+SET unique_checks=0,foreign_key_checks=0;
+INSERT INTO t SELECT * FROM seq_1_to_10000000;
echo # xtrabackup backup;
let $targetdir=$MYSQLTEST_VARDIR/tmp/backup;
--disable_result_log
-exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf --backup --compress --target-dir=$targetdir;
+exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf --backup --throttle=0 --compress --target-dir=$targetdir;
--enable_result_log
-INSERT INTO t VALUES(2);
+INSERT INTO t SET i=0;
echo # xtrabackup prepare;
@@ -19,6 +21,6 @@ exec $XTRABACKUP --prepare --target-dir=$targetdir;
-- source include/restart_and_restore.inc
--enable_result_log
-SELECT * FROM t;
+CHECK TABLE t;
DROP TABLE t;
The mariadbd would run for 21 seconds, and then mariabackup would hang practically immediately, after consuming 0 seconds of CPU time.