revision-id: knielsen@knielsen-hq.org-20140321123055-8ch69qymsj1xqmw4
date: 2014-03-21 13:30:55 +0100
build-date: 2014-03-24 18:54:08 +0200
revno: 4076
branch-nick: 10.0
The timeout error was encountered while running a concurrent test (12 threads on master) with SBR replication using GTID, and slave-parallel-threads=10.
140321 20:08:47 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:10730',replication starts at GTID position ''
140321 20:12:58 [ERROR] mysqld: Lock wait timeout exceeded; try restarting transaction
140321 20:12:58 [ERROR] Slave SQL: Error 'Lock wait timeout exceeded; try restarting transaction' on query. Default database: 'test'. Query: 'UPDATE `table10_innodb_int_autoinc` AS X SET `col_char_12_key` = 'j' WHERE X . `col_int_key` IN ( 223 , 4 , 113 , 1674772480 , 242679808 ) ORDER BY `col_char_12`,`col_char_12_key`,`col_int`,`col_int_key`,`pk` LIMIT 5', Internal MariaDB error code: 1205
140321 20:12:58 [Warning] Slave: Lock wait timeout exceeded; try restarting transaction Error_code: 1205
140321 20:12:58 [Warning] Slave: Sort aborted: Lock wait timeout exceeded; try restarting transaction Error_code: 1028
140321 20:12:58 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'mysql-bin.000033' position 20863; GTID position '0-1-669'
The test mainly executes DML, but involves DDL and FLUSH LOGS as well.
The test flow includes a lot of statements that are unsafe for SBR or are considered to be such, but as far as I can see from the slave log, there was nothing particularly wrong done to the slave around the time when the problem occured.
Slave is not restarted during the test (neither the server, nor the logical slave).
I encountered the same error several times later, so it's not a unique occasion, but it's sporadic and not easily reproducible. Also, I couldn't reproduce it while feeding the same master binary logs to a clean slave, so it seems to be a true race condition.
The following logs are attached:
master_binlogs.tar.gz - all master binary logs
slave_error.log
slave_general.log
my.cnf (for the reference, only one meaningful option in there, slave-parallel-threads=10); identical for master and slave
Server command lines (although semisync plugins are there, they were not available at the time of server startup, so the error of not finding them can be seen in the slave error log):
<basedir>/sql/mysqld --defaults-group-suffix=.runtime --defaults-file=<master_vardir>/my.cnf --basedir=<basedir> --datadir=<master_vardir>/data --lc-messages-dir=<basedir>/sql/share --character-sets-dir=<basedir>/sql/share/charsets --tmpdir=<master_vardir>/tmp --core-file --max-allowed-packet=128Mb --port=10730 --socket=<master_vardir>/mysql.sock --pid-file=<master_vardir>/mysql.pid --general-log --general-log-file=<master_vardir>/mysql.log --server_id=1 --log-bin=mysql-bin --report-host=127.0.0.1 --report_port=10730 --sql-mode=no_engine_substitution --binlog_commit_wait_count=10 --binlog_commit_wait_usec=1000000 --plugin-load-add=semisync_master --plugin-load-add=semisync_slave --loose-rpl_semi_sync_master_timeout=600 --log-output=FILE --slave-skip-errors=1054,1317,1049,1305,1539,1505
<basedir>/sql/mysqld --defaults-group-suffix=.runtime --defaults-file=<slave_vardir>/my.cnf --basedir=<basedir> --datadir=<slave_vardir>/data --lc-messages-dir=<basedir>/sql/share --character-sets-dir=<basedir>/sql/share/charsets --tmpdir=<slave_vardir>/tmp --core-file --max-allowed-packet=128Mb --port=10732 --socket=<slave_vardir>/mysql.sock --pid-file=<slave_vardir>/mysql.pid --general-log --general-log-file=<slave_vardir>/mysql.log --server_id=2 --report-host=127.0.0.1 --report_port=10732 --sql-mode=no_engine_substitution --binlog_commit_wait_count=10 --binlog_commit_wait_usec=1000000 --plugin-load-add=semisync_master --plugin-load-add=semisync_slave --loose-rpl_semi_sync_master_timeout=600 --log-output=FILE --slave-skip-errors=1054,1317,1049,1305,1539,1505
Kristian Nielsen
made changes -
2014-03-25 10:22
Field
Original Value
New Value
Status
Open
[ 1
]
In Progress
[ 3
]
Kristian Nielsen
made changes -
2014-03-27 12:08
Priority
Major
[ 3
]
Critical
[ 2
]
Sergei Golubchik
made changes -
2014-03-31 14:23
Fix Version/s
10.0.11
[ 15200
]
Fix Version/s
10.0.10
[ 14500
]
Elena Stepanova
made changes -
2014-04-07 18:29
Affects Version/s
10.0.10
[ 14500
]
Kristian Nielsen
made changes -
2014-04-11 12:18
Status
In Progress
[ 3
]
Stalled
[ 10000
]
Kristian Nielsen
made changes -
2014-04-29 16:24
Priority
Critical
[ 2
]
Minor
[ 4
]
Kristian Nielsen
made changes -
2014-04-29 16:25
Priority
Minor
[ 4
]
Major
[ 3
]
Kristian Nielsen
made changes -
2014-04-30 11:51
Status
Stalled
[ 10000
]
In Progress
[ 3
]
Sergei Golubchik
made changes -
2014-05-10 23:12
Fix Version/s
10.0.12
[ 15201
]
Fix Version/s
10.0.11
[ 15200
]
Kristian Nielsen
made changes -
2014-06-03 16:45
Priority
Major
[ 3
]
Minor
[ 4
]
Sergei Golubchik
made changes -
2014-06-10 10:34
Priority
Minor
[ 4
]
Critical
[ 2
]
Kristian Nielsen
made changes -
2014-06-10 14:14
Assignee
Kristian Nielsen
[ knielsen
]
Sergei Golubchik
[ serg
]
Sergei Golubchik
made changes -
2014-06-10 21:47
Labels
parallelslave
parallelslave replication
Sergei Golubchik
made changes -
2014-06-13 15:06
Workflow
defaullt
[ 37101
]
MariaDB v2
[ 42457
]
Sergei Golubchik
made changes -
2014-06-13 15:09
Status
In Progress
[ 3
]
Stalled
[ 10000
]
Sergei Golubchik
made changes -
2014-06-13 15:09
Status
Stalled
[ 10000
]
In Review
[ 10002
]
Sergei Golubchik
made changes -
2014-06-16 13:27
Fix Version/s
10.0.13
[ 16000
]
Fix Version/s
10.0.12
[ 15201
]
Sergei Golubchik
made changes -
2014-06-24 17:49
Fix Version/s
10.0.13
[ 16300
]
Fix Version/s
10.0
[ 16000
]
Sergei Golubchik
made changes -
2014-07-03 11:31
Assignee
Sergei Golubchik
[ serg
]
Kristian Nielsen
[ knielsen
]
Status
In Review
[ 10002
]
Stalled
[ 10000
]
Kristian Nielsen
made changes -
2014-07-08 17:59
Status
Stalled
[ 10000
]
In Progress
[ 3
]
Kristian Nielsen
made changes -
2014-07-11 13:09
Resolution
Fixed
[ 1
]
Status
In Progress
[ 3
]
Closed
[ 6
]
Sergei Golubchik
made changes -
2021-12-06 21:39
Workflow
MariaDB v3
[ 61414
]
MariaDB v4
[ 147690
]
{"report":{"fcp":878.8999996185303,"ttfb":306.8999996185303,"pageVisibility":"visible","entityId":33301,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":64,"apdex":1,"journeyId":"be112c5d-ea2d-4e4b-86f7-21615fe9e1c7","navigationType":0,"readyForUser":964.6999998092651,"redirectCount":0,"resourceLoadedEnd":997.0999994277954,"resourceLoadedStart":315.29999923706055,"resourceTiming":[{"duration":35.40000057220459,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2bv2/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":315.29999923706055,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":315.29999923706055,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":350.69999980926514,"responseStart":0,"secureConnectionStart":0},{"duration":35.39999961853027,"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":315.69999980926514,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":315.69999980926514,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":351.0999994277954,"responseStart":0,"secureConnectionStart":0},{"duration":93.09999942779541,"initiatorType":"script","name":"https://jira.mariadb.org/s/e9b27a47da5fb0f74a35acd57e9847fb-CDN/lu2bv2/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":316,"connectEnd":316,"connectStart":316,"domainLookupEnd":316,"domainLookupStart":316,"fetchStart":316,"redirectEnd":0,"redirectStart":0,"requestStart":316,"responseEnd":409.0999994277954,"responseStart":409.0999994277954,"secureConnectionStart":316},{"duration":165.5,"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":316.5,"connectEnd":316.5,"connectStart":316.5,"domainLookupEnd":316.5,"domainLookupStart":316.5,"fetchStart":316.5,"redirectEnd":0,"redirectStart":0,"requestStart":316.5,"responseEnd":482,"responseStart":482,"secureConnectionStart":316.5},{"duration":169.60000038146973,"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":316.79999923706055,"connectEnd":316.79999923706055,"connectStart":316.79999923706055,"domainLookupEnd":316.79999923706055,"domainLookupStart":316.79999923706055,"fetchStart":316.79999923706055,"redirectEnd":0,"redirectStart":0,"requestStart":316.79999923706055,"responseEnd":486.3999996185303,"responseStart":486.3999996185303,"secureConnectionStart":316.79999923706055},{"duration":169.89999961853027,"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":317,"connectEnd":317,"connectStart":317,"domainLookupEnd":317,"domainLookupStart":317,"fetchStart":317,"redirectEnd":0,"redirectStart":0,"requestStart":317,"responseEnd":486.8999996185303,"responseStart":486.8999996185303,"secureConnectionStart":317},{"duration":170,"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":317.19999980926514,"connectEnd":317.19999980926514,"connectStart":317.19999980926514,"domainLookupEnd":317.19999980926514,"domainLookupStart":317.19999980926514,"fetchStart":317.19999980926514,"redirectEnd":0,"redirectStart":0,"requestStart":317.19999980926514,"responseEnd":487.19999980926514,"responseStart":487.19999980926514,"secureConnectionStart":317.19999980926514},{"duration":236.70000076293945,"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":317.29999923706055,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":317.29999923706055,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":554,"responseStart":0,"secureConnectionStart":0},{"duration":170.0999994277954,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":317.5,"connectEnd":317.5,"connectStart":317.5,"domainLookupEnd":317.5,"domainLookupStart":317.5,"fetchStart":317.5,"redirectEnd":0,"redirectStart":0,"requestStart":317.5,"responseEnd":487.5999994277954,"responseStart":487.5999994277954,"secureConnectionStart":317.5},{"duration":236.5,"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":317.69999980926514,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":317.69999980926514,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":554.1999998092651,"responseStart":0,"secureConnectionStart":0},{"duration":170.30000019073486,"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":317.8999996185303,"connectEnd":317.8999996185303,"connectStart":317.8999996185303,"domainLookupEnd":317.8999996185303,"domainLookupStart":317.8999996185303,"fetchStart":317.8999996185303,"redirectEnd":0,"redirectStart":0,"requestStart":317.8999996185303,"responseEnd":488.19999980926514,"responseStart":488.19999980926514,"secureConnectionStart":317.8999996185303},{"duration":388.3999996185303,"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":328.5,"connectEnd":328.5,"connectStart":328.5,"domainLookupEnd":328.5,"domainLookupStart":328.5,"fetchStart":328.5,"redirectEnd":0,"redirectStart":0,"requestStart":328.5,"responseEnd":716.8999996185303,"responseStart":716.7999992370605,"secureConnectionStart":328.5},{"duration":596.8999996185303,"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":348.8999996185303,"connectEnd":348.8999996185303,"connectStart":348.8999996185303,"domainLookupEnd":348.8999996185303,"domainLookupStart":348.8999996185303,"fetchStart":348.8999996185303,"redirectEnd":0,"redirectStart":0,"requestStart":348.8999996185303,"responseEnd":945.7999992370605,"responseStart":945.7999992370605,"secureConnectionStart":348.8999996185303},{"duration":156,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":565.5999994277954,"connectEnd":565.5999994277954,"connectStart":565.5999994277954,"domainLookupEnd":565.5999994277954,"domainLookupStart":565.5999994277954,"fetchStart":565.5999994277954,"redirectEnd":0,"redirectStart":0,"requestStart":565.5999994277954,"responseEnd":721.5999994277954,"responseStart":721.5999994277954,"secureConnectionStart":565.5999994277954},{"duration":168.5,"initiatorType":"link","name":"https://jira.mariadb.org/s/d5715adaadd168a9002b108b2b039b50-CDN/lu2bv2/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","startTime":828.5999994277954,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":828.5999994277954,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":997.0999994277954,"responseStart":0,"secureConnectionStart":0},{"duration":119.19999980926514,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bv2/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","startTime":829.5999994277954,"connectEnd":829.5999994277954,"connectStart":829.5999994277954,"domainLookupEnd":829.5999994277954,"domainLookupStart":829.5999994277954,"fetchStart":829.5999994277954,"redirectEnd":0,"redirectStart":0,"requestStart":829.5999994277954,"responseEnd":948.7999992370605,"responseStart":948.7999992370605,"secureConnectionStart":829.5999994277954},{"duration":123.79999923706055,"initiatorType":"script","name":"https://jira.mariadb.org/s/53a43b6764f587426c7bb9a150184c00-CDN/lu2bv2/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","startTime":830,"connectEnd":830,"connectStart":830,"domainLookupEnd":830,"domainLookupStart":830,"fetchStart":830,"redirectEnd":0,"redirectStart":0,"requestStart":830,"responseEnd":953.7999992370605,"responseStart":953.7999992370605,"secureConnectionStart":830},{"duration":172.80000019073486,"initiatorType":"script","name":"https://www.google-analytics.com/analytics.js","startTime":871.8999996185303,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":871.8999996185303,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1044.6999998092651,"responseStart":0,"secureConnectionStart":0}],"fetchStart":0,"domainLookupStart":0,"domainLookupEnd":0,"connectStart":0,"connectEnd":0,"requestStart":58,"responseStart":307,"responseEnd":349,"domLoading":310,"domInteractive":1091,"domContentLoadedEventStart":1091,"domContentLoadedEventEnd":1140,"domComplete":1613,"loadEventStart":1613,"loadEventEnd":1613,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":1055.2999992370605},{"name":"bigPipe.sidebar-id.end","time":1057.2999992370605},{"name":"bigPipe.activity-panel-pipe-id.start","time":1057.5},{"name":"bigPipe.activity-panel-pipe-id.end","time":1063.7999992370605},{"name":"activityTabFullyLoaded","time":1169.1999998092651}],"measures":[],"correlationId":"cededaa6a86af7","effectiveType":"4g","downlink":9.9,"rtt":0,"serverDuration":171,"dbReadsTimeInMs":39,"dbConnsTimeInMs":50,"applicationHash":"9d11dbea5f4be3d4cc21f03a88dd11d8c8687422","experiments":[]}}