Open Bug 1948006 Opened 8 days ago Updated 5 days ago

Intermittent TV devtools/client/inspector/fonts/test/browser_fontinspector_reveal-in-page.js | The expected font is displayed -

Categories

(DevTools :: Inspector, defect, P5)

Product:
DevTools
Component:
Inspector
Type:
defect

Tracking

(firefox-esr128 unaffected, firefox135 unaffected, firefox136 unaffected, firefox137 affected)

Tracking Flags:
Tracking Status
firefox-esr128 --- unaffected
firefox135 --- unaffected
firefox136 --- unaffected
firefox137 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, test-verify-fail)

Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=494759101&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/br5USHY9TSapAGVHz2gCug/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/br5USHY9TSapAGVHz2gCug/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2025-02-13T10:13:42.667Z] 10:13:42     INFO - TEST-PASS | devtools/client/inspector/fonts/test/browser_fontinspector_reveal-in-page.js | 1 selectionchange events detected on mouseover - 
[task 2025-02-13T10:13:42.667Z] 10:13:42     INFO - TEST-PASS | devtools/client/inspector/fonts/test/browser_fontinspector_reveal-in-page.js | 1 selectionchange events detected on mouseout - 
[task 2025-02-13T10:13:42.668Z] 10:13:42     INFO - Mousing over and out of font number 4 ("Arial") in the list
[task 2025-02-13T10:13:42.668Z] 10:13:42     INFO - TEST-PASS | devtools/client/inspector/fonts/test/browser_fontinspector_reveal-in-page.js | 1 selectionchange events detected on mouseover - 
[task 2025-02-13T10:13:42.669Z] 10:13:42     INFO - Buffered messages logged at 10:13:42
[task 2025-02-13T10:13:42.669Z] 10:13:42     INFO - TEST-PASS | devtools/client/inspector/fonts/test/browser_fontinspector_reveal-in-page.js | 1 selectionchange events detected on mouseout - 
[task 2025-02-13T10:13:42.670Z] 10:13:42     INFO - Check that highlighting works for iframe nodes
[task 2025-02-13T10:13:42.670Z] 10:13:42     INFO - Loop through all frame selectors
[task 2025-02-13T10:13:42.671Z] 10:13:42     INFO - Find the frame element for selector iframe in https://example.com/browser/devtools/client/inspector/fonts/test/doc_browser_fontinspector.html
[task 2025-02-13T10:13:42.671Z] 10:13:42     INFO - Connect to frame and retrieve the targetFront
[task 2025-02-13T10:13:42.671Z] 10:13:42     INFO - Selecting the node for '[Front for domnode/server0.conn0.watcher2.process14//domnode115]'
[task 2025-02-13T10:13:42.672Z] 10:13:42     INFO - TEST-PASS | devtools/client/inspector/fonts/test/browser_fontinspector_reveal-in-page.js | There's only one font used in the iframe document - 
[task 2025-02-13T10:13:42.672Z] 10:13:42     INFO - Buffered messages finished
[task 2025-02-13T10:13:42.674Z] 10:13:42     INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/fonts/test/browser_fontinspector_reveal-in-page.js | The expected font is displayed - 
[task 2025-02-13T10:13:42.674Z] 10:13:42     INFO - Stack trace:
[task 2025-02-13T10:13:42.674Z] 10:13:42     INFO - chrome://mochikit/content/browser-test.js:test_ok:1599
[task 2025-02-13T10:13:42.674Z] 10:13:42     INFO - chrome://mochitests/content/browser/devtools/client/inspector/fonts/test/browser_fontinspector_reveal-in-page.js:testFontHighlightingInIframe:129
[task 2025-02-13T10:13:42.674Z] 10:13:42     INFO - chrome://mochitests/content/browser/devtools/client/inspector/fonts/test/browser_fontinspector_reveal-in-page.js:null:23
[task 2025-02-13T10:13:42.674Z] 10:13:42     INFO - chrome://mochikit/content/browser-test.js:handleTask:1147
[task 2025-02-13T10:13:42.674Z] 10:13:42     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1219
[task 2025-02-13T10:13:42.674Z] 10:13:42     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1360
[task 2025-02-13T10:13:42.674Z] 10:13:42     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1130
[task 2025-02-13T10:13:42.674Z] 10:13:42     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058
[task 2025-02-13T10:13:42.674Z] 10:13:42     INFO - Mousing over and out of the font  in the list
[task 2025-02-13T10:13:43.108Z] 10:13:43     INFO - GECKO(3347) | console.error: "Could not get the list of font families" (new TypeError("families.has is not a function", "resource://devtools/client/inspector/rules/views/text-property-editor.js", 660))
[task 2025-02-13T10:14:06.914Z] 10:14:06     INFO - Not taking screenshot here: see the one that was previously logged
[task 2025-02-13T10:14:06.915Z] 10:14:06     INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/fonts/test/browser_fontinspector_reveal-in-page.js | Test timed out - 
[task 2025-02-13T10:14:06.915Z] 10:14:06     INFO - GECKO(3347) | Completed ShutdownLeaks collections in process 3347
[task 2025-02-13T10:14:06.916Z] 10:14:06     INFO - TEST-START | Shutdown
[task 2025-02-13T10:14:06.916Z] 10:14:06     INFO - Browser Chrome Test Summary
[task 2025-02-13T10:14:06.917Z] 10:14:06     INFO - Passed:  50
[task 2025-02-13T10:14:06.918Z] 10:14:06     INFO - Failed:  2
[task 2025-02-13T10:14:06.919Z] 10:14:06     INFO - Todo:    0
[task 2025-02-13T10:14:06.919Z] 10:14:06     INFO - Mode:    e10s
[task 2025-02-13T10:14:06.920Z] 10:14:06     INFO - *** End BrowserChrome Test Results ***
[task 2025-02-13T10:14:06.956Z] 10:14:06     INFO - GECKO(3347) | Exiting due to channel error.
[task 2025-02-13T10:14:06.957Z] 10:14:06     INFO - GECKO(3347) | Exiting due to channel error.
[task 2025-02-13T10:14:06.958Z] 10:14:06     INFO - GECKO(3347) | Exiting due to channel error.
[task 2025-02-13T10:14:06.958Z] 10:14:06     INFO - GECKO(3347) | Exiting due to channel error.
[task 2025-02-13T10:14:06.959Z] 10:14:06     INFO - GECKO(3347) | Exiting due to channel error.
[task 2025-02-13T10:14:06.959Z] 10:14:06     INFO - GECKO(3347) | Exiting due to channel error.
[task 2025-02-13T10:14:06.961Z] 10:14:06     INFO - TEST-INFO | Main app process: exit 0
[task 2025-02-13T10:14:06.961Z] 10:14:06     INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/fonts/test/browser_fontinspector_reveal-in-page.js | Application shut down (without crashing) in the middle of a test!
[task 2025-02-13T10:14:06.961Z] 10:14:06     INFO - TEST-INFO took 44192ms
[task 2025-02-13T10:14:06.962Z] 10:14:06     INFO - runtests.py | Application ran for: 0:01:46.876610
[task 2025-02-13T10:14:06.962Z] 10:14:06     INFO - zombiecheck | Reading PID log: /var/folders/8p/h82rs71j6n73n2df1zk2nfp80000jb/T/tmpku2wunvdpidlog
[task 2025-02-13T10:14:06.963Z] 10:14:06     INFO - ==> process 3347 launched child process 3353
[task 2025-02-13T10:14:06.963Z] 10:14:06     INFO - ==> process 3347 launched child process 3354
[task 2025-02-13T10:14:06.963Z] 10:14:06     INFO - ==> process 3347 launched child process 3362
[task 2025-02-13T10:14:06.964Z] 10:14:06     INFO - ==> process 3347 launched child process 3370
[task 2025-02-13T10:14:06.964Z] 10:14:06     INFO - ==> process 3347 launched child process 3371
[task 2025-02-13T10:14:06.964Z] 10:14:06     INFO - ==> process 3347 launched child process 3372
[task 2025-02-13T10:14:06.965Z] 10:14:06     INFO - ==> process 3347 launched child process 3373
[task 2025-02-13T10:14:06.965Z] 10:14:06     INFO - ==> process 3347 launched child process 3374
[task 2025-02-13T10:14:06.966Z] 10:14:06     INFO - ==> process 3347 launched child process 3391
[task 2025-02-13T10:14:06.966Z] 10:14:06     INFO - ==> process 3347 launched child process 3392
[task 2025-02-13T10:14:06.966Z] 10:14:06     INFO - ==> process 3347 launched child process 3393
[task 2025-02-13T10:14:06.967Z] 10:14:06     INFO - ==> process 3347 launched child process 3410
[task 2025-02-13T10:14:06.967Z] 10:14:06     INFO - ==> process 3347 launched child process 3411
[task 2025-02-13T10:14:06.967Z] 10:14:06     INFO - ==> process 3347 launched child process 3417
[task 2025-02-13T10:14:06.968Z] 10:14:06     INFO - ==> process 3347 launched child process 3418
[task 2025-02-13T10:14:06.968Z] 10:14:06     INFO - ==> process 3347 launched child process 3424
[task 2025-02-13T10:14:06.968Z] 10:14:06     INFO - zombiecheck | Checking for orphan process with PID: 3392
[task 2025-02-13T10:14:06.969Z] 10:14:06     INFO - zombiecheck | Checking for orphan process with PID: 3393

:nchevobbe, since you are the author of the regressor, bug 1943605, could you take a look?

For more information, please visit BugBot documentation.

Flags: needinfo?(nchevobbe)

not sure how my patch impacted this, but I can reproduce locally, so I'll investigate

Flags: needinfo?(nchevobbe)

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

status-firefox135: --- → unaffected
status-firefox136: --- → unaffected
status-firefox137: --- → affected
status-firefox-esr128: --- → unaffected

From what I can see, we're missing the creation of the iframe target when we reload the page.

I added some logs, and I can see that the init-devtools-content-process-actor event (https://searchfox.org/mozilla-release/rev/64f25e3dd28985a6b0db743d37b7e556c5038cad/devtools/server/connectors/js-process-actor/content-process-jsprocessactor-startup.js#27) is emitted before the DevToolsProcessChild is created:

 0:45.91 [PID: 96070] content-process-jsprocessactor-startup.js | isContentProcessStartup: true
 0:45.91 [PID: 96070] <init-devtools-content-process-actor>
 0:46.25 [PID: 96070] DevToolsProcessChild constructor()

Here we can see the DevToolsProcessChild being created almost half a second after the event is emitted.
We're already working around a similar (same?) issue in the code https://searchfox.org/mozilla-release/rev/64f25e3dd28985a6b0db743d37b7e556c5038cad/devtools/server/connectors/js-process-actor/content-process-jsprocessactor-startup.js#17-22

/*
   We can't spawn the JSProcessActor right away and have to spin the event loop.
   Otherwise it isn't registered yet and isn't listening to observer service.
   Could it be the reason why JSProcessActor aren't spawn via process actor option's child.observers notifications ??
*/
Services.tm.dispatchToMainThread(() => {

Here the delay seems way longer, but it might just be because of chaos mode? I can't seem to reproduce the failure when not in chaos mode

You need to log in before you can comment on or make changes to this bug.