Closed
Bug 1733717
Opened 3 years ago
Closed 1 year ago
Intermittent [Tier2-TV] remote/cdp/test/browser/page/browser_frameAttached.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. -
Categories
(Remote Protocol :: CDP, defect, P5)
Remote Protocol
CDP
Tracking
(Not tracked)
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(Keywords: intermittent-failure)
Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=353388454&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/RCpW_5ARQ2eeYPVctX-eOA/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/RCpW_5ARQ2eeYPVctX-eOA/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1
[task 2021-10-01T19:28:04.340Z] 19:28:04 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_frameAttached.js | Got expected parent frame id for frameAttached event -
[task 2021-10-01T19:28:04.340Z] 19:28:04 INFO - CDP client closed
[task 2021-10-01T19:28:04.341Z] 19:28:04 INFO - Leaving test bound eventWhenAttachingFrame
[task 2021-10-01T19:28:04.341Z] 19:28:04 INFO - Buffered messages finished
[task 2021-10-01T19:28:04.341Z] 19:28:04 INFO - TEST-UNEXPECTED-FAIL | remote/cdp/test/browser/page/browser_frameAttached.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. -
[task 2021-10-01T19:28:04.342Z] 19:28:04 INFO - GECKO(2232) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2021-10-01T19:28:04.342Z] 19:28:04 INFO - GECKO(2232) | MEMORY STAT | vsize 7835MB | residentFast 289MB | heapAllocated 113MB
[task 2021-10-01T19:28:04.342Z] 19:28:04 INFO - TEST-OK | remote/cdp/test/browser/page/browser_frameAttached.js | took 46179ms
[task 2021-10-01T19:28:04.343Z] 19:28:04 INFO - GECKO(2232) | 1633116484194 CDP TRACE CDPConnection {70ae1d04-b839-a342-830b-8bc0357f95ab} <- {
[task 2021-10-01T19:28:04.343Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetCreated",
[task 2021-10-01T19:28:04.343Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.344Z] 19:28:04 INFO - GECKO(2232) | "targetInfo": {
[task 2021-10-01T19:28:04.344Z] 19:28:04 INFO - GECKO(2232) | "targetId": "1b22a5da-ef56-304a-bd18-1e2a0d3366fc",
[task 2021-10-01T19:28:04.345Z] 19:28:04 INFO - GECKO(2232) | "type": "page",
[task 2021-10-01T19:28:04.345Z] 19:28:04 INFO - GECKO(2232) | "title": "",
[task 2021-10-01T19:28:04.345Z] 19:28:04 INFO - GECKO(2232) | "url": "about:blank",
[task 2021-10-01T19:28:04.345Z] 19:28:04 INFO - GECKO(2232) | "attached": false,
[task 2021-10-01T19:28:04.346Z] 19:28:04 INFO - GECKO(2232) | "browserContextId": null
[task 2021-10-01T19:28:04.346Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.346Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.347Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.347Z] 19:28:04 INFO - GECKO(2232) | 1633116484194 CDP TRACE CDPConnection {43c87061-6835-1946-a7b7-6b5b1523001c} <- {
[task 2021-10-01T19:28:04.348Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetCreated",
[task 2021-10-01T19:28:04.348Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.348Z] 19:28:04 INFO - GECKO(2232) | "targetInfo": {
[task 2021-10-01T19:28:04.349Z] 19:28:04 INFO - GECKO(2232) | "targetId": "1b22a5da-ef56-304a-bd18-1e2a0d3366fc",
[task 2021-10-01T19:28:04.349Z] 19:28:04 INFO - GECKO(2232) | "type": "page",
[task 2021-10-01T19:28:04.349Z] 19:28:04 INFO - GECKO(2232) | "title": "",
[task 2021-10-01T19:28:04.350Z] 19:28:04 INFO - GECKO(2232) | "url": "about:blank",
[task 2021-10-01T19:28:04.350Z] 19:28:04 INFO - GECKO(2232) | "attached": false,
[task 2021-10-01T19:28:04.350Z] 19:28:04 INFO - GECKO(2232) | "browserContextId": null
[task 2021-10-01T19:28:04.351Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.351Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.351Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.352Z] 19:28:04 INFO - GECKO(2232) | 1633116484194 CDP TRACE CDPConnection {ae9476f5-990f-fd4e-ac71-d1f2a2c294c3} <- {
[task 2021-10-01T19:28:04.352Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetCreated",
[task 2021-10-01T19:28:04.352Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.353Z] 19:28:04 INFO - GECKO(2232) | "targetInfo": {
[task 2021-10-01T19:28:04.353Z] 19:28:04 INFO - GECKO(2232) | "targetId": "1b22a5da-ef56-304a-bd18-1e2a0d3366fc",
[task 2021-10-01T19:28:04.354Z] 19:28:04 INFO - GECKO(2232) | "type": "page",
[task 2021-10-01T19:28:04.354Z] 19:28:04 INFO - GECKO(2232) | "title": "",
[task 2021-10-01T19:28:04.354Z] 19:28:04 INFO - GECKO(2232) | "url": "about:blank",
[task 2021-10-01T19:28:04.355Z] 19:28:04 INFO - GECKO(2232) | "attached": false,
[task 2021-10-01T19:28:04.355Z] 19:28:04 INFO - GECKO(2232) | "browserContextId": null
[task 2021-10-01T19:28:04.355Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.355Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.356Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.356Z] 19:28:04 INFO - GECKO(2232) | 1633116484194 CDP TRACE CDPConnection {05b378af-c101-cc47-a6ca-2fe50ce07764} <- {
[task 2021-10-01T19:28:04.357Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetCreated",
[task 2021-10-01T19:28:04.357Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.357Z] 19:28:04 INFO - GECKO(2232) | "targetInfo": {
[task 2021-10-01T19:28:04.358Z] 19:28:04 INFO - GECKO(2232) | "targetId": "1b22a5da-ef56-304a-bd18-1e2a0d3366fc",
[task 2021-10-01T19:28:04.358Z] 19:28:04 INFO - GECKO(2232) | "type": "page",
[task 2021-10-01T19:28:04.358Z] 19:28:04 INFO - GECKO(2232) | "title": "",
[task 2021-10-01T19:28:04.359Z] 19:28:04 INFO - GECKO(2232) | "url": "about:blank",
[task 2021-10-01T19:28:04.359Z] 19:28:04 INFO - GECKO(2232) | "attached": false,
[task 2021-10-01T19:28:04.359Z] 19:28:04 INFO - GECKO(2232) | "browserContextId": null
[task 2021-10-01T19:28:04.360Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.360Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.360Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.361Z] 19:28:04 INFO - GECKO(2232) | 1633116484194 CDP TRACE CDPConnection {d8949aa5-34f5-0e4f-8efa-110cf7ebba21} <- {
[task 2021-10-01T19:28:04.361Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetCreated",
[task 2021-10-01T19:28:04.361Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.362Z] 19:28:04 INFO - GECKO(2232) | "targetInfo": {
[task 2021-10-01T19:28:04.362Z] 19:28:04 INFO - GECKO(2232) | "targetId": "1b22a5da-ef56-304a-bd18-1e2a0d3366fc",
[task 2021-10-01T19:28:04.362Z] 19:28:04 INFO - GECKO(2232) | "type": "page",
[task 2021-10-01T19:28:04.363Z] 19:28:04 INFO - GECKO(2232) | "title": "",
[task 2021-10-01T19:28:04.363Z] 19:28:04 INFO - GECKO(2232) | "url": "about:blank",
[task 2021-10-01T19:28:04.363Z] 19:28:04 INFO - GECKO(2232) | "attached": false,
[task 2021-10-01T19:28:04.364Z] 19:28:04 INFO - GECKO(2232) | "browserContextId": null
[task 2021-10-01T19:28:04.364Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.364Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.365Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.365Z] 19:28:04 INFO - GECKO(2232) | 1633116484194 CDP TRACE CDPConnection {576ca23f-55b4-044c-a1b0-114fdb6a1bf9} <- {
[task 2021-10-01T19:28:04.365Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetCreated",
[task 2021-10-01T19:28:04.366Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.366Z] 19:28:04 INFO - GECKO(2232) | "targetInfo": {
[task 2021-10-01T19:28:04.367Z] 19:28:04 INFO - GECKO(2232) | "targetId": "1b22a5da-ef56-304a-bd18-1e2a0d3366fc",
[task 2021-10-01T19:28:04.367Z] 19:28:04 INFO - GECKO(2232) | "type": "page",
[task 2021-10-01T19:28:04.367Z] 19:28:04 INFO - GECKO(2232) | "title": "",
[task 2021-10-01T19:28:04.368Z] 19:28:04 INFO - GECKO(2232) | "url": "about:blank",
[task 2021-10-01T19:28:04.368Z] 19:28:04 INFO - GECKO(2232) | "attached": false,
[task 2021-10-01T19:28:04.368Z] 19:28:04 INFO - GECKO(2232) | "browserContextId": null
[task 2021-10-01T19:28:04.369Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.369Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.369Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.370Z] 19:28:04 INFO - GECKO(2232) | 1633116484210 CDP TRACE CDPConnection {70ae1d04-b839-a342-830b-8bc0357f95ab} <- {
[task 2021-10-01T19:28:04.370Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetDestroyed",
[task 2021-10-01T19:28:04.370Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.371Z] 19:28:04 INFO - GECKO(2232) | "targetId": "993fa43b-6103-ab49-ae78-2a98ce91f7f4"
[task 2021-10-01T19:28:04.371Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.371Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.372Z] 19:28:04 INFO - GECKO(2232) | 1633116484210 CDP TRACE CDPConnection {43c87061-6835-1946-a7b7-6b5b1523001c} <- {
[task 2021-10-01T19:28:04.372Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetDestroyed",
[task 2021-10-01T19:28:04.372Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.373Z] 19:28:04 INFO - GECKO(2232) | "targetId": "993fa43b-6103-ab49-ae78-2a98ce91f7f4"
[task 2021-10-01T19:28:04.373Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.373Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.374Z] 19:28:04 INFO - GECKO(2232) | 1633116484210 CDP TRACE CDPConnection {ae9476f5-990f-fd4e-ac71-d1f2a2c294c3} <- {
[task 2021-10-01T19:28:04.374Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetDestroyed",
[task 2021-10-01T19:28:04.374Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.375Z] 19:28:04 INFO - GECKO(2232) | "targetId": "993fa43b-6103-ab49-ae78-2a98ce91f7f4"
[task 2021-10-01T19:28:04.375Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.375Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.376Z] 19:28:04 INFO - GECKO(2232) | 1633116484210 CDP TRACE CDPConnection {05b378af-c101-cc47-a6ca-2fe50ce07764} <- {
[task 2021-10-01T19:28:04.376Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetDestroyed",
[task 2021-10-01T19:28:04.377Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.377Z] 19:28:04 INFO - GECKO(2232) | "targetId": "993fa43b-6103-ab49-ae78-2a98ce91f7f4"
[task 2021-10-01T19:28:04.377Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.378Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.378Z] 19:28:04 INFO - GECKO(2232) | 1633116484210 CDP TRACE CDPConnection {d8949aa5-34f5-0e4f-8efa-110cf7ebba21} <- {
[task 2021-10-01T19:28:04.379Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetDestroyed",
[task 2021-10-01T19:28:04.379Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.380Z] 19:28:04 INFO - GECKO(2232) | "targetId": "993fa43b-6103-ab49-ae78-2a98ce91f7f4"
[task 2021-10-01T19:28:04.380Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.380Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.380Z] 19:28:04 INFO - GECKO(2232) | 1633116484210 CDP TRACE CDPConnection {576ca23f-55b4-044c-a1b0-114fdb6a1bf9} <- {
[task 2021-10-01T19:28:04.381Z] 19:28:04 INFO - GECKO(2232) | "method": "Target.targetDestroyed",
[task 2021-10-01T19:28:04.381Z] 19:28:04 INFO - GECKO(2232) | "params": {
[task 2021-10-01T19:28:04.381Z] 19:28:04 INFO - GECKO(2232) | "targetId": "993fa43b-6103-ab49-ae78-2a98ce91f7f4"
[task 2021-10-01T19:28:04.382Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.382Z] 19:28:04 INFO - GECKO(2232) | }
[task 2021-10-01T19:28:04.382Z] 19:28:04 INFO - checking window state
[task 2021-10-01T19:28:04.383Z] 19:28:04 INFO - GECKO(2232) | Completed ShutdownLeaks collections in process 2232
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•3 years ago
|
||
It's unclear why the timeout happens. Will be investigated over on bug 1733711.
Depends on: 1733711
|
||
Comment 3•3 years ago
|
||
For this test it seems we hit the 45s limit for a single test when running in Chaos mode. We are still way under the 900s test-verify timeout, but the last test which runs is the first chaos mode test, which takes a lot longer than normal mode apparently (normal mode takes ~10s ).
We might just increase the individual test timeout or split the test here.
bug 1733711 ran with fission, it's probably a different issue.
|
|
||
Comment 4•3 years ago
•
|
||
I quickly tested locally, this test is 2-3 times slower in chaos mode compared to normal mode.
So if we ever want to get rid of those test-verify failures, I think we will either have to increase the timeout or split.
|
|
||
Comment 5•3 years ago
|
||
Oh, interesting. Do you know why we are that slow in chaos mode? Nothing should actually change, or is that a performance bug in our CDP implementation?
|
|
||
Comment 6•3 years ago
|
||
I don't think that it is anything specific to our implementation or to our tests. I tried a dummy test with 10 tasks such as:
add_task(async function test1() {
await loadURL(FRAMESET_NESTED_URL);
ok(true);
});
And I removed everything from the head.js files except for the const FRAMESET_NESTED_URL definition and the loadURL definition. This test took 4 seconds in normal mode and 17 seconds in chaos mode.
|
|
||
Updated•3 years ago
|
Depends on: tv-chaosmode-timeout-wpt
|
|
||
Updated•1 year ago
|
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•