Closed
Bug 1872339
Opened 2 years ago
Closed 2 years ago
Intermittent /webdriver/tests/classic/print/printcmd.py | single tracking bug
Categories
(Remote Protocol :: Marionette, defect, P5)
Remote Protocol
Marionette
Tracking
(Not tracked)
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure, intermittent-testcase)
Filed by: nerli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=441622549&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/OIZ4XqvqSS-lfCCA7gsJVA/runs/0/artifacts/public/logs/live_backing.log
[task 2023-12-29T10:16:07.395Z] 10:16:07 INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/classic/print/printcmd.py | test_page_ranges_document[ranges7-expected7] - AssertionError: assert None == ['Page 1', 'Page 2', 'Page 7', 'Page 9', 'Page 10']
[task 2023-12-29T10:16:07.395Z] 10:16:07 INFO - session = <Session 5c429c5b-9238-43ed-bd54-7c64a40cd277>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - inline = <function inline.<locals>.inline at 0x7fc40c0fd790>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - load_pdf_http = <function load_pdf_http.<locals>.load_pdf_http at 0x7fc40c0fd670>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - ranges = ['-2', '9-', '7']
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - expected = ['Page 1', 'Page 2', 'Page 7', 'Page 9', 'Page 10']
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO -
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - @pytest.mark.parametrize("ranges,expected", [
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - (["2-4"], ["Page 2", "Page 3", "Page 4"]),
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - (["2-4", "2-3"], ["Page 2", "Page 3", "Page 4"]),
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - (["2-4", "3-5"], ["Page 2", "Page 3", "Page 4", "Page 5"]),
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - (["9-"], ["Page 9", "Page 10"]),
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - (["-2"], ["Page 1", "Page 2"]),
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - (["7"], ["Page 7"]),
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - ([7],["Page 7"]),
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - (["-2", "9-", "7"], ["Page 1", "Page 2", "Page 7", "Page 9", "Page 10"]),
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - (["-2", "9-", 7], ["Page 1", "Page 2", "Page 7", "Page 9", "Page 10"]),
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - (["-5", "2-"], ["Page 1", "Page 2", "Page 3", "Page 4", "Page 5", "Page 6", "Page 7", "Page 8", "Page 9", "Page 10"]),
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - ([], ["Page 1", "Page 2", "Page 3", "Page 4", "Page 5", "Page 6", "Page 7", "Page 8", "Page 9", "Page 10"]),
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - ])
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - def test_page_ranges_document(session, inline, load_pdf_http, ranges, expected):
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - session.url = inline("""
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - <style>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - div {page-break-after: always}
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - </style>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO -
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - <div>Page 1</div>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - <div>Page 2</div>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - <div>Page 3</div>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - <div>Page 4</div>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - <div>Page 5</div>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - <div>Page 6</div>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - <div>Page 7</div>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - <div>Page 8</div>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - <div>Page 9</div>
[task 2023-12-29T10:16:07.396Z] 10:16:07 INFO - <div>Page 10</div>""")
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO -
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - response = do_print(session, {
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - "pageRanges": ranges
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - })
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - value = assert_success(response)
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - # TODO: Test that the output is reasonable
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - assert_pdf(value)
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO -
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - load_pdf_http(value)
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - pages = session.execute_async_script("""let callback = arguments[arguments.length - 1];
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - window.getText().then(pages => callback(pages));""")
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - > assert pages == expected
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - E AssertionError: assert None == ['Page 1', 'Page 2', 'Page 7', 'Page 9', 'Page 10']
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - E +None
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - E -['Page 1', 'Page 2', 'Page 7', 'Page 9', 'Page 10']
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO -
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - expected = ['Page 1', 'Page 2', 'Page 7', 'Page 9', 'Page 10']
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - inline = <function inline.<locals>.inline at 0x7fc40c0fd790>
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - load_pdf_http = <function load_pdf_http.<locals>.load_pdf_http at 0x7fc40c0fd670>
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - pages = None
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - ranges = ['-2', '9-', '7']
[task 2023-12-29T10:16:07.397Z] 10:16:07 INFO - response = <Response: status=200 body={"value":
|
||
Comment 1•2 years ago
|
||
This failure is caused by a crash in the content process. Here an excerpt from the emulator logcat:
12-29 10:15:45.969 25726 25741 D GeckoViewContentDelegateParent: receiveMessage: DispatcherMessage
12-29 10:15:46.168 25754 25966 F MOZ_Assert: Assertion failure: !NS_HasPendingEvents(currentThread), at /builds/worker/checkouts/gecko/dom/workers/WorkerPrivate.cpp:3837
12-29 10:15:46.168 25754 25966 F MOZ_Assert: #01: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x6dd500d]
12-29 10:15:46.168 25754 25966 F MOZ_Assert:
12-29 10:15:46.169 25754 25966 F MOZ_Assert: #02: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x6dc66e4]
12-29 10:15:46.169 25754 25966 F MOZ_Assert:
12-29 10:15:46.169 25754 25966 F MOZ_Assert: #03: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x4237a37]
12-29 10:15:46.169 25754 25966 F MOZ_Assert:
12-29 10:15:46.169 25754 25966 F MOZ_Assert: #04: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x423bcc4]
12-29 10:15:46.169 25754 25966 F MOZ_Assert:
12-29 10:15:46.169 25754 25966 F MOZ_Assert: #05: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x4969a96]
12-29 10:15:46.169 25754 25966 F MOZ_Assert:
12-29 10:15:46.169 25754 25966 F MOZ_Assert: #06: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x490b838]
12-29 10:15:46.169 25754 25966 F MOZ_Assert:
12-29 10:15:46.169 25754 25966 F MOZ_Assert: #07: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x490b7a1]
12-29 10:15:46.169 25754 25966 F MOZ_Assert:
12-29 10:15:46.169 25754 25966 F MOZ_Assert: #08: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x42349d5]
12-29 10:15:46.169 25754 25966 F MOZ_Assert:
12-29 10:15:46.169 25754 25966 F MOZ_Assert: #09: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libnss3.so +0x1cfee0]
12-29 10:15:46.169 25754 25966 F MOZ_Assert:
12-29 10:15:46.169 25754 25966 F MOZ_Assert: #10: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libmozglue.so +0xcecb0]
12-29 10:15:46.169 25754 25966 F MOZ_Assert:
12-29 10:15:46.169 25754 25966 F MOZ_Assert: #11: ???[/system/lib64/libc.so +0x89772]
12-29 10:15:46.169 25754 25966 F MOZ_Assert:
12-29 10:15:46.170 25754 25966 F MOZ_Assert: #12: ???[/system/lib64/libc.so +0x299ec]
12-29 10:15:46.170 25754 25966 F MOZ_Assert:
12-29 10:15:46.170 25754 25966 F MOZ_Assert: #13: ???[/system/lib64/libc.so +0x1ca66]
12-29 10:15:46.170 25754 25966 F MOZ_Assert:
12-29 10:15:46.305 25726 25745 I Gecko : [Parent 25726, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2B1FBB4C1DB12D80.D81BF819C81F54D5: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
12-29 10:15:46.305 25726 25745 I Gecko : [Parent 25726, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2B1FBB4C1DB12D80.D81BF819C81F54D5: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
12-29 10:15:46.305 25726 25745 I Gecko : [Parent 25726, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2B1FBB4C1DB12D80.D81BF819C81F54D5: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
12-29 10:15:46.305 25726 25745 I Gecko : [Parent 25726, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2B1FBB4C1DB12D80.D81BF819C81F54D5: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
12-29 10:15:46.305 25726 25745 I Gecko : [Parent 25726, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2B1FBB4C1DB12D80.D81BF819C81F54D5: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
12-29 10:15:46.305 25726 25745 I Gecko : [Parent 25726, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2B1FBB4C1DB12D80.D81BF819C81F54D5: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
12-29 10:15:46.305 25726 25745 I Gecko : [Parent 25726, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2B1FBB4C1DB12D80.D81BF819C81F54D5: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
12-29 10:15:46.305 25726 25745 I Gecko : [Parent 25726, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2B1FBB4C1DB12D80.D81BF819C81F54D5: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
12-29 10:15:46.306 25726 25745 I Gecko : [Parent 25726, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2B1FBB4C1DB12D80.D81BF819C81F54D5: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
12-29 10:15:46.306 25726 25745 I Gecko : [Parent 25726, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2B1FBB4C1DB12D80.D81BF819C81F54D5: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
12-29 10:15:46.306 25726 25745 I Gecko : [Parent 25726, IPC I/O Parent] WARNING: [1.1]: Rejecting introduction request from 'E13878D83E79CCD6.CAE1651EEF88C728' for unknown peer '2B1FBB4C1DB12D80.D81BF819C81F54D5': file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:676
12-29 10:15:46.308 25790 25812 I Gecko : [GPU 25790, IPC I/O Child] WARNING: [E13878D83E79CCD6.CAE1651EEF88C728]: Could not be introduced to peer 2B1FBB4C1DB12D80.D81BF819C81F54D5: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:605
12-29 10:15:46.308 25726 25741 I Gecko : 1703844946308 Marionette TRACE [2] Querying "executeScript" failed with AbortError, returning "null" as fallback
12-29 10:15:46.309 25726 25741 I Gecko : 1703844946309 Marionette DEBUG 0 <- [1,240,null,{"value":null}]
12-29 10:15:46.313 25726 25741 I Gecko : [Parent 25726, Main Thread] WARNING: IPC message 'PBrowser::Msg_StopIMEStateManagement' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
12-29 10:15:46.314 25726 25741 I Gecko : [Parent 25726, Main Thread] WARNING: IPC message 'PBrowser::Msg_Destroy' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
12-29 10:15:46.315 25726 25741 D GeckoViewContent: observe: oop-frameloader-crashed
Olivia, is that an already known issue or a new one?
Flags: needinfo?(ohall)
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 3•2 years ago
|
||
This trace seems new to me and doesn't seem similar to the print junit intermittent failures we have.
We have a few print junit intermittent failures (bug 1834367, bug 1835373, bug 1837584). I reviewed some of the traces on those and they all seem related to how those tests open the print spooler on Android and need to quickly return back to the test. I'm guessing it is a timing or resource issue for those bugs. That variety usually shows something was sent to the print spooler and the new Activity started.
Flags: needinfo?(ohall)
|
|
||
Comment 4•2 years ago
|
||
Thanks Olivia. Lets observe this failure for now given that it only happened twice so far.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 7•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
|
Reporter | |
Comment 8•2 years ago
|
||
| treeherder | ||
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=448163191&repo=mozilla-central
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 10•2 years ago
|
||
(In reply to Treeherder Bug Filer from comment #8)
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=448163191&repo=mozilla-central
No, that is actually bug 1825501.
Status: REOPENED → RESOLVED
Closed: 2 years ago → 2 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•