I had added this debug assertion in MDEV-34212, which fixed a regression that had been introduced in MDEV-32042. The assertion is failing on the server bootstrap.
The purpose of the assertion is to ensure that the special mode == BUF_GET_RECOVER is only being used during server bootstrap, or in early startup while there are no other users of the buffer pool. My assumption was that during server bootstrap, the log sequence number would not grow beyond 50000. I did not think of the overhead of creating undo log tablespaces. I relaxed the assertion and ran with the maximum value:
Curiously, there are no shutdown messages for the bootstrap (which confirms the finding that was made during the review of MDEV-33853, and maybe deserves another bug to be filed):
11.1 d34289a3e269de69796a3309ce441af836776ef7
2024-06-19 14:09:57 0 [Note] InnoDB: Doublewrite buffer not found: creating new
2024-06-19 14:09:57 0 [Note] InnoDB: Opened 127 undo tablespaces
2024-06-19 14:09:57 0 [Note] InnoDB: 128 rollback segments in 127 undo tablespaces are active.
2024-06-19 14:09:57 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
2024-06-19 14:09:57 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
2024-06-19 14:09:57 0 [Note] InnoDB: log sequence number 0 (memory-mapped); transaction id 3
…
2024-06-19 14:09:57 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2024-06-19 14:09:57 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.
2024-06-19 14:09:57 0 [Note] Plugin 'unix_socket' is disabled.
2024-06-19 14:09:57 0 [Note] Plugin 'wsrep_provider' is disabled.
So, I had to resort to using
rr replay var/log/bootstrap.rr/latest-trace
continue
print log_sys.lsn._M_i
Thread 1 received signal SIGKILL, Killed.
0x0000000070000002 in syscall_traced ()
(rr) print log_sys.lsn._M_i
$1 = 105625
I think that the 50000 in the assertion expression had better be relaxed to 120000, to add some safety margin.
Marko Mäkelä
added a comment - I had added this debug assertion in MDEV-34212 , which fixed a regression that had been introduced in MDEV-32042 . The assertion is failing on the server bootstrap.
The purpose of the assertion is to ensure that the special mode == BUF_GET_RECOVER is only being used during server bootstrap, or in early startup while there are no other users of the buffer pool. My assumption was that during server bootstrap, the log sequence number would not grow beyond 50000. I did not think of the overhead of creating undo log tablespaces. I relaxed the assertion and ran with the maximum value:
./mtr 1st --boot-rr --mysqld=--innodb-undo-tablespaces=127
Curiously, there are no shutdown messages for the bootstrap (which confirms the finding that was made during the review of MDEV-33853 , and maybe deserves another bug to be filed):
11.1 d34289a3e269de69796a3309ce441af836776ef7
2024-06-19 14:09:57 0 [Note] InnoDB: Doublewrite buffer not found: creating new
2024-06-19 14:09:57 0 [Note] InnoDB: Opened 127 undo tablespaces
2024-06-19 14:09:57 0 [Note] InnoDB: 128 rollback segments in 127 undo tablespaces are active.
2024-06-19 14:09:57 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
2024-06-19 14:09:57 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
2024-06-19 14:09:57 0 [Note] InnoDB: log sequence number 0 (memory-mapped); transaction id 3
…
2024-06-19 14:09:57 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2024-06-19 14:09:57 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.
2024-06-19 14:09:57 0 [Note] Plugin 'unix_socket' is disabled.
2024-06-19 14:09:57 0 [Note] Plugin 'wsrep_provider' is disabled.
So, I had to resort to using
rr replay var/log/bootstrap.rr/latest-trace
continue
print log_sys.lsn._M_i
Thread 1 received signal SIGKILL, Killed.
0x0000000070000002 in syscall_traced ()
(rr) print log_sys.lsn._M_i
$1 = 105625
I think that the 50000 in the assertion expression had better be relaxed to 120000, to add some safety margin.
People
Marko Mäkelä
Alice Sherepa
Votes:
0Vote for this issue
Watchers:
3Start 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":1920.5,"ttfb":836.0999999940395,"pageVisibility":"visible","entityId":129666,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":64,"apdex":0.5,"journeyId":"6b350bff-e865-4be6-8b19-7fd8a016cc62","navigationType":0,"readyForUser":2030.699999988079,"redirectCount":0,"resourceLoadedEnd":2587.5999999940395,"resourceLoadedStart":855.0999999940395,"resourceTiming":[{"duration":484.70000000298023,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2bv2/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":855.0999999940395,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":855.0999999940395,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1339.7999999970198,"responseStart":0,"secureConnectionStart":0},{"duration":484.6000000089407,"initiatorType":"link","name":"https://jira.mariadb.org/s/7ebd35e77e471bc30ff0eba799ebc151-CDN/lu2bv2/820016/12ta74/2380add21a9a1006587582385952de73/_/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","startTime":855.3999999910593,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":855.3999999910593,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1340,"responseStart":0,"secureConnectionStart":0},{"duration":494.59999999403954,"initiatorType":"script","name":"https://jira.mariadb.org/s/e9b27a47da5fb0f74a35acd57e9847fb-CDN/lu2bv2/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":855.5,"connectEnd":855.5,"connectStart":855.5,"domainLookupEnd":855.5,"domainLookupStart":855.5,"fetchStart":855.5,"redirectEnd":0,"redirectStart":0,"requestStart":855.5,"responseEnd":1350.0999999940395,"responseStart":1350.0999999940395,"secureConnectionStart":855.5},{"duration":576.7000000029802,"initiatorType":"script","name":"https://jira.mariadb.org/s/c32eb0da7ad9831253f8397e6cc26afd-CDN/lu2bv2/820016/12ta74/2380add21a9a1006587582385952de73/_/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","startTime":855.6999999880791,"connectEnd":855.6999999880791,"connectStart":855.6999999880791,"domainLookupEnd":855.6999999880791,"domainLookupStart":855.6999999880791,"fetchStart":855.6999999880791,"redirectEnd":0,"redirectStart":0,"requestStart":855.6999999880791,"responseEnd":1432.3999999910593,"responseStart":1432.3999999910593,"secureConnectionStart":855.6999999880791},{"duration":580.0999999940395,"initiatorType":"script","name":"https://jira.mariadb.org/s/bc0bcb146314416123c992714ee00ff7-CDN/lu2bv2/820016/12ta74/c92c0caa9a024ae85b0ebdbed7fb4bd7/_/download/contextbatch/js/atl.global,-_super/batch.js?locale=en","startTime":856,"connectEnd":856,"connectStart":856,"domainLookupEnd":856,"domainLookupStart":856,"fetchStart":856,"redirectEnd":0,"redirectStart":0,"requestStart":856,"responseEnd":1436.0999999940395,"responseStart":1436.0999999940395,"secureConnectionStart":856},{"duration":580.4000000059605,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bv2/820016/12ta74/1.0/_/download/batch/jira.webresources:calendar-en/jira.webresources:calendar-en.js","startTime":856.1999999880791,"connectEnd":856.1999999880791,"connectStart":856.1999999880791,"domainLookupEnd":856.1999999880791,"domainLookupStart":856.1999999880791,"fetchStart":856.1999999880791,"redirectEnd":0,"redirectStart":0,"requestStart":856.1999999880791,"responseEnd":1436.5999999940395,"responseStart":1436.5999999940395,"secureConnectionStart":856.1999999880791},{"duration":580.7999999970198,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bv2/820016/12ta74/1.0/_/download/batch/jira.webresources:calendar-localisation-moment/jira.webresources:calendar-localisation-moment.js","startTime":856.2999999970198,"connectEnd":856.2999999970198,"connectStart":856.2999999970198,"domainLookupEnd":856.2999999970198,"domainLookupStart":856.2999999970198,"fetchStart":856.2999999970198,"redirectEnd":0,"redirectStart":0,"requestStart":856.2999999970198,"responseEnd":1437.0999999940395,"responseStart":1437.0999999940395,"secureConnectionStart":856.2999999970198},{"duration":671.7999999970198,"initiatorType":"link","name":"https://jira.mariadb.org/s/b04b06a02d1959df322d9cded3aeecc1-CDN/lu2bv2/820016/12ta74/a2ff6aa845ffc9a1d22fe23d9ee791fc/_/download/contextbatch/css/jira.global.look-and-feel,-_super/batch.css","startTime":856.5999999940395,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":856.5999999940395,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1528.3999999910593,"responseStart":0,"secureConnectionStart":0},{"duration":580.9000000059605,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":856.6999999880791,"connectEnd":856.6999999880791,"connectStart":856.6999999880791,"domainLookupEnd":856.6999999880791,"domainLookupStart":856.6999999880791,"fetchStart":856.6999999880791,"redirectEnd":0,"redirectStart":0,"requestStart":856.6999999880791,"responseEnd":1437.5999999940395,"responseStart":1437.5999999940395,"secureConnectionStart":856.6999999880791},{"duration":672,"initiatorType":"link","name":"https://jira.mariadb.org/s/3ac36323ba5e4eb0af2aa7ac7211b4bb-CDN/lu2bv2/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":856.8999999910593,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":856.8999999910593,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1528.8999999910593,"responseStart":0,"secureConnectionStart":0},{"duration":581.0999999940395,"initiatorType":"script","name":"https://jira.mariadb.org/s/719848dd97ebe0663199f49a3936487a-CDN/lu2bv2/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":857.0999999940395,"connectEnd":857.0999999940395,"connectStart":857.0999999940395,"domainLookupEnd":857.0999999940395,"domainLookupStart":857.0999999940395,"fetchStart":857.0999999940395,"redirectEnd":0,"redirectStart":0,"requestStart":857.0999999940395,"responseEnd":1438.199999988079,"responseStart":1438.199999988079,"secureConnectionStart":857.0999999940395},{"duration":1483.2000000029802,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bv2/820016/12ta74/1.0/_/download/batch/jira.webresources:bigpipe-js/jira.webresources:bigpipe-js.js","startTime":857.8999999910593,"connectEnd":857.8999999910593,"connectStart":857.8999999910593,"domainLookupEnd":857.8999999910593,"domainLookupStart":857.8999999910593,"fetchStart":857.8999999910593,"redirectEnd":0,"redirectStart":0,"requestStart":857.8999999910593,"responseEnd":2341.0999999940395,"responseStart":2341.0999999940395,"secureConnectionStart":857.8999999910593},{"duration":1729.5999999940395,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bv2/820016/12ta74/1.0/_/download/batch/jira.webresources:bigpipe-init/jira.webresources:bigpipe-init.js","startTime":858,"connectEnd":858,"connectStart":858,"domainLookupEnd":858,"domainLookupStart":858,"fetchStart":858,"redirectEnd":0,"redirectStart":0,"requestStart":858,"responseEnd":2587.5999999940395,"responseStart":2587.5999999940395,"secureConnectionStart":858},{"duration":791.9000000059605,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":1573.3999999910593,"connectEnd":1573.3999999910593,"connectStart":1573.3999999910593,"domainLookupEnd":1573.3999999910593,"domainLookupStart":1573.3999999910593,"fetchStart":1573.3999999910593,"redirectEnd":0,"redirectStart":0,"requestStart":1573.3999999910593,"responseEnd":2365.2999999970198,"responseStart":2365.2999999970198,"secureConnectionStart":1573.3999999910593}],"fetchStart":0,"domainLookupStart":0,"domainLookupEnd":0,"connectStart":0,"connectEnd":0,"requestStart":671,"responseStart":836,"responseEnd":841,"domLoading":852,"domInteractive":2621,"domContentLoadedEventStart":2621,"domContentLoadedEventEnd":2674,"domComplete":3609,"loadEventStart":3609,"loadEventEnd":3609,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":2592.5},{"name":"bigPipe.sidebar-id.end","time":2593.5999999940395},{"name":"bigPipe.activity-panel-pipe-id.start","time":2593.7999999970198},{"name":"bigPipe.activity-panel-pipe-id.end","time":2595.8999999910593},{"name":"activityTabFullyLoaded","time":2689}],"measures":[],"correlationId":"7d41ab3395cf9","effectiveType":"4g","downlink":9.3,"rtt":0,"serverDuration":102,"dbReadsTimeInMs":17,"dbConnsTimeInMs":26,"applicationHash":"9d11dbea5f4be3d4cc21f03a88dd11d8c8687422","experiments":[]}}
Bug
Major
I had added this debug assertion in
MDEV-34212, which fixed a regression that had been introduced inMDEV-32042. The assertion is failing on the server bootstrap.The purpose of the assertion is to ensure that the special mode == BUF_GET_RECOVER is only being used during server bootstrap, or in early startup while there are no other users of the buffer pool. My assumption was that during server bootstrap, the log sequence number would not grow beyond 50000. I did not think of the overhead of creating undo log tablespaces. I relaxed the assertion and ran with the maximum value:
./mtr 1st --boot-rr --mysqld=--innodb-undo-tablespaces=127Curiously, there are no shutdown messages for the bootstrap (which confirms the finding that was made during the review of
MDEV-33853, and maybe deserves another bug to be filed):11.1 d34289a3e269de69796a3309ce441af836776ef7
2024-06-19 14:09:57 0 [Note] InnoDB: Doublewrite buffer not found: creating new2024-06-19 14:09:57 0 [Note] InnoDB: Opened 127 undo tablespaces2024-06-19 14:09:57 0 [Note] InnoDB: 128 rollback segments in 127 undo tablespaces are active.2024-06-19 14:09:57 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...2024-06-19 14:09:57 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.2024-06-19 14:09:57 0 [Note] InnoDB: log sequence number 0 (memory-mapped); transaction id 3…2024-06-19 14:09:57 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.2024-06-19 14:09:57 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.2024-06-19 14:09:57 0 [Note] Plugin 'unix_socket' is disabled.2024-06-19 14:09:57 0 [Note] Plugin 'wsrep_provider' is disabled.So, I had to resort to using
rr replay var/log/bootstrap.rr/latest-tracecontinueprint log_sys.lsn._M_iThread 1 received signal SIGKILL, Killed.0x0000000070000002 in syscall_traced ()(rr) print log_sys.lsn._M_i$1 = 105625I think that the 50000 in the assertion expression had better be relaxed to 120000, to add some safety margin.