Type:
Bug
Priority:
Major
Resolution:
Fixed
Affects Version/s:
10.5 , 10.6 , 10.11 , 11.1(EOL) , 11.2(EOL) , 11.4 , 11.5(EOL) , 11.6(EOL)
We got a hung server :
10.6 2ceadb390309f9c29786bb5ec2a6459dfe88344e
versioning.rpl 'innodb,row,trx_id' w3 [ fail ] timeout after 900 seconds
Test ended at 2021-05-06 15:23:30
Test case timeout after 900 seconds
== D:/winx64-debug/build/mysql-test/var/3/log/rpl.log ==
include/master-slave.inc
== D:/winx64-debug/build/mysql-test/var/3/tmp/analyze-timeout-mysqld.2.err ==
SHOW PROCESSLIST;
Id User Host db Command Time State Info Progress
16 root localhost:38509 NULL Query 0 starting SHOW PROCESSLIST 0.000
== D:/winx64-debug/build/mysql-test/var/3/tmp/analyze-timeout-mysqld.1.err ==
SHOW PROCESSLIST;
Id User Host db Command Time State Info Progress
15 root localhost:37368 test Query 960 starting RESET MASTER 0.000
17 root localhost:38510 NULL Query 0 starting SHOW PROCESSLIST 0.000
mysqltest failed but provided no output
Among the stack traces, no InnoDB code is executing (only buf_flush_page_cleaner() is in an untimed wait). The culprit for the hang seems to be a thread that is executing RESET MASTER :
10.6 2ceadb390309f9c29786bb5ec2a6459dfe88344e
server!pthread_cond_wait(struct _RTL_CONDITION_VARIABLE * cond = 0x00007fff`622137a8, struct _RTL_CRITICAL_SECTION * mutex = 0x00007fff`62213778) [D:\winx64-debug\build\src\mysys\my_wincond.c @ 91]
server!psi_cond_wait(struct st_mysql_cond * that = 0x00007fff`622137a8, struct st_mysql_mutex * mutex = 0x00007fff`62213778, char * file = 0x00007fff`60671dc8 "D:\winx64-debug\build\src\sql\log.cc", unsigned int line = 0x10f8) [D:\winx64-debug\build\src\mysys\my_thr_init.c @ 596]
server!inline_mysql_cond_wait(struct st_mysql_cond * that = 0x00007fff`622137a8, struct st_mysql_mutex * mutex = 0x00007fff`62213778, char * src_file = 0x00007fff`60671dc8 "D:\winx64-debug\build\src\sql\log.cc", unsigned int src_line = 0x10f8) [D:\winx64-debug\build\src\include\mysql\psi\mysql_thread.h @ 1070]
server!MYSQL_BIN_LOG::reset_logs(class THD * thd = 0x00000227`de152788, bool create_new_log = true, struct rpl_gtid * init_state = 0x00000000`00000000, unsigned int init_state_len = 0, unsigned long next_log_number = 0) [D:\winx64-debug\build\src\sql\log.cc @ 4345]
server!reset_master(class THD * thd = 0x00000227`de152788, struct rpl_gtid * init_state = 0x00000000`00000000, unsigned int init_state_len = 0, unsigned long next_log_number = 0) [D:\winx64-debug\build\src\sql\sql_repl.cc @ 3966]
server!reload_acl_and_cache(class THD * thd = 0x00000227`de152788, unsigned int64 options = 0x80, struct TABLE_LIST * tables = 0x00000000`00000000, int * write_to_binlog = 0x00000063`731edb74) [D:\winx64-debug\build\src\sql\sql_reload.cc @ 362]
server!mysql_execute_command(class THD * thd = 0x00000227`de152788) [D:\winx64-debug\build\src\sql\sql_parse.cc @ 5452]
server!mysql_parse(class THD * thd = 0x00000227`de152788, char * rawbuf = 0x00000227`de1ca690 "--- memory read error at address 0x00000227`de1ca690 ---", unsigned int length = 0xc, class Parser_state * parser_state = 0x00000063`731ee950) [D:\winx64-debug\build\src\sql\sql_parse.cc @ 8018]
server!dispatch_command(enum_server_command command = COM_QUERY (0n3), class THD * thd = 0x00000227`de152788, char * packet = 0x00000227`ddfceec9 "--- memory read error at address 0x00000227`ddfceec9 ---", unsigned int packet_length = 0xc, bool blocking = false) [D:\winx64-debug\build\src\sql\sql_parse.cc @ 1899]
server!do_command(class THD * thd = 0x00000227`de152788, bool blocking = false) [D:\winx64-debug\build\src\sql\sql_parse.cc @ 1406]
server!threadpool_process_request(class THD * thd = 0x00000227`de152788) [D:\winx64-debug\build\src\sql\threadpool_common.cc @ 394]
server!tp_callback(struct TP_connection * c = 0x00000227`ddf80e30) [D:\winx64-debug\build\src\sql\threadpool_common.cc @ 203]
server!tp_callback(struct _TP_CALLBACK_INSTANCE * instance = 0x00000063`731ef968, void * context = 0x00000227`ddf80e30) [D:\winx64-debug\build\src\sql\threadpool_win.cc @ 279]
server!io_completion_callback(struct _TP_CALLBACK_INSTANCE * instance = 0x00000063`731ef968, void * context = 0x00000227`ddf80e30, void * overlapped = 0x00000227`ddf80ea0, unsigned long io_result = 0, unsigned int64 nbytes = 0x11, struct _TP_IO * io = 0x00000227`de05a5e0) [D:\winx64-debug\build\src\sql\threadpool_win.cc @ 299]
I think that also 10.5 must be affected by this. On older server versions, it is probably harder to reproduce this, because we never observed MDEV-24302 on older versions than 10.5. This could correlate with scheduling improvements in 10.5 (MDEV-23855 ) and 10.6 (MDEV-20612 , MDEV-25404 ); earlier, there could have been more scattered calls to write InnoDB log that would wake up RESET MASTER from its wait.
{"report":{"fcp":891.1000001430511,"ttfb":137.40000009536743,"pageVisibility":"visible","entityId":99447,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":64,"apdex":1,"journeyId":"a1ee0ac4-c6f5-4785-b73d-c12a70d270eb","navigationType":0,"readyForUser":959.9000000953674,"redirectCount":0,"resourceLoadedEnd":1325.2000000476837,"resourceLoadedStart":151.90000009536743,"resourceTiming":[{"duration":311.40000009536743,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2bu7/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":151.90000009536743,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":151.90000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":463.30000019073486,"responseStart":0,"secureConnectionStart":0},{"duration":311.2000000476837,"initiatorType":"link","name":"https://jira.mariadb.org/s/7ebd35e77e471bc30ff0eba799ebc151-CDN/lu2bu7/820016/12ta74/8679b4946efa1a0bb029a3a22206fb5d/_/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":152.10000014305115,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":152.10000014305115,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":463.30000019073486,"responseStart":0,"secureConnectionStart":0},{"duration":320,"initiatorType":"script","name":"https://jira.mariadb.org/s/fbf975c0cce4b1abf04784eeae9ba1f4-CDN/lu2bu7/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":152.30000019073486,"connectEnd":152.30000019073486,"connectStart":152.30000019073486,"domainLookupEnd":152.30000019073486,"domainLookupStart":152.30000019073486,"fetchStart":152.30000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":152.30000019073486,"responseEnd":472.30000019073486,"responseStart":472.30000019073486,"secureConnectionStart":152.30000019073486},{"duration":344.59999990463257,"initiatorType":"script","name":"https://jira.mariadb.org/s/099b33461394b8015fc36c0a4b96e19f-CDN/lu2bu7/820016/12ta74/8679b4946efa1a0bb029a3a22206fb5d/_/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":152.40000009536743,"connectEnd":152.40000009536743,"connectStart":152.40000009536743,"domainLookupEnd":152.40000009536743,"domainLookupStart":152.40000009536743,"fetchStart":152.40000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":152.40000009536743,"responseEnd":497,"responseStart":497,"secureConnectionStart":152.40000009536743},{"duration":348.30000019073486,"initiatorType":"script","name":"https://jira.mariadb.org/s/94c15bff32baef80f4096a08aceae8bc-CDN/lu2bu7/820016/12ta74/c92c0caa9a024ae85b0ebdbed7fb4bd7/_/download/contextbatch/js/atl.global,-_super/batch.js?locale=en","startTime":152.5,"connectEnd":152.5,"connectStart":152.5,"domainLookupEnd":152.5,"domainLookupStart":152.5,"fetchStart":152.5,"redirectEnd":0,"redirectStart":0,"requestStart":152.5,"responseEnd":500.80000019073486,"responseStart":500.7000000476837,"secureConnectionStart":152.5},{"duration":348.59999990463257,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bu7/820016/12ta74/1.0/_/download/batch/jira.webresources:calendar-en/jira.webresources:calendar-en.js","startTime":152.60000014305115,"connectEnd":152.60000014305115,"connectStart":152.60000014305115,"domainLookupEnd":152.60000014305115,"domainLookupStart":152.60000014305115,"fetchStart":152.60000014305115,"redirectEnd":0,"redirectStart":0,"requestStart":152.60000014305115,"responseEnd":501.2000000476837,"responseStart":501.2000000476837,"secureConnectionStart":152.60000014305115},{"duration":348.7999999523163,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bu7/820016/12ta74/1.0/_/download/batch/jira.webresources:calendar-localisation-moment/jira.webresources:calendar-localisation-moment.js","startTime":152.70000004768372,"connectEnd":152.70000004768372,"connectStart":152.70000004768372,"domainLookupEnd":152.70000004768372,"domainLookupStart":152.70000004768372,"fetchStart":152.70000004768372,"redirectEnd":0,"redirectStart":0,"requestStart":152.70000004768372,"responseEnd":501.5,"responseStart":501.5,"secureConnectionStart":152.70000004768372},{"duration":349.39999985694885,"initiatorType":"link","name":"https://jira.mariadb.org/s/b04b06a02d1959df322d9cded3aeecc1-CDN/lu2bu7/820016/12ta74/a2ff6aa845ffc9a1d22fe23d9ee791fc/_/download/contextbatch/css/jira.global.look-and-feel,-_super/batch.css","startTime":152.80000019073486,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":152.80000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":502.2000000476837,"responseStart":0,"secureConnectionStart":0},{"duration":349.09999990463257,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":152.80000019073486,"connectEnd":152.80000019073486,"connectStart":152.80000019073486,"domainLookupEnd":152.80000019073486,"domainLookupStart":152.80000019073486,"fetchStart":152.80000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":152.80000019073486,"responseEnd":501.90000009536743,"responseStart":501.90000009536743,"secureConnectionStart":152.80000019073486},{"duration":349.40000009536743,"initiatorType":"link","name":"https://jira.mariadb.org/s/3ac36323ba5e4eb0af2aa7ac7211b4bb-CDN/lu2bu7/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":153,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":153,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":502.40000009536743,"responseStart":0,"secureConnectionStart":0},{"duration":349.2999999523163,"initiatorType":"script","name":"https://jira.mariadb.org/s/3339d87fa2538a859872f2df449bf8d0-CDN/lu2bu7/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":153.20000004768372,"connectEnd":153.20000004768372,"connectStart":153.20000004768372,"domainLookupEnd":153.20000004768372,"domainLookupStart":153.20000004768372,"fetchStart":153.20000004768372,"redirectEnd":0,"redirectStart":0,"requestStart":153.20000004768372,"responseEnd":502.5,"responseStart":502.5,"secureConnectionStart":153.20000004768372},{"duration":640.5,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bu7/820016/12ta74/1.0/_/download/batch/jira.webresources:bigpipe-js/jira.webresources:bigpipe-js.js","startTime":154.30000019073486,"connectEnd":154.30000019073486,"connectStart":154.30000019073486,"domainLookupEnd":154.30000019073486,"domainLookupStart":154.30000019073486,"fetchStart":154.30000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":154.30000019073486,"responseEnd":794.8000001907349,"responseStart":794.8000001907349,"secureConnectionStart":154.30000019073486},{"duration":1170.8999998569489,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bu7/820016/12ta74/1.0/_/download/batch/jira.webresources:bigpipe-init/jira.webresources:bigpipe-init.js","startTime":154.30000019073486,"connectEnd":154.30000019073486,"connectStart":154.30000019073486,"domainLookupEnd":154.30000019073486,"domainLookupStart":154.30000019073486,"fetchStart":154.30000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":154.30000019073486,"responseEnd":1325.2000000476837,"responseStart":1325.2000000476837,"secureConnectionStart":154.30000019073486},{"duration":513.1000001430511,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":699,"connectEnd":699,"connectStart":699,"domainLookupEnd":699,"domainLookupStart":699,"fetchStart":699,"redirectEnd":0,"redirectStart":0,"requestStart":699,"responseEnd":1212.1000001430511,"responseStart":1212.1000001430511,"secureConnectionStart":699},{"duration":467.39999985694885,"initiatorType":"script","name":"https://www.google-analytics.com/analytics.js","startTime":869.8000001907349,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":869.8000001907349,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":1337.2000000476837,"responseStart":0,"secureConnectionStart":0}],"fetchStart":0,"domainLookupStart":0,"domainLookupEnd":0,"connectStart":0,"connectEnd":0,"requestStart":2,"responseStart":137,"responseEnd":141,"domLoading":149,"domInteractive":1347,"domContentLoadedEventStart":1347,"domContentLoadedEventEnd":1383,"domComplete":2084,"loadEventStart":2084,"loadEventEnd":2086,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":1331.5},{"name":"bigPipe.sidebar-id.end","time":1332.3000001907349},{"name":"bigPipe.activity-panel-pipe-id.start","time":1332.4000000953674},{"name":"bigPipe.activity-panel-pipe-id.end","time":1334.7000000476837},{"name":"activityTabFullyLoaded","time":1389.8000001907349}],"measures":[],"correlationId":"7bd589d7190c3","effectiveType":"4g","downlink":9.7,"rtt":0,"serverDuration":81,"dbReadsTimeInMs":20,"dbConnsTimeInMs":28,"applicationHash":"9d11dbea5f4be3d4cc21f03a88dd11d8c8687422","experiments":[]}}