encryption.innodb-redo-nokeys 'cbc,innodb' w4 [ fail ] Found warnings/errors in server log file!
Test ended at 2022-06-02 15:22:32
line
2022-06-02 15:22:30 0 [ERROR] InnoDB: Missing FILE_CHECKPOINT at 1166935 between the checkpoint 51825 and the end 1232384.
^ Found warnings in /tmp/var/4/log/mysqld.1.err
The test is not encrypting the log; it is testing recovery of encrypted tables when the keys are missing.
Marko Mäkelä
added a comment - Even after this fix, we got a failure on FreeBSD 13.0 that I was not able to repeat:
In a FreeBSD 13.0 virtual machine with a CMAKE_BUILD_TYPE=RelWithDebInfo build
On Linux (liburing or innodb_use_native_aio=0 ) on ext4fs on NVMe, both CMAKE_BUILD_TYPE=Debug and CMAKE_BUILD_TYPE=RelWithDebInfo
The failure looks like this:
10.6 8920a6f80b91592f3bb072d0707ff21362702144
encryption.tempfiles_encrypted 'ctr,innodb' w4 [ pass ] 20339
worker[4] > Restart [mysqld.1 - pid: 9200, winpid: 9200] - running with different options '--innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --innodb-lock-waits --innodb-metrics --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --innodb-sys-columns --innodb-sys-fields --innodb-sys-foreign --innodb-sys-foreign-cols --innodb-sys-indexes --innodb-sys-tables --innodb-sys-virtual --plugin-load-add=file_key_management.so --loose-file-key-management --loose-file-key-management-filename=/usr/local/share/mysql-test/std_data/keys.txt --file-key-management-encryption-algorithm=aes_cbc --skip-innodb-read-only-compressed --innodb-change-buffering=none --innodb-default-encryption-key-id=20' != '--innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --innodb-lock-waits --innodb-metrics --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --innodb-sys-columns --innodb-sys-fields --innodb-sys-foreign --innodb-sys-foreign-cols --innodb-sys-indexes --innodb-sys-tables --innodb-sys-virtual --plugin-load-add=file_key_management.so --loose-file-key-management --loose-file-key-management-filename=/usr/local/share/mysql-test/std_data/keys.txt --file-key-management-encryption-algorithm=aes_ctr --skip-innodb-read-only-compressed --loose-sequence --loose-sequence --encrypt-tmp_files=ON'
…
encryption.innodb-redo-nokeys 'cbc,innodb' w4 [ fail ] Found warnings/errors in server log file!
Test ended at 2022-06-02 15:22:32
line
2022-06-02 15:22:30 0 [ERROR] InnoDB: Missing FILE_CHECKPOINT at 1166935 between the checkpoint 51825 and the end 1232384.
^ Found warnings in /tmp/var/4/log/mysqld.1.err
The test is not encrypting the log; it is testing recovery of encrypted tables when the keys are missing.
People
Marko Mäkelä
Marko Mäkelä
Votes:
0Vote for this issue
Watchers:
1Start watching this issue
Dates
Created:
Updated:
Resolved:
Git Integration
Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.
{"report":{"fcp":1927,"ttfb":548.6999998092651,"pageVisibility":"visible","entityId":111532,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":64,"apdex":0.5,"journeyId":"376cdf63-d6b1-42b4-bca1-0e6405a11b96","navigationType":0,"readyForUser":2010.5999999046326,"redirectCount":0,"resourceLoadedEnd":2418.699999809265,"resourceLoadedStart":555.6999998092651,"resourceTiming":[{"duration":778.7000002861023,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":555.6999998092651,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":555.6999998092651,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1334.4000000953674,"responseStart":0,"secureConnectionStart":0},{"duration":778.6999998092651,"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":555.9000000953674,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":555.9000000953674,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1334.5999999046326,"responseStart":0,"secureConnectionStart":0},{"duration":786.8000001907349,"initiatorType":"script","name":"https://jira.mariadb.org/s/0917945aaa57108d00c5076fea35e069-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":556.0999999046326,"connectEnd":556.0999999046326,"connectStart":556.0999999046326,"domainLookupEnd":556.0999999046326,"domainLookupStart":556.0999999046326,"fetchStart":556.0999999046326,"redirectEnd":0,"redirectStart":0,"requestStart":556.0999999046326,"responseEnd":1342.9000000953674,"responseStart":1342.9000000953674,"secureConnectionStart":556.0999999046326},{"duration":845.1000003814697,"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":556.2999997138977,"connectEnd":556.2999997138977,"connectStart":556.2999997138977,"domainLookupEnd":556.2999997138977,"domainLookupStart":556.2999997138977,"fetchStart":556.2999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":556.2999997138977,"responseEnd":1401.4000000953674,"responseStart":1401.4000000953674,"secureConnectionStart":556.2999997138977},{"duration":848.3000001907349,"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":556.5999999046326,"connectEnd":556.5999999046326,"connectStart":556.5999999046326,"domainLookupEnd":556.5999999046326,"domainLookupStart":556.5999999046326,"fetchStart":556.5999999046326,"redirectEnd":0,"redirectStart":0,"requestStart":556.5999999046326,"responseEnd":1404.9000000953674,"responseStart":1404.9000000953674,"secureConnectionStart":556.5999999046326},{"duration":848.9000000953674,"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":556.6999998092651,"connectEnd":556.6999998092651,"connectStart":556.6999998092651,"domainLookupEnd":556.6999998092651,"domainLookupStart":556.6999998092651,"fetchStart":556.6999998092651,"redirectEnd":0,"redirectStart":0,"requestStart":556.6999998092651,"responseEnd":1405.5999999046326,"responseStart":1405.5999999046326,"secureConnectionStart":556.6999998092651},{"duration":849.1999998092651,"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":556.9000000953674,"connectEnd":556.9000000953674,"connectStart":556.9000000953674,"domainLookupEnd":556.9000000953674,"domainLookupStart":556.9000000953674,"fetchStart":556.9000000953674,"redirectEnd":0,"redirectStart":0,"requestStart":556.9000000953674,"responseEnd":1406.0999999046326,"responseStart":1406,"secureConnectionStart":556.9000000953674},{"duration":966.5,"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":557,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":557,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1523.5,"responseStart":0,"secureConnectionStart":0},{"duration":849.4000000953674,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":557.1999998092651,"connectEnd":557.1999998092651,"connectStart":557.1999998092651,"domainLookupEnd":557.1999998092651,"domainLookupStart":557.1999998092651,"fetchStart":557.1999998092651,"redirectEnd":0,"redirectStart":0,"requestStart":557.1999998092651,"responseEnd":1406.5999999046326,"responseStart":1406.5999999046326,"secureConnectionStart":557.1999998092651},{"duration":966.2999997138977,"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":557.4000000953674,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":557.4000000953674,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1523.6999998092651,"responseStart":0,"secureConnectionStart":0},{"duration":850.0999999046326,"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":557.5,"connectEnd":557.5,"connectStart":557.5,"domainLookupEnd":557.5,"domainLookupStart":557.5,"fetchStart":557.5,"redirectEnd":0,"redirectStart":0,"requestStart":557.5,"responseEnd":1407.5999999046326,"responseStart":1407.5999999046326,"secureConnectionStart":557.5},{"duration":1618.9000000953674,"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":558.5,"connectEnd":558.5,"connectStart":558.5,"domainLookupEnd":558.5,"domainLookupStart":558.5,"fetchStart":558.5,"redirectEnd":0,"redirectStart":0,"requestStart":558.5,"responseEnd":2177.4000000953674,"responseStart":2177.4000000953674,"secureConnectionStart":558.5},{"duration":1860.1999998092651,"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":558.5,"connectEnd":558.5,"connectStart":558.5,"domainLookupEnd":558.5,"domainLookupStart":558.5,"fetchStart":558.5,"redirectEnd":0,"redirectStart":0,"requestStart":558.5,"responseEnd":2418.699999809265,"responseStart":2418.699999809265,"secureConnectionStart":558.5},{"duration":673.6999998092651,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":1537,"connectEnd":1537,"connectStart":1537,"domainLookupEnd":1537,"domainLookupStart":1537,"fetchStart":1537,"redirectEnd":0,"redirectStart":0,"requestStart":1537,"responseEnd":2210.699999809265,"responseStart":2210.699999809265,"secureConnectionStart":1537},{"duration":529.0999999046326,"initiatorType":"script","name":"https://www.google-analytics.com/analytics.js","startTime":1920.1999998092651,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":1920.1999998092651,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":2449.2999997138977,"responseStart":0,"secureConnectionStart":0}],"fetchStart":0,"domainLookupStart":0,"domainLookupEnd":0,"connectStart":0,"connectEnd":0,"requestStart":355,"responseStart":549,"responseEnd":551,"domLoading":553,"domInteractive":2453,"domContentLoadedEventStart":2453,"domContentLoadedEventEnd":2508,"domComplete":3156,"loadEventStart":3156,"loadEventEnd":3157,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":2421.7999997138977},{"name":"bigPipe.sidebar-id.end","time":2422.699999809265},{"name":"bigPipe.activity-panel-pipe-id.start","time":2422.9000000953674},{"name":"bigPipe.activity-panel-pipe-id.end","time":2426.0999999046326},{"name":"activityTabFullyLoaded","time":2519.7999997138977}],"measures":[],"correlationId":"ba42843801c769","effectiveType":"4g","downlink":9.8,"rtt":0,"serverDuration":132,"dbReadsTimeInMs":22,"dbConnsTimeInMs":32,"applicationHash":"9d11dbea5f4be3d4cc21f03a88dd11d8c8687422","experiments":[]}}
Bug
Major
MDEV-12353 Efficient InnoDB redo log record format
Even after this fix, we got a failure on FreeBSD 13.0 that I was not able to repeat:
The failure looks like this:
10.6 8920a6f80b91592f3bb072d0707ff21362702144
encryption.tempfiles_encrypted 'ctr,innodb' w4 [ pass ] 20339worker[4] > Restart [mysqld.1 - pid: 9200, winpid: 9200] - running with different options '--innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --innodb-lock-waits --innodb-metrics --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --innodb-sys-columns --innodb-sys-fields --innodb-sys-foreign --innodb-sys-foreign-cols --innodb-sys-indexes --innodb-sys-tables --innodb-sys-virtual --plugin-load-add=file_key_management.so --loose-file-key-management --loose-file-key-management-filename=/usr/local/share/mysql-test/std_data/keys.txt --file-key-management-encryption-algorithm=aes_cbc --skip-innodb-read-only-compressed --innodb-change-buffering=none --innodb-default-encryption-key-id=20' != '--innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --innodb-lock-waits --innodb-metrics --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --innodb-sys-columns --innodb-sys-fields --innodb-sys-foreign --innodb-sys-foreign-cols --innodb-sys-indexes --innodb-sys-tables --innodb-sys-virtual --plugin-load-add=file_key_management.so --loose-file-key-management --loose-file-key-management-filename=/usr/local/share/mysql-test/std_data/keys.txt --file-key-management-encryption-algorithm=aes_ctr --skip-innodb-read-only-compressed --loose-sequence --loose-sequence --encrypt-tmp_files=ON'…encryption.innodb-redo-nokeys 'cbc,innodb' w4 [ fail ] Found warnings/errors in server log file!Test ended at 2022-06-02 15:22:32line2022-06-02 15:22:30 0 [ERROR] InnoDB: Missing FILE_CHECKPOINT at 1166935 between the checkpoint 51825 and the end 1232384.^ Found warnings in /tmp/var/4/log/mysqld.1.errThe test is not encrypting the log; it is testing recovery of encrypted tables when the keys are missing.