Description:
Hi team,
MySQL Shell dumpInstance() is stuck in a loop creating chunks because of problematic strings with CHARACTER SET ascii COLLATE ascii_bin in the where condition of chunking queries:
2025-01-07T06:13:06.355289Z 15 Query SELECT SQL_NO_CACHE `col_id`,`col_date` FROM `test`.`example` PARTITION (`p_06_11`) WHERE (`col_id`>'?^???o????p???P??????5' OR(`col_id`='?^???o????p???P??????5' AND(`col_date`>=1686528386))) ORDER BY `col_id`,`col_date` LIMIT 1121,2 /* mysqlsh dumpInstance, chunking table `test`.`example` partition `p_06_11`, ID: 60368 */
MySQL Shell should detect this problem and avoid falling into an endless loop due to bad chunking.
How to repeat:
- Create example table in MySQL version 5.7.44. Since these problematic strings with CHARACTER SET ascii COLLATE ascii_bin can't be inserted directly in version 8.x, we need to insert them in version 5.7.44 and then upgrade the database to version 8.x.
CREATE TABLE `test`.`example` (
`col_id` varchar(26) CHARACTER SET ascii COLLATE ascii_bin NOT NULL DEFAULT '',
`col_date` int(10) unsigned NOT NULL,
`col_varchar_1` varchar(26) NOT NULL DEFAULT '',
`col_varchar_2` varchar(26) NOT NULL DEFAULT '',
`col_varchar_3` varchar(26) NOT NULL DEFAULT '',
`col_varchar_4` varchar(26) NOT NULL DEFAULT '',
`col_varchar_5` varchar(26) NOT NULL DEFAULT '',
PRIMARY KEY (`col_id`,`col_date`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 ROW_FORMAT=COMPRESSED
/*!50100 PARTITION BY RANGE (`col_date`)
(PARTITION p_06_09 VALUES LESS THAN (1686356775) ENGINE = InnoDB,
PARTITION p_06_10 VALUES LESS THAN (1686443175) ENGINE = InnoDB,
PARTITION p_06_11 VALUES LESS THAN (1686529575) ENGINE = InnoDB,
PARTITION p_06_12 VALUES LESS THAN (1686615975) ENGINE = InnoDB,
PARTITION p_06_13 VALUES LESS THAN (1686702375) ENGINE = InnoDB,
PARTITION p_06_14 VALUES LESS THAN (1686726000) ENGINE = InnoDB,
PARTITION p_06_15 VALUES LESS THAN (1686812400) ENGINE = InnoDB,
PARTITION p_06_16 VALUES LESS THAN (1686898800) ENGINE = InnoDB,
PARTITION p_06_17 VALUES LESS THAN (1686985200) ENGINE = InnoDB,
PARTITION p_06_18 VALUES LESS THAN (1687071600) ENGINE = InnoDB,
PARTITION p_06_19 VALUES LESS THAN (1687158000) ENGINE = InnoDB,
PARTITION p_06_20 VALUES LESS THAN (1687244400) ENGINE = InnoDB,
PARTITION p_06_21 VALUES LESS THAN (1687330800) ENGINE = InnoDB,
PARTITION p_06_22 VALUES LESS THAN (1687417200) ENGINE = InnoDB,
PARTITION p_06_23 VALUES LESS THAN (1687503600) ENGINE = InnoDB,
PARTITION p_06_24 VALUES LESS THAN (1687590000) ENGINE = InnoDB,
PARTITION p_06_25 VALUES LESS THAN (1687676400) ENGINE = InnoDB,
PARTITION p_06_26 VALUES LESS THAN (1687762800) ENGINE = InnoDB,
PARTITION p_06_27 VALUES LESS THAN (1687849200) ENGINE = InnoDB,
PARTITION p_06_28 VALUES LESS THAN (1687935600) ENGINE = InnoDB,
PARTITION p_06_29 VALUES LESS THAN (1688022000) ENGINE = InnoDB,
PARTITION p_06_30 VALUES LESS THAN (1688108400) ENGINE = InnoDB,
PARTITION p_07_01 VALUES LESS THAN (1688194800) ENGINE = InnoDB,
PARTITION p_07_02 VALUES LESS THAN (1688281200) ENGINE = InnoDB,
PARTITION p_07_03 VALUES LESS THAN (1688367600) ENGINE = InnoDB,
PARTITION p_07_04 VALUES LESS THAN (1688454000) ENGINE = InnoDB,
PARTITION p_07_05 VALUES LESS THAN (1688540400) ENGINE = InnoDB,
PARTITION p_07_06 VALUES LESS THAN (1688626800) ENGINE = InnoDB,
PARTITION p_07_07 VALUES LESS THAN (1688713200) ENGINE = InnoDB,
PARTITION p_07_08 VALUES LESS THAN (1688799600) ENGINE = InnoDB,
PARTITION p_07_09 VALUES LESS THAN (1688886000) ENGINE = InnoDB,
PARTITION p_07_10 VALUES LESS THAN (1688972400) ENGINE = InnoDB,
PARTITION p_07_11 VALUES LESS THAN (1689058800) ENGINE = InnoDB,
PARTITION p_07_12 VALUES LESS THAN (1689145200) ENGINE = InnoDB,
PARTITION p_07_13 VALUES LESS THAN (1689231600) ENGINE = InnoDB,
PARTITION p_07_14 VALUES LESS THAN (1689318000) ENGINE = InnoDB,
PARTITION p_07_15 VALUES LESS THAN (1689404400) ENGINE = InnoDB,
PARTITION p_07_16 VALUES LESS THAN (1689490800) ENGINE = InnoDB,
PARTITION p_07_17 VALUES LESS THAN (1689577200) ENGINE = InnoDB,
PARTITION p_07_18 VALUES LESS THAN (1689663600) ENGINE = InnoDB,
PARTITION p_07_19 VALUES LESS THAN (1689750000) ENGINE = InnoDB,
PARTITION p_07_20 VALUES LESS THAN (1689836400) ENGINE = InnoDB,
PARTITION p_07_21 VALUES LESS THAN (1689922800) ENGINE = InnoDB,
PARTITION p_07_22 VALUES LESS THAN (1690009200) ENGINE = InnoDB,
PARTITION p_07_23 VALUES LESS THAN (1690095600) ENGINE = InnoDB,
PARTITION p_07_24 VALUES LESS THAN (1690182000) ENGINE = InnoDB,
PARTITION p_07_25 VALUES LESS THAN (1690268400) ENGINE = InnoDB,
PARTITION p_07_26 VALUES LESS THAN (1690354800) ENGINE = InnoDB,
PARTITION p_07_27 VALUES LESS THAN (1690441200) ENGINE = InnoDB,
PARTITION p_07_28 VALUES LESS THAN (1690527600) ENGINE = InnoDB,
PARTITION p_07_29 VALUES LESS THAN (1690614000) ENGINE = InnoDB,
PARTITION p_07_30 VALUES LESS THAN (1690700400) ENGINE = InnoDB,
PARTITION p_07_31 VALUES LESS THAN (1690786800) ENGINE = InnoDB,
PARTITION p_08_01 VALUES LESS THAN (1690873200) ENGINE = InnoDB,
PARTITION p_08_02 VALUES LESS THAN (1690959600) ENGINE = InnoDB,
PARTITION p_08_03 VALUES LESS THAN (1691046000) ENGINE = InnoDB,
PARTITION p_08_04 VALUES LESS THAN (1691132400) ENGINE = InnoDB,
PARTITION p_08_05 VALUES LESS THAN (1691218800) ENGINE = InnoDB,
PARTITION p_08_06 VALUES LESS THAN (1691305200) ENGINE = InnoDB,
PARTITION p_08_07 VALUES LESS THAN (1691391600) ENGINE = InnoDB,
PARTITION p_08_08 VALUES LESS THAN (1691478000) ENGINE = InnoDB,
PARTITION p_08_09 VALUES LESS THAN (1691564400) ENGINE = InnoDB,
PARTITION p_08_10 VALUES LESS THAN (1691650800) ENGINE = InnoDB,
PARTITION p_08_11 VALUES LESS THAN (1691737200) ENGINE = InnoDB,
PARTITION p_08_12 VALUES LESS THAN (1691823600) ENGINE = InnoDB,
PARTITION p_08_13 VALUES LESS THAN (1691910000) ENGINE = InnoDB,
PARTITION p_08_14 VALUES LESS THAN (1691996400) ENGINE = InnoDB,
PARTITION p_08_15 VALUES LESS THAN (1692082800) ENGINE = InnoDB,
PARTITION p_08_16 VALUES LESS THAN (1692169200) ENGINE = InnoDB,
PARTITION p_08_17 VALUES LESS THAN (1692255600) ENGINE = InnoDB) */
;
- Bash script to insert binary ASCII strings, run this until insert about 200-300k rows, then stop
function client() {
rows="";
for i in {1..500}; do {
col_id_value=$(dd if=/dev/urandom bs=1 count=26 2>/dev/null | tr -d "'" | xxd -c26 -ps);
col_date_value=$(shuf -i1686356775-1692255600 -n1);
rows="(BINARY UNHEX('${col_id_value}'),${col_date_value},'col_varchar_value','col_varchar_value','col_varchar_value','col_varchar_value','col_varchar_value'),${rows}";
} done;
echo "SET sql_mode=''; INSERT INTO test.example (col_id,col_date,col_varchar_1,col_varchar_2,col_varchar_3,col_varchar_4,col_varchar_5) VALUES ${rows%,}" | mysql -P5744;
}
threads_max=8;
while true; do {
r=$(jobs -r | wc -l);
[[ $r == 0 ]] && r=1;
if [[ $r < $threads_max ]]; then {
for thread in $(seq ${r} ${threads_max}); do {
echo "[$(date +%F_%T)] Starting new client.";
client &
} done;
} fi;
sleep 1;
inserted=$(mysql -P5744 -BNe "SHOW GLOBAL STATUS LIKE 'Innodb_rows_inserted'" 2>/dev/null| awk '{print $2}');
echo "[$(date +%F_%T)] Inserted: $((inserted-inserted_prev))";
inserted_prev=$inserted;
} done;
- Example value in the table:
mysql> select * from example limit 1 \G
*************************** 1. row ***************************
col_id: ???*Vf?j?T{?l?4?g??%???
col_date: 1691623832
col_varchar_1: col_varchar_value
col_varchar_2: col_varchar_value
col_varchar_3: col_varchar_value
col_varchar_4: col_varchar_value
col_varchar_5: col_varchar_value
1 row in set (0.00 sec)
- Upgrade from the database server from 5.7.44 to 8.0.36:
...
2025-01-07T04:27:12.256193Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2025-01-07T04:27:13.148973Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2025-01-07T04:27:15.461340Z 2 [System] [MY-011003] [Server] Finished populating Data Dictionary tables with data.
2025-01-07T04:27:19.124939Z 5 [System] [MY-013381] [Server] Server upgrade from '50700' to '80036' started.
2025-01-07T04:27:33.231723Z 5 [System] [MY-013381] [Server] Server upgrade from '50700' to '80036' completed.
2025-01-07T04:27:33.417563Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2025-01-07T04:27:33.417700Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2025-01-07T04:27:33.504019Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 18036, socket: /tmp/mysqlx-18036.sock
2025-01-07T04:27:33.504181Z 0 [System] [MY-010931] [Server] /home/hai.nguyen/mysql/8.0.36/bin/mysqld: ready for connections. Version: '8.0.36' socket: '/tmp/mysql_sandbox8036.sock' port: 8036 MySQL Community Server - GPL.
- Run MySQL Shell dumpInstance with chunking enabled:
$ mysqlsh -h 127.0.0.1 -P 8036 -u root --log-level=8 --log-file=/home/hai.nguyen/backup/log/dump.log --js -e 'util.dumpInstance("/home/hai.nguyen/backup/dump/", {"threads":4,"chunking":true,"bytesPerChunk":"128000"})'
Please provide the password for 'root@127.0.0.1:8036': ****
Save password for 'root@127.0.0.1:8036'? [Y]es/[N]o/Ne[v]er (default No):
Acquiring global read lock
Global read lock acquired
Initializing - done
1 out of 5 schemas will be dumped and within them 1 table, 0 views.
8 out of 11 users will be dumped.
Gathering information - done
All transactions have been started
Locking instance for backup
Global read lock has been released
Writing global DDL files
Writing users DDL
Running data dump using 4 threads.
NOTE: Progress information uses estimated values and may not be accurate.
Writing schema metadata - done
Writing DDL - done
Writing table metadata - done
Starting data dump
4 thds chunking / 0% (0 rows / ~155.67K rows), 0.00 rows/s, 0.00 B/s uncompressed, 0.00 B/s compressed
- It then run forever trying to create chunks:
2025-01-07 03:27:47: Info: ./mysqlsh Ver 8.4.0 for Linux on x86_64 - for MySQL 8.4.0 (MySQL Community Server (GPL)) - build 15032060 - commit_id 4de2d1695fdc7089e81c99dcb042953620e444fb - product_id linux-glibc2.28-x86-64bit tar-gz
2025-01-07 03:27:47: Debug2: Invoking helper
2025-01-07 03:27:47: Debug2: Command line: /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/bin/mysql-secret-store-login-path version
2025-01-07 03:27:47: Debug2: Input:
2025-01-07 03:27:47: Debug2: Output: mysql-secret-store-login-path Ver 8.4.0 for Linux on x86_64 - for MySQL 8.4.0 (MySQL Community Server (GPL))
Copyright (c) 2018, 2024, Oracle and/or its affiliates. All rights reserved.
2025-01-07 03:27:47: Debug2: Exit code: 0
2025-01-07 03:27:47: Info: Using credential store helper: /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/bin/mysql-secret-store-login-path
2025-01-07 03:27:47: Info: Setting Python home to '/home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/lib/mysqlsh'
2025-01-07 03:27:47: Info: Loading startup files...
2025-01-07 03:27:47: Debug: Searching for plugins at '/home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/lib/mysqlsh/plugins'
2025-01-07 03:27:47: Info: Loading plugins...
2025-01-07 03:27:47: Debug: - /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/lib/mysqlsh/plugins/debug/init.py
2025-01-07 03:27:47: Debug: The 'debug' extension object has been registered as a member into the 'util' extension object.
2025-01-07 03:27:47: Debug: The 'collectDiagnostics' function has been registered into the 'debug' extension object.
2025-01-07 03:27:47: Debug: The 'collectHighLoadDiagnostics' function has been registered into the 'debug' extension object.
2025-01-07 03:27:47: Debug: The 'collectSlowQueryDiagnostics' function has been registered into the 'debug' extension object.
2025-01-07 03:27:47: Debug: - /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/lib/mysqlsh/plugins/plugins_plugin/init.py
2025-01-07 03:27:47: Debug: The 'plugins' extension object has been registered as a global object.
2025-01-07 03:27:47: Debug: The 'repositories' extension object has been registered as a member into the 'plugins' extension object.
2025-01-07 03:27:47: Debug: The 'list' function has been registered into the 'repositories' extension object.
2025-01-07 03:27:47: Debug: The 'add' function has been registered into the 'repositories' extension object.
2025-01-07 03:27:47: Debug: The 'remove' function has been registered into the 'repositories' extension object.
2025-01-07 03:27:47: Debug: The 'info' function has been registered into the 'plugins' extension object.
2025-01-07 03:27:47: Debug: The 'version' function has been registered into the 'plugins' extension object.
2025-01-07 03:27:47: Debug: The 'about' function has been registered into the 'plugins' extension object.
2025-01-07 03:27:47: Debug: The 'list' function has been registered into the 'plugins' extension object.
2025-01-07 03:27:47: Debug: The 'install' function has been registered into the 'plugins' extension object.
2025-01-07 03:27:47: Debug: The 'uninstall' function has been registered into the 'plugins' extension object.
2025-01-07 03:27:47: Debug: The 'update' function has been registered into the 'plugins' extension object.
2025-01-07 03:27:47: Debug: The 'details' function has been registered into the 'plugins' extension object.
2025-01-07 03:27:47: Debug: Using color mode 2
2025-01-07 03:27:47: Debug2: Invoking helper
2025-01-07 03:27:47: Debug2: Command line: /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/bin/mysql-secret-store-login-path get
2025-01-07 03:27:47: Debug2: Input: {"SecretType":"password","ServerURL":"root@127.0.0.1:8036"}
2025-01-07 03:27:47: Debug2: Output: Could not find the secret
2025-01-07 03:27:47: Debug2: Exit code: 1
2025-01-07 03:27:49: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036
2025-01-07 03:27:49: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING
2025-01-07 03:27:49: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:49: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:49: Info: main: tid=26: CONNECTED: 127.0.0.1:8036
2025-01-07 03:27:50: Info: Now tracking 'sql_mode' system variable.
2025-01-07 03:27:50: Debug: Using prompt theme file /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/share/mysqlsh/prompt/prompt_256.json
2025-01-07 03:27:50: Info: Dump options: {"bytesPerChunk":"128000","chunking":true,"threads":4}
2025-01-07 03:27:50: Debug: Initializing...
2025-01-07 03:27:50: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036?max-allowed-packet=1073741824&net-read-timeout=86400000
2025-01-07 03:27:50: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING
2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:50: Info: util.dumpInstance(): tid=27: CONNECTED: 127.0.0.1:8036
2025-01-07 03:27:50: Info: Source server: 8.0.36 MySQL Community Server - GPL
2025-01-07 03:27:50: Debug: Reading roles information for user 'root'@'localhost'
2025-01-07 03:27:50: Debug: Acquiring global read lock
2025-01-07 03:27:50: Debug: Global read lock acquired
2025-01-07 03:27:50: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036?max-allowed-packet=1073741824&net-read-timeout=86400000
2025-01-07 03:27:50: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING
2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:50: Info: util.dumpInstance(): tid=28: CONNECTED: 127.0.0.1:8036
2025-01-07 03:27:50: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036?max-allowed-packet=1073741824&net-read-timeout=86400000
2025-01-07 03:27:50: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING
2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:50: Info: util.dumpInstance(): tid=29: CONNECTED: 127.0.0.1:8036
2025-01-07 03:27:50: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036?max-allowed-packet=1073741824&net-read-timeout=86400000
2025-01-07 03:27:50: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING
2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:50: Info: util.dumpInstance(): tid=30: CONNECTED: 127.0.0.1:8036
2025-01-07 03:27:50: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036?max-allowed-packet=1073741824&net-read-timeout=86400000
2025-01-07 03:27:50: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING
2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN
2025-01-07 03:27:50: Info: util.dumpInstance(): tid=31: CONNECTED: 127.0.0.1:8036
2025-01-07 03:27:50: Info: Initializing - done, duration: 0.127594 seconds
2025-01-07 03:27:50: Debug: Gathering information...
2025-01-07 03:27:50: Debug: -> fetching version
2025-01-07 03:27:50: Debug: <- fetching version took 0.000859 seconds
2025-01-07 03:27:50: Debug: -> filtering schemas
2025-01-07 03:27:50: Debug: <- filtering schemas took 0.006534 seconds
2025-01-07 03:27:50: Debug: -> filtering tables
2025-01-07 03:27:50: Debug: -> iterating schemas
2025-01-07 03:27:50: Debug: <- iterating schemas took 0.040407 seconds
2025-01-07 03:27:50: Debug: <- filtering tables took 0.048864 seconds
2025-01-07 03:27:50: Debug: -> fetching metadata
2025-01-07 03:27:50: Debug: -> fetching ndbinfo
2025-01-07 03:27:50: Debug: <- fetching ndbinfo took 0.005840 seconds
2025-01-07 03:27:50: Debug: -> fetching server metadata
2025-01-07 03:27:50: Debug: <- fetching server metadata took 0.004274 seconds
2025-01-07 03:27:50: Debug: -> fetching view metadata
2025-01-07 03:27:50: Debug: <- fetching view metadata took 0.000000 seconds
2025-01-07 03:27:50: Debug: -> fetching columns
2025-01-07 03:27:50: Debug: -> iterating tables and views
2025-01-07 03:27:50: Debug: <- iterating tables and views took 0.007431 seconds
2025-01-07 03:27:50: Debug: <- fetching columns took 0.007516 seconds
2025-01-07 03:27:50: Debug: -> fetching table indexes
2025-01-07 03:27:50: Debug: -> iterating tables
2025-01-07 03:27:50: Debug: -> iterating tables and views
2025-01-07 03:27:50: Debug: <- iterating tables and views took 0.007509 seconds
2025-01-07 03:27:50: Debug: <- iterating tables took 0.007580 seconds
2025-01-07 03:27:50: Debug: <- fetching table indexes took 0.007617 seconds
2025-01-07 03:27:50: Debug: -> fetching table histograms
2025-01-07 03:27:50: Debug: -> iterating tables
2025-01-07 03:27:50: Debug: -> iterating tables and views
2025-01-07 03:27:50: Debug: <- iterating tables and views took 0.001316 seconds
2025-01-07 03:27:50: Debug: <- iterating tables took 0.001359 seconds
2025-01-07 03:27:50: Debug: <- fetching table histograms took 0.001388 seconds
2025-01-07 03:27:50: Debug: -> fetching table partitions
2025-01-07 03:27:50: Debug: -> iterating tables
2025-01-07 03:27:50: Debug: -> iterating tables and views
2025-01-07 03:27:50: Debug: <- iterating tables and views took 0.009139 seconds
2025-01-07 03:27:50: Debug: <- iterating tables took 0.009203 seconds
2025-01-07 03:27:50: Debug: <- fetching table partitions took 0.009239 seconds
2025-01-07 03:27:50: Debug: <- fetching metadata took 0.036203 seconds
2025-01-07 03:27:50: Debug: -> fetching users
2025-01-07 03:27:50: Debug: <- fetching users took 0.005443 seconds
2025-01-07 03:27:50: Debug: -> fetching events
2025-01-07 03:27:50: Debug: -> iterating schemas
2025-01-07 03:27:50: Debug: <- iterating schemas took 0.003273 seconds
2025-01-07 03:27:50: Debug: <- fetching events took 0.004881 seconds
2025-01-07 03:27:50: Debug: -> fetching routines
2025-01-07 03:27:50: Debug: -> iterating schemas
2025-01-07 03:27:50: Debug: <- iterating schemas took 0.004430 seconds
2025-01-07 03:27:50: Debug: <- fetching routines took 0.006941 seconds
2025-01-07 03:27:50: Debug: -> fetching triggers
2025-01-07 03:27:50: Debug: -> iterating tables
2025-01-07 03:27:50: Debug: -> iterating tables and views
2025-01-07 03:27:50: Debug: <- iterating tables and views took 0.003038 seconds
2025-01-07 03:27:50: Debug: <- iterating tables took 0.003084 seconds
2025-01-07 03:27:50: Debug: <- fetching triggers took 0.005593 seconds
2025-01-07 03:27:50: Debug: -> fetching binlog info
2025-01-07 03:27:50: Debug: <- fetching binlog info took 0.001162 seconds
2025-01-07 03:27:50: Debug: 1 out of 5 schemas will be dumped and within them 1 table, 0 views.
2025-01-07 03:27:50: Debug: 8 out of 11 users will be dumped.
2025-01-07 03:27:50: Info: Gathering information - done, duration: 0.117840 seconds
2025-01-07 03:27:50: Debug: All transactions have been started
2025-01-07 03:27:50: Debug: Locking instance for backup
2025-01-07 03:27:50: Debug: Global read lock has been released
2025-01-07 03:27:50: Debug: Writing global DDL files
2025-01-07 03:27:50: Debug: Writing users DDL
2025-01-07 03:27:50: Debug: Dumping grants for server
2025-01-07 03:27:50: Debug: Writing schema metadata...
2025-01-07 03:27:50: Debug: Writing DDL...
2025-01-07 03:27:50: Info: [Worker000]: Writing metadata for schema `test`
2025-01-07 03:27:50: Debug: Writing table metadata...
2025-01-07 03:27:50: Info: [Worker001]: Writing DDL for schema `test`
2025-01-07 03:27:50: Info: [Worker002]: Writing DDL for table `test`.`example`
2025-01-07 03:27:50: Info: Preparing data dump of table `test`.`example`
2025-01-07 03:27:50: Info: [Worker003]: Writing metadata for table `test`.`example`
2025-01-07 03:27:50: Info: The data dump of table `test`.`example` will be chunked using columns `id`,`date_created`
2025-01-07 03:27:50: Debug: Dumping table example from database test
2025-01-07 03:27:50: Debug: -- Retrieving table structure for table example...
2025-01-07 03:27:50: Debug: Dumping events for database test
2025-01-07 03:27:50: Debug: Dumping routines for database test
2025-01-07 03:27:50: Info: [Worker003]: Chunking `test`.`example` partition `p2023_06_10`, rows: 13219, average row length: 99, rows per chunk: 1292
2025-01-07 03:27:50: Info: [Worker001]: Chunking `test`.`example` partition `p2023_06_11`, rows: 13681, average row length: 96, rows per chunk: 1333
2025-01-07 03:27:50: Debug: Running data dump using 4 threads.
2025-01-07 03:27:50: Info: Progress information uses estimated values and may not be accurate.
2025-01-07 03:27:50: Debug: Dumping data...
2025-01-07 03:27:50: Info: [Worker000]: Chunking `test`.`example` partition `p2023_06_09`, rows: 0, average row length: 256, rows per chunk: 500
2025-01-07 03:27:50: Info: [Worker001]: Chunking `test`.`example` partition `p2023_06_11`, using columns: `id` (String), `date_created` (UInteger), min: [], max: [??3c?G??{yW??O???i_???K, 1686520461]
2025-01-07 03:27:50: Info: [Worker001]: Chunking `test`.`example` partition `p2023_06_11` using non-integer algorithm
2025-01-07 03:27:50: Info: [Worker003]: Chunking `test`.`example` partition `p2023_06_10`, using columns: `id` (String), `date_created` (UInteger), min: [], max: [????z???????c???N??Q?/", 1686406197]
2025-01-07 03:27:50: Info: [Worker003]: Chunking `test`.`example` partition `p2023_06_10` using non-integer algorithm
2025-01-07 03:27:50: Debug: [Worker000]: Chunking of `test`.`example` partition `p2023_06_09` took 0.002950 seconds
2025-01-07 03:27:50: Info: [Worker000]: Data dump for table `test`.`example` partition `p2023_06_09` will be written to 1 file
2025-01-07 03:27:50: Info: [Worker000]: Chunking `test`.`example` partition `p2023_06_12`, rows: 13527, average row length: 97, rows per chunk: 1319
2025-01-07 03:27:50: Info: [Worker000]: Chunking `test`.`example` partition `p2023_06_12`, using columns: `id` (String), `date_created` (UInteger), min: [], max: [???b+??2%;L?mO?? 7???*, 1686571049]
2025-01-07 03:27:50: Info: [Worker000]: Chunking `test`.`example` partition `p2023_06_12` using non-integer algorithm
2025-01-07 03:27:50: Info: [Worker002]: Chunking `test`.`example` partition `p2023_06_13`, rows: 13846, average row length: 95, rows per chunk: 1347
2025-01-07 03:27:50: Info: [Worker002]: Chunking `test`.`example` partition `p2023_06_13`, using columns: `id` (String), `date_created` (UInteger), min: [], max: [?????????+?A.?????>-?d*, 1686676293]
2025-01-07 03:27:50: Info: [Worker002]: Chunking `test`.`example` partition `p2023_06_13` using non-integer algorithm
2025-01-07 03:27:50: Info: Writing schema metadata - done, duration: 0.250109 seconds
2025-01-07 03:27:50: Info: Writing DDL - done, duration: 0.250222 seconds
2025-01-07 03:27:50: Info: Writing table metadata - done, duration: 0.250163 seconds
2025-01-07 03:27:50: Debug: Starting data dump
- General log shows MySQL Shell running these chunking queries in loop:
2025-01-07T06:13:06.345952Z 14 Query SELECT SQL_NO_CACHE `col_id`,`col_date` FROM `test`.`example` PARTITION (`p_06_12`) WHERE (`col_id`>'?,KA)????5?S????x?????
H' OR(`col_id`='?,KA)????5?S????x?????
H' AND(`col_date`>=1686545899))) ORDER BY `col_id`,`col_date` LIMIT 1141,2 /* mysqlsh dumpInstance, chunking table `test`.`example` partition `p_06_12`, ID: 61595 */
2025-01-07T06:13:06.355289Z 15 Query SELECT SQL_NO_CACHE `col_id`,`col_date` FROM `test`.`example` PARTITION (`p_06_11`) WHERE (`col_id`>'?^???o????p???P??????5' OR(`col_id`='?^???o????p???P??????5' AND(`col_date`>=1686528386))) ORDER BY `col_id`,`col_date` LIMIT 1121,2 /* mysqlsh dumpInstance, chunking table `test`.`example` partition `p_06_11`, ID: 60368 */
Description: Hi team, MySQL Shell dumpInstance() is stuck in a loop creating chunks because of problematic strings with CHARACTER SET ascii COLLATE ascii_bin in the where condition of chunking queries: 2025-01-07T06:13:06.355289Z 15 Query SELECT SQL_NO_CACHE `col_id`,`col_date` FROM `test`.`example` PARTITION (`p_06_11`) WHERE (`col_id`>'?^???o????p???P??????5' OR(`col_id`='?^???o????p???P??????5' AND(`col_date`>=1686528386))) ORDER BY `col_id`,`col_date` LIMIT 1121,2 /* mysqlsh dumpInstance, chunking table `test`.`example` partition `p_06_11`, ID: 60368 */ MySQL Shell should detect this problem and avoid falling into an endless loop due to bad chunking. How to repeat: - Create example table in MySQL version 5.7.44. Since these problematic strings with CHARACTER SET ascii COLLATE ascii_bin can't be inserted directly in version 8.x, we need to insert them in version 5.7.44 and then upgrade the database to version 8.x. CREATE TABLE `test`.`example` ( `col_id` varchar(26) CHARACTER SET ascii COLLATE ascii_bin NOT NULL DEFAULT '', `col_date` int(10) unsigned NOT NULL, `col_varchar_1` varchar(26) NOT NULL DEFAULT '', `col_varchar_2` varchar(26) NOT NULL DEFAULT '', `col_varchar_3` varchar(26) NOT NULL DEFAULT '', `col_varchar_4` varchar(26) NOT NULL DEFAULT '', `col_varchar_5` varchar(26) NOT NULL DEFAULT '', PRIMARY KEY (`col_id`,`col_date`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 ROW_FORMAT=COMPRESSED /*!50100 PARTITION BY RANGE (`col_date`) (PARTITION p_06_09 VALUES LESS THAN (1686356775) ENGINE = InnoDB, PARTITION p_06_10 VALUES LESS THAN (1686443175) ENGINE = InnoDB, PARTITION p_06_11 VALUES LESS THAN (1686529575) ENGINE = InnoDB, PARTITION p_06_12 VALUES LESS THAN (1686615975) ENGINE = InnoDB, PARTITION p_06_13 VALUES LESS THAN (1686702375) ENGINE = InnoDB, PARTITION p_06_14 VALUES LESS THAN (1686726000) ENGINE = InnoDB, PARTITION p_06_15 VALUES LESS THAN (1686812400) ENGINE = InnoDB, PARTITION p_06_16 VALUES LESS THAN (1686898800) ENGINE = InnoDB, PARTITION p_06_17 VALUES LESS THAN (1686985200) ENGINE = InnoDB, PARTITION p_06_18 VALUES LESS THAN (1687071600) ENGINE = InnoDB, PARTITION p_06_19 VALUES LESS THAN (1687158000) ENGINE = InnoDB, PARTITION p_06_20 VALUES LESS THAN (1687244400) ENGINE = InnoDB, PARTITION p_06_21 VALUES LESS THAN (1687330800) ENGINE = InnoDB, PARTITION p_06_22 VALUES LESS THAN (1687417200) ENGINE = InnoDB, PARTITION p_06_23 VALUES LESS THAN (1687503600) ENGINE = InnoDB, PARTITION p_06_24 VALUES LESS THAN (1687590000) ENGINE = InnoDB, PARTITION p_06_25 VALUES LESS THAN (1687676400) ENGINE = InnoDB, PARTITION p_06_26 VALUES LESS THAN (1687762800) ENGINE = InnoDB, PARTITION p_06_27 VALUES LESS THAN (1687849200) ENGINE = InnoDB, PARTITION p_06_28 VALUES LESS THAN (1687935600) ENGINE = InnoDB, PARTITION p_06_29 VALUES LESS THAN (1688022000) ENGINE = InnoDB, PARTITION p_06_30 VALUES LESS THAN (1688108400) ENGINE = InnoDB, PARTITION p_07_01 VALUES LESS THAN (1688194800) ENGINE = InnoDB, PARTITION p_07_02 VALUES LESS THAN (1688281200) ENGINE = InnoDB, PARTITION p_07_03 VALUES LESS THAN (1688367600) ENGINE = InnoDB, PARTITION p_07_04 VALUES LESS THAN (1688454000) ENGINE = InnoDB, PARTITION p_07_05 VALUES LESS THAN (1688540400) ENGINE = InnoDB, PARTITION p_07_06 VALUES LESS THAN (1688626800) ENGINE = InnoDB, PARTITION p_07_07 VALUES LESS THAN (1688713200) ENGINE = InnoDB, PARTITION p_07_08 VALUES LESS THAN (1688799600) ENGINE = InnoDB, PARTITION p_07_09 VALUES LESS THAN (1688886000) ENGINE = InnoDB, PARTITION p_07_10 VALUES LESS THAN (1688972400) ENGINE = InnoDB, PARTITION p_07_11 VALUES LESS THAN (1689058800) ENGINE = InnoDB, PARTITION p_07_12 VALUES LESS THAN (1689145200) ENGINE = InnoDB, PARTITION p_07_13 VALUES LESS THAN (1689231600) ENGINE = InnoDB, PARTITION p_07_14 VALUES LESS THAN (1689318000) ENGINE = InnoDB, PARTITION p_07_15 VALUES LESS THAN (1689404400) ENGINE = InnoDB, PARTITION p_07_16 VALUES LESS THAN (1689490800) ENGINE = InnoDB, PARTITION p_07_17 VALUES LESS THAN (1689577200) ENGINE = InnoDB, PARTITION p_07_18 VALUES LESS THAN (1689663600) ENGINE = InnoDB, PARTITION p_07_19 VALUES LESS THAN (1689750000) ENGINE = InnoDB, PARTITION p_07_20 VALUES LESS THAN (1689836400) ENGINE = InnoDB, PARTITION p_07_21 VALUES LESS THAN (1689922800) ENGINE = InnoDB, PARTITION p_07_22 VALUES LESS THAN (1690009200) ENGINE = InnoDB, PARTITION p_07_23 VALUES LESS THAN (1690095600) ENGINE = InnoDB, PARTITION p_07_24 VALUES LESS THAN (1690182000) ENGINE = InnoDB, PARTITION p_07_25 VALUES LESS THAN (1690268400) ENGINE = InnoDB, PARTITION p_07_26 VALUES LESS THAN (1690354800) ENGINE = InnoDB, PARTITION p_07_27 VALUES LESS THAN (1690441200) ENGINE = InnoDB, PARTITION p_07_28 VALUES LESS THAN (1690527600) ENGINE = InnoDB, PARTITION p_07_29 VALUES LESS THAN (1690614000) ENGINE = InnoDB, PARTITION p_07_30 VALUES LESS THAN (1690700400) ENGINE = InnoDB, PARTITION p_07_31 VALUES LESS THAN (1690786800) ENGINE = InnoDB, PARTITION p_08_01 VALUES LESS THAN (1690873200) ENGINE = InnoDB, PARTITION p_08_02 VALUES LESS THAN (1690959600) ENGINE = InnoDB, PARTITION p_08_03 VALUES LESS THAN (1691046000) ENGINE = InnoDB, PARTITION p_08_04 VALUES LESS THAN (1691132400) ENGINE = InnoDB, PARTITION p_08_05 VALUES LESS THAN (1691218800) ENGINE = InnoDB, PARTITION p_08_06 VALUES LESS THAN (1691305200) ENGINE = InnoDB, PARTITION p_08_07 VALUES LESS THAN (1691391600) ENGINE = InnoDB, PARTITION p_08_08 VALUES LESS THAN (1691478000) ENGINE = InnoDB, PARTITION p_08_09 VALUES LESS THAN (1691564400) ENGINE = InnoDB, PARTITION p_08_10 VALUES LESS THAN (1691650800) ENGINE = InnoDB, PARTITION p_08_11 VALUES LESS THAN (1691737200) ENGINE = InnoDB, PARTITION p_08_12 VALUES LESS THAN (1691823600) ENGINE = InnoDB, PARTITION p_08_13 VALUES LESS THAN (1691910000) ENGINE = InnoDB, PARTITION p_08_14 VALUES LESS THAN (1691996400) ENGINE = InnoDB, PARTITION p_08_15 VALUES LESS THAN (1692082800) ENGINE = InnoDB, PARTITION p_08_16 VALUES LESS THAN (1692169200) ENGINE = InnoDB, PARTITION p_08_17 VALUES LESS THAN (1692255600) ENGINE = InnoDB) */ ; - Bash script to insert binary ASCII strings, run this until insert about 200-300k rows, then stop function client() { rows=""; for i in {1..500}; do { col_id_value=$(dd if=/dev/urandom bs=1 count=26 2>/dev/null | tr -d "'" | xxd -c26 -ps); col_date_value=$(shuf -i1686356775-1692255600 -n1); rows="(BINARY UNHEX('${col_id_value}'),${col_date_value},'col_varchar_value','col_varchar_value','col_varchar_value','col_varchar_value','col_varchar_value'),${rows}"; } done; echo "SET sql_mode=''; INSERT INTO test.example (col_id,col_date,col_varchar_1,col_varchar_2,col_varchar_3,col_varchar_4,col_varchar_5) VALUES ${rows%,}" | mysql -P5744; } threads_max=8; while true; do { r=$(jobs -r | wc -l); [[ $r == 0 ]] && r=1; if [[ $r < $threads_max ]]; then { for thread in $(seq ${r} ${threads_max}); do { echo "[$(date +%F_%T)] Starting new client."; client & } done; } fi; sleep 1; inserted=$(mysql -P5744 -BNe "SHOW GLOBAL STATUS LIKE 'Innodb_rows_inserted'" 2>/dev/null| awk '{print $2}'); echo "[$(date +%F_%T)] Inserted: $((inserted-inserted_prev))"; inserted_prev=$inserted; } done; - Example value in the table: mysql> select * from example limit 1 \G *************************** 1. row *************************** col_id: ???*Vf?j?T{?l?4?g??%??? col_date: 1691623832 col_varchar_1: col_varchar_value col_varchar_2: col_varchar_value col_varchar_3: col_varchar_value col_varchar_4: col_varchar_value col_varchar_5: col_varchar_value 1 row in set (0.00 sec) - Upgrade from the database server from 5.7.44 to 8.0.36: ... 2025-01-07T04:27:12.256193Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started. 2025-01-07T04:27:13.148973Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended. 2025-01-07T04:27:15.461340Z 2 [System] [MY-011003] [Server] Finished populating Data Dictionary tables with data. 2025-01-07T04:27:19.124939Z 5 [System] [MY-013381] [Server] Server upgrade from '50700' to '80036' started. 2025-01-07T04:27:33.231723Z 5 [System] [MY-013381] [Server] Server upgrade from '50700' to '80036' completed. 2025-01-07T04:27:33.417563Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed. 2025-01-07T04:27:33.417700Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel. 2025-01-07T04:27:33.504019Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 18036, socket: /tmp/mysqlx-18036.sock 2025-01-07T04:27:33.504181Z 0 [System] [MY-010931] [Server] /home/hai.nguyen/mysql/8.0.36/bin/mysqld: ready for connections. Version: '8.0.36' socket: '/tmp/mysql_sandbox8036.sock' port: 8036 MySQL Community Server - GPL. - Run MySQL Shell dumpInstance with chunking enabled: $ mysqlsh -h 127.0.0.1 -P 8036 -u root --log-level=8 --log-file=/home/hai.nguyen/backup/log/dump.log --js -e 'util.dumpInstance("/home/hai.nguyen/backup/dump/", {"threads":4,"chunking":true,"bytesPerChunk":"128000"})' Please provide the password for 'root@127.0.0.1:8036': **** Save password for 'root@127.0.0.1:8036'? [Y]es/[N]o/Ne[v]er (default No): Acquiring global read lock Global read lock acquired Initializing - done 1 out of 5 schemas will be dumped and within them 1 table, 0 views. 8 out of 11 users will be dumped. Gathering information - done All transactions have been started Locking instance for backup Global read lock has been released Writing global DDL files Writing users DDL Running data dump using 4 threads. NOTE: Progress information uses estimated values and may not be accurate. Writing schema metadata - done Writing DDL - done Writing table metadata - done Starting data dump 4 thds chunking / 0% (0 rows / ~155.67K rows), 0.00 rows/s, 0.00 B/s uncompressed, 0.00 B/s compressed - It then run forever trying to create chunks: 2025-01-07 03:27:47: Info: ./mysqlsh Ver 8.4.0 for Linux on x86_64 - for MySQL 8.4.0 (MySQL Community Server (GPL)) - build 15032060 - commit_id 4de2d1695fdc7089e81c99dcb042953620e444fb - product_id linux-glibc2.28-x86-64bit tar-gz 2025-01-07 03:27:47: Debug2: Invoking helper 2025-01-07 03:27:47: Debug2: Command line: /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/bin/mysql-secret-store-login-path version 2025-01-07 03:27:47: Debug2: Input: 2025-01-07 03:27:47: Debug2: Output: mysql-secret-store-login-path Ver 8.4.0 for Linux on x86_64 - for MySQL 8.4.0 (MySQL Community Server (GPL)) Copyright (c) 2018, 2024, Oracle and/or its affiliates. All rights reserved. 2025-01-07 03:27:47: Debug2: Exit code: 0 2025-01-07 03:27:47: Info: Using credential store helper: /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/bin/mysql-secret-store-login-path 2025-01-07 03:27:47: Info: Setting Python home to '/home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/lib/mysqlsh' 2025-01-07 03:27:47: Info: Loading startup files... 2025-01-07 03:27:47: Debug: Searching for plugins at '/home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/lib/mysqlsh/plugins' 2025-01-07 03:27:47: Info: Loading plugins... 2025-01-07 03:27:47: Debug: - /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/lib/mysqlsh/plugins/debug/init.py 2025-01-07 03:27:47: Debug: The 'debug' extension object has been registered as a member into the 'util' extension object. 2025-01-07 03:27:47: Debug: The 'collectDiagnostics' function has been registered into the 'debug' extension object. 2025-01-07 03:27:47: Debug: The 'collectHighLoadDiagnostics' function has been registered into the 'debug' extension object. 2025-01-07 03:27:47: Debug: The 'collectSlowQueryDiagnostics' function has been registered into the 'debug' extension object. 2025-01-07 03:27:47: Debug: - /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/lib/mysqlsh/plugins/plugins_plugin/init.py 2025-01-07 03:27:47: Debug: The 'plugins' extension object has been registered as a global object. 2025-01-07 03:27:47: Debug: The 'repositories' extension object has been registered as a member into the 'plugins' extension object. 2025-01-07 03:27:47: Debug: The 'list' function has been registered into the 'repositories' extension object. 2025-01-07 03:27:47: Debug: The 'add' function has been registered into the 'repositories' extension object. 2025-01-07 03:27:47: Debug: The 'remove' function has been registered into the 'repositories' extension object. 2025-01-07 03:27:47: Debug: The 'info' function has been registered into the 'plugins' extension object. 2025-01-07 03:27:47: Debug: The 'version' function has been registered into the 'plugins' extension object. 2025-01-07 03:27:47: Debug: The 'about' function has been registered into the 'plugins' extension object. 2025-01-07 03:27:47: Debug: The 'list' function has been registered into the 'plugins' extension object. 2025-01-07 03:27:47: Debug: The 'install' function has been registered into the 'plugins' extension object. 2025-01-07 03:27:47: Debug: The 'uninstall' function has been registered into the 'plugins' extension object. 2025-01-07 03:27:47: Debug: The 'update' function has been registered into the 'plugins' extension object. 2025-01-07 03:27:47: Debug: The 'details' function has been registered into the 'plugins' extension object. 2025-01-07 03:27:47: Debug: Using color mode 2 2025-01-07 03:27:47: Debug2: Invoking helper 2025-01-07 03:27:47: Debug2: Command line: /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/bin/mysql-secret-store-login-path get 2025-01-07 03:27:47: Debug2: Input: {"SecretType":"password","ServerURL":"root@127.0.0.1:8036"} 2025-01-07 03:27:47: Debug2: Output: Could not find the secret 2025-01-07 03:27:47: Debug2: Exit code: 1 2025-01-07 03:27:49: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036 2025-01-07 03:27:49: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING 2025-01-07 03:27:49: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:49: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:49: Info: main: tid=26: CONNECTED: 127.0.0.1:8036 2025-01-07 03:27:50: Info: Now tracking 'sql_mode' system variable. 2025-01-07 03:27:50: Debug: Using prompt theme file /home/hai.nguyen/mysql-shell-8.4.0-linux-glibc2.28-x86-64bit/share/mysqlsh/prompt/prompt_256.json 2025-01-07 03:27:50: Info: Dump options: {"bytesPerChunk":"128000","chunking":true,"threads":4} 2025-01-07 03:27:50: Debug: Initializing... 2025-01-07 03:27:50: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036?max-allowed-packet=1073741824&net-read-timeout=86400000 2025-01-07 03:27:50: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING 2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:50: Info: util.dumpInstance(): tid=27: CONNECTED: 127.0.0.1:8036 2025-01-07 03:27:50: Info: Source server: 8.0.36 MySQL Community Server - GPL 2025-01-07 03:27:50: Debug: Reading roles information for user 'root'@'localhost' 2025-01-07 03:27:50: Debug: Acquiring global read lock 2025-01-07 03:27:50: Debug: Global read lock acquired 2025-01-07 03:27:50: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036?max-allowed-packet=1073741824&net-read-timeout=86400000 2025-01-07 03:27:50: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING 2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:50: Info: util.dumpInstance(): tid=28: CONNECTED: 127.0.0.1:8036 2025-01-07 03:27:50: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036?max-allowed-packet=1073741824&net-read-timeout=86400000 2025-01-07 03:27:50: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING 2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:50: Info: util.dumpInstance(): tid=29: CONNECTED: 127.0.0.1:8036 2025-01-07 03:27:50: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036?max-allowed-packet=1073741824&net-read-timeout=86400000 2025-01-07 03:27:50: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING 2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:50: Info: util.dumpInstance(): tid=30: CONNECTED: 127.0.0.1:8036 2025-01-07 03:27:50: Info: Connecting to MySQL at: mysql://root@127.0.0.1:8036?max-allowed-packet=1073741824&net-read-timeout=86400000 2025-01-07 03:27:50: Debug3: PLUGIN-TRACE-START: PluginEventHandler.CONNECTING 2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: caching_sha2_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:50: Debug3: PLUGIN-EVENT: mysql_native_password.AUTHENTICATE.AUTH_PLUGIN 2025-01-07 03:27:50: Info: util.dumpInstance(): tid=31: CONNECTED: 127.0.0.1:8036 2025-01-07 03:27:50: Info: Initializing - done, duration: 0.127594 seconds 2025-01-07 03:27:50: Debug: Gathering information... 2025-01-07 03:27:50: Debug: -> fetching version 2025-01-07 03:27:50: Debug: <- fetching version took 0.000859 seconds 2025-01-07 03:27:50: Debug: -> filtering schemas 2025-01-07 03:27:50: Debug: <- filtering schemas took 0.006534 seconds 2025-01-07 03:27:50: Debug: -> filtering tables 2025-01-07 03:27:50: Debug: -> iterating schemas 2025-01-07 03:27:50: Debug: <- iterating schemas took 0.040407 seconds 2025-01-07 03:27:50: Debug: <- filtering tables took 0.048864 seconds 2025-01-07 03:27:50: Debug: -> fetching metadata 2025-01-07 03:27:50: Debug: -> fetching ndbinfo 2025-01-07 03:27:50: Debug: <- fetching ndbinfo took 0.005840 seconds 2025-01-07 03:27:50: Debug: -> fetching server metadata 2025-01-07 03:27:50: Debug: <- fetching server metadata took 0.004274 seconds 2025-01-07 03:27:50: Debug: -> fetching view metadata 2025-01-07 03:27:50: Debug: <- fetching view metadata took 0.000000 seconds 2025-01-07 03:27:50: Debug: -> fetching columns 2025-01-07 03:27:50: Debug: -> iterating tables and views 2025-01-07 03:27:50: Debug: <- iterating tables and views took 0.007431 seconds 2025-01-07 03:27:50: Debug: <- fetching columns took 0.007516 seconds 2025-01-07 03:27:50: Debug: -> fetching table indexes 2025-01-07 03:27:50: Debug: -> iterating tables 2025-01-07 03:27:50: Debug: -> iterating tables and views 2025-01-07 03:27:50: Debug: <- iterating tables and views took 0.007509 seconds 2025-01-07 03:27:50: Debug: <- iterating tables took 0.007580 seconds 2025-01-07 03:27:50: Debug: <- fetching table indexes took 0.007617 seconds 2025-01-07 03:27:50: Debug: -> fetching table histograms 2025-01-07 03:27:50: Debug: -> iterating tables 2025-01-07 03:27:50: Debug: -> iterating tables and views 2025-01-07 03:27:50: Debug: <- iterating tables and views took 0.001316 seconds 2025-01-07 03:27:50: Debug: <- iterating tables took 0.001359 seconds 2025-01-07 03:27:50: Debug: <- fetching table histograms took 0.001388 seconds 2025-01-07 03:27:50: Debug: -> fetching table partitions 2025-01-07 03:27:50: Debug: -> iterating tables 2025-01-07 03:27:50: Debug: -> iterating tables and views 2025-01-07 03:27:50: Debug: <- iterating tables and views took 0.009139 seconds 2025-01-07 03:27:50: Debug: <- iterating tables took 0.009203 seconds 2025-01-07 03:27:50: Debug: <- fetching table partitions took 0.009239 seconds 2025-01-07 03:27:50: Debug: <- fetching metadata took 0.036203 seconds 2025-01-07 03:27:50: Debug: -> fetching users 2025-01-07 03:27:50: Debug: <- fetching users took 0.005443 seconds 2025-01-07 03:27:50: Debug: -> fetching events 2025-01-07 03:27:50: Debug: -> iterating schemas 2025-01-07 03:27:50: Debug: <- iterating schemas took 0.003273 seconds 2025-01-07 03:27:50: Debug: <- fetching events took 0.004881 seconds 2025-01-07 03:27:50: Debug: -> fetching routines 2025-01-07 03:27:50: Debug: -> iterating schemas 2025-01-07 03:27:50: Debug: <- iterating schemas took 0.004430 seconds 2025-01-07 03:27:50: Debug: <- fetching routines took 0.006941 seconds 2025-01-07 03:27:50: Debug: -> fetching triggers 2025-01-07 03:27:50: Debug: -> iterating tables 2025-01-07 03:27:50: Debug: -> iterating tables and views 2025-01-07 03:27:50: Debug: <- iterating tables and views took 0.003038 seconds 2025-01-07 03:27:50: Debug: <- iterating tables took 0.003084 seconds 2025-01-07 03:27:50: Debug: <- fetching triggers took 0.005593 seconds 2025-01-07 03:27:50: Debug: -> fetching binlog info 2025-01-07 03:27:50: Debug: <- fetching binlog info took 0.001162 seconds 2025-01-07 03:27:50: Debug: 1 out of 5 schemas will be dumped and within them 1 table, 0 views. 2025-01-07 03:27:50: Debug: 8 out of 11 users will be dumped. 2025-01-07 03:27:50: Info: Gathering information - done, duration: 0.117840 seconds 2025-01-07 03:27:50: Debug: All transactions have been started 2025-01-07 03:27:50: Debug: Locking instance for backup 2025-01-07 03:27:50: Debug: Global read lock has been released 2025-01-07 03:27:50: Debug: Writing global DDL files 2025-01-07 03:27:50: Debug: Writing users DDL 2025-01-07 03:27:50: Debug: Dumping grants for server 2025-01-07 03:27:50: Debug: Writing schema metadata... 2025-01-07 03:27:50: Debug: Writing DDL... 2025-01-07 03:27:50: Info: [Worker000]: Writing metadata for schema `test` 2025-01-07 03:27:50: Debug: Writing table metadata... 2025-01-07 03:27:50: Info: [Worker001]: Writing DDL for schema `test` 2025-01-07 03:27:50: Info: [Worker002]: Writing DDL for table `test`.`example` 2025-01-07 03:27:50: Info: Preparing data dump of table `test`.`example` 2025-01-07 03:27:50: Info: [Worker003]: Writing metadata for table `test`.`example` 2025-01-07 03:27:50: Info: The data dump of table `test`.`example` will be chunked using columns `id`,`date_created` 2025-01-07 03:27:50: Debug: Dumping table example from database test 2025-01-07 03:27:50: Debug: -- Retrieving table structure for table example... 2025-01-07 03:27:50: Debug: Dumping events for database test 2025-01-07 03:27:50: Debug: Dumping routines for database test 2025-01-07 03:27:50: Info: [Worker003]: Chunking `test`.`example` partition `p2023_06_10`, rows: 13219, average row length: 99, rows per chunk: 1292 2025-01-07 03:27:50: Info: [Worker001]: Chunking `test`.`example` partition `p2023_06_11`, rows: 13681, average row length: 96, rows per chunk: 1333 2025-01-07 03:27:50: Debug: Running data dump using 4 threads. 2025-01-07 03:27:50: Info: Progress information uses estimated values and may not be accurate. 2025-01-07 03:27:50: Debug: Dumping data... 2025-01-07 03:27:50: Info: [Worker000]: Chunking `test`.`example` partition `p2023_06_09`, rows: 0, average row length: 256, rows per chunk: 500 2025-01-07 03:27:50: Info: [Worker001]: Chunking `test`.`example` partition `p2023_06_11`, using columns: `id` (String), `date_created` (UInteger), min: [], max: [??3c?G??{yW??O???i_???K, 1686520461] 2025-01-07 03:27:50: Info: [Worker001]: Chunking `test`.`example` partition `p2023_06_11` using non-integer algorithm 2025-01-07 03:27:50: Info: [Worker003]: Chunking `test`.`example` partition `p2023_06_10`, using columns: `id` (String), `date_created` (UInteger), min: [], max: [????z???????c???N??Q?/", 1686406197] 2025-01-07 03:27:50: Info: [Worker003]: Chunking `test`.`example` partition `p2023_06_10` using non-integer algorithm 2025-01-07 03:27:50: Debug: [Worker000]: Chunking of `test`.`example` partition `p2023_06_09` took 0.002950 seconds 2025-01-07 03:27:50: Info: [Worker000]: Data dump for table `test`.`example` partition `p2023_06_09` will be written to 1 file 2025-01-07 03:27:50: Info: [Worker000]: Chunking `test`.`example` partition `p2023_06_12`, rows: 13527, average row length: 97, rows per chunk: 1319 2025-01-07 03:27:50: Info: [Worker000]: Chunking `test`.`example` partition `p2023_06_12`, using columns: `id` (String), `date_created` (UInteger), min: [], max: [???b+??2%;L?mO?? 7???*, 1686571049] 2025-01-07 03:27:50: Info: [Worker000]: Chunking `test`.`example` partition `p2023_06_12` using non-integer algorithm 2025-01-07 03:27:50: Info: [Worker002]: Chunking `test`.`example` partition `p2023_06_13`, rows: 13846, average row length: 95, rows per chunk: 1347 2025-01-07 03:27:50: Info: [Worker002]: Chunking `test`.`example` partition `p2023_06_13`, using columns: `id` (String), `date_created` (UInteger), min: [], max: [?????????+?A.?????>-?d*, 1686676293] 2025-01-07 03:27:50: Info: [Worker002]: Chunking `test`.`example` partition `p2023_06_13` using non-integer algorithm 2025-01-07 03:27:50: Info: Writing schema metadata - done, duration: 0.250109 seconds 2025-01-07 03:27:50: Info: Writing DDL - done, duration: 0.250222 seconds 2025-01-07 03:27:50: Info: Writing table metadata - done, duration: 0.250163 seconds 2025-01-07 03:27:50: Debug: Starting data dump - General log shows MySQL Shell running these chunking queries in loop: 2025-01-07T06:13:06.345952Z 14 Query SELECT SQL_NO_CACHE `col_id`,`col_date` FROM `test`.`example` PARTITION (`p_06_12`) WHERE (`col_id`>'?,KA)????5?S????x????? H' OR(`col_id`='?,KA)????5?S????x????? H' AND(`col_date`>=1686545899))) ORDER BY `col_id`,`col_date` LIMIT 1141,2 /* mysqlsh dumpInstance, chunking table `test`.`example` partition `p_06_12`, ID: 61595 */ 2025-01-07T06:13:06.355289Z 15 Query SELECT SQL_NO_CACHE `col_id`,`col_date` FROM `test`.`example` PARTITION (`p_06_11`) WHERE (`col_id`>'?^???o????p???P??????5' OR(`col_id`='?^???o????p???P??????5' AND(`col_date`>=1686528386))) ORDER BY `col_id`,`col_date` LIMIT 1121,2 /* mysqlsh dumpInstance, chunking table `test`.`example` partition `p_06_11`, ID: 60368 */