Type:
Bug
Priority:
Major
Resolution:
Fixed
Affects Version/s:
11.4
The following failure does not look like an actual error:
11.4 d2c9d86ed9465c814f7cbc29eaeb73274f550c5b
innodb.blob-crash '16k' w4 [ fail ] Found warnings/errors in server log file!
Test ended at 2024-05-22 15:26:23
line
2024-05-22 15:26:14 0 [ERROR] InnoDB: Checksum mismatch in the first page of file .//undo001
^ Found warnings in /home/buildbot/amd64-debian-sid/build/mysql-test/var/4/log/mysqld.1.err
In the error log we have the following:
11.4 d2c9d86ed9465c814f7cbc29eaeb73274f550c5b
2024-05-22 15:26:14 0 [Note] InnoDB: Using AVX512 instructions
2024-05-22 15:26:14 0 [Note] InnoDB: Using liburing
2024-05-22 15:26:14 0 [Note] InnoDB: Initializing buffer pool, total size = 8.000MiB, chunk size = 1.000MiB
2024-05-22 15:26:14 0 [Note] InnoDB: Completed initialization of buffer pool
2024-05-22 15:26:14 0 [ERROR] InnoDB: Checksum mismatch in the first page of file .//undo001
2024-05-22 15:26:14 0 [Note] InnoDB: Restoring page [page id: space=1, page number=0] of datafile './/undo001' from the doublewrite buffer. Writing 16384 bytes into file './/undo001'
2024-05-22 15:26:14 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=79160
2024-05-22 15:26:14 0 [Note] InnoDB: Multi-batch recovery needed at LSN 2104096
2024-05-22 15:26:14 0 [Note] InnoDB: End of log at LSN=4347308
2024-05-22 15:26:14 0 [Note] InnoDB: To recover: LSN 2104096/4347308; 189 pages
2024-05-22 15:26:14 0 [Note] InnoDB: To recover: LSN 4120277/4347308; 127 pages
2024-05-22 15:26:14 0 [Note] InnoDB: To recover: 18 pages
2024-05-22 15:26:14 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 1 row operations to undo
2024-05-22 15:26:14 0 [Note] InnoDB: Trx id counter is 133
2024-05-22 15:26:14 0 [Note] InnoDB: Opened 3 undo tablespaces
2024-05-22 15:26:14 0 [Note] InnoDB: 128 rollback segments in 3 undo tablespaces are active.
2024-05-22 15:26:14 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
2024-05-22 15:26:14 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
2024-05-22 15:26:14 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
2024-05-22 15:26:14 0 [Note] InnoDB: Rolled back recovered transaction 131
2024-05-22 15:26:14 0 [Note] InnoDB: Rollback of non-prepared transactions completed
2024-05-22 15:26:14 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
2024-05-22 15:26:14 0 [Note] InnoDB: log sequence number 4347308 (memory-mapped); transaction id 135
So, everything recovered just fine, and there is no need to scare users with that ERROR message. The Note InnoDB: Restoring page would have been enough. Only if the page could be restored from the doublewrite buffer, it should be reported as an error.
relates to
MDEV-11770
innodb.group_commit_crash_no_optimize_thread, innodb.group_commit_crash failed in buildbot
Open
{"report":{"fcp":946.3000001907349,"ttfb":281.40000009536743,"pageVisibility":"visible","entityId":129256,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":64,"apdex":0.5,"journeyId":"72d2dccc-621f-4126-a60a-2917cbe482f6","navigationType":0,"readyForUser":1153.8000001907349,"redirectCount":0,"resourceLoadedEnd":844.7000002861023,"resourceLoadedStart":289.59999990463257,"resourceTiming":[{"duration":41.10000038146973,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":289.59999990463257,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":289.59999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":330.7000002861023,"responseStart":0,"secureConnectionStart":0},{"duration":41.40000009536743,"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":289.80000019073486,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":289.80000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":331.2000002861023,"responseStart":0,"secureConnectionStart":0},{"duration":157.40000009536743,"initiatorType":"script","name":"https://jira.mariadb.org/s/0917945aaa57108d00c5076fea35e069-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":290,"connectEnd":290,"connectStart":290,"domainLookupEnd":290,"domainLookupStart":290,"fetchStart":290,"redirectEnd":0,"redirectStart":0,"requestStart":369.90000009536743,"responseEnd":447.40000009536743,"responseStart":392.30000019073486,"secureConnectionStart":290},{"duration":190.7999997138977,"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":290.30000019073486,"connectEnd":290.30000019073486,"connectStart":290.30000019073486,"domainLookupEnd":290.30000019073486,"domainLookupStart":290.30000019073486,"fetchStart":290.30000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":359.5,"responseEnd":481.09999990463257,"responseStart":396.40000009536743,"secureConnectionStart":290.30000019073486},{"duration":101.69999980926514,"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":290.40000009536743,"connectEnd":290.40000009536743,"connectStart":290.40000009536743,"domainLookupEnd":290.40000009536743,"domainLookupStart":290.40000009536743,"fetchStart":290.40000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":374.09999990463257,"responseEnd":392.09999990463257,"responseStart":391.40000009536743,"secureConnectionStart":290.40000009536743},{"duration":107.10000038146973,"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":290.59999990463257,"connectEnd":290.59999990463257,"connectStart":290.59999990463257,"domainLookupEnd":290.59999990463257,"domainLookupStart":290.59999990463257,"fetchStart":290.59999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":376.90000009536743,"responseEnd":397.7000002861023,"responseStart":397.09999990463257,"secureConnectionStart":290.59999990463257},{"duration":102.7999997138977,"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":290.7000002861023,"connectEnd":290.7000002861023,"connectStart":290.7000002861023,"domainLookupEnd":290.7000002861023,"domainLookupStart":290.7000002861023,"fetchStart":290.7000002861023,"redirectEnd":0,"redirectStart":0,"requestStart":376.59999990463257,"responseEnd":393.5,"responseStart":393,"secureConnectionStart":290.7000002861023},{"duration":63.69999980926514,"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":290.90000009536743,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":290.90000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":354.59999990463257,"responseStart":0,"secureConnectionStart":0},{"duration":103.90000009536743,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":291.09999990463257,"connectEnd":291.09999990463257,"connectStart":291.09999990463257,"domainLookupEnd":291.09999990463257,"domainLookupStart":291.09999990463257,"fetchStart":291.09999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":377.2000002861023,"responseEnd":395,"responseStart":394.40000009536743,"secureConnectionStart":291.09999990463257},{"duration":64.90000009536743,"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":291.30000019073486,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":291.30000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":356.2000002861023,"responseStart":0,"secureConnectionStart":0},{"duration":104.90000009536743,"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":291.40000009536743,"connectEnd":291.40000009536743,"connectStart":291.40000009536743,"domainLookupEnd":291.40000009536743,"domainLookupStart":291.40000009536743,"fetchStart":291.40000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":377.2000002861023,"responseEnd":396.30000019073486,"responseStart":395.09999990463257,"secureConnectionStart":291.40000009536743},{"duration":544,"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":300.5,"connectEnd":300.5,"connectStart":300.5,"domainLookupEnd":300.5,"domainLookupStart":300.5,"fetchStart":300.5,"redirectEnd":0,"redirectStart":0,"requestStart":709.0999999046326,"responseEnd":844.5,"responseStart":840.2000002861023,"secureConnectionStart":300.5},{"duration":544.2000002861023,"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":300.5,"connectEnd":300.5,"connectStart":300.5,"domainLookupEnd":300.5,"domainLookupStart":300.5,"fetchStart":300.5,"redirectEnd":0,"redirectStart":0,"requestStart":713.3000001907349,"responseEnd":844.7000002861023,"responseStart":840.9000000953674,"secureConnectionStart":300.5},{"duration":242.80000019073486,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":649.9000000953674,"connectEnd":649.9000000953674,"connectStart":649.9000000953674,"domainLookupEnd":649.9000000953674,"domainLookupStart":649.9000000953674,"fetchStart":649.9000000953674,"redirectEnd":0,"redirectStart":0,"requestStart":859.3000001907349,"responseEnd":892.7000002861023,"responseStart":892,"secureConnectionStart":649.9000000953674},{"duration":285.19999980926514,"initiatorType":"script","name":"https://www.google-analytics.com/analytics.js","startTime":938.3000001907349,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":938.3000001907349,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1223.5,"responseStart":0,"secureConnectionStart":0},{"duration":284.7999997138977,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":969.3000001907349,"connectEnd":969.3000001907349,"connectStart":969.3000001907349,"domainLookupEnd":969.3000001907349,"domainLookupStart":969.3000001907349,"fetchStart":969.3000001907349,"redirectEnd":0,"redirectStart":0,"requestStart":1217.4000000953674,"responseEnd":1254.0999999046326,"responseStart":1253.3000001907349,"secureConnectionStart":969.3000001907349}],"fetchStart":0,"domainLookupStart":0,"domainLookupEnd":0,"connectStart":0,"connectEnd":0,"requestStart":70,"responseStart":281,"responseEnd":299,"domLoading":285,"domInteractive":1231,"domContentLoadedEventStart":1231,"domContentLoadedEventEnd":1307,"domComplete":2014,"loadEventStart":2014,"loadEventEnd":2015,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":1207.4000000953674},{"name":"bigPipe.sidebar-id.end","time":1208.5999999046326},{"name":"bigPipe.activity-panel-pipe-id.start","time":1208.7000002861023},{"name":"bigPipe.activity-panel-pipe-id.end","time":1209.8000001907349},{"name":"activityTabFullyLoaded","time":1338.9000000953674}],"measures":[],"correlationId":"ff0db0eec31679","effectiveType":"4g","downlink":10,"rtt":0,"serverDuration":143,"dbReadsTimeInMs":14,"dbConnsTimeInMs":22,"applicationHash":"9d11dbea5f4be3d4cc21f03a88dd11d8c8687422","experiments":[]}}
Other prominent tests that were affected by this were innodb.101_compatibility and innodb_fts.crash_recovery, mainly in 11.x branches due to
MDEV-29986. The error messages were always issued for undo tablespace files, and in the failures that I checked, the corrupted page was recovered from the doublewrite buffer just fine. Both these tests kill and restart the server, which I think was a prerequisite for the error message to be issued.