1722320 - Intermittent devtools/client/netmonitor/test/browser_net_stacktraces-visibility.js | Test timed out -

Status: RESOLVED FIXED

(DevTools :: Netmonitor, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: dluca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=346352712&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aedJNkQoQjyXt1QgNPps-w/runs/0/artifacts/public/logs/live_backing.log

---

INFO - TEST-START | devtools/client/netmonitor/test/browser_net_stacktraces-visibility.js
[task 2021-07-26T13:52:25.561Z] 13:52:25     INFO - GECKO(1537) | [Child 6359: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (7f52ccc27000) [pid = 6359] [serial = 2] [outer = 0] [url = about:blank]
[task 2021-07-26T13:52:25.564Z] 13:52:25     INFO - GECKO(1537) | [Child 6359: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7f52e7964580) [pid = 6359] [serial = 1] [outer = 0] [url = http://mochi.test:8888/browser/devtools/client/netmonitor/test/html_sse-test-page.html]
[task 2021-07-26T13:52:25.566Z] 13:52:25     INFO - GECKO(1537) | [Child 6359: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7f52cc79c400) [pid = 6359] [serial = 4] [outer = 0] [url = http://mochi.test:8888/browser/devtools/client/netmonitor/test/html_sse-test-page.html]
[task 2021-07-26T13:52:25.574Z] 13:52:25     INFO - GECKO(1537) | [Child 6359: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (7f52ccc2d400) [pid = 6359] [serial = 3] [outer = 0] [url = http://mochi.test:8888/browser/devtools/client/netmonitor/test/html_sse-test-page.html]
[task 2021-07-26T13:52:25.577Z] 13:52:25     INFO - GECKO(1537) | [Child 6359, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3357
[task 2021-07-26T13:52:25.610Z] 13:52:25     INFO - GECKO(1537) | [Child 6359, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4438
[task 2021-07-26T13:52:25.643Z] 13:52:25     INFO - GECKO(1537) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp5sc53ne6.mozrunner/runtests_leaks_tab_pid6387.log
[task 2021-07-26T13:52:25.644Z] 13:52:25     INFO - GECKO(1537) | [6387, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:250
[task 2021-07-26T13:52:25.682Z] 13:52:25     INFO - GECKO(1537) | [Child 6387, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-07-26T13:52:25.821Z] 13:52:25     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (7f7a483f3040) [pid = 1537] [serial = 765] [outer = 0] [url = about:devtools-toolbox]
[task 2021-07-26T13:52:25.821Z] 13:52:25     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (7f7a490dd3c0) [pid = 1537] [serial = 768] [outer = 0] [url = chrome://devtools/content/netmonitor/index.html]
[task 2021-07-26T13:52:25.895Z] 13:52:25     INFO - GECKO(1537) | [Child 6387: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7fe888122800 == 1 [pid = 6387] [id = 0]
[task 2021-07-26T13:52:25.897Z] 13:52:25     INFO - GECKO(1537) | [Child 6387: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (7fe8a2e64580) [pid = 6387] [serial = 1] [outer = 0]
[task 2021-07-26T13:52:25.899Z] 13:52:25     INFO - GECKO(1537) | [Child 6387: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (7fe888127000) [pid = 6387] [serial = 2] [outer = 7fe8a2e64580]
[task 2021-07-26T13:52:26.028Z] 13:52:26     INFO - GECKO(1537) | [Child 6387, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2021-07-26T13:52:26.035Z] 13:52:26     INFO - GECKO(1537) | [Child 6387: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (7fe88812d000) [pid = 6387] [serial = 3] [outer = 7fe8a2e64580]
[task 2021-07-26T13:52:26.485Z] 13:52:26     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f7a1ff10800 == 8 [pid = 1537] [id = 313]
[task 2021-07-26T13:52:26.486Z] 13:52:26     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 18 (7f7a3ee4f580) [pid = 1537] [serial = 775] [outer = 0]
[task 2021-07-26T13:52:26.486Z] 13:52:26     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 19 (7f7a37f4f800) [pid = 1537] [serial = 776] [outer = 7f7a3ee4f580]
[task 2021-07-26T13:52:26.627Z] 13:52:26     INFO - GECKO(1537) | [Child 1621: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7fa54a54a400 == 1 [pid = 1621] [id = 64] [url = about:blank]
[task 2021-07-26T13:52:26.650Z] 13:52:26     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 20 (7f7a3839f000) [pid = 1537] [serial = 777] [outer = 7f7a3ee4f580]
[task 2021-07-26T13:52:26.734Z] 13:52:26     INFO - GECKO(1537) | [Child 1621: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (7fa565b64200) [pid = 1621] [serial = 130] [outer = 0] [url = about:blank]
[task 2021-07-26T13:52:26.797Z] 13:52:26     INFO - GECKO(1537) | [Parent 1537, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/dom/base/nsContentUtils.cpp:4018
[task 2021-07-26T13:52:27.092Z] 13:52:27     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f7a1ff10000 == 9 [pid = 1537] [id = 314]
[task 2021-07-26T13:52:27.093Z] 13:52:27     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 21 (7f7a41141200) [pid = 1537] [serial = 778] [outer = 0]
[task 2021-07-26T13:52:27.095Z] 13:52:27     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 22 (7f7a383a3c00) [pid = 1537] [serial = 779] [outer = 7f7a41141200]
[task 2021-07-26T13:52:27.109Z] 13:52:27     INFO - GECKO(1537) | [Parent 1537, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/chrome/nsChromeRegistry.cpp:180
[task 2021-07-26T13:52:27.110Z] 13:52:27     INFO - GECKO(1537) | [Parent 1537, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/dom/security/nsCSPService.cpp:191
[task 2021-07-26T13:52:27.461Z] 13:52:27     INFO - GECKO(1537) | [Parent 1537, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1371
[task 2021-07-26T13:52:27.744Z] 13:52:27     INFO - GECKO(1537) | [Parent 1537, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A (NS_ERROR_MALFORMED_URI): file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:46
[task 2021-07-26T13:52:27.746Z] 13:52:27     INFO - GECKO(1537) | [Parent 1537, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:58
[task 2021-07-26T13:52:28.584Z] 13:52:28     INFO - GECKO(1537) | console.error: "Task cancelled"
[task 2021-07-26T13:52:28.839Z] 13:52:28     INFO - GECKO(1537) | [Child 6387: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (7fe888129000) [pid = 6387] [serial = 4] [outer = 7fe8a2e64580]
[task 2021-07-26T13:52:28.865Z] 13:52:28     INFO - GECKO(1537) | console.warn: "Already stopped listening to websocket events for this window."
[task 2021-07-26T13:52:28.867Z] 13:52:28     INFO - GECKO(1537) | console.warn: "Already stopped listening to server sent events for this window."
[task 2021-07-26T13:52:30.378Z] 13:52:30     INFO - GECKO(1537) | [Child 6387: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (7fe886f7e000) [pid = 6387] [serial = 5] [outer = 7fe8a2e64580]
[task 2021-07-26T13:52:30.400Z] 13:52:30     INFO - GECKO(1537) | console.warn: "Already stopped listening to websocket events for this window."
[task 2021-07-26T13:52:30.402Z] 13:52:30     INFO - GECKO(1537) | console.warn: "Already stopped listening to server sent events for this window."
[task 2021-07-26T13:52:30.757Z] 13:52:30     INFO - GECKO(1537) | [Child 1621: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7fa54a54c400) [pid = 1621] [serial = 131] [outer = 0] [url = about:blank]
[task 2021-07-26T13:52:33.510Z] 13:52:33     INFO - GECKO(1537) | [Child 1681: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7fd546666800 == 0 [pid = 1681] [id = 64] [url = about:blank]
[task 2021-07-26T13:52:34.759Z] 13:52:34     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f7a1ff0dc00 == 8 [pid = 1537] [id = 311] [url = about:devtools-toolbox]
[task 2021-07-26T13:52:34.760Z] 13:52:34     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f7a1ff0c000 == 7 [pid = 1537] [id = 312] [url = chrome://devtools/content/netmonitor/index.html]
[task 2021-07-26T13:52:34.774Z] 13:52:34     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 21 (7f7a1ff0b800) [pid = 1537] [serial = 771] [outer = 0] [url = about:blank]
[task 2021-07-26T13:52:34.776Z] 13:52:34     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 20 (7f7a38894800) [pid = 1537] [serial = 767] [outer = 0] [url = about:devtools-toolbox]
[task 2021-07-26T13:52:34.777Z] 13:52:34     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (7f7a385ed400) [pid = 1537] [serial = 769] [outer = 0] [url = about:blank]
[task 2021-07-26T13:52:35.498Z] 13:52:35     INFO - GECKO(1537) | [Parent 1537, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-07-26T13:52:35.499Z] 13:52:35     INFO - GECKO(1537) | [Parent 1537, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-07-26T13:52:35.500Z] 13:52:35     INFO - GECKO(1537) | [Parent 1537, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-07-26T13:52:35.502Z] 13:52:35     INFO - GECKO(1537) | [Parent 1537, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-07-26T13:52:35.504Z] 13:52:35     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (7f7a3c8c9740) [pid = 1537] [serial = 773] [outer = 0] [url = chrome://devtools/content/netmonitor/index.html]
[task 2021-07-26T13:52:35.505Z] 13:52:35     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (7f7a151fa900) [pid = 1537] [serial = 770] [outer = 0] [url = about:devtools-toolbox]
[task 2021-07-26T13:52:37.615Z] 13:52:37     INFO - GECKO(1537) | [Child 1681: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7fd561e64740) [pid = 1681] [serial = 130] [outer = 0] [url = about:blank]
[task 2021-07-26T13:52:38.335Z] 13:52:38     INFO - GECKO(1537) | [Child 6387: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (7fe888127000) [pid = 6387] [serial = 2] [outer = 0] [url = about:blank]
[task 2021-07-26T13:52:38.336Z] 13:52:38     INFO - GECKO(1537) | [Child 6387: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (7fe88812d000) [pid = 6387] [serial = 3] [outer = 0] [url = http://example.com/browser/devtools/client/netmonitor/test/html_cause-test-page.html]
[task 2021-07-26T13:52:39.677Z] 13:52:39     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (7f7a385b6c00) [pid = 1537] [serial = 774] [outer = 0] [url = about:blank]
[task 2021-07-26T13:52:39.678Z] 13:52:39     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (7f7a383a3400) [pid = 1537] [serial = 772] [outer = 0] [url = about:devtools-toolbox]
[task 2021-07-26T13:52:39.679Z] 13:52:39     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (7f7a37f4f800) [pid = 1537] [serial = 776] [outer = 0] [url = about:blank]
[task 2021-07-26T13:52:41.677Z] 13:52:41     INFO - GECKO(1537) | [Child 1681: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (7fd546668400) [pid = 1681] [serial = 131] [outer = 0] [url = about:blank]
[task 2021-07-26T13:53:55.498Z] 13:53:55     INFO - TEST-INFO | started process screentopng
[task 2021-07-26T13:53:55.802Z] 13:53:55     INFO - TEST-INFO | screentopng: exit 0
[task 2021-07-26T13:53:55.802Z] 13:53:55     INFO - Buffered messages logged at 13:52:25
[task 2021-07-26T13:53:55.802Z] 13:53:55     INFO - Entering test bound 
[task 2021-07-26T13:53:55.803Z] 13:53:55     INFO - Initializing a network monitor pane.
[task 2021-07-26T13:53:55.805Z] 13:53:55     INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/netmonitor/test/html_cause-test-page.html
[task 2021-07-26T13:53:55.806Z] 13:53:55     INFO - Buffered messages logged at 13:52:26
[task 2021-07-26T13:53:55.807Z] 13:53:55     INFO - Tab added and finished loading
[task 2021-07-26T13:53:55.809Z] 13:53:55     INFO - Net tab added successfully: http://example.com/browser/devtools/client/netmonitor/test/html_cause-test-page.html
[task 2021-07-26T13:53:55.809Z] 13:53:55     INFO - Buffered messages logged at 13:52:27
[task 2021-07-26T13:53:55.809Z] 13:53:55     INFO - Console message: Invalid chrome URI (need path): chrome://devtools/
[task 2021-07-26T13:53:55.813Z] 13:53:55     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2021-07-26T13:53:55.815Z] 13:53:55     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2021-07-26T13:53:55.815Z] 13:53:55     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 75}]
[task 2021-07-26T13:53:55.817Z] 13:53:55     INFO - Console message: [JavaScript Error: "[Exception... "Favicon at "http://example.com/browser/devtools/client/netmonitor/test/favicon_request" failed to load: Not Found."  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource:///modules/FaviconLoader.jsm :: onStopRequest :: line 253"  data: no]"]
[task 2021-07-26T13:53:55.817Z] 13:53:55     INFO - onStopRequest@resource:///modules/FaviconLoader.jsm:253:22
[task 2021-07-26T13:53:55.817Z] 13:53:55     INFO - 
[task 2021-07-26T13:53:55.818Z] 13:53:55     INFO - Buffered messages logged at 13:52:28
[task 2021-07-26T13:53:55.818Z] 13:53:55     INFO - Console message: [JavaScript Warning: "Relative positioning of table rows and row groups is now supported. This site may need to be updated because it may depend on this feature having no effect." {file: "resource://devtools/client/netmonitor/src/components/request-list/RequestListHeader.js" line: 545}]
[task 2021-07-26T13:53:55.820Z] 13:53:55     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2021-07-26T13:53:55.823Z] 13:53:55     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2021-07-26T13:53:55.823Z] 13:53:55     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 75}]
[task 2021-07-26T13:53:55.824Z] 13:53:55     INFO - Network monitor pane shown successfully.
[task 2021-07-26T13:53:55.825Z] 13:53:55     INFO - Disabling cache and reloading page.
[task 2021-07-26T13:53:55.826Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 0/1, PayloadReady: 0/1, EventTimings: 1/0, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn144.netEvent7
[task 2021-07-26T13:53:55.826Z] 13:53:55     INFO - Buffered messages logged at 13:52:29
[task 2021-07-26T13:53:55.827Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 0/1, PayloadReady: 1/1, EventTimings: 1/0, got NetMonitor:PayloadReady for server0.conn144.netEvent23
[task 2021-07-26T13:53:55.828Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 1/1, PayloadReady: 1/1, EventTimings: 1/1, got NetMonitor:NetworkEvent for server0.conn144.netEvent23
[task 2021-07-26T13:53:55.829Z] 13:53:55     INFO - Got marker: dom-interactive
[task 2021-07-26T13:53:55.829Z] 13:53:55     INFO - Got marker: dom-complete
[task 2021-07-26T13:53:55.830Z] 13:53:55     INFO - Got two timeline markers, done waiting
[task 2021-07-26T13:53:55.831Z] 13:53:55     INFO - Clearing requests in the UI.
[task 2021-07-26T13:53:55.832Z] 13:53:55     INFO - Starting test... 
[task 2021-07-26T13:53:55.832Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 0/8, PayloadReady: 1/8, EventTimings: 0/0, got NetMonitor:PayloadReady for server0.conn144.netEvent42
[task 2021-07-26T13:53:55.833Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 0/8, PayloadReady: 2/8, EventTimings: 0/0, got NetMonitor:PayloadReady for server0.conn144.netEvent59
[task 2021-07-26T13:53:55.834Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 0/8, PayloadReady: 3/8, EventTimings: 0/0, got NetMonitor:PayloadReady for server0.conn144.netEvent76
[task 2021-07-26T13:53:55.835Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 1/8, PayloadReady: 3/8, EventTimings: 0/1, got NetMonitor:NetworkEvent for server0.conn144.netEvent96
[task 2021-07-26T13:53:55.836Z] 13:53:55     INFO - Buffered messages logged at 13:52:30
[task 2021-07-26T13:53:55.836Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 2/8, PayloadReady: 3/8, EventTimings: 0/2, got NetMonitor:NetworkEvent for server0.conn144.netEvent109
[task 2021-07-26T13:53:55.837Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 2/8, PayloadReady: 4/8, EventTimings: 0/2, got NetMonitor:PayloadReady for server0.conn144.netEvent109
[task 2021-07-26T13:53:55.838Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 3/8, PayloadReady: 4/8, EventTimings: 0/3, got NetMonitor:NetworkEvent for server0.conn144.netEvent128
[task 2021-07-26T13:53:55.839Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 4/8, PayloadReady: 4/8, EventTimings: 0/4, got NetMonitor:NetworkEvent for server0.conn144.netEvent139
[task 2021-07-26T13:53:55.840Z] 13:53:55     INFO - Buffered messages logged at 13:52:31
[task 2021-07-26T13:53:55.840Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 5/8, PayloadReady: 4/8, EventTimings: 0/5, got NetMonitor:NetworkEvent for server0.conn144.netEvent150
[task 2021-07-26T13:53:55.841Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 5/8, PayloadReady: 4/8, EventTimings: 1/5, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn144.netEvent109
[task 2021-07-26T13:53:55.842Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 5/8, PayloadReady: 5/8, EventTimings: 1/5, got NetMonitor:PayloadReady for server0.conn144.netEvent128
[task 2021-07-26T13:53:55.843Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 5/8, PayloadReady: 6/8, EventTimings: 1/5, got NetMonitor:PayloadReady for server0.conn144.netEvent139
[task 2021-07-26T13:53:55.844Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 5/8, PayloadReady: 7/8, EventTimings: 1/5, got NetMonitor:PayloadReady for server0.conn144.netEvent150
[task 2021-07-26T13:53:55.844Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 5/8, PayloadReady: 8/8, EventTimings: 1/5, got NetMonitor:PayloadReady for server0.conn144.netEvent182
[task 2021-07-26T13:53:55.845Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 6/8, PayloadReady: 8/8, EventTimings: 1/6, got NetMonitor:NetworkEvent for server0.conn144.netEvent182
[task 2021-07-26T13:53:55.846Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 7/8, PayloadReady: 8/8, EventTimings: 1/7, got NetMonitor:NetworkEvent for server0.conn144.netEvent200
[task 2021-07-26T13:53:55.847Z] 13:53:55     INFO - Buffered messages logged at 13:52:32
[task 2021-07-26T13:53:55.848Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 7/8, PayloadReady: 9/8, EventTimings: 1/7, got NetMonitor:PayloadReady for server0.conn144.netEvent200
[task 2021-07-26T13:53:55.849Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 7/8, PayloadReady: 9/8, EventTimings: 2/7, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn144.netEvent128
[task 2021-07-26T13:53:55.849Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 7/8, PayloadReady: 9/8, EventTimings: 3/7, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn144.netEvent139
[task 2021-07-26T13:53:55.850Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 7/8, PayloadReady: 9/8, EventTimings: 4/7, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn144.netEvent150
[task 2021-07-26T13:53:55.851Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 7/8, PayloadReady: 9/8, EventTimings: 5/7, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn144.netEvent182
[task 2021-07-26T13:53:55.852Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 8/8, PayloadReady: 9/8, EventTimings: 5/8, got NetMonitor:NetworkEvent for server0.conn144.netEvent218
[task 2021-07-26T13:53:55.853Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 8/8, PayloadReady: 10/8, EventTimings: 5/8, got NetMonitor:PayloadReady for server0.conn144.netEvent218
[task 2021-07-26T13:53:55.854Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 8/8, PayloadReady: 10/8, EventTimings: 6/8, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn144.netEvent200
[task 2021-07-26T13:53:55.854Z] 13:53:55     INFO - Buffered messages logged at 13:52:33
[task 2021-07-26T13:53:55.855Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 9/8, PayloadReady: 10/8, EventTimings: 6/9, got NetMonitor:NetworkEvent for server0.conn144.netEvent236
[task 2021-07-26T13:53:55.856Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 9/8, PayloadReady: 11/8, EventTimings: 6/9, got NetMonitor:PayloadReady for server0.conn144.netEvent236
[task 2021-07-26T13:53:55.857Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 9/8, PayloadReady: 11/8, EventTimings: 7/9, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn144.netEvent218
[task 2021-07-26T13:53:55.857Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 10/8, PayloadReady: 11/8, EventTimings: 7/10, got NetMonitor:NetworkEvent for server0.conn144.netEvent254
[task 2021-07-26T13:53:55.858Z] 13:53:55     INFO - Console message: [JavaScript Error: "[Exception... "Favicon at "http://example.com/browser/devtools/client/netmonitor/test/favicon_request" failed to load: Not Found."  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource:///modules/FaviconLoader.jsm :: onStopRequest :: line 253"  data: no]"]
[task 2021-07-26T13:53:55.858Z] 13:53:55     INFO - onStopRequest@resource:///modules/FaviconLoader.jsm:253:22
[task 2021-07-26T13:53:55.858Z] 13:53:55     INFO - 
[task 2021-07-26T13:53:55.859Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 10/8, PayloadReady: 12/8, EventTimings: 7/10, got NetMonitor:PayloadReady for server0.conn144.netEvent254
[task 2021-07-26T13:53:55.860Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 10/8, PayloadReady: 12/8, EventTimings: 8/10, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn144.netEvent236
[task 2021-07-26T13:53:55.860Z] 13:53:55     INFO - Buffered messages logged at 13:52:34
[task 2021-07-26T13:53:55.861Z] 13:53:55     INFO - > Network event progress: NetworkEvent: 10/8, PayloadReady: 12/8, EventTimings: 9/10, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn144.netEvent254
[task 2021-07-26T13:53:55.861Z] 13:53:55     INFO - Buffered messages finished
[task 2021-07-26T13:53:55.862Z] 13:53:55     INFO - TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_stacktraces-visibility.js | Test timed out - 
[task 2021-07-26T13:53:57.166Z] 13:53:57     INFO - Removing tab.
[task 2021-07-26T13:53:57.167Z] 13:53:57     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2021-07-26T13:53:57.195Z] 13:53:57     INFO - Got event: 'TabClose' on [object XULElement].
[task 2021-07-26T13:53:57.214Z] 13:53:57     INFO - GECKO(1537) | [Parent 1537, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:184
[task 2021-07-26T13:53:57.221Z] 13:53:57     INFO - Tab removed and finished closing
[task 2021-07-26T13:53:57.252Z] 13:53:57     INFO - GECKO(1537) | [Parent 1537: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f7a1ff10000 == 6 [pid = 1537] [id = 314] [url = chrome://devtools/content/netmonitor/index.html]
[task 2021-07-26T13:53:57.266Z] 13:53:57     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_stacktraces-visibility.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2021-07-26T13:53:57.267Z] 13:53:57     INFO - finish() was called, cleaning up...
[task 2021-07-26T13:53:57.305Z] 13:53:57     INFO - GECKO(1537) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-07-26T13:53:57.326Z] 13:53:57     INFO - GECKO(1537) | MEMORY STAT | vsize 3887MB | residentFast 659MB | heapAllocated 286MB
[task 2021-07-26T13:53:57.328Z] 13:53:57     INFO - TEST-OK | devtools/client/netmonitor/test/browser_net_stacktraces-visibility.js | took 91859ms

Comment 1

[Dorel Luca [:dluca]]

Hubert: Can you please take a look at this bug? Looks to be a regression of bug 1722153

Comment 2

[Intermittent Failures Robot]

20 failures in 541 pushes (0.037 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 18
• mozilla-central: 2

Platform and build breakdown:

• linux1804-64-qr: 8
  • debug: 6
  • opt: 2
• linux1804-64: 2
  • debug: 1
  • opt: 1
• macosx1015-64-qr: 5
  • opt: 3
  • debug: 2
• windows10-32-qr: 2
  • opt: 1
  • debug: 1
• windows10-64-qr: 2
  • debug: 1
  • opt: 1
• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1722320&startday=2021-07-26&endday=2021-07-26&tree=all

Comment 3

[Hubert Boma Manilla (:bomsy)]

Thanks ... looking into it...

Comment 4

[Hubert Boma Manilla (:bomsy)]

Attachment: Bug 1722320 - [devtools] Fix intermittent for browser_net_stacktraces-visibility r=nchevobbe

Switched to using a simple/consistent test page with one request
as we just test stacktrace visibility

Comment 5

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1722153

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/f35b547fc811
[devtools] Fix intermittent for browser_net_stacktraces-visibility r=nchevobbe

Comment 7

[Alexandru Michis [:malexandru]]

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

Comment 8

[Intermittent Failures Robot]

32 failures in 3131 pushes (0.01 failures/push) were associated with this bug in the last 7 days.

This is the #47 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 21
• mozilla-central: 7
• try: 4

Platform and build breakdown:

• linux1804-64-qr: 12
  • debug: 9
  • opt: 3
• linux1804-64: 2
  • debug: 1
  • opt: 1
• macosx1015-64-qr: 7
  • opt: 4
  • debug: 3
• windows10-32-qr: 2
  • opt: 1
  • debug: 1
• windows10-64-qr: 3
  • debug: 1
  • opt: 2
• linux1804-64-shippable-qr: 1
  • opt: 1
• macosx1015-64-shippable-qr: 1
  • opt: 1
• windows10-64-devedition-qr: 1
  • opt: 1
• macosx1015-64-devedition-qr: 1
  • opt: 1
• windows10-64-shippable-qr: 1
  • opt: 1
• windows10-64-ccov-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1722320&startday=2021-07-26&endday=2021-08-01&tree=all