Summary: | Layout Test http/tests/inspector/network/beacon-type.html is flaky. | ||
---|---|---|---|
Product: | WebKit | Reporter: | Matt Lewis <jlewis3> |
Component: | Web Inspector | Assignee: | Nobody <webkit-unassigned> |
Status: | RESOLVED FIXED | ||
Severity: | Normal | CC: | inspector-bugzilla-changes, joepeck, webkit-bug-importer |
Priority: | P2 | Keywords: | InRadar |
Version: | WebKit Nightly Build | ||
Hardware: | Unspecified | ||
OS: | Unspecified |
Description
Matt Lewis
2017-10-03 13:20:06 PDT
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.
|