177834 2017-10-03 13:20:06 -0700 Layout Test http/tests/inspector/network/beacon-type.html is flaky. 2017-10-03 14:11:56 -0700 1 1 1 Unclassified WebKit Web Inspector WebKit Nightly Build Unspecified Unspecified RESOLVED FIXED InRadar P2 Normal --- 1 jlewis3 webkit-unassigned inspector-bugzilla-changes joepeck webkit-bug-importer oldest_to_newest 1356002 0 jlewis3 2017-10-03 13:20:06 -0700 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 1356010 1 joepeck 2017-10-03 13:37:09 -0700 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. 1356017 2 jlewis3 2017-10-03 13:49:33 -0700 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 1356033 3 joepeck 2017-10-03 14:10:00 -0700 > {"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. 1356034 4 joepeck 2017-10-03 14:10:52 -0700 <https://trac.webkit.org/changeset/222808/webkit> 1356035 5 webkit-bug-importer 2017-10-03 14:11:56 -0700 <rdar://problem/34798863>