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":3189.2000002861023,"ttfb":259.7000002861023,"pageVisibility":"visible","entityId":116605,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":64,"apdex":0.5,"journeyId":"c29d2dcb-8fd0-4bca-b21f-b820ec8c7da0","navigationType":0,"readyForUser":3171.6000003814697,"redirectCount":0,"resourceLoadedEnd":4689.10000038147,"resourceLoadedStart":487.7000002861023,"resourceTiming":[{"duration":162.19999980926514,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":487.7000002861023,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":487.7000002861023,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":649.9000000953674,"responseStart":0,"secureConnectionStart":0},{"duration":162.60000038146973,"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":488,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":488,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":650.6000003814697,"responseStart":0,"secureConnectionStart":0},{"duration":2041.9000000953674,"initiatorType":"script","name":"https://jira.mariadb.org/s/0917945aaa57108d00c5076fea35e069-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":488.2000002861023,"connectEnd":488.2000002861023,"connectStart":488.2000002861023,"domainLookupEnd":488.2000002861023,"domainLookupStart":488.2000002861023,"fetchStart":488.2000002861023,"redirectEnd":0,"redirectStart":0,"requestStart":654.1000003814697,"responseEnd":2530.1000003814697,"responseStart":1271.9000000953674,"secureConnectionStart":488.2000002861023},{"duration":2097.2000002861023,"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":488.40000009536743,"connectEnd":488.40000009536743,"connectStart":488.40000009536743,"domainLookupEnd":488.40000009536743,"domainLookupStart":488.40000009536743,"fetchStart":488.40000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":805.9000000953674,"responseEnd":2585.6000003814697,"responseStart":874,"secureConnectionStart":488.40000009536743},{"duration":384.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":488.6000003814697,"connectEnd":488.6000003814697,"connectStart":488.6000003814697,"domainLookupEnd":488.6000003814697,"domainLookupStart":488.6000003814697,"fetchStart":488.6000003814697,"redirectEnd":0,"redirectStart":0,"requestStart":807.2000002861023,"responseEnd":873.3000001907349,"responseStart":872.8000001907349,"secureConnectionStart":488.6000003814697},{"duration":383.30000019073486,"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":488.80000019073486,"connectEnd":488.80000019073486,"connectStart":488.80000019073486,"domainLookupEnd":488.80000019073486,"domainLookupStart":488.80000019073486,"fetchStart":488.80000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":807.5,"responseEnd":872.1000003814697,"responseStart":871.6000003814697,"secureConnectionStart":488.80000019073486},{"duration":384.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":489.1000003814697,"connectEnd":489.1000003814697,"connectStart":489.1000003814697,"domainLookupEnd":489.1000003814697,"domainLookupStart":489.1000003814697,"fetchStart":489.1000003814697,"redirectEnd":0,"redirectStart":0,"requestStart":807.8000001907349,"responseEnd":873.9000000953674,"responseStart":873.4000000953674,"secureConnectionStart":489.1000003814697},{"duration":162.40000009536743,"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":489.30000019073486,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":489.30000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":651.7000002861023,"responseStart":0,"secureConnectionStart":0},{"duration":383.30000019073486,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":489.40000009536743,"connectEnd":489.40000009536743,"connectStart":489.40000009536743,"domainLookupEnd":489.40000009536743,"domainLookupStart":489.40000009536743,"fetchStart":489.40000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":807.8000001907349,"responseEnd":872.7000002861023,"responseStart":872.2000002861023,"secureConnectionStart":489.40000009536743},{"duration":162.5,"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":489.6000003814697,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":489.6000003814697,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":652.1000003814697,"responseStart":0,"secureConnectionStart":0},{"duration":782,"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":489.80000019073486,"connectEnd":489.80000019073486,"connectStart":489.80000019073486,"domainLookupEnd":489.80000019073486,"domainLookupStart":489.80000019073486,"fetchStart":489.80000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":807.9000000953674,"responseEnd":1271.8000001907349,"responseStart":1003.4000000953674,"secureConnectionStart":489.80000019073486},{"duration":4195.800000190735,"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":490.80000019073486,"connectEnd":490.80000019073486,"connectStart":490.80000019073486,"domainLookupEnd":490.80000019073486,"domainLookupStart":490.80000019073486,"fetchStart":490.80000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":1376.5,"responseEnd":4686.60000038147,"responseStart":4050.1000003814697,"secureConnectionStart":490.80000019073486},{"duration":4196,"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":490.90000009536743,"connectEnd":490.90000009536743,"connectStart":490.90000009536743,"domainLookupEnd":490.90000009536743,"domainLookupStart":490.90000009536743,"fetchStart":490.90000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":1598.2000002861023,"responseEnd":4686.900000095367,"responseStart":4161.900000095367,"secureConnectionStart":490.90000009536743},{"duration":218.89999961853027,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":2765.6000003814697,"connectEnd":2765.6000003814697,"connectStart":2765.6000003814697,"domainLookupEnd":2765.6000003814697,"domainLookupStart":2765.6000003814697,"fetchStart":2765.6000003814697,"redirectEnd":0,"redirectStart":0,"requestStart":2943.6000003814697,"responseEnd":2984.5,"responseStart":2980.300000190735,"secureConnectionStart":2765.6000003814697},{"duration":169.90000009536743,"initiatorType":"script","name":"https://www.google-analytics.com/analytics.js","startTime":3048.5,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":3048.5,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":3218.4000000953674,"responseStart":0,"secureConnectionStart":0},{"duration":362.7000002861023,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":3067,"connectEnd":3067,"connectStart":3067,"domainLookupEnd":3067,"domainLookupStart":3067,"fetchStart":3067,"redirectEnd":0,"redirectStart":0,"requestStart":3220.5,"responseEnd":3429.7000002861023,"responseStart":3262.4000000953674,"secureConnectionStart":3067},{"duration":756.8000001907349,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/viewIssue/1/remoteIssueLink/render/36308?_=1743577927596","startTime":3101.300000190735,"connectEnd":3101.300000190735,"connectStart":3101.300000190735,"domainLookupEnd":3101.300000190735,"domainLookupStart":3101.300000190735,"fetchStart":3101.300000190735,"redirectEnd":0,"redirectStart":0,"requestStart":3430.300000190735,"responseEnd":3858.1000003814697,"responseStart":3734,"secureConnectionStart":3101.300000190735},{"duration":1251.6000003814697,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2cib/820016/12ta74/e65b778d185daf5aee24936755b43da6/_/download/contextbatch/js/browser-metrics-plugin.contrib,-_super,-project.issue.navigator,-jira.view.issue,-atl.general/batch.js?agile_global_admin_condition=true&jag=true&jira.create.linked.issue=true&slack-enabled=true&whisper-enabled=true","startTime":3437.5,"connectEnd":3437.5,"connectStart":3437.5,"domainLookupEnd":3437.5,"domainLookupStart":3437.5,"fetchStart":3437.5,"redirectEnd":0,"redirectStart":0,"requestStart":3689.6000003814697,"responseEnd":4689.10000038147,"responseStart":4643.700000286102,"secureConnectionStart":3437.5}],"fetchStart":0,"domainLookupStart":0,"domainLookupEnd":0,"connectStart":0,"connectEnd":0,"requestStart":93,"responseStart":259,"responseEnd":384,"domLoading":300,"domInteractive":4853,"domContentLoadedEventStart":4853,"domContentLoadedEventEnd":4893,"domComplete":5700,"loadEventStart":5700,"loadEventEnd":5701,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":4692.300000190735},{"name":"bigPipe.sidebar-id.end","time":4693.10000038147},{"name":"bigPipe.activity-panel-pipe-id.start","time":4693.200000286102},{"name":"bigPipe.activity-panel-pipe-id.end","time":4694.700000286102},{"name":"activityTabFullyLoaded","time":4908.5}],"measures":[],"correlationId":"e29c1a66d22b26","effectiveType":"4g","downlink":9.1,"rtt":0,"serverDuration":104,"dbReadsTimeInMs":16,"dbConnsTimeInMs":26,"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.