mariadb-10.5.9 3a8ca9096ea82ca61811450775511533d6cb1bb4 2021-02-19T10:37:51+01:00 + a code of MDEV-25031
|
|
1. Start server and create some initial data
|
2. Several sessions run a concurrent DDL/DML mix
|
3. During 2. is ongoing
|
mariabackup --backup ... to <other_dir>
|
mariabackup --prepare ... in other_dir
|
This "prepare" fails with
|
2021-03-10 13:11:24 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=162939,15421408
|
# 2021-03-10T13:12:35 [3326538] | 2021-03-10 13:11:30 0 [Note] InnoDB: Starting final batch to recover 497 pages from redo log.
|
# 2021-03-10T13:12:35 [3326538] | 2021-03-10 13:11:33 0 [ERROR] [FATAL] InnoDB: Trying to write 16384 bytes at 1032192 outside the bounds of the file: test/table100_innodb_int_autoinc.ibd
|
# 2021-03-10T13:12:35 [3326538] | 210310 13:11:33 [ERROR] mysqld got signal 6 ;
|
|
(rr) bt
|
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
|
#1 0x000073605f7e8859 in __GI_abort () at abort.c:79
|
#2 0x000055db8e6edb37 in ib::fatal::~fatal (this=0x439a0eee0570, __in_chrg=<optimized out>) at /Server/10.5.9-MDEV-25031/storage/innobase/ut/ut0ut.cc:576
|
#3 0x000055db8e0d00ab in fil_report_invalid_page_access (name=0x60600000a3b8 "test/table100_innodb_int_autoinc.ibd", offset=1032192, len=16384, is_read=false) at /Server/10.5.9-MDEV-25031/storage/innobase/fil/fil0fil.cc:3321
|
#4 0x000055db8e0d0e46 in fil_space_t::io (this=0x615000003a18, type=..., offset=1032192, len=16384, buf=0x7a864000, bpage=0x79c30be8) at /Server/10.5.9-MDEV-25031/storage/innobase/fil/fil0fil.cc:3412
|
#5 0x000055db8e009653 in buf_flush_page (bpage=0x79c30be8, lru=false, space=0x615000003a18) at /Server/10.5.9-MDEV-25031/storage/innobase/buf/buf0flu.cc:962
|
#6 0x000055db8e00de54 in buf_do_flush_list_batch (max_n=200, lsn=18446744073709551615) at /Server/10.5.9-MDEV-25031/storage/innobase/buf/buf0flu.cc:1472
|
#7 0x000055db8e00e9b4 in buf_flush_lists (max_n=200, lsn=18446744073709551615) at /Server/10.5.9-MDEV-25031/storage/innobase/buf/buf0flu.cc:1581
|
#8 0x000055db8e013626 in buf_flush_page_cleaner () at /Server/10.5.9-MDEV-25031/storage/innobase/buf/buf0flu.cc:2168
|
#9 0x00007feed4e78609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#10 0x000073605f8e5293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
(rr)
|
pluto:/home/mleich/RQG_O/storage/1615376730/TBR-932/dev/shm/vardir/1615376730/58/1_clone/rr
|
|
- is caused by
-
MDEV-23855
InnoDB log checkpointing causes regression for write-heavy OLTP
-
-
Closed
{"report":{"fcp":914.6000003814697,"ttfb":279,"pageVisibility":"visible","entityId":97791,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":64,"apdex":0.5,"journeyId":"3f3f4d4e-a18c-45e8-9d11-0f38fbf6b3d4","navigationType":0,"readyForUser":1004.8000001907349,"redirectCount":0,"resourceLoadedEnd":802,"resourceLoadedStart":287.30000019073486,"resourceTiming":[{"duration":131,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":287.30000019073486,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":287.30000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":418.30000019073486,"responseStart":0,"secureConnectionStart":0},{"duration":131.09999990463257,"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":287.6000003814697,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":287.6000003814697,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":418.7000002861023,"responseStart":0,"secureConnectionStart":0},{"duration":248.09999990463257,"initiatorType":"script","name":"https://jira.mariadb.org/s/0917945aaa57108d00c5076fea35e069-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":287.80000019073486,"connectEnd":287.80000019073486,"connectStart":287.80000019073486,"domainLookupEnd":287.80000019073486,"domainLookupStart":287.80000019073486,"fetchStart":287.80000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":428.6000003814697,"responseEnd":535.9000000953674,"responseStart":453.1000003814697,"secureConnectionStart":287.80000019073486},{"duration":361.5,"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":287.90000009536743,"connectEnd":427.80000019073486,"connectStart":427.80000019073486,"domainLookupEnd":427.80000019073486,"domainLookupStart":427.80000019073486,"fetchStart":287.90000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":428.30000019073486,"responseEnd":649.4000000953674,"responseStart":448.6000003814697,"secureConnectionStart":427.80000019073486},{"duration":169.59999990463257,"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":288.1000003814697,"connectEnd":288.1000003814697,"connectStart":288.1000003814697,"domainLookupEnd":288.1000003814697,"domainLookupStart":288.1000003814697,"fetchStart":288.1000003814697,"redirectEnd":0,"redirectStart":0,"requestStart":428.80000019073486,"responseEnd":457.7000002861023,"responseStart":456,"secureConnectionStart":288.1000003814697},{"duration":172.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":288.30000019073486,"connectEnd":288.30000019073486,"connectStart":288.30000019073486,"domainLookupEnd":288.30000019073486,"domainLookupStart":288.30000019073486,"fetchStart":288.30000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":432.40000009536743,"responseEnd":460.6000003814697,"responseStart":459.1000003814697,"secureConnectionStart":288.30000019073486},{"duration":171.80000019073486,"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":288.5,"connectEnd":288.5,"connectStart":288.5,"domainLookupEnd":288.5,"domainLookupStart":288.5,"fetchStart":288.5,"redirectEnd":0,"redirectStart":0,"requestStart":432.2000002861023,"responseEnd":460.30000019073486,"responseStart":458.6000003814697,"secureConnectionStart":288.5},{"duration":140.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":288.7000002861023,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":288.7000002861023,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":429.40000009536743,"responseStart":0,"secureConnectionStart":0},{"duration":169.30000019073486,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":288.90000009536743,"connectEnd":288.90000009536743,"connectStart":288.90000009536743,"domainLookupEnd":288.90000009536743,"domainLookupStart":288.90000009536743,"fetchStart":288.90000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":433.1000003814697,"responseEnd":458.2000002861023,"responseStart":456.6000003814697,"secureConnectionStart":288.90000009536743},{"duration":142.80000019073486,"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":289,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":289,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":431.80000019073486,"responseStart":0,"secureConnectionStart":0},{"duration":182.09999990463257,"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":289.1000003814697,"connectEnd":289.1000003814697,"connectStart":289.1000003814697,"domainLookupEnd":289.1000003814697,"domainLookupStart":289.1000003814697,"fetchStart":289.1000003814697,"redirectEnd":0,"redirectStart":0,"requestStart":451.2000002861023,"responseEnd":471.2000002861023,"responseStart":470.30000019073486,"secureConnectionStart":289.1000003814697},{"duration":442.7000002861023,"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":301,"connectEnd":301,"connectStart":301,"domainLookupEnd":301,"domainLookupStart":301,"fetchStart":301,"redirectEnd":0,"redirectStart":0,"requestStart":621.5,"responseEnd":743.7000002861023,"responseStart":740.8000001907349,"secureConnectionStart":301},{"duration":500.7999997138977,"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":301.2000002861023,"connectEnd":301.2000002861023,"connectStart":301.2000002861023,"domainLookupEnd":301.2000002861023,"domainLookupStart":301.2000002861023,"fetchStart":301.2000002861023,"redirectEnd":0,"redirectStart":0,"requestStart":789.6000003814697,"responseEnd":802,"responseStart":801.4000000953674,"secureConnectionStart":301.2000002861023},{"duration":159.19999980926514,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":670.2000002861023,"connectEnd":670.2000002861023,"connectStart":670.2000002861023,"domainLookupEnd":670.2000002861023,"domainLookupStart":670.2000002861023,"fetchStart":670.2000002861023,"redirectEnd":0,"redirectStart":0,"requestStart":794.4000000953674,"responseEnd":829.4000000953674,"responseStart":828.6000003814697,"secureConnectionStart":670.2000002861023},{"duration":242.09999990463257,"initiatorType":"script","name":"https://www.google-analytics.com/analytics.js","startTime":908.6000003814697,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":908.6000003814697,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1150.7000002861023,"responseStart":0,"secureConnectionStart":0}],"fetchStart":0,"domainLookupStart":0,"domainLookupEnd":0,"connectStart":0,"connectEnd":0,"requestStart":113,"responseStart":279,"responseEnd":301,"domLoading":282,"domInteractive":1099,"domContentLoadedEventStart":1099,"domContentLoadedEventEnd":1144,"domComplete":1598,"loadEventStart":1598,"loadEventEnd":1598,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":1081.6000003814697},{"name":"bigPipe.sidebar-id.end","time":1082.4000000953674},{"name":"bigPipe.activity-panel-pipe-id.start","time":1082.6000003814697},{"name":"bigPipe.activity-panel-pipe-id.end","time":1083.5},{"name":"activityTabFullyLoaded","time":1160}],"measures":[],"correlationId":"89f77b766e4202","effectiveType":"4g","downlink":9.7,"rtt":0,"serverDuration":90,"dbReadsTimeInMs":14,"dbConnsTimeInMs":23,"applicationHash":"9d11dbea5f4be3d4cc21f03a88dd11d8c8687422","experiments":[]}}
Blocker
I suspect that this was caused by the changes in
MDEV-23855. In the trace that I analyzed, the log is being applied in multiple batches, and the data file is being extended multiple times according to the parsed redo log. However, the data file was opened already early during the batch, and therefore fil_space_t::prepare() will not be invoked. That function would normally extend the data file to the recovered size before anything is going to be written to the file.