We should get the change buffer merge process reported in the log In the same way as it was done in MDEV-22577 "innodb_fast_shutdown=0 fails to report purge progress"
Currently, with innodb_fast_shutdown=0, the change buffer merge can take some time, a user might think that the server hans on shutdown as there are no updates in the server log file.
Attachments
Issue Links
relates to
MDEV-30009InnoDB shutdown hangs when the change buffer is corrupted
Closed
MDEV-22577innodb_fast_shutdown=0 fails to report purge progress
Closed
MDEV-29905Change buffer operations fail to check for log file overflow
There actually is some progress reporting for the change buffer merge, once per 60 seconds, implemented in the function srv_shutdown_print_master_pending(). But those messages were not present in the log extract that was posted in MDEV-29905. This would suggest that the case involves a corrupted change buffer, similar to MDEV-20934.
In any case, it does make sense to reduce the reporting interval from 60 to 15 seconds, to be consistent with MDEV-22577.
Marko Mäkelä
added a comment - There actually is some progress reporting for the change buffer merge, once per 60 seconds, implemented in the function srv_shutdown_print_master_pending() . But those messages were not present in the log extract that was posted in MDEV-29905 . This would suggest that the case involves a corrupted change buffer, similar to MDEV-20934 .
In any case, it does make sense to reduce the reporting interval from 60 to 15 seconds, to be consistent with MDEV-22577 .
This is from a modified test innodb.ibuf_not_empty, actually reproducing a shutdown hang that is basically the same as MDEV-20934. I filed MDEV-30009 for that.
Marko Mäkelä
added a comment - - edited The revised progress report will look like this:
10.6 ae6ebafd819d48c965d2615fc78f1f950e0fbf40
2022-11-14 15:44:37 0 [Note] InnoDB: Starting shutdown...
2022-11-14 15:44:37 0 [Note] InnoDB: Dumping buffer pool(s) to /dev/shm/10.6m/mysql-test/var/mysqld.1/data/ib_buffer_pool
2022-11-14 15:44:37 0 [Note] InnoDB: Buffer pool(s) dump completed at 221114 15:44:37
2022-11-14 15:44:52 0 [Note] Completing change buffer merge; 409 page reads initiated; 1 change buffer pages remain
2022-11-14 15:45:07 0 [Note] Completing change buffer merge; 409 page reads initiated; 1 change buffer pages remain
2022-11-14 15:45:22 0 [Note] Completing change buffer merge; 409 page reads initiated; 1 change buffer pages remain
This is from a modified test innodb.ibuf_not_empty , actually reproducing a shutdown hang that is basically the same as MDEV-20934 . I filed MDEV-30009 for that.
People
Marko Mäkelä
Ralf Gebhardt
Votes:
0Vote for this issue
Watchers:
2Start 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":1271.3999996185303,"ttfb":466.8999996185303,"pageVisibility":"visible","entityId":116605,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":32,"apdex":0.5,"journeyId":"b40329d6-ab1b-4123-bb68-239be4008d9a","navigationType":0,"readyForUser":1396.1999998092651,"redirectCount":0,"resourceLoadedEnd":1019.7999997138977,"resourceLoadedStart":473.2999997138977,"resourceTiming":[{"duration":178.59999990463257,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":473.2999997138977,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":473.2999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":651.8999996185303,"responseStart":0,"secureConnectionStart":0},{"duration":178.5,"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":473.69999980926514,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":473.69999980926514,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":652.1999998092651,"responseStart":0,"secureConnectionStart":0},{"duration":286.5,"initiatorType":"script","name":"https://jira.mariadb.org/s/0917945aaa57108d00c5076fea35e069-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":473.7999997138977,"connectEnd":654.5999999046326,"connectStart":654.5999999046326,"domainLookupEnd":654.5999999046326,"domainLookupStart":654.5999999046326,"fetchStart":473.7999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":655,"responseEnd":760.2999997138977,"responseStart":667.5999999046326,"secureConnectionStart":654.5999999046326},{"duration":440.59999990463257,"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":474,"connectEnd":474,"connectStart":474,"domainLookupEnd":474,"domainLookupStart":474,"fetchStart":474,"redirectEnd":0,"redirectStart":0,"requestStart":655.1999998092651,"responseEnd":914.5999999046326,"responseStart":670.5,"secureConnectionStart":474},{"duration":192.2999997138977,"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":474.09999990463257,"connectEnd":474.09999990463257,"connectStart":474.09999990463257,"domainLookupEnd":474.09999990463257,"domainLookupStart":474.09999990463257,"fetchStart":474.09999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":655.5999999046326,"responseEnd":666.3999996185303,"responseStart":665.6999998092651,"secureConnectionStart":474.09999990463257},{"duration":203,"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":474.2999997138977,"connectEnd":474.2999997138977,"connectStart":474.2999997138977,"domainLookupEnd":474.2999997138977,"domainLookupStart":474.2999997138977,"fetchStart":474.2999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":656.8999996185303,"responseEnd":677.2999997138977,"responseStart":673.5,"secureConnectionStart":474.2999997138977},{"duration":203,"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":474.59999990463257,"connectEnd":474.59999990463257,"connectStart":474.59999990463257,"domainLookupEnd":474.59999990463257,"domainLookupStart":474.59999990463257,"fetchStart":474.59999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":658.0999999046326,"responseEnd":677.5999999046326,"responseStart":675.6999998092651,"secureConnectionStart":474.59999990463257},{"duration":183.19999980926514,"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":474.69999980926514,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":474.69999980926514,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":657.8999996185303,"responseStart":0,"secureConnectionStart":0},{"duration":203.09999990463257,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":474.7999997138977,"connectEnd":474.7999997138977,"connectStart":474.7999997138977,"domainLookupEnd":474.7999997138977,"domainLookupStart":474.7999997138977,"fetchStart":474.7999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":660.1999998092651,"responseEnd":677.8999996185303,"responseStart":676.1999998092651,"secureConnectionStart":474.7999997138977},{"duration":184,"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":475,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":475,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":659,"responseStart":0,"secureConnectionStart":0},{"duration":206.5,"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":475.19999980926514,"connectEnd":475.19999980926514,"connectStart":475.19999980926514,"domainLookupEnd":475.19999980926514,"domainLookupStart":475.19999980926514,"fetchStart":475.19999980926514,"redirectEnd":0,"redirectStart":0,"requestStart":662,"responseEnd":681.6999998092651,"responseStart":679.7999997138977,"secureConnectionStart":475.19999980926514},{"duration":536.5,"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":483.2999997138977,"connectEnd":483.2999997138977,"connectStart":483.2999997138977,"domainLookupEnd":483.2999997138977,"domainLookupStart":483.2999997138977,"fetchStart":483.2999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":823.5,"responseEnd":1019.7999997138977,"responseStart":1008.0999999046326,"secureConnectionStart":483.2999997138977},{"duration":534.6999998092651,"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":483.59999990463257,"connectEnd":483.59999990463257,"connectStart":483.59999990463257,"domainLookupEnd":483.59999990463257,"domainLookupStart":483.59999990463257,"fetchStart":483.59999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":964.8999996185303,"responseEnd":1018.2999997138977,"responseStart":1007.0999999046326,"secureConnectionStart":483.59999990463257},{"duration":134.5,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":888.6999998092651,"connectEnd":888.6999998092651,"connectStart":888.6999998092651,"domainLookupEnd":888.6999998092651,"domainLookupStart":888.6999998092651,"fetchStart":888.6999998092651,"redirectEnd":0,"redirectStart":0,"requestStart":970.3999996185303,"responseEnd":1023.1999998092651,"responseStart":1015.2999997138977,"secureConnectionStart":888.6999998092651},{"duration":343.19999980926514,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":1181.0999999046326,"connectEnd":1181.0999999046326,"connectStart":1181.0999999046326,"domainLookupEnd":1181.0999999046326,"domainLookupStart":1181.0999999046326,"fetchStart":1181.0999999046326,"redirectEnd":0,"redirectStart":0,"requestStart":1489.5999999046326,"responseEnd":1524.2999997138977,"responseStart":1523.0999999046326,"secureConnectionStart":1181.0999999046326}],"fetchStart":0,"domainLookupStart":289,"domainLookupEnd":299,"connectStart":299,"connectEnd":317,"secureConnectionStart":307,"requestStart":318,"responseStart":466,"responseEnd":483,"domLoading":471,"domInteractive":1478,"domContentLoadedEventStart":1478,"domContentLoadedEventEnd":1553,"domComplete":3062,"loadEventStart":3062,"loadEventEnd":3062,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":1445.2999997138977},{"name":"bigPipe.sidebar-id.end","time":1446.0999999046326},{"name":"bigPipe.activity-panel-pipe-id.start","time":1446.1999998092651},{"name":"bigPipe.activity-panel-pipe-id.end","time":1448},{"name":"activityTabFullyLoaded","time":1568.5}],"measures":[],"correlationId":"be220e482db","effectiveType":"4g","downlink":10,"rtt":0,"serverDuration":95,"dbReadsTimeInMs":15,"dbConnsTimeInMs":23,"applicationHash":"9d11dbea5f4be3d4cc21f03a88dd11d8c8687422","experiments":[]}}
Bug
Major
Page Failed to load
There actually is some progress reporting for the change buffer merge, once per 60 seconds, implemented in the function srv_shutdown_print_master_pending(). But those messages were not present in the log extract that was posted in
MDEV-29905. This would suggest that the case involves a corrupted change buffer, similar toMDEV-20934.In any case, it does make sense to reduce the reporting interval from 60 to 15 seconds, to be consistent with
MDEV-22577.