1681855 - Intermittent remote/test/browser/runtime/browser_consoleAPICalled.js | Got expected amount of events - Got +0, expected 1

Status: RESOLVED FIXED

(Remote Protocol :: CDP, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: dluca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=324197244&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/S8y67lD8Tr2D1fZwdXItAw/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/S8y67lD8Tr2D1fZwdXItAw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | The execution context has an id - 
[task 2020-12-10T23:05:32.738Z] 23:05:32     INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | The execution context is the default one - 
[task 2020-12-10T23:05:32.738Z] 23:05:32     INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | The execution context has a frame id set - 
[task 2020-12-10T23:05:32.738Z] 23:05:32     INFO - Buffered messages finished
[task 2020-12-10T23:05:32.738Z] 23:05:32     INFO - TEST-UNEXPECTED-FAIL | remote/test/browser/runtime/browser_consoleAPICalled.js | Got expected amount of events - Got +0, expected 1
[task 2020-12-10T23:05:32.738Z] 23:05:32     INFO - Stack trace:
[task 2020-12-10T23:05:32.738Z] 23:05:32     INFO - chrome://mochikit/content/browser-test.js:test_is:1332
[task 2020-12-10T23:05:32.738Z] 23:05:32     INFO - chrome://mochitests/content/browser/remote/test/browser/runtime/browser_consoleAPICalled.js:runConsoleTest:182
[task 2020-12-10T23:05:32.738Z] 23:05:32     INFO - CDP client closed
[task 2020-12-10T23:05:32.738Z] 23:05:32     INFO - CDP server stopped
[task 2020-12-10T23:05:32.779Z] 23:05:32     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-12-10T23:05:32.780Z] 23:05:32     INFO - TEST-UNEXPECTED-FAIL | remote/test/browser/runtime/browser_consoleAPICalled.js | Uncaught exception - at chrome://mochitests/content/browser/remote/test/browser/runtime/browser_consoleAPICalled.js:132 - TypeError: can't access property "type", events[0] is undefined
[task 2020-12-10T23:05:32.780Z] 23:05:32     INFO - Stack trace:
[task 2020-12-10T23:05:32.780Z] 23:05:32     INFO - consoleAPIByContentInteraction@chrome://mochitests/content/browser/remote/test/browser/runtime/browser_consoleAPICalled.js:132:3
[task 2020-12-10T23:05:32.780Z] 23:05:32     INFO - Leaving test bound consoleAPIByContentInteraction
[task 2020-12-10T23:05:32.780Z] 23:05:32     INFO - Entering test bound consoleMessageByContent
[task 2020-12-10T23:05:32.823Z] 23:05:32     INFO - CDP server started
[task 2020-12-10T23:05:36.005Z] 23:05:36     INFO - CDP client instantiated
[task 2020-12-10T23:05:37.174Z] 23:05:37     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/remote/test/browser/runtime/doc_console_events.html" line: 0}]
[task 2020-12-10T23:05:37.389Z] 23:05:37     INFO - Runtime domain has been enabled
[task 2020-12-10T23:05:37.389Z] 23:05:37     INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | The execution context has an id - 
[task 2020-12-10T23:05:37.389Z] 23:05:37     INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | The execution context is the default one - 
[task 2020-12-10T23:05:37.390Z] 23:05:37     INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | The execution context has a frame id set - 
[task 2020-12-10T23:05:37.477Z] 23:05:37     INFO - Console message: [JavaScript Warning: "document.execCommand(‘cut’/‘copy’) was denied because it was not called from inside a short running user-generated event handler." {file: "debugger eval code" line: 2}]
[task 2020-12-10T23:05:37.523Z] 23:05:37     INFO - Received Runtime.consoleAPICalled for warning
[task 2020-12-10T23:05:37.757Z] 23:05:37     INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | Got expected amount of events - 
[task 2020-12-10T23:05:37.757Z] 23:05:37     INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | Got valid timestamp - 
[task 2020-12-10T23:05:37.757Z] 23:05:37     INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | Got expected type - 
[task 2020-12-10T23:05:37.757Z] 23:05:37     INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | Got expected amount of argumnets - 1 == 1 - 
[task 2020-12-10T23:05:37.758Z] 23:05:37     INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | Got expected argument value - 
[task 2020-12-10T23:05:37.758Z] 23:05:37     INFO - TEST-PASS | remote/test/browser/runtime/browser_consoleAPICalled.js | Got event from current execution context - 
[task 2020-12-10T23:05:38.041Z] 23:05:38     INFO - Console message: [JavaScript Error: "The connection to ws://localhost:9222/devtools/page/40f59e22-ff57-3d44-89c2-9d35105820d1 was interrupted while the page was loading." {file: "chrome://mochitests/content/browser/remote/test/browser/chrome-remote-interface.js" line: 8}]
[task 2020-12-10T23:05:38.041Z] 23:05:38     INFO - CDP client closed
[task 2020-12-10T23:05:38.073Z] 23:05:38     INFO - CDP server stopped
[task 2020-12-10T23:05:38.073Z] 23:05:38     INFO - Leaving test bound consoleMessageByContent
[task 2020-12-10T23:05:38.743Z] 23:05:38     INFO - GECKO(2763) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2020-12-10T23:05:38.743Z] 23:05:38     INFO - GECKO(2763) | MEMORY STAT | vsize 7657MB | residentFast 286MB | heapAllocated 108MB
[task 2020-12-10T23:05:38.743Z] 23:05:38     INFO - TEST-OK | remote/test/browser/runtime/browser_consoleAPICalled.js | took 43390ms
[task 2020-12-10T23:05:38.798Z] 23:05:38     INFO - checking window state
[task 2020-12-10T23:05:38.963Z] 23:05:38     INFO - TEST-START | remote/test/browser/runtime/browser_consoleAPICalled.js```

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+1]]

This failure happens in consoleAPIByContentInteraction. Maybe the click for the link is delayed, and as such runConsoleTest() returns before the code actually gets evaluated. We could check if increasing the default timeout of 250ms to maybe 500m will give better results. Lets see how often this test fails.

Comment 2

[Intermittent Failures Robot]

6 failures in 4060 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 5
• mozilla-central: 1

Platform breakdown:

• linux1804-64: 1
• macosx1014-64-qr: 3
• windows10-64: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1681855&startday=2020-12-07&endday=2020-12-13&tree=all

Comment 3

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Attachment: Bug 1681855 - [remote] Fallback to default timeout in browser_consoleAPICalled.js.

The 250ms are too short given that the call to any console API could be
delayed due to IPC communication. As such use the default timeout
value as done by all the other tests that are using the events
recorder.

Comment 4

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a4e5bf783117
[remote] Fallback to default timeout in browser_consoleAPICalled.js. r=remote-protocol-reviewers,jgraham

Comment 5

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/mozilla-central/rev/a4e5bf783117

Comment 6

[Intermittent Failures Robot]

1 failures in 3421 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• macosx1014-64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1681855&startday=2020-12-14&endday=2020-12-20&tree=all