Open Bug 1960623 Opened 7 days ago Updated 1 day ago

Intermittent devtools/client/netmonitor/test/browser_net_duration.js | single tracking bug

Categories

(DevTools :: Netmonitor, defect, P5)

Product:
DevTools
Component:
Netmonitor
Type:
defect

Tracking

(Not tracked)

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, intermittent-testcase)

Filed by: amarc [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=504047527&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/PQTbi8KvTy-YveVsigKiWQ/runs/0/artifacts/public/logs/live_backing.log

[task 2025-04-15T11:31:01.284Z] 11:31:01     INFO - TEST-START | devtools/client/netmonitor/test/browser_net_duration.js
[task 2025-04-15T11:31:02.716Z] 11:31:02     INFO - GECKO(6370) | -----------------------------------------------------
[task 2025-04-15T11:31:02.718Z] 11:31:02     INFO - GECKO(6370) | Suppressions used:
[task 2025-04-15T11:31:02.718Z] 11:31:02     INFO - GECKO(6370) |   count      bytes template
[task 2025-04-15T11:31:02.718Z] 11:31:02     INFO - GECKO(6370) |      34      16384 nsComponentManagerImpl
[task 2025-04-15T11:31:02.718Z] 11:31:02     INFO - GECKO(6370) |       2        288 libfontconfig.so
[task 2025-04-15T11:31:02.718Z] 11:31:02     INFO - GECKO(6370) |       1       9496 style::sharing::SHARING_CACHE_KEY
[task 2025-04-15T11:31:02.718Z] 11:31:02     INFO - GECKO(6370) |       1       4104 style::bloom::BLOOM_KEY
[task 2025-04-15T11:31:02.718Z] 11:31:02     INFO - GECKO(6370) | -----------------------------------------------------
[task 2025-04-15T11:31:09.254Z] 11:31:09     INFO - GECKO(6370) | [dump-scope] Serializing variables for frame: chrome://mochikit/content/browser-test.js @ 37:9
[task 2025-04-15T11:31:09.255Z] 11:31:09     INFO - GECKO(6370) | [dump-scope] Serializing variables for frame: chrome://mochikit/content/browser-test.js @ 1605:3
[task 2025-04-15T11:31:09.255Z] 11:31:09     INFO - GECKO(6370) | [dump-scope] Serializing variables for frame: chrome://mochikit/content/browser-test.js @ 1643:9
[task 2025-04-15T11:31:09.255Z] 11:31:09     INFO - GECKO(6370) | [dump-scope] Serializing variables for frame: chrome://mochikit/content/browser-test.js @ 1654:10
[task 2025-04-15T11:31:09.255Z] 11:31:09     INFO - GECKO(6370) | [dump-scope] Serializing variables for frame: chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_duration.js @ 47:5
[task 2025-04-15T11:31:09.292Z] 11:31:09     INFO - GECKO(6370) | [dump-scope] Serializing variables for frame: chrome://mochikit/content/browser-test.js @ 1170:26
[task 2025-04-15T11:31:09.293Z] 11:31:09     INFO - GECKO(6370) | [dump-scope] Serializing variables for frame: chrome://mochikit/content/browser-test.js @ 1242:18
[task 2025-04-15T11:31:09.298Z] 11:31:09     INFO - GECKO(6370) | [dump-scope] Saving scope variables as a JSON file: /builds/worker/workspace/build/blobber_upload_dir/scope-variables-1744716669297-browser_net_duration.js_47_5.json
[task 2025-04-15T11:31:09.300Z] 11:31:09     INFO - TEST-INFO | started process screentopng
[task 2025-04-15T11:31:09.481Z] 11:31:09     INFO - TEST-INFO | screentopng: exit 0
[task 2025-04-15T11:31:09.481Z] 11:31:09     INFO - Buffered messages logged at 11:31:01
[task 2025-04-15T11:31:09.482Z] 11:31:09     INFO - Entering test bound 
[task 2025-04-15T11:31:09.482Z] 11:31:09     INFO - Initializing a network monitor pane.
[task 2025-04-15T11:31:09.482Z] 11:31:09     INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/netmonitor/test/html_slow-requests-test-page.html
[task 2025-04-15T11:31:09.483Z] 11:31:09     INFO - Console message: [JavaScript Warning: "HTTPS-First Mode: Upgrading insecure speculative TCP connection “http://example.com/browser/devtools/client/netmonitor/test/html_slow-requests-test-page.html” to use “https”."]
[task 2025-04-15T11:31:09.483Z] 11:31:09     INFO - Buffered messages logged at 11:31:04
[task 2025-04-15T11:31:09.483Z] 11:31:09     INFO - Tab added and finished loading
[task 2025-04-15T11:31:09.483Z] 11:31:09     INFO - Net tab added successfully: http://example.com/browser/devtools/client/netmonitor/test/html_slow-requests-test-page.html
[task 2025-04-15T11:31:09.484Z] 11:31:09     INFO - Network monitor pane shown successfully.
[task 2025-04-15T11:31:09.484Z] 11:31:09     INFO - Disabling cache and reloading page.
[task 2025-04-15T11:31:09.486Z] 11:31:09     INFO - Buffered messages logged at 11:31:05
[task 2025-04-15T11:31:09.486Z] 11:31:09     INFO - > Network event progress: NetworkEvent: 0/1, PayloadReady: 1/1, EventTimings: 0/0, got NetMonitor:PayloadReady for server0.conn0.netEvent8
[task 2025-04-15T11:31:09.487Z] 11:31:09     INFO - > Network event progress: NetworkEvent: 1/1, PayloadReady: 1/1, EventTimings: 0/1, got NetMonitor:NetworkEvent for server0.conn0.netEvent8
[task 2025-04-15T11:31:09.487Z] 11:31:09     INFO - > Network event progress: NetworkEvent: 2/1, PayloadReady: 1/1, EventTimings: 0/2, got NetMonitor:NetworkEvent for server0.conn0.netEvent10
[task 2025-04-15T11:31:09.487Z] 11:31:09     INFO - > Network event progress: NetworkEvent: 2/1, PayloadReady: 1/1, EventTimings: 1/2, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn0.netEvent8
[task 2025-04-15T11:31:09.487Z] 11:31:09     INFO - Buffered messages logged at 11:31:07
[task 2025-04-15T11:31:09.488Z] 11:31:09     INFO - > Network event progress: NetworkEvent: 2/1, PayloadReady: 2/1, EventTimings: 1/2, got NetMonitor:PayloadReady for server0.conn0.netEvent10
[task 2025-04-15T11:31:09.489Z] 11:31:09     INFO - Got marker: dom-interactive
[task 2025-04-15T11:31:09.489Z] 11:31:09     INFO - Got marker: dom-complete
[task 2025-04-15T11:31:09.490Z] 11:31:09     INFO - Got two timeline markers, done waiting
[task 2025-04-15T11:31:09.490Z] 11:31:09     INFO - > Network event progress: NetworkEvent: 2/1, PayloadReady: 2/1, EventTimings: 2/2, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn0.netEvent10
[task 2025-04-15T11:31:09.490Z] 11:31:09     INFO - Wait for completion of all NetworkUpdateEvents packets...
[task 2025-04-15T11:31:09.491Z] 11:31:09     INFO - Clearing the network requests in the UI
[task 2025-04-15T11:31:09.492Z] 11:31:09     INFO - Starting test... 
[task 2025-04-15T11:31:09.492Z] 11:31:09     INFO - Performing requests in the context of the content.
[task 2025-04-15T11:31:09.493Z] 11:31:09     INFO - > Network event progress: NetworkEvent: 1/1, PayloadReady: 0/0, EventTimings: 0/0, got NetMonitor:NetworkEvent for server0.conn0.netEvent13
[task 2025-04-15T11:31:09.493Z] 11:31:09     INFO - Performing requests in the context of the content.
[task 2025-04-15T11:31:09.494Z] 11:31:09     INFO - Buffered messages logged at 11:31:08
[task 2025-04-15T11:31:09.494Z] 11:31:09     INFO - > Network event progress: NetworkEvent: 1/1, PayloadReady: 0/1, EventTimings: 0/1, got NetMonitor:NetworkEvent for server0.conn0.netEvent14
[task 2025-04-15T11:31:09.495Z] 11:31:09     INFO - > Network event progress: NetworkEvent: 1/1, PayloadReady: 1/1, EventTimings: 0/1, got NetMonitor:PayloadReady for server0.conn0.netEvent13
[task 2025-04-15T11:31:09.496Z] 11:31:09     INFO - > Network event progress: NetworkEvent: 1/1, PayloadReady: 2/1, EventTimings: 0/1, got NetMonitor:PayloadReady for server0.conn0.netEvent14
[task 2025-04-15T11:31:09.496Z] 11:31:09     INFO - > Network event progress: NetworkEvent: 1/1, PayloadReady: 2/1, EventTimings: 1/1, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn0.netEvent13
[task 2025-04-15T11:31:09.497Z] 11:31:09     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_duration.js | Duration should be listed as '' until resolved. - 
[task 2025-04-15T11:31:09.497Z] 11:31:09     INFO - Buffered messages finished
[task 2025-04-15T11:31:09.498Z] 11:31:09     INFO - TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_duration.js | Duration of resolved request should be displayed correctly. - Got "1.04 s", expected "1041 ms"
[task 2025-04-15T11:31:09.498Z] 11:31:09     INFO - Stack trace:
[task 2025-04-15T11:31:09.498Z] 11:31:09     INFO - chrome://mochikit/content/browser-test.js:test_is:1654
[task 2025-04-15T11:31:09.498Z] 11:31:09     INFO - chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_duration.js:null:47
[task 2025-04-15T11:31:09.498Z] 11:31:09     INFO - chrome://mochikit/content/browser-test.js:handleTask:1170
[task 2025-04-15T11:31:09.499Z] 11:31:09     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1242
[task 2025-04-15T11:31:09.499Z] 11:31:09     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1383
[task 2025-04-15T11:31:09.499Z] 11:31:09     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1159
[task 2025-04-15T11:31:09.500Z] 11:31:09     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058
[task 2025-04-15T11:31:09.500Z] 11:31:09     INFO - Leaving test bound 
[task 2025-04-15T11:31:09.775Z] 11:31:09     INFO - Removing tab.
[task 2025-04-15T11:31:09.776Z] 11:31:09     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2025-04-15T11:31:09.789Z] 11:31:09     INFO - Got event: 'TabClose' on [object XULElement].
[task 2025-04-15T11:31:09.810Z] 11:31:09     INFO - Tab removed and finished closing
[task 2025-04-15T11:31:09.822Z] 11:31:09     INFO - GECKO(6370) | JavaScript error: , line 0: NotFoundError: No such JSProcessActor 'DevToolsProcess'
[task 2025-04-15T11:31:09.823Z] 11:31:09     INFO - GECKO(6370) | JavaScript error: , line 0: NotFoundError: No such JSProcessActor 'DevToolsProcess'
[task 2025-04-15T11:31:09.824Z] 11:31:09     INFO - GECKO(6370) | JavaScript error: , line 0: NotFoundError: No such JSProcessActor 'DevToolsProcess'
[task 2025-04-15T11:31:09.833Z] 11:31:09     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSProcessActor 'DevToolsProcess'"]
[task 2025-04-15T11:31:09.834Z] 11:31:09     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSProcessActor 'DevToolsProcess'"]
[task 2025-04-15T11:31:09.837Z] 11:31:09     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSProcessActor 'DevToolsProcess'"]
[task 2025-04-15T11:31:09.838Z] 11:31:09     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_duration.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2025-04-15T11:31:09.838Z] 11:31:09     INFO - finish() was called, cleaning up...
[task 2025-04-15T11:31:10.165Z] 11:31:10     INFO - GECKO(6370) | MEMORY STAT | vsize 20985669MB | residentFast 2718MB
[task 2025-04-15T11:31:10.166Z] 11:31:10     INFO - TEST-OK | devtools/client/netmonitor/test/browser_net_duration.js | took 8882ms
[task 2025-04-15T11:31:10.206Z] 11:31:10     INFO - checking window state
[task 2025-04-15T11:31:10.238Z] 11:31:10     INFO - TEST-START | devtools/client/netmonitor/test/browser_net_earlyhints.js
You need to log in before you can comment on or make changes to this bug.