The two test cases below differ only in FTWRL vs BACKUP STAGE x 2 and cause the same effect, both on release and debug builds.
FTWRL
|
--source include/have_binlog_format_mixed_or_statement.inc
|
|
CREATE TEMPORARY TABLE tmp (a INT);
|
|
--connect (con1,localhost,root,,)
|
FLUSH TABLES WITH READ LOCK;
|
|
--connection default
|
SET lock_wait_timeout= 1;
|
ALTER TABLE tmp;
|
BACKUP STAGE
|
--source include/have_binlog_format_mixed_or_statement.inc
|
|
CREATE TEMPORARY TABLE tmp (a INT);
|
|
--connect (con1,localhost,root,,)
|
BACKUP STAGE START;
|
BACKUP STAGE BLOCK_COMMIT;
|
|
--connection default
|
SET lock_wait_timeout= 1;
|
ALTER TABLE tmp;
|
The backup lock taken by con1 blocks ALTER on a temporary table in the connection default and makes it eventually fail with a timeout. It affects debug and non-debug builds alike.
10.4 880baedc
|
connection default;
|
SET lock_wait_timeout= 1;
|
ALTER TABLE tmp;
|
bug.t [ fail ]
|
Test ended at 2021-04-03 20:00:05
|
|
CURRENT_TEST: bug.t
|
mysqltest: At line 12: query 'ALTER TABLE tmp' failed: 1205: Lock wait timeout exceeded; try restarting transaction
|
Debug builds further abort with an assertion failure in diagnostics area:
10.4 880baedc debug
|
mysqld: /data/src/10.4/sql/sql_error.cc:445: void Diagnostics_area::set_error_status(uint, const char*, const char*, const Sql_user_condition_identity&, const Sql_condition*): Assertion `! is_set() || m_can_overwrite_status' failed.
|
210403 20:02:19 [ERROR] mysqld got signal 6 ;
|
|
#7 0x00007f081775af36 in __GI___assert_fail (assertion=0x5564e69c1468 "! is_set() || m_can_overwrite_status", file=0x5564e69c1200 "/data/src/10.4/sql/sql_error.cc", line=445, function=0x5564e69c1490 "void Diagnostics_area::set_error_status(uint, const char*, const char*, const Sql_user_condition_identity&, const Sql_condition*)") at assert.c:101
|
#8 0x00005564e5c71870 in Diagnostics_area::set_error_status (this=0x7f07f40067a8, sql_errno=1205, message=0x7f08116dc3a0 "Lock wait timeout exceeded; try restarting transaction", sqlstate=0x5564e69e6e6d "HY000", ucid=..., error_condition=0x0) at /data/src/10.4/sql/sql_error.cc:445
|
#9 0x00005564e5c4b83f in THD::raise_condition (this=0x7f07f4000d90, sql_errno=1205, sqlstate=0x5564e69e6e6d "HY000", level=Sql_state_errno_level::WARN_LEVEL_ERROR, ucid=..., msg=0x7f08116dc3a0 "Lock wait timeout exceeded; try restarting transaction") at /data/src/10.4/sql/sql_class.cc:1103
|
#10 0x00005564e5b8cb50 in THD::raise_condition (this=0x7f07f4000d90, sql_errno=1205, sqlstate=0x0, level=Sql_state_errno_level::WARN_LEVEL_ERROR, msg=0x7f08116dc3a0 "Lock wait timeout exceeded; try restarting transaction") at /data/src/10.4/sql/sql_class.h:4400
|
#11 0x00005564e5b7f530 in my_message_sql (error=1205, str=0x7f08116dc3a0 "Lock wait timeout exceeded; try restarting transaction", MyFlags=0) at /data/src/10.4/sql/mysqld.cc:3346
|
#12 0x00005564e68dd15f in my_error (nr=1205, MyFlags=0) at /data/src/10.4/mysys/my_error.c:125
|
#13 0x00005564e5e5f3eb in MDL_context::acquire_lock (this=0x7f07f4000eb0, mdl_request=0x7f08116dc870, lock_wait_timeout=1) at /data/src/10.4/sql/mdl.cc:2365
|
#14 0x00005564e6173c16 in MYSQL_BIN_LOG::write (this=0x5564e7479300 <mysql_bin_log>, event_info=0x7f08116dcab0, with_annotate=0x0) at /data/src/10.4/sql/log.cc:6393
|
#15 0x00005564e5c5cd1e in THD::binlog_query (this=0x7f07f4000d90, qtype=THD::STMT_QUERY_TYPE, query_arg=0x7f07f4014888 "ALTER TABLE tmp", query_len=15, is_trans=false, direct=false, suppress_use=false, errcode=0) at /data/src/10.4/sql/sql_class.cc:7209
|
#16 0x00005564e5da7114 in write_bin_log (thd=0x7f07f4000d90, clear_error=true, query=0x7f07f4014888 "ALTER TABLE tmp", query_length=15, is_trans=false) at /data/src/10.4/sql/sql_table.cc:1987
|
#17 0x00005564e5dbe074 in mysql_alter_table (thd=0x7f07f4000d90, new_db=0x7f07f4005560, new_name=0x7f07f4005988, create_info=0x7f08116df330, table_list=0x7f07f4014948, alter_info=0x7f08116df270, order_num=0, order=0x0, ignore=false) at /data/src/10.4/sql/sql_table.cc:9815
|
#18 0x00005564e5e59264 in Sql_cmd_alter_table::execute (this=0x7f07f4015010, thd=0x7f07f4000d90) at /data/src/10.4/sql/sql_alter.cc:520
|
#19 0x00005564e5ccfd9f in mysql_execute_command (thd=0x7f07f4000d90) at /data/src/10.4/sql/sql_parse.cc:6186
|
#20 0x00005564e5cd519d in mysql_parse (thd=0x7f07f4000d90, rawbuf=0x7f07f4014888 "ALTER TABLE tmp", length=15, parser_state=0x7f08116e0550, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7989
|
#21 0x00005564e5cc13f9 in dispatch_command (command=COM_QUERY, thd=0x7f07f4000d90, packet=0x7f07f400ace1 "ALTER TABLE tmp", packet_length=15, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1855
|
#22 0x00005564e5cbfc61 in do_command (thd=0x7f07f4000d90) at /data/src/10.4/sql/sql_parse.cc:1373
|
#23 0x00005564e5e4f9c1 in do_handle_one_connection (connect=0x5564e92ebfd0) at /data/src/10.4/sql/sql_connect.cc:1412
|
#24 0x00005564e5e4f70a in handle_one_connection (arg=0x5564e92ebfd0) at /data/src/10.4/sql/sql_connect.cc:1316
|
#25 0x00005564e68784e8 in pfs_spawn_thread (arg=0x5564e92381d0) at /data/src/10.4/storage/perfschema/pfs.cc:1869
|
#26 0x00007f0817fdb609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#27 0x00007f0817846293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
Query (0x7f07f4014888): ALTER TABLE tmp
|
|
Connection ID (thread ID): 5
|
Status: NOT_KILLED
|
The problem was introduced in 10.4.16/10.5.7 by this commit:
commit 16ea692ed490a1a2c6dc0b855247d5bd02bd2345 (HEAD)
|
Author: Monty
|
Date: Mon Sep 7 10:38:12 2020 +0300
|
|
MDEV-23586 Mariabackup: GTID saved for replication in 10.4.14 is wrong
|
|
MDEV-21953 deadlock between BACKUP STAGE BLOCK_COMMIT and parallel
|
replication
|
|
Fixed by partly reverting MDEV-21953 to put back MDL_BACKUP_COMMIT locking
|
before log_and_order.
|
|
The original problem for MDEV-21953 was that while a thread was waiting in
|
for another threads to commit in 'log_and_order', it had the
|
MDL_BACKUP_COMMIT lock. The backup thread was waiting to get the
|
MDL_BACKUP_WAIT_COMMIT lock, which blocks all new MDL_BACKUP_COMMIT locks.
|
This causes a deadlock as the waited-for thread can never get past the
|
MDL_BACKUP_COMMIT lock in ha_commit_trans.
|
|
The main part of the bug fix is to release the MDL_BACKUP_COMMIT lock while
|
a thread is waiting for other 'previous' threads to commit. This ensures
|
that no transactional thread keeps MDL_BACKUP_COMMIT while waiting, which
|
ensures that there are no deadlocks anymore.
|
I can't figure from the commit comment whether the effect with blocking temporary table actions was intentional. The assertion failure obviously wasn't.
- is caused by
-
MDEV-23586
Mariabackup: GTID saved for replication in 10.4.14 is wrong
-
-
Closed
{"report":{"fcp":1160.6999998092651,"ttfb":326.5,"pageVisibility":"visible","entityId":98525,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":64,"apdex":0.5,"journeyId":"1907c3c5-2424-46f9-a73d-b76a2d149887","navigationType":0,"readyForUser":1261.2999997138977,"redirectCount":0,"resourceLoadedEnd":1298.6999998092651,"resourceLoadedStart":333.2999997138977,"resourceTiming":[{"duration":301.5,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":333.2999997138977,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":333.2999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":634.7999997138977,"responseStart":0,"secureConnectionStart":0},{"duration":301.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":333.69999980926514,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":333.69999980926514,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":635.1999998092651,"responseStart":0,"secureConnectionStart":0},{"duration":310.3999996185303,"initiatorType":"script","name":"https://jira.mariadb.org/s/0917945aaa57108d00c5076fea35e069-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":333.90000009536743,"connectEnd":333.90000009536743,"connectStart":333.90000009536743,"domainLookupEnd":333.90000009536743,"domainLookupStart":333.90000009536743,"fetchStart":333.90000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":333.90000009536743,"responseEnd":644.2999997138977,"responseStart":644.2999997138977,"secureConnectionStart":333.90000009536743},{"duration":358.69999980926514,"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":334.09999990463257,"connectEnd":334.09999990463257,"connectStart":334.09999990463257,"domainLookupEnd":334.09999990463257,"domainLookupStart":334.09999990463257,"fetchStart":334.09999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":334.09999990463257,"responseEnd":692.7999997138977,"responseStart":692.7999997138977,"secureConnectionStart":334.09999990463257},{"duration":362.90000009536743,"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":334.2999997138977,"connectEnd":334.2999997138977,"connectStart":334.2999997138977,"domainLookupEnd":334.2999997138977,"domainLookupStart":334.2999997138977,"fetchStart":334.2999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":334.2999997138977,"responseEnd":697.1999998092651,"responseStart":697.1999998092651,"secureConnectionStart":334.2999997138977},{"duration":363.19999980926514,"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":334.59999990463257,"connectEnd":334.59999990463257,"connectStart":334.59999990463257,"domainLookupEnd":334.59999990463257,"domainLookupStart":334.59999990463257,"fetchStart":334.59999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":334.59999990463257,"responseEnd":697.7999997138977,"responseStart":697.7999997138977,"secureConnectionStart":334.59999990463257},{"duration":363.40000009536743,"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":334.7999997138977,"connectEnd":334.7999997138977,"connectStart":334.7999997138977,"domainLookupEnd":334.7999997138977,"domainLookupStart":334.7999997138977,"fetchStart":334.7999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":334.7999997138977,"responseEnd":698.1999998092651,"responseStart":698.1999998092651,"secureConnectionStart":334.7999997138977},{"duration":460.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":334.90000009536743,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":334.90000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":795.5999999046326,"responseStart":0,"secureConnectionStart":0},{"duration":363.80000019073486,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":335.09999990463257,"connectEnd":335.09999990463257,"connectStart":335.09999990463257,"domainLookupEnd":335.09999990463257,"domainLookupStart":335.09999990463257,"fetchStart":335.09999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":335.09999990463257,"responseEnd":698.9000000953674,"responseStart":698.9000000953674,"secureConnectionStart":335.09999990463257},{"duration":460.40000009536743,"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":335.2999997138977,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":335.2999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":795.6999998092651,"responseStart":0,"secureConnectionStart":0},{"duration":364.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":335.5,"connectEnd":335.5,"connectStart":335.5,"domainLookupEnd":335.5,"domainLookupStart":335.5,"fetchStart":335.5,"redirectEnd":0,"redirectStart":0,"requestStart":335.5,"responseEnd":699.5999999046326,"responseStart":699.5,"secureConnectionStart":335.5},{"duration":676.7999997138977,"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":336.40000009536743,"connectEnd":336.40000009536743,"connectStart":336.40000009536743,"domainLookupEnd":336.40000009536743,"domainLookupStart":336.40000009536743,"fetchStart":336.40000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":336.40000009536743,"responseEnd":1013.1999998092651,"responseStart":1013.1999998092651,"secureConnectionStart":336.40000009536743},{"duration":955,"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":336.5,"connectEnd":336.5,"connectStart":336.5,"domainLookupEnd":336.5,"domainLookupStart":336.5,"fetchStart":336.5,"redirectEnd":0,"redirectStart":0,"requestStart":336.5,"responseEnd":1291.5,"responseStart":1291.5,"secureConnectionStart":336.5},{"duration":196.5,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":817.0999999046326,"connectEnd":817.0999999046326,"connectStart":817.0999999046326,"domainLookupEnd":817.0999999046326,"domainLookupStart":817.0999999046326,"fetchStart":817.0999999046326,"redirectEnd":0,"redirectStart":0,"requestStart":817.0999999046326,"responseEnd":1013.5999999046326,"responseStart":1013.5999999046326,"secureConnectionStart":817.0999999046326},{"duration":208.7999997138977,"initiatorType":"link","name":"https://jira.mariadb.org/s/d5715adaadd168a9002b108b2b039b50-CDN/lu2cib/820016/12ta74/be4b45e9cec53099498fa61c8b7acba4/_/download/contextbatch/css/jira.project.sidebar,-_super,-project.issue.navigator,-jira.general,-jira.browse.project,-jira.view.issue,-jira.global,-atl.general,-com.atlassian.jira.projects.sidebar.init/batch.css?agile_global_admin_condition=true&jag=true&jira.create.linked.issue=true&slack-enabled=true&whisper-enabled=true","startTime":1089.9000000953674,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":1089.9000000953674,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1298.6999998092651,"responseStart":0,"secureConnectionStart":0},{"duration":308.80000019073486,"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":1090.7999997138977,"connectEnd":1090.7999997138977,"connectStart":1090.7999997138977,"domainLookupEnd":1090.7999997138977,"domainLookupStart":1090.7999997138977,"fetchStart":1090.7999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":1090.7999997138977,"responseEnd":1399.5999999046326,"responseStart":1399.5999999046326,"secureConnectionStart":1090.7999997138977},{"duration":317.80000019073486,"initiatorType":"script","name":"https://jira.mariadb.org/s/097ae97cb8fbec7d6ea4bbb1f26955b9-CDN/lu2cib/820016/12ta74/be4b45e9cec53099498fa61c8b7acba4/_/download/contextbatch/js/jira.project.sidebar,-_super,-project.issue.navigator,-jira.general,-jira.browse.project,-jira.view.issue,-jira.global,-atl.general,-com.atlassian.jira.projects.sidebar.init/batch.js?agile_global_admin_condition=true&jag=true&jira.create.linked.issue=true&locale=en&slack-enabled=true&whisper-enabled=true","startTime":1091.2999997138977,"connectEnd":1091.2999997138977,"connectStart":1091.2999997138977,"domainLookupEnd":1091.2999997138977,"domainLookupStart":1091.2999997138977,"fetchStart":1091.2999997138977,"redirectEnd":0,"redirectStart":0,"requestStart":1091.2999997138977,"responseEnd":1409.0999999046326,"responseStart":1409.0999999046326,"secureConnectionStart":1091.2999997138977}],"fetchStart":0,"domainLookupStart":0,"domainLookupEnd":0,"connectStart":0,"connectEnd":0,"requestStart":153,"responseStart":326,"responseEnd":330,"domLoading":331,"domInteractive":1368,"domContentLoadedEventStart":1368,"domContentLoadedEventEnd":1421,"domComplete":2128,"loadEventStart":2128,"loadEventEnd":2129,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":1351.9000000953674},{"name":"bigPipe.sidebar-id.end","time":1353.7999997138977},{"name":"bigPipe.activity-panel-pipe-id.start","time":1354},{"name":"bigPipe.activity-panel-pipe-id.end","time":1355.1999998092651},{"name":"activityTabFullyLoaded","time":1449}],"measures":[],"correlationId":"96a8008800866d","effectiveType":"4g","downlink":10,"rtt":0,"serverDuration":101,"dbReadsTimeInMs":12,"dbConnsTimeInMs":21,"applicationHash":"9d11dbea5f4be3d4cc21f03a88dd11d8c8687422","experiments":[]}}
Fixed by adding a MDL_BACKUP_COMMIT lock before altering temporary tables whose creation was logged to binary log (in which case the ALTER TABLE must also be logged)