Closed Bug 1683279 Opened 3 years ago Closed 2 years ago

Intermittent toolkit/components/printing/tests/browser_print_in_container.js | Uncaught exception - Wait for dialog - timed out after 50 tries.

Categories

(Toolkit :: Printing, defect, P5)

Product:
Toolkit
Component:
Printing
Type:
defect

Tracking

()

Status:
RESOLVED DUPLICATE of bug 1775886
Tracking Flags:
Tracking Status
firefox-esr78 --- unaffected
firefox84 --- unaffected
firefox85 --- unaffected
firefox86 --- fix-optional
firefox87 --- fix-optional

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug, Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disabled])

Attachments

(2 files)

Bug 1683279, fix intermittent test error and use the focused window in PrintingSelectionChild.jsm
48 bytes, text/x-phabricator-request
Details | Review
Bug 1683279 - disable browser_print_in_container.js on linux64 debug r?#intermittent-reviewers
48 bytes, text/x-phabricator-request
Details | Review

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

INFO - TEST-OK | toolkit/components/printing/tests/browser_print_duplex.js | took 9177ms
[task 2020-12-18T08:42:10.036Z] 08:42:10     INFO - checking window state
[task 2020-12-18T08:42:10.096Z] 08:42:10     INFO - TEST-START | toolkit/components/printing/tests/browser_print_in_container.js
[task 2020-12-18T08:42:15.839Z] 08:42:15     INFO - TEST-INFO | started process screentopng
[task 2020-12-18T08:42:16.162Z] 08:42:16     INFO - TEST-INFO | screentopng: exit 0
[task 2020-12-18T08:42:16.163Z] 08:42:16     INFO - Buffered messages logged at 08:42:10
[task 2020-12-18T08:42:16.163Z] 08:42:16     INFO - Entering test bound test
[task 2020-12-18T08:42:16.166Z] 08:42:16     INFO - TEST-PASS | toolkit/components/printing/tests/browser_print_in_container.js | There are no print dialogs - 
[task 2020-12-18T08:42:16.166Z] 08:42:16     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: "https://example.com/browser/toolkit/components/printing/tests/simplifyArticleSample.html" line: 0}]
[task 2020-12-18T08:42:16.167Z] 08:42:16     INFO - Buffered messages finished
[task 2020-12-18T08:42:16.167Z] 08:42:16     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_print_in_container.js | Uncaught exception - Wait for dialog - timed out after 50 tries.
[task 2020-12-18T08:42:16.167Z] 08:42:16     INFO - Leaving test bound test
[task 2020-12-18T08:42:16.167Z] 08:42:16     INFO - GECKO(4146) | MEMORY STAT | vsize 130551399MB | residentFast 2843MB
[task 2020-12-18T08:42:16.167Z] 08:42:16     INFO - TEST-OK | toolkit/components/printing/tests/browser_print_in_container.js | took 5756ms
[task 2020-12-18T08:42:16.168Z] 08:42:16     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-12-18T08:42:16.168Z] 08:42:16     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_print_in_container.js | Found an unexpected tab at the end of test run: https://example.com/browser/toolkit/components/printing/tests/simplifyArticleSample.html - 
[task 2020-12-18T08:42:16.168Z] 08:42:16     INFO - checking window state
[task 2020-12-18T08:42:16.168Z] 08:42:16     INFO - TEST-START | toolkit/components/printing/tests/browser_print_margins.js
[task 2020-12-18T08:42:17.573Z] 08:42:17     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:17.573Z] 08:42:17     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:17.567: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:20.623Z] 08:42:20     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:20.623Z] 08:42:20     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:20.621: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:21.329Z] 08:42:21     INFO - GECKO(4146) | Waiting for removal
[task 2020-12-18T08:42:22.954Z] 08:42:22     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:22.955Z] 08:42:22     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:22.948: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:23.606Z] 08:42:23     INFO - GECKO(4146) | Waiting for removal
[task 2020-12-18T08:42:27.105Z] 08:42:27     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:27.105Z] 08:42:27     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:27.100: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:27.958Z] 08:42:27     INFO - GECKO(4146) | Waiting for removal
[task 2020-12-18T08:42:30.071Z] 08:42:30     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:30.071Z] 08:42:30     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:30.065: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:30.799Z] 08:42:30     INFO - GECKO(4146) | Waiting for removal
[task 2020-12-18T08:42:32.901Z] 08:42:32     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:32.902Z] 08:42:32     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:32.894: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:34.232Z] 08:42:34     INFO - GECKO(4146) | Waiting for removal
[task 2020-12-18T08:42:36.052Z] 08:42:36     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:36.052Z] 08:42:36     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:36.047: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:37.817Z] 08:42:37     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:37.817Z] 08:42:37     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:37.806: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:40.865Z] 08:42:40     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:40.865Z] 08:42:40     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:40.861: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:43.525Z] 08:42:43     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:43.525Z] 08:42:43     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:43.517: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:45.653Z] 08:42:45     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:45.653Z] 08:42:45     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:45.648: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:47.379Z] 08:42:47     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:47.380Z] 08:42:47     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:47.373: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:49.328Z] 08:42:49     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:49.328Z] 08:42:49     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:49.320: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:51.015Z] 08:42:51     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:51.016Z] 08:42:51     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:51.010: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:54.024Z] 08:42:54     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:54.024Z] 08:42:54     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:54.022: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:54.732Z] 08:42:54     INFO - GECKO(4146) | Waiting for removal
[task 2020-12-18T08:42:54.829Z] 08:42:54     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:54.829Z] 08:42:54     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:54.822: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:54.829Z] 08:42:54     INFO - GECKO(4146) | console.warn: printUI: Printer has empty paperList:  undefined using fallbackPaperList
[task 2020-12-18T08:42:56.568Z] 08:42:56     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:56.568Z] 08:42:56     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:56.564: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:42:59.518Z] 08:42:59     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:42:59.519Z] 08:42:59     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:42:59.517: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:43:02.335Z] 08:43:02     INFO - GECKO(4146) | [Parent 4146, Main Thread] WARNING: g_object_ref: assertion 'G_IS_OBJECT (object)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp:135
[task 2020-12-18T08:43:02.335Z] 08:43:02     INFO - GECKO(4146) | (firefox:4146): GLib-GObject-CRITICAL **: 08:43:02.322: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
[task 2020-12-18T08:43:04.026Z] 08:43:04     INFO - GECKO(4146) | MEMORY STAT | vsize 130551455MB | residentFast 2976MB
[task 2020-12-18T08:43:04.026Z] 08:43:04     INFO - TEST-OK | toolkit/components/printing/tests/browser_print_margins.js | took 47860ms```

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

status-firefox84: --- → unaffected
status-firefox85: --- → unaffected
status-firefox86: --- → affected
status-firefox-esr78: --- → unaffected
Whiteboard: [stockwell needswork:owner]
Flags: needinfo?(emalysz) → needinfo?(emalysz)

I can also reproduce this regularly on mac when running with --verify.

I traced it down to this line:
https://searchfox.org/mozilla-central/rev/a0ccd492719b1ad2106f6456549be62a76f45acb/toolkit/actors/PrintingSelectionChild.jsm#22

This throws a DomException, which we end up catching here: https://searchfox.org/mozilla-central/rev/a0ccd492719b1ad2106f6456549be62a76f45acb/toolkit/components/printing/content/printUtils.js#337

It looks like global is null, though I'm not sure why because the document.readyState is complete before we execute the print command (https://searchfox.org/mozilla-central/rev/a0ccd492719b1ad2106f6456549be62a76f45acb/toolkit/components/printing/tests/head.js#115-117).

Going to take a closer look at this

Assignee: nobody → emalysz
Flags: needinfo?(emalysz)

Emma, do you have an update on this bug? Thanks

Flags: needinfo?(emalysz)
Flags: needinfo?(emalysz)
Attachment #9198458 - Attachment description: Bug 1683279, fix intermittent test error and wuse the focused window in PrintingSelectionChild.jsm → Bug 1683279, fix intermittent test error and use the focused window in PrintingSelectionChild.jsm
Pushed by emalysz@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/5fed2013c954
fix intermittent test error and use the focused window in PrintingSelectionChild.jsm r=mstriemer

https://hg.mozilla.org/mozilla-central/rev/5fed2013c954

Status: NEW → RESOLVED
Closed: 3 years ago
status-firefox86: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → 86 Branch

It is still failing.
Log link: https://treeherder.mozilla.org/logviewer?job_id=327456182&repo=autoland&lineNumber=18202
Log snippet:

[task 2021-01-22T10:44:25.489Z] 10:44:25     INFO - TEST-PASS | toolkit/components/printing/tests/browser_print_in_container.js | There are no print dialogs - 
[task 2021-01-22T10:44:25.489Z] 10:44:25     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: "https://example.com/browser/toolkit/components/printing/tests/simplifyArticleSample.html" line: 0}]
[task 2021-01-22T10:44:25.490Z] 10:44:25     INFO - Buffered messages finished
[task 2021-01-22T10:44:25.490Z] 10:44:25     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_print_in_container.js | Uncaught exception - Wait for dialog - timed out after 50 tries.
[task 2021-01-22T10:44:25.491Z] 10:44:25     INFO - Leaving test bound test
[task 2021-01-22T10:44:25.492Z] 10:44:25     INFO - GECKO(8866) | MEMORY STAT | vsize 3493MB | residentFast 463MB | heapAllocated 151MB
[task 2021-01-22T10:44:25.492Z] 10:44:25     INFO - TEST-OK | toolkit/components/printing/tests/browser_print_in_container.js | took 7360ms
[task 2021-01-22T10:44:25.493Z] 10:44:25     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-01-22T10:44:25.494Z] 10:44:25     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_print_in_container.js | Found an unexpected tab at the end of test run: https://example.com/browser/toolkit/components/printing/tests/simplifyArticleSample.html - 
[task 2021-01-22T10:44:25.495Z] 10:44:25     INFO - GECKO(8866) | [Child 9026: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f9ed9ce5400 == 1 [pid = 9026] [id = 12]
[task 2021-01-22T10:44:25.495Z] 10:44:25     INFO - GECKO(8866) | [Child 9026: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f9ed9cbf200) [pid = 9026] [serial = 28] [outer = (nil)]
[task 2021-01-22T10:44:25.495Z] 10:44:25     INFO - GECKO(8866) | [Child 9026: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f9ed9ceac00) [pid = 9026] [serial = 29] [outer = 0x7f9ed9cbf200]
[task 2021-01-22T10:44:25.497Z] 10:44:25     INFO - checking window state
Status: RESOLVED → REOPENED
status-firefox86: fixed → affected
Flags: needinfo?(emalysz)
Resolution: FIXED → ---

I will take another look at this. For now, we can disable on linux64 debug since we are seeing so many failures

Flags: needinfo?(emalysz)
Pushed by abutkovits@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/f456a37c71fc
disable browser_print_in_container.js on linux64 debug r=intermittent-reviewers,jmaher DONTBUILD
Whiteboard: [stockwell disable-recommended]
Keywords: leave-open
Whiteboard: [stockwell disabled]
Assignee: emalysz → sfoster
Target Milestone: 86 Branch → ---
Assignee: sfoster → nobody
Has Regression Range: --- → yes
Status: REOPENED → RESOLVED
Closed: 3 years ago → 2 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: