1732102 - Intermittent TEST-UNEXPECTED-TIMEOUT | toolkit/components/printing/tests/browser_print_in_container.js | application timed out after 370 seconds with no output

Status: RESOLVED INCOMPLETE

(Toolkit :: Printing, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=352349978&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/EyGsP41BRZiN-UwDrUObMg/runs/0/artifacts/public/logs/live_backing.log

---

[task 2021-09-22T10:55:21.507Z] 10:55:21     INFO - TEST-PASS | toolkit/components/printing/tests/browser_print_in_container.js | There are no print dialogs - 
[task 2021-09-22T10:55:21.508Z] 10:55:21     INFO - Buffered messages finished
[task 2021-09-22T10:55:21.508Z] 10:55:21    ERROR - TEST-UNEXPECTED-TIMEOUT | toolkit/components/printing/tests/browser_print_in_container.js | application timed out after 370 seconds with no output
[task 2021-09-22T10:55:21.508Z] 10:55:21    ERROR - Force-terminating active process(es).
[task 2021-09-22T10:55:21.509Z] 10:55:21     INFO - Determining child pids from psutil...
[task 2021-09-22T10:55:21.509Z] 10:55:21     INFO - [4439, 4440, 4441, 4442, 4443, 4507, 4508]
[task 2021-09-22T10:55:21.510Z] 10:55:21     INFO - ==> process 4434 launched child process 4439
[task 2021-09-22T10:55:21.510Z] 10:55:21     INFO - ==> process 4434 launched child process 4440
[task 2021-09-22T10:55:21.510Z] 10:55:21     INFO - ==> process 4434 launched child process 4441
[task 2021-09-22T10:55:21.511Z] 10:55:21     INFO - ==> process 4434 launched child process 4442
[task 2021-09-22T10:55:21.511Z] 10:55:21     INFO - ==> process 4434 launched child process 4443
[task 2021-09-22T10:55:21.511Z] 10:55:21     INFO - ==> process 4434 launched child process 4444
[task 2021-09-22T10:55:21.512Z] 10:55:21     INFO - ==> process 4434 launched child process 4446
[task 2021-09-22T10:55:21.512Z] 10:55:21     INFO - ==> process 4434 launched child process 4447
[task 2021-09-22T10:55:21.512Z] 10:55:21     INFO - ==> process 4434 launched child process 4448
[task 2021-09-22T10:55:21.513Z] 10:55:21     INFO - ==> process 4434 launched child process 4449
[task 2021-09-22T10:55:21.513Z] 10:55:21     INFO - ==> process 4434 launched child process 4450
[task 2021-09-22T10:55:21.513Z] 10:55:21     INFO - ==> process 4434 launched child process 4451
[task 2021-09-22T10:55:21.514Z] 10:55:21     INFO - ==> process 4434 launched child process 4452
[task 2021-09-22T10:55:21.514Z] 10:55:21     INFO - ==> process 4434 launched child process 4453
[task 2021-09-22T10:55:21.514Z] 10:55:21     INFO - ==> process 4434 launched child process 4454
[task 2021-09-22T10:55:21.515Z] 10:55:21     INFO - ==> process 4434 launched child process 4455
[task 2021-09-22T10:55:21.515Z] 10:55:21     INFO - ==> process 4434 launched child process 4456
[task 2021-09-22T10:55:21.515Z] 10:55:21     INFO - ==> process 4434 launched child process 4461
[task 2021-09-22T10:55:21.516Z] 10:55:21     INFO - ==> process 4434 launched child process 4464
[task 2021-09-22T10:55:21.516Z] 10:55:21     INFO - ==> process 4434 launched child process 4465
[task 2021-09-22T10:55:21.516Z] 10:55:21     INFO - ==> process 4434 launched child process 4466
[task 2021-09-22T10:55:21.517Z] 10:55:21     INFO - ==> process 4434 launched child process 4467
[task 2021-09-22T10:55:21.517Z] 10:55:21     INFO - ==> process 4434 launched child process 4468
[task 2021-09-22T10:55:21.517Z] 10:55:21     INFO - ==> process 4434 launched child process 4469
[task 2021-09-22T10:55:21.518Z] 10:55:21     INFO - ==> process 4434 launched child process 4470
[task 2021-09-22T10:55:21.518Z] 10:55:21     INFO - ==> process 4434 launched child process 4471
[task 2021-09-22T10:55:21.518Z] 10:55:21     INFO - ==> process 4434 launched child process 4476
[task 2021-09-22T10:55:21.519Z] 10:55:21     INFO - ==> process 4434 launched child process 4477
[task 2021-09-22T10:55:21.519Z] 10:55:21     INFO - ==> process 4434 launched child process 4478
[task 2021-09-22T10:55:21.519Z] 10:55:21     INFO - ==> process 4434 launched child process 4479
[task 2021-09-22T10:55:21.520Z] 10:55:21     INFO - ==> process 4434 launched child process 4480
[task 2021-09-22T10:55:21.520Z] 10:55:21     INFO - ==> process 4434 launched child process 4481
[task 2021-09-22T10:55:21.520Z] 10:55:21     INFO - ==> process 4434 launched child process 4482
[task 2021-09-22T10:55:21.521Z] 10:55:21     INFO - ==> process 4434 launched child process 4483
[task 2021-09-22T10:55:21.521Z] 10:55:21     INFO - ==> process 4434 launched child process 4484
[task 2021-09-22T10:55:21.522Z] 10:55:21     INFO - ==> process 4434 launched child process 4485
[task 2021-09-22T10:55:21.522Z] 10:55:21     INFO - ==> process 4434 launched child process 4486
[task 2021-09-22T10:55:21.522Z] 10:55:21     INFO - ==> process 4434 launched child process 4491
[task 2021-09-22T10:55:21.523Z] 10:55:21     INFO - ==> process 4434 launched child process 4492
[task 2021-09-22T10:55:21.523Z] 10:55:21     INFO - ==> process 4434 launched child process 4493
[task 2021-09-22T10:55:21.523Z] 10:55:21     INFO - ==> process 4434 launched child process 4494
[task 2021-09-22T10:55:21.524Z] 10:55:21     INFO - ==> process 4434 launched child process 4495
[task 2021-09-22T10:55:21.524Z] 10:55:21     INFO - ==> process 4434 launched child process 4496
[task 2021-09-22T10:55:21.524Z] 10:55:21     INFO - ==> process 4434 launched child process 4497
[task 2021-09-22T10:55:21.525Z] 10:55:21     INFO - ==> process 4434 launched child process 4498
[task 2021-09-22T10:55:21.525Z] 10:55:21     INFO - ==> process 4434 launched child process 4499
[task 2021-09-22T10:55:21.525Z] 10:55:21     INFO - ==> process 4434 launched child process 4500
[task 2021-09-22T10:55:21.526Z] 10:55:21     INFO - ==> process 4434 launched child process 4501
[task 2021-09-22T10:55:21.526Z] 10:55:21     INFO - ==> process 4434 launched child process 4502
[task 2021-09-22T10:55:21.526Z] 10:55:21     INFO - ==> process 4434 launched child process 4507
[task 2021-09-22T10:55:21.527Z] 10:55:21     INFO - ==> process 4434 launched child process 4508
[task 2021-09-22T10:55:21.527Z] 10:55:21     INFO - Found child pids: {4480, 4481, 4482, 4483, 4484, 4485, 4486, 4491, 4492, 4493, 4494, 4495, 4496, 4497, 4498, 4499, 4500, 4501, 4502, 4507, 4508, 4439, 4440, 4441, 4442, 4443, 4444, 4446, 4447, 4448, 4449, 4450, 4451, 4452, 4453, 4454, 4455, 4456, 4461, 4464, 4465, 4466, 4467, 4468, 4469, 4470, 4471, 4476, 4477, 4478, 4479}
[task 2021-09-22T10:55:21.528Z] 10:55:21     INFO - Failed to get child procs
[task 2021-09-22T10:55:21.528Z] 10:55:21     INFO - Killing process: 4480
[task 2021-09-22T10:55:21.528Z] 10:55:21     INFO - TEST-INFO | started process screencapture
[task 2021-09-22T10:55:21.638Z] 10:55:21     INFO - TEST-INFO | screencapture: exit 0
[task 2021-09-22T10:55:21.639Z] 10:55:21     INFO - Can't trigger Breakpad, process no longer exists
[task 2021-09-22T10:55:21.639Z] 10:55:21     INFO - Killing process: 4481
[task 2021-09-22T10:55:21.640Z] 10:55:21     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-22T10:55:21.640Z] 10:55:21     INFO - Can't trigger Breakpad, process no longer exists
[task 2021-09-22T10:55:21.640Z] 10:55:21     INFO - Killing process: 4482
[task 2021-09-22T10:55:21.641Z] 10:55:21     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-22T10:55:21.641Z] 10:55:21     INFO - Can't trigger Breakpad, process no longer exists
[task 2021-09-22T10:55:21.641Z] 10:55:21     INFO - Killing process: 4483
[task 2021-09-22T10:55:21.642Z] 10:55:21     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-22T10:55:21.642Z] 10:55:21     INFO - Can't trigger Breakpad, process no longer exists
[task 2021-09-22T10:55:21.643Z] 10:55:21     INFO - Killing process: 4484
<...>
[task 2021-09-22T10:55:21.686Z] 10:55:21     INFO - Killing process: 4471
[task 2021-09-22T10:55:21.687Z] 10:55:21     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-22T10:55:21.687Z] 10:55:21     INFO - Can't trigger Breakpad, process no longer exists
[task 2021-09-22T10:55:21.687Z] 10:55:21     INFO - Killing process: 4476
[task 2021-09-22T10:55:21.688Z] 10:55:21     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-22T10:55:21.688Z] 10:55:21     INFO - Can't trigger Breakpad, process no longer exists
[task 2021-09-22T10:55:21.688Z] 10:55:21     INFO - Killing process: 4477
[task 2021-09-22T10:55:21.689Z] 10:55:21     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-22T10:55:21.689Z] 10:55:21     INFO - Can't trigger Breakpad, process no longer exists
[task 2021-09-22T10:55:21.690Z] 10:55:21     INFO - Killing process: 4478
[task 2021-09-22T10:55:21.690Z] 10:55:21     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-22T10:55:21.690Z] 10:55:21     INFO - Can't trigger Breakpad, process no longer exists
[task 2021-09-22T10:55:21.691Z] 10:55:21     INFO - Killing process: 4479
[task 2021-09-22T10:55:21.691Z] 10:55:21     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-22T10:55:21.691Z] 10:55:21     INFO - Can't trigger Breakpad, process no longer exists
[task 2021-09-22T10:55:21.692Z] 10:55:21     INFO - Killing process: 4434
[task 2021-09-22T10:55:21.692Z] 10:55:21     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-22T10:55:22.082Z] 10:55:22     INFO - psutil found pid 4434 dead
[task 2021-09-22T10:55:22.082Z] 10:55:22     INFO - TEST-INFO | Main app process: exit 0
[task 2021-09-22T10:55:22.083Z] 10:55:22    ERROR - TEST-UNEXPECTED-FAIL | ShutdownLeaks | process() called before end of test suite
[task 2021-09-22T10:55:22.083Z] 10:55:22     INFO - TEST-INFO | Confirming we saw 273 DOCSHELL created and 246 destroyed log strings.
[task 2021-09-22T10:55:22.084Z] 10:55:22     INFO - TEST-INFO | Confirming we saw 704 DOMWINDOW created and 540 destroyed log strings.
[task 2021-09-22T10:55:22.084Z] 10:55:22     INFO - runtests.py | Application ran for: 0:07:10.781930
[task 2021-09-22T10:55:22.085Z] 10:55:22     INFO - zombiecheck | Reading PID log: /var/folders/0s/9_msfg952n912mkbfp_g6dqm000014/T/tmpmsrzvo94pidlog
[task 2021-09-22T10:55:22.085Z] 10:55:22     INFO - ==> process 4434 launched child process 4439
[task 2021-09-22T10:55:22.086Z] 10:55:22     INFO - ==> process 4434 launched child process 4440
<...>
[task 2021-09-22T10:55:22.121Z] 10:55:22     INFO - zombiecheck | Checking for orphan process with PID: 4478
[task 2021-09-22T10:55:22.121Z] 10:55:22     INFO - zombiecheck | Checking for orphan process with PID: 4479
[task 2021-09-22T10:55:22.122Z] 10:55:22     INFO - mozcrash Copy/paste: /opt/worker/tasks/task_163230568079235/fetches/minidump_stackwalk/minidump_stackwalk /var/folders/0s/9_msfg952n912mkbfp_g6dqm000014/T/tmpm4jljcvf.mozrunner/minidumps/9F8EBFBB-D34C-43CA-AC2D-DD6266CD4C51.dmp /opt/worker/tasks/task_163230568079235/build/symbols
[task 2021-09-22T10:55:28.316Z] 10:55:28     INFO - mozcrash Saved minidump as /opt/worker/tasks/task_163230568079235/build/blobber_upload_dir/9F8EBFBB-D34C-43CA-AC2D-DD6266CD4C51.dmp
[task 2021-09-22T10:55:28.317Z] 10:55:28     INFO - mozcrash Saved app info as /opt/worker/tasks/task_163230568079235/build/blobber_upload_dir/9F8EBFBB-D34C-43CA-AC2D-DD6266CD4C51.extra
[task 2021-09-22T10:55:28.823Z] 10:55:28     INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ js::BarrierMethods<JSObject*>::exposeToJS(JSObject*)]
[task 2021-09-22T10:55:28.823Z] 10:55:28     INFO - Crash dump filename: /var/folders/0s/9_msfg952n912mkbfp_g6dqm000014/T/tmpm4jljcvf.mozrunner/minidumps/9F8EBFBB-D34C-43CA-AC2D-DD6266CD4C51.dmp
[task 2021-09-22T10:55:28.823Z] 10:55:28     INFO - Operating system: Mac OS X
[task 2021-09-22T10:55:28.823Z] 10:55:28     INFO -                   10.15.7 19H524
[task 2021-09-22T10:55:28.823Z] 10:55:28     INFO - CPU: amd64
[task 2021-09-22T10:55:28.823Z] 10:55:28     INFO -      family 6 model 158 stepping 10
[task 2021-09-22T10:55:28.824Z] 10:55:28     INFO -      12 CPUs
[task 2021-09-22T10:55:28.824Z] 10:55:28     INFO - 
[task 2021-09-22T10:55:28.824Z] 10:55:28     INFO - GPU: UNKNOWN
[task 2021-09-22T10:55:28.824Z] 10:55:28     INFO - 
[task 2021-09-22T10:55:28.824Z] 10:55:28     INFO - Crash reason:  EXC_SOFTWARE / SIGABRT
[task 2021-09-22T10:55:28.824Z] 10:55:28     INFO - Crash address: 0x11fe9ec0d
[task 2021-09-22T10:55:28.824Z] 10:55:28     INFO - Process uptime: 430 seconds
[task 2021-09-22T10:55:28.824Z] 10:55:28     INFO - 
[task 2021-09-22T10:55:28.824Z] 10:55:28     INFO - Thread 0 tid 775 (crashed) - GeckoMain 0  XUL!JS::RuntimeHeapState() [GCAPI.cpp:42800c2f8e8cdaa7a2ada33f0cc075445f722ea9 : 48 + 0x19]

Comment 1

[Intermittent Failures Robot]

1 failures in 2873 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • debug: 1

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

Comment 2

[Intermittent Failures Robot]

1 failures in 3376 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1732102&startday=2021-09-27&endday=2021-10-03&tree=all

Comment 3

[Intermittent Failures Robot]

1 failures in 3186 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1732102&startday=2021-10-18&endday=2021-10-24&tree=all

Comment 4

[Intermittent Failures Robot]

1 failures in 3030 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • debug: 1

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

Comment 5

[Intermittent Failures Robot]

1 failures in 2723 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1732102&startday=2021-11-08&endday=2021-11-14&tree=all

Comment 6

[Intermittent Failures Robot]

2 failures in 3259 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• windows10-64-2004-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1732102&startday=2021-11-15&endday=2021-11-21&tree=all

Comment 7

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 8

[Alexandru Michis [:malexandru]]

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=362293442&repo=autoland&lineNumber=109321

Comment 9

[Intermittent Failures Robot]

1 failures in 2286 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • debug: 1

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

Comment 10

[Intermittent Failures Robot]

1 failures in 1011 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1732102&startday=2021-12-27&endday=2022-01-02&tree=all

Comment 11

[Intermittent Failures Robot]

2 failures in 3060 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• windows10-64-2004-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1732102&startday=2022-01-10&endday=2022-01-16&tree=all

Comment 12

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 13

[Iulian Moraru]

This started to fail on tier 1: https://treeherder.mozilla.org/logviewer?job_id=367925329&repo=mozilla-central&lineNumber=144573

Comment 14

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=367925329&repo=mozilla-central

Comment 15

[Intermittent Failures Robot]

2 failures in 3281 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2

Platform and build breakdown:

• windows10-64-2004-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1732102&startday=2022-02-14&endday=2022-02-20&tree=all

Comment 16

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 17

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=371936884&repo=mozilla-esr91

Comment 18

[Intermittent Failures Robot]

1 failures in 3341 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-esr91: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1732102&startday=2022-03-21&endday=2022-03-27&tree=all

Comment 19

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 20

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=377428796&repo=mozilla-esr91

Comment 21

[Intermittent Failures Robot]

2 failures in 3317 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-esr91: 2

Platform and build breakdown:

• windows10-64-2004-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1732102&startday=2022-05-09&endday=2022-05-15&tree=all

Comment 22

[Intermittent Failures Robot]

1 failures in 2917 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1732102&startday=2022-05-30&endday=2022-06-05&tree=all

Comment 23

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.