Affects only macOS afaik. main.show_explain includes wait_condition.inc whenever it needs to wait for a bit before checking a condition. On linux, this wait is very short but on macOS (as verified with --mark-progress), it's quite lengthy, sometimes 10 or more seconds. Why is this? Interestingly, the $wait_condition variable isn't set before sourcing wait_condition.inc; setting that variable is a common pattern in other tests that use wait_condition.inc. Perhaps that usage is incorrect and on Linux it just happens to be enough of a delay for the desired event to occur, but I'm speculating.
let $wait_condition= select State='show_explain_trap' from information_schema.processlist where id=$thr2;
at the start of show_explain.test before any "invocation" of wait_condition.inc, isn't it?
Sergei Petrunia
added a comment - - edited there is
let $wait_condition= select State='show_explain_trap' from information_schema.processlist where id=$thr2;
at the start of show_explain.test before any "invocation" of wait_condition.inc , isn't it?
This isn't a test issue after all, but rather show explain for takes nearly one second on macOS when the same is nearly instantaneous on Linux.
Dave Gosselin
added a comment - This isn't a test issue after all, but rather show explain for takes nearly one second on macOS when the same is nearly instantaneous on Linux.
The use of APCs causes at least part of the slowdown observed on macOS. When waiting for all APC calls to be serviced, we invoke my_sleep from dbug_serve_apcs. This sleep is implemented as a call to select() with a valid timeval struct. However on macOS, this select takes longer to return than on Linux. Experimenting with this mechanism leads to show explain for running essentially in the same time as on Linux. However, as far as the test is concerned, it still runs in about 60s on mac (after applying improvements to the waiting mechanism) when on linux it completes in about 5s.
Rather than take a polled approach, we could convert dbug_serve_apcs to use a condition variable as that is supported on both linux and mac.
As an aside, I noticed that my_sleep is supposed to be passed a value in microseconds, but I surmise from usage in our codebase that many callers treat it like it's in milliseconds. I wonder if there are latent bugs as a result.
For now, I'm setting this ticket aside and lowering the priority.
Dave Gosselin
added a comment - The use of APCs causes at least part of the slowdown observed on macOS. When waiting for all APC calls to be serviced, we invoke my_sleep from dbug_serve_apcs. This sleep is implemented as a call to select() with a valid timeval struct. However on macOS, this select takes longer to return than on Linux. Experimenting with this mechanism leads to show explain for running essentially in the same time as on Linux. However, as far as the test is concerned, it still runs in about 60s on mac (after applying improvements to the waiting mechanism) when on linux it completes in about 5s.
Rather than take a polled approach, we could convert dbug_serve_apcs to use a condition variable as that is supported on both linux and mac.
As an aside, I noticed that my_sleep is supposed to be passed a value in microseconds, but I surmise from usage in our codebase that many callers treat it like it's in milliseconds. I wonder if there are latent bugs as a result.
For now, I'm setting this ticket aside and lowering the priority.
People
Dave Gosselin
Dave Gosselin
Votes:
0Vote for this issue
Watchers:
3Start watching this issue
Dates
Created:
Updated:
Git Integration
Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.
{"report":{"fcp":1080.2000002861023,"ttfb":246.2000002861023,"pageVisibility":"visible","entityId":127011,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":64,"apdex":0.5,"journeyId":"ff4c86aa-7a79-4b9e-b82a-cee91f51f3b6","navigationType":0,"readyForUser":1181.0999999046326,"redirectCount":0,"resourceLoadedEnd":1137.0999999046326,"resourceLoadedStart":251.59999990463257,"resourceTiming":[{"duration":137,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":251.59999990463257,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":251.59999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":388.59999990463257,"responseStart":0,"secureConnectionStart":0},{"duration":155.59999990463257,"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":252,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":252,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":407.59999990463257,"responseStart":0,"secureConnectionStart":0},{"duration":270.1000003814697,"initiatorType":"script","name":"https://jira.mariadb.org/s/0917945aaa57108d00c5076fea35e069-CDN/lu2cib/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":252.09999990463257,"connectEnd":252.09999990463257,"connectStart":252.09999990463257,"domainLookupEnd":252.09999990463257,"domainLookupStart":252.09999990463257,"fetchStart":252.09999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":419.30000019073486,"responseEnd":522.2000002861023,"responseStart":445.59999990463257,"secureConnectionStart":252.09999990463257},{"duration":266.2999997138977,"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":252.30000019073486,"connectEnd":252.30000019073486,"connectStart":252.30000019073486,"domainLookupEnd":252.30000019073486,"domainLookupStart":252.30000019073486,"fetchStart":252.30000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":419.5,"responseEnd":518.5999999046326,"responseStart":457.90000009536743,"secureConnectionStart":252.30000019073486},{"duration":196.30000019073486,"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":252.5,"connectEnd":252.5,"connectStart":252.5,"domainLookupEnd":252.5,"domainLookupStart":252.5,"fetchStart":252.5,"redirectEnd":0,"redirectStart":0,"requestStart":419.59999990463257,"responseEnd":448.80000019073486,"responseStart":447.59999990463257,"secureConnectionStart":252.5},{"duration":208.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":252.7000002861023,"connectEnd":252.7000002861023,"connectStart":252.7000002861023,"domainLookupEnd":252.7000002861023,"domainLookupStart":252.7000002861023,"fetchStart":252.7000002861023,"redirectEnd":0,"redirectStart":0,"requestStart":419.7000002861023,"responseEnd":460.90000009536743,"responseStart":459.80000019073486,"secureConnectionStart":252.7000002861023},{"duration":185.19999980926514,"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":252.80000019073486,"connectEnd":252.80000019073486,"connectStart":252.80000019073486,"domainLookupEnd":252.80000019073486,"domainLookupStart":252.80000019073486,"fetchStart":252.80000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":419.80000019073486,"responseEnd":438,"responseStart":436.30000019073486,"secureConnectionStart":252.80000019073486},{"duration":165.59999990463257,"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":253,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":253,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":418.59999990463257,"responseStart":0,"secureConnectionStart":0},{"duration":184.60000038146973,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":253.09999990463257,"connectEnd":253.09999990463257,"connectStart":253.09999990463257,"domainLookupEnd":253.09999990463257,"domainLookupStart":253.09999990463257,"fetchStart":253.09999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":419.90000009536743,"responseEnd":437.7000002861023,"responseStart":435.7000002861023,"secureConnectionStart":253.09999990463257},{"duration":165.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":253.30000019073486,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":253.30000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":418.80000019073486,"responseStart":0,"secureConnectionStart":0},{"duration":253,"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":253.40000009536743,"connectEnd":253.40000009536743,"connectStart":253.40000009536743,"domainLookupEnd":253.40000009536743,"domainLookupStart":253.40000009536743,"fetchStart":253.40000009536743,"redirectEnd":0,"redirectStart":0,"requestStart":439.2000002861023,"responseEnd":506.40000009536743,"responseStart":505.30000019073486,"secureConnectionStart":253.40000009536743},{"duration":558.6999998092651,"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":259.2000002861023,"connectEnd":259.2000002861023,"connectStart":259.2000002861023,"domainLookupEnd":259.2000002861023,"domainLookupStart":259.2000002861023,"fetchStart":259.2000002861023,"redirectEnd":0,"redirectStart":0,"requestStart":805.5999999046326,"responseEnd":817.9000000953674,"responseStart":816,"secureConnectionStart":259.2000002861023},{"duration":877.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":259.30000019073486,"connectEnd":259.30000019073486,"connectStart":259.30000019073486,"domainLookupEnd":259.30000019073486,"domainLookupStart":259.30000019073486,"fetchStart":259.30000019073486,"redirectEnd":0,"redirectStart":0,"requestStart":1113.9000000953674,"responseEnd":1137.0999999046326,"responseStart":1135.0999999046326,"secureConnectionStart":259.30000019073486},{"duration":266,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":733.8000001907349,"connectEnd":733.8000001907349,"connectStart":733.8000001907349,"domainLookupEnd":733.8000001907349,"domainLookupStart":733.8000001907349,"fetchStart":733.8000001907349,"redirectEnd":0,"redirectStart":0,"requestStart":966.4000000953674,"responseEnd":999.8000001907349,"responseStart":997.9000000953674,"secureConnectionStart":733.8000001907349}],"fetchStart":0,"domainLookupStart":0,"domainLookupEnd":0,"connectStart":0,"connectEnd":0,"requestStart":78,"responseStart":246,"responseEnd":252,"domLoading":250,"domInteractive":1281,"domContentLoadedEventStart":1282,"domContentLoadedEventEnd":1369,"domComplete":2403,"loadEventStart":2403,"loadEventEnd":2404,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":1245.9000000953674},{"name":"bigPipe.sidebar-id.end","time":1246.8000001907349},{"name":"bigPipe.activity-panel-pipe-id.start","time":1247},{"name":"bigPipe.activity-panel-pipe-id.end","time":1250.7000002861023},{"name":"activityTabFullyLoaded","time":1395.7000002861023}],"measures":[],"correlationId":"6125172e62ca24","effectiveType":"4g","downlink":9.4,"rtt":0,"serverDuration":97,"dbReadsTimeInMs":10,"dbConnsTimeInMs":17,"applicationHash":"9d11dbea5f4be3d4cc21f03a88dd11d8c8687422","experiments":[]}}
there is
let $wait_condition= select State='show_explain_trap' from information_schema.processlist where id=$thr2;
at the start of show_explain.test before any "invocation" of wait_condition.inc, isn't it?