The test mariabackup.huge_lsn that was rewritten in MDEV-14425 often fails, mostly on the amd64-windows builder, but occasionally also on Linux. I was able to reproduce the failure on a local ASAN build with the following simplification (disabling encryption for easier analysis):
diff --git a/mysql-test/suite/mariabackup/huge_lsn.opt b/mysql-test/suite/mariabackup/huge_lsn.opt
|
deleted file mode 100644
|
index c65b76fb7d2..00000000000
|
--- a/mysql-test/suite/mariabackup/huge_lsn.opt
|
+++ /dev/null
|
@@ -1,10 +0,0 @@
|
---innodb-encrypt-log=ON
|
---innodb-tablespaces-encryption
|
---innodb-encrypt-tables=ON
|
---innodb-encryption-rotate-key-age=1
|
---innodb-encryption-threads=4
|
---plugin-load-add=$FILE_KEY_MANAGEMENT_SO
|
---loose-file-key-management
|
---loose-file-key-management-filekey=FILE:$MTR_SUITE_DIR/filekeys-data.key
|
---loose-file-key-management-filename=$MTR_SUITE_DIR/filekeys-data.enc
|
---loose-file-key-management-encryption-algorithm=aes_cbc
|
diff --git a/mysql-test/suite/mariabackup/huge_lsn.result b/mysql-test/suite/mariabackup/huge_lsn.result
|
index 503d13fcac4..bc8c9b7a1ab 100644
|
--- a/mysql-test/suite/mariabackup/huge_lsn.result
|
+++ b/mysql-test/suite/mariabackup/huge_lsn.result
|
@@ -1,9 +1,9 @@
|
#
|
# MDEV-13416 mariabackup fails with EFAULT "Bad Address"
|
#
|
-# restart: --innodb-log-file-size=4M --innodb-encrypt-log=0
|
+# restart: --innodb-log-file-size=4M
|
FOUND 1 /InnoDB: log sequence number 17596481011216/ in mysqld.1.err
|
-CREATE TABLE t(i INT) ENGINE=INNODB ENCRYPTED=YES;
|
+CREATE TABLE t(i INT) ENGINE=INNODB;
|
INSERT INTO t VALUES(1);
|
# xtrabackup backup
|
SET GLOBAL innodb_flush_log_at_trx_commit=1;
|
diff --git a/mysql-test/suite/mariabackup/huge_lsn.test b/mysql-test/suite/mariabackup/huge_lsn.test
|
index 8850e9d8954..84702bcfdef 100644
|
--- a/mysql-test/suite/mariabackup/huge_lsn.test
|
+++ b/mysql-test/suite/mariabackup/huge_lsn.test
|
@@ -1,5 +1,4 @@
|
--source include/not_embedded.inc
|
---source include/have_file_key_management.inc
|
|
--echo #
|
--echo # MDEV-13416 mariabackup fails with EFAULT "Bad Address"
|
@@ -66,14 +65,14 @@ print FILE $extra;
|
close(FILE) or die "Unable to close $file\n";
|
EOF
|
--let SEARCH_PATTERN= InnoDB: log sequence number 17596481011216
|
---let $restart_parameters=--innodb-log-file-size=4M --innodb-encrypt-log=0
|
+--let $restart_parameters=--innodb-log-file-size=4M
|
}
|
|
--source include/start_mysqld.inc
|
let SEARCH_FILE= $MYSQLTEST_VARDIR/log/mysqld.1.err;
|
--source include/search_pattern_in_file.inc
|
|
-CREATE TABLE t(i INT) ENGINE=INNODB ENCRYPTED=YES;
|
+CREATE TABLE t(i INT) ENGINE=INNODB;
|
INSERT INTO t VALUES(1);
|
|
echo # xtrabackup backup;
|
@@ -85,6 +84,7 @@ SET GLOBAL innodb_flush_log_at_trx_commit=1;
|
INSERT INTO t VALUES(2);
|
echo # xtrabackup prepare;
|
--disable_result_log
|
+exec tar cJf $MYSQLTEST_VARDIR/targetdir.tar.xz $targetdir/
|
exec $XTRABACKUP --prepare --target-dir=$targetdir;
|
--let $restart_parameters=
|
--source include/restart_and_restore.inc
|
The test would not fail in a non-ASAN build for me. targetdir.tar.xz
is a copy of a database that was restored incorrectly. Actually, I had run the --backup command under rr record, because I was anticipating an error there. But the backed up log seems to be fine. The relevant part from the backup output (only available via rr replay) is:
|
10.10 63961a08a6203f4d58363a9321e4cf9c8b07a9fe
|
[00] 2022-06-29 11:13:25 Redo log (from LSN 17596478913900 to 17596481013381) was copied.
|
[00] 2022-06-29 11:13:25 completed OK!
|
The ib_logfile0 in targetdir.tar.xz indeed contains the artificially generated records for c/d.ibd, a/b.ibd as well as the records for creating and initializing the file test/t.ibd. The test failure output contains the following:
|
10.10 63961a08a6203f4d58363a9321e4cf9c8b07a9fe
|
CURRENT_TEST: mariabackup.huge_lsn
|
tar: Removing leading `/' from member names
|
/dev/shm/10.10a/extra/mariabackup/mariabackup based on MariaDB server 10.10.0-MariaDB Linux (x86_64)
|
[01] 2022-06-29 11:13:32 Copying ib_logfile0 to /dev/shm/10.10a/mysql-test/var/22/mysqld.1/data/ib_logfile0
|
[01] 2022-06-29 11:13:32 ...done
|
…
|
[01] 2022-06-29 11:13:33 Copying ./mysql/transaction_registry.ibd to /dev/shm/10.10a/mysql-test/var/22/mysqld.1/data/mysql/transaction_registry.ibd
|
[01] 2022-06-29 11:13:33 ...done
|
[01] 2022-06-29 11:13:33 Copying ib_buffer_pool to /dev/shm/10.10a/mysql-test/var/22/mysqld.1/data/ib_buffer_pool
|
[01] 2022-06-29 11:13:33 ...done
|
[00] 2022-06-29 11:13:33 completed OK!
|
mysqltest: At line 92: query 'SELECT * FROM t' failed: ER_TABLE_CORRUPT (1877): Table test/t is corrupted. Please drop the table and recreate.
|
There was no message about applying any log. The log was replaced with a dummy one that only represents the end LSN of the backup:
000000 50 68 79 73 00 00 00 00 00 00 10 01 00 00 06 85
|
000010 4d 61 72 69 61 44 42 20 31 30 2e 31 30 2e 30 00
|
000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
*
|
0001f0 00 00 00 00 00 00 00 00 00 00 00 00 41 17 f5 8a
|
000200 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
*
|
002000 00 00 10 01 00 00 06 85 00 00 10 01 00 00 06 85
|
002010 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
*
|
002030 00 00 00 00 00 00 00 00 00 00 00 00 d7 50 d3 b5
|
002040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
*
|
003000 fa 00 00 00 00 10 01 00 00 06 85 01 79 77 29 c7
|
003010 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
*
|
a00000
|
Because the first page of test/t.ibd was all-zero at the time it was backed up, the subsequent server startup (and the SELECT statement) would fail due to this:
|
10.10 63961a08a6203f4d58363a9321e4cf9c8b07a9fe
|
2022-06-29 11:13:33 0 [ERROR] InnoDB: Expected tablespace id 5 but found 0 in the file ./test/t.ibd
|
2022-06-29 11:13:33 0 [Note] Server socket created on IP: '127.0.0.1'.
|
2022-06-29 11:13:33 0 [Note] /dev/shm/10.10a/sql/mariadbd: ready for connections.
|
Version: '10.10.0-MariaDB-debug-log' socket: '/dev/shm/10.10a/mysql-test/var/tmp/22/mysqld.1.sock' port: 16420 Source distribution
|
2022-06-29 11:13:33 3 [ERROR] mariadbd: Table test/t is corrupted. Please drop the table and recreate.
|
{"report":{"fcp":1012.2000000476837,"ttfb":325.8000000715256,"pageVisibility":"visible","entityId":112343,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":64,"apdex":0.5,"journeyId":"19055016-230c-4381-92aa-823c7945d682","navigationType":0,"readyForUser":1160.8000000715256,"redirectCount":0,"resourceLoadedEnd":1052.5,"resourceLoadedStart":333.2000000476837,"resourceTiming":[{"duration":140.5,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":333.2000000476837,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":333.2000000476837,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":473.7000000476837,"responseStart":0,"secureConnectionStart":0},{"duration":141.39999997615814,"initiatorType":"link","name":"https://jira.mariadb.org/s/7ebd35e77e471bc30ff0eba799ebc151-CDN/lu2cib/820016/12ta74/494e4c556ecbb29f90a3d3b4f09cb99c/_/download/contextbatch/css/jira.browse.project,project.issue.navigator,jira.view.issue,jira.general,jira.global,atl.general,-_super/batch.css?agile_global_admin_condition=true&jag=true&jira.create.linked.issue=true&slack-enabled=true&whisper-enabled=true","startTime":333.5,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":333.5,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":474.89999997615814,"responseStart":0,"secureConnectionStart":0},{"duration":201.19999992847443,"initiatorType":"script","name":"https://jira.mariadb.org/s/0917945aaa57108d00c5076fea35e069-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":333.7000000476837,"connectEnd":333.7000000476837,"connectStart":333.7000000476837,"domainLookupEnd":333.7000000476837,"domainLookupStart":333.7000000476837,"fetchStart":333.7000000476837,"redirectEnd":0,"redirectStart":0,"requestStart":333.7000000476837,"responseEnd":534.8999999761581,"responseStart":534.8999999761581,"secureConnectionStart":333.7000000476837},{"duration":307.10000002384186,"initiatorType":"script","name":"https://jira.mariadb.org/s/2d8175ec2fa4c816e8023260bd8c1786-CDN/lu2cib/820016/12ta74/494e4c556ecbb29f90a3d3b4f09cb99c/_/download/contextbatch/js/jira.browse.project,project.issue.navigator,jira.view.issue,jira.general,jira.global,atl.general,-_super/batch.js?agile_global_admin_condition=true&jag=true&jira.create.linked.issue=true&locale=en&slack-enabled=true&whisper-enabled=true","startTime":333.89999997615814,"connectEnd":333.89999997615814,"connectStart":333.89999997615814,"domainLookupEnd":333.89999997615814,"domainLookupStart":333.89999997615814,"fetchStart":333.89999997615814,"redirectEnd":0,"redirectStart":0,"requestStart":333.89999997615814,"responseEnd":641,"responseStart":641,"secureConnectionStart":333.89999997615814},{"duration":310.7999999523163,"initiatorType":"script","name":"https://jira.mariadb.org/s/a9324d6758d385eb45c462685ad88f1d-CDN/lu2cib/820016/12ta74/c92c0caa9a024ae85b0ebdbed7fb4bd7/_/download/contextbatch/js/atl.global,-_super/batch.js?locale=en","startTime":334.10000002384186,"connectEnd":334.10000002384186,"connectStart":334.10000002384186,"domainLookupEnd":334.10000002384186,"domainLookupStart":334.10000002384186,"fetchStart":334.10000002384186,"redirectEnd":0,"redirectStart":0,"requestStart":334.10000002384186,"responseEnd":644.8999999761581,"responseStart":644.8999999761581,"secureConnectionStart":334.10000002384186},{"duration":311,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2cib/820016/12ta74/1.0/_/download/batch/jira.webresources:calendar-en/jira.webresources:calendar-en.js","startTime":334.3000000715256,"connectEnd":334.3000000715256,"connectStart":334.3000000715256,"domainLookupEnd":334.3000000715256,"domainLookupStart":334.3000000715256,"fetchStart":334.3000000715256,"redirectEnd":0,"redirectStart":0,"requestStart":334.3000000715256,"responseEnd":645.3000000715256,"responseStart":645.3000000715256,"secureConnectionStart":334.3000000715256},{"duration":311.5,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2cib/820016/12ta74/1.0/_/download/batch/jira.webresources:calendar-localisation-moment/jira.webresources:calendar-localisation-moment.js","startTime":334.5,"connectEnd":334.5,"connectStart":334.5,"domainLookupEnd":334.5,"domainLookupStart":334.5,"fetchStart":334.5,"redirectEnd":0,"redirectStart":0,"requestStart":334.5,"responseEnd":646,"responseStart":646,"secureConnectionStart":334.5},{"duration":344.39999997615814,"initiatorType":"link","name":"https://jira.mariadb.org/s/b04b06a02d1959df322d9cded3aeecc1-CDN/lu2cib/820016/12ta74/a2ff6aa845ffc9a1d22fe23d9ee791fc/_/download/contextbatch/css/jira.global.look-and-feel,-_super/batch.css","startTime":334.7000000476837,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":334.7000000476837,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":679.1000000238419,"responseStart":0,"secureConnectionStart":0},{"duration":311.90000009536743,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":334.89999997615814,"connectEnd":334.89999997615814,"connectStart":334.89999997615814,"domainLookupEnd":334.89999997615814,"domainLookupStart":334.89999997615814,"fetchStart":334.89999997615814,"redirectEnd":0,"redirectStart":0,"requestStart":334.89999997615814,"responseEnd":646.8000000715256,"responseStart":646.8000000715256,"secureConnectionStart":334.89999997615814},{"duration":344.3000000715256,"initiatorType":"link","name":"https://jira.mariadb.org/s/3ac36323ba5e4eb0af2aa7ac7211b4bb-CDN/lu2cib/820016/12ta74/d176f0986478cc64f24226b3d20c140d/_/download/contextbatch/css/com.atlassian.jira.projects.sidebar.init,-_super,-project.issue.navigator,-jira.view.issue/batch.css?jira.create.linked.issue=true","startTime":335,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":335,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":679.3000000715256,"responseStart":0,"secureConnectionStart":0},{"duration":312.2999999523163,"initiatorType":"script","name":"https://jira.mariadb.org/s/5d5e8fe91fbc506585e83ea3b62ccc4b-CDN/lu2cib/820016/12ta74/d176f0986478cc64f24226b3d20c140d/_/download/contextbatch/js/com.atlassian.jira.projects.sidebar.init,-_super,-project.issue.navigator,-jira.view.issue/batch.js?jira.create.linked.issue=true&locale=en","startTime":335.10000002384186,"connectEnd":335.10000002384186,"connectStart":335.10000002384186,"domainLookupEnd":335.10000002384186,"domainLookupStart":335.10000002384186,"fetchStart":335.10000002384186,"redirectEnd":0,"redirectStart":0,"requestStart":335.10000002384186,"responseEnd":647.3999999761581,"responseStart":647.3999999761581,"secureConnectionStart":335.10000002384186},{"duration":493.59999990463257,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2cib/820016/12ta74/1.0/_/download/batch/jira.webresources:bigpipe-js/jira.webresources:bigpipe-js.js","startTime":336.3000000715256,"connectEnd":336.3000000715256,"connectStart":336.3000000715256,"domainLookupEnd":336.3000000715256,"domainLookupStart":336.3000000715256,"fetchStart":336.3000000715256,"redirectEnd":0,"redirectStart":0,"requestStart":336.3000000715256,"responseEnd":829.8999999761581,"responseStart":829.8999999761581,"secureConnectionStart":336.3000000715256},{"duration":679.7000000476837,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2cib/820016/12ta74/1.0/_/download/batch/jira.webresources:bigpipe-init/jira.webresources:bigpipe-init.js","startTime":336.39999997615814,"connectEnd":336.39999997615814,"connectStart":336.39999997615814,"domainLookupEnd":336.39999997615814,"domainLookupStart":336.39999997615814,"fetchStart":336.39999997615814,"redirectEnd":0,"redirectStart":0,"requestStart":336.39999997615814,"responseEnd":1016.1000000238419,"responseStart":1016.1000000238419,"secureConnectionStart":336.39999997615814},{"duration":141.39999997615814,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":691.1000000238419,"connectEnd":691.1000000238419,"connectStart":691.1000000238419,"domainLookupEnd":691.1000000238419,"domainLookupStart":691.1000000238419,"fetchStart":691.1000000238419,"redirectEnd":0,"redirectStart":0,"requestStart":691.1000000238419,"responseEnd":832.5,"responseStart":832.3999999761581,"secureConnectionStart":691.1000000238419},{"duration":100.29999995231628,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2cib/820016/12ta74/e65b778d185daf5aee24936755b43da6/_/download/contextbatch/js/browser-metrics-plugin.contrib,-_super,-atl.general/batch.js?agile_global_admin_condition=true&jag=true&slack-enabled=true&whisper-enabled=true","startTime":952.2000000476837,"connectEnd":952.2000000476837,"connectStart":952.2000000476837,"domainLookupEnd":952.2000000476837,"domainLookupStart":952.2000000476837,"fetchStart":952.2000000476837,"redirectEnd":0,"redirectStart":0,"requestStart":952.2000000476837,"responseEnd":1052.5,"responseStart":1052.5,"secureConnectionStart":952.2000000476837},{"duration":206,"initiatorType":"script","name":"https://www.google-analytics.com/analytics.js","startTime":1006.3999999761581,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":1006.3999999761581,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1212.3999999761581,"responseStart":0,"secureConnectionStart":0}],"fetchStart":0,"domainLookupStart":0,"domainLookupEnd":0,"connectStart":0,"connectEnd":0,"requestStart":142,"responseStart":325,"responseEnd":327,"domLoading":329,"domInteractive":1229,"domContentLoadedEventStart":1229,"domContentLoadedEventEnd":1275,"domComplete":1878,"loadEventStart":1878,"loadEventEnd":1880,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":1217.2000000476837},{"name":"bigPipe.sidebar-id.end","time":1218},{"name":"bigPipe.activity-panel-pipe-id.start","time":1218.2000000476837},{"name":"bigPipe.activity-panel-pipe-id.end","time":1220.8999999761581},{"name":"activityTabFullyLoaded","time":1293.8000000715256}],"measures":[],"correlationId":"af83aa420e6d39","effectiveType":"4g","downlink":9.1,"rtt":0,"serverDuration":107,"dbReadsTimeInMs":15,"dbConnsTimeInMs":24,"applicationHash":"9d11dbea5f4be3d4cc21f03a88dd11d8c8687422","experiments":[]}}
Bug
Blocker
MDEV-14425 Change the InnoDB redo log format to reduce write amplification