http/tests/inspector/network/beacon-type.html is a flaky timeout on Sierra and High Sierra WK2 according to the dashboard. https://webkit-test-results.webkit.org/dashboards/flakiness_dashboard.html#showAllRuns=true&tests=http%2Ftests%2Finspector%2Fnetwork%2Fbeacon-type.html It looks like the flaky timeout started with this build: https://build.webkit.org/results/Apple%20High%20Sierra%20Release%20WK2%20(Tests)/r222740%20(113)/results.html https://build.webkit.org/builders/Apple%20High%20Sierra%20Release%20WK2%20(Tests)/builds/113 and this revision: https://trac.webkit.org/changeset/222739/webkit Diff: --- /Volumes/Data/slave/sierra-release-tests-wk2/build/layout-test-results/http/tests/inspector/network/beacon-type-expected.txt +++ /Volumes/Data/slave/sierra-release-tests-wk2/build/layout-test-results/http/tests/inspector/network/beacon-type-actual.txt @@ -1,22 +1,5 @@ -Tests for Resource.Type.Beacon. +#PID UNRESPONSIVE - com.apple.WebKit.WebContent.Development (pid 28326) +FAIL: Timed out waiting for notifyDone to be called - -== Running test suite: Resource.Type.Beacon --- Running test case: Resource.Type.Beacon.204 -PASS: Resource should be Beacon type. -PASS: Resource should be a POST request. -PASS: Resource should have a 204 response. -PASS: Resource should not have request data. - --- Running test case: Resource.Type.Beacon.404 -PASS: Resource should be Beacon type. -PASS: Resource should be a POST request. -PASS: Resource should have a 404 response. -PASS: Resource should not have request data. - --- Running test case: Resource.Type.Beacon.WithData -PASS: Resource should be Beacon type. -PASS: Resource should be a POST request. -PASS: Resource should have a 200 response. -PASS: Resource should have 'SENDING-DATA' request data. - +#EOF +#EOF current build: https://build.webkit.org/results/Apple%20Sierra%20Release%20WK2%20(Tests)/r222788%20(4724)/results.html https://build.webkit.org/builders/Apple%20Sierra%20Release%20WK2%20(Tests)/builds/4724
Added debug logging with: https://trac.webkit.org/changeset/222805/webkit That will hopefully get me actionable data about why this test is timing out.
event: {"method":"Network.requestWillBeSent","params":{"requestId":"0.23","frameId":"0.1","loaderId":"0.6","documentURL":"http://127.0.0.1:8000/inspector/network/beacon-type.html", "request":{"url":"http://127.0.0.1:8000/inspector/network/resources/beacon.php?status=204","method":"POST","headers":{"Referer":"http://127.0.0.1:8000/inspector/network/beacon-type.html","User-Agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13) AppleWebKit/605.1.9 (KHTML, like Gecko)","Origin":"http://127.0.0.1:8000","Accept":"*/*","Cache-Control":"max-age=0"}},"timestamp":0.015034461997856852,"initiator":{"type":"script","stackTrace":[{"functionName":"sendBeacon","url":"[native code]","scriptId":"0","lineNumber":0,"columnNumber":0},{"functionName":"triggerBeaconWith204Response","url":"http://127.0.0.1:8000/inspector/network/beacon-type.html","scriptId":"113","lineNumber":8,"columnNumber":25},{"functionName":"global code","url":"","scriptId":"121","lineNumber":1,"columnNumber":29},{"functionName":"evaluateWithScopeExtension","url":"[native code]","scriptId":"0","lineNumber":0,"columnNumber":0},{"functionName":"_evaluateOn","url":"","scriptId":"117","lineNumber":128,"columnNumber":29},{"functionName":"_evaluateAndWrap","url":"","scriptId":"117","lineNumber":122,"columnNumber":108}]},"type":"Beacon"}} response: {"result":{"result":{"type":"undefined"},"wasThrown":false},"id":27} event: {"method":"Network.responseReceived","params":{"requestId":"0.23","frameId":"0.1","loaderId":"0.6","timestamp":0.017259075997571927,"type":"Beacon","response":{"url":"http://127.0.0.1:8000/inspector/network/resources/beacon.php?status=204","status":204,"statusText":"No Content","headers":{"Content-Type":"text/html","Keep-Alive":"timeout=15, max=86","Date":"Tue, 03 Oct 2017 20:43:45 GMT","Connection":"Keep-Alive","X-Powered-By":"PHP/7.1.7","Server":"Apache/2.4.27 (Unix) PHP/7.1.7 LibreSSL/2.2.7"},"mimeType":"text/html","source":"unknown"}}} event: {"method":"Network.loadingFinished","params":{"requestId":"0.23","timestamp":0.0172940810007276,"metrics":{}}} PASS: Resource should be Beacon type. request: {"id":28,"method":"Runtime.evaluate","params":{"expression":"TestPage.addResult(unescape(\"PASS%3A%20Resource%20should%20be%20Beacon%20type.\"))","objectGroup":"test","includeCommandLineAPI":false}} PASS: Resource should be a POST request. request: {"id":29,"method":"Runtime.evaluate","params":{"expression":"TestPage.addResult(unescape(\"PASS%3A%20Resource%20should%20be%20a%20POST%20request.\"))","objectGroup":"test","includeCommandLineAPI":false}} event: {"method":"Debugger.scriptParsed","params":{"scriptId":"122","url":"","startLine":0,"startColumn":0,"endLine":0,"endColumn":81}} response: {"result":{"result":{"type":"undefined"},"wasThrown":false},"id":28} event: {"method":"Debugger.scriptParsed","params":{"scriptId":"123","url":"","startLine":0,"startColumn":0,"endLine":0,"endColumn":86}} response: {"result":{"result":{"type":"undefined"},"wasThrown":false},"id":29} Wait on notifyDone timed out, process com.apple.WebKit.WebContent.Development pid = 12965#EOF
> {"method":"Network.loadingFinished","params":{"requestId":"0.23","timestamp": 0.0172940810007276,"metrics":{}}} > PASS: Resource should be Beacon type. This is the key. The loadingFinished event was received and processed before the Test's Promise microtask runs. So this promise ends up waiting on events for the resource load to complete but it has already completed. We can skip the wait on events if the resource load finished. I was able to reproduce ~1 in 250 runs on my laptop. After fix I wasn't able to reproduce. Going to land the tiny test change unreviewed.
<https://trac.webkit.org/changeset/222808/webkit>
<rdar://problem/34798863>