1685371 - Intermittent TEST-UNEXPECTED-TIMEOUT | browser/components/sessionstore/test/browser_closed_objects_changed_notifications_tabs.js | application timed out after 370 seconds with no output

Status: RESOLVED INCOMPLETE

(Firefox :: Session Restore, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2021-01-06T17:31:32.707Z] 17:31:31     INFO - TEST-PASS | browser/components/sessionstore/test/browser_closed_objects_changed_notifications_tabs.js | The expected number of notifications was received. - 
[task 2021-01-06T17:31:39.105Z] 17:31:38     INFO - Opening and closing another tab.
[task 2021-01-06T17:31:45.640Z] 17:31:43     INFO - Buffered messages finished
[task 2021-01-06T17:31:53.960Z] 17:31:52    ERROR - TEST-UNEXPECTED-TIMEOUT | browser/components/sessionstore/test/browser_closed_objects_changed_notifications_tabs.js | application timed out after 370 seconds with no output
[task 2021-01-06T17:31:59.627Z] 17:31:58    ERROR - Force-terminating active process(es).
[task 2021-01-06T17:32:04.555Z] 17:32:03     INFO - Determining child pids from psutil...
[task 2021-01-06T17:32:47.759Z] 17:32:46     INFO - [1637, 1662, 1723, 1755, 1788, 1832]
[task 2021-01-06T17:33:01.991Z] 17:33:00     INFO - ==> process 1566 launched child process 1581
[task 2021-01-06T17:33:05.927Z] 17:33:04     INFO - ==> process 1566 launched child process 1637
[task 2021-01-06T17:33:11.904Z] 17:33:10     INFO - ==> process 1566 launched child process 1662
[task 2021-01-06T17:33:17.066Z] 17:33:15     INFO - ==> process 1566 launched child process 1723
[task 2021-01-06T17:33:24.939Z] 17:33:23     INFO - ==> process 1566 launched child process 1755
[task 2021-01-06T17:33:33.599Z] 17:33:31     INFO - ==> process 1566 launched child process 1788
[task 2021-01-06T17:33:39.666Z] 17:33:38     INFO - ==> process 1566 launched child process 1832
[task 2021-01-06T17:33:45.286Z] 17:33:44     INFO - Found child pids: set([1723, 1637, 1832, 1581, 1755, 1788, 1662])
[task 2021-01-06T17:34:16.029Z] 17:34:14     INFO - Failed to get child procs
[task 2021-01-06T17:34:21.985Z] 17:34:20     INFO - Killing process: 1723
[task 2021-01-06T17:34:27.122Z] 17:34:26     INFO - TEST-INFO | started process screentopng
[task 2021-01-06T17:40:27.933Z] 17:40:27     INFO - TEST-INFO | screentopng: exit 0
[task 2021-01-06T17:40:27.933Z] 17:40:27     INFO - TEST-INFO | screentopng: exit 0
[task 2021-01-06T17:40:27.960Z] 17:40:27     INFO - Can't trigger Breakpad, just killing process
[task 2021-01-06T17:40:31.328Z] 17:40:31     INFO - psutil found pid 1723 dead
[task 2021-01-06T17:40:31.328Z] 17:40:31     INFO - Killing process: 1637
[task 2021-01-06T17:40:31.328Z] 17:40:31     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-01-06T17:40:31.328Z] 17:40:31     INFO - Can't trigger Breakpad, just killing process
[task 2021-01-06T17:40:33.843Z] 17:40:33     INFO - psutil found pid 1637 dead
[task 2021-01-06T17:40:33.843Z] 17:40:33     INFO - Killing process: 1832
[task 2021-01-06T17:40:33.843Z] 17:40:33     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-01-06T17:40:33.843Z] 17:40:33     INFO - Can't trigger Breakpad, just killing process
[task 2021-01-06T17:40:36.782Z] 17:40:36     INFO - psutil found pid 1832 dead
[task 2021-01-06T17:40:36.783Z] 17:40:36     INFO - Killing process: 1581
[task 2021-01-06T17:40:36.784Z] 17:40:36     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-01-06T17:40:36.784Z] 17:40:36     INFO - Can't trigger Breakpad, just killing process
[task 2021-01-06T17:40:36.785Z] 17:40:36     INFO - Error: Failed to kill process 1581: psutil.NoSuchProcess no process found with pid 1581
[task 2021-01-06T17:40:36.788Z] 17:40:36     INFO - Killing process: 1755
[task 2021-01-06T17:40:36.789Z] 17:40:36     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-01-06T17:40:36.789Z] 17:40:36     INFO - Can't trigger Breakpad, just killing process
[task 2021-01-06T17:40:39.363Z] 17:40:39     INFO - psutil found pid 1755 dead
[task 2021-01-06T17:40:39.363Z] 17:40:39     INFO - Killing process: 1788
[task 2021-01-06T17:40:39.363Z] 17:40:39     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-01-06T17:40:39.364Z] 17:40:39     INFO - Can't trigger Breakpad, just killing process
[task 2021-01-06T17:40:41.411Z] 17:40:41     INFO - psutil found pid 1788 dead
[task 2021-01-06T17:40:41.411Z] 17:40:41     INFO - Killing process: 1662
[task 2021-01-06T17:40:41.411Z] 17:40:41     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-01-06T17:40:41.411Z] 17:40:41     INFO - Can't trigger Breakpad, just killing process
[task 2021-01-06T17:40:44.382Z] 17:40:44     INFO - psutil found pid 1662 dead
[task 2021-01-06T17:40:44.382Z] 17:40:44     INFO - Killing process: 1566
[task 2021-01-06T17:40:44.383Z] 17:40:44     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-01-06T17:40:44.383Z] 17:40:44     INFO - Can't trigger Breakpad, just killing process
[task 2021-01-06T17:41:14.420Z] 17:41:14     INFO - psutil found pid 1566 dead
[task 2021-01-06T17:41:14.420Z] 17:41:14     INFO - failed to kill pid 2038 after 30s
[task 2021-01-06T17:41:14.420Z] 17:41:14     INFO - failed to kill pid 2072 after 30s
[task 2021-01-06T17:41:14.421Z] 17:41:14     INFO - psutil found pid 1566 dead
[task 2021-01-06T17:41:14.436Z] 17:41:14  WARNING - runtests.py | Failed to get app exit code - running/crashed?
[task 2021-01-06T17:41:14.436Z] 17:41:14     INFO - TEST-INFO | Main app process: exit 0
[task 2021-01-06T17:41:14.436Z] 17:41:14     INFO - runtests.py | Application ran for: 0:24:58.631901
[task 2021-01-06T17:41:14.436Z] 17:41:14     INFO - zombiecheck | Reading PID log: /tmp/tmppP6ZOfpidlog
[task 2021-01-06T17:41:14.436Z] 17:41:14     INFO - ==> process 1566 launched child process 1581
[task 2021-01-06T17:41:14.437Z] 17:41:14     INFO - ==> process 1566 launched child process 1637
[task 2021-01-06T17:41:14.437Z] 17:41:14     INFO - ==> process 1566 launched child process 1662
[task 2021-01-06T17:41:14.437Z] 17:41:14     INFO - ==> process 1566 launched child process 1723
[task 2021-01-06T17:41:14.437Z] 17:41:14     INFO - ==> process 1566 launched child process 1755
[task 2021-01-06T17:41:14.437Z] 17:41:14     INFO - ==> process 1566 launched child process 1788
[task 2021-01-06T17:41:14.437Z] 17:41:14     INFO - ==> process 1566 launched child process 1832
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - ==> process 1566 launched child process 2038
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - ==> process 1566 launched child process 2072
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - zombiecheck | Checking for orphan process with PID: 1723
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - zombiecheck | Checking for orphan process with PID: 1637
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - zombiecheck | Checking for orphan process with PID: 1832
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - zombiecheck | Checking for orphan process with PID: 1581
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - zombiecheck | Checking for orphan process with PID: 2038
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - zombiecheck | Checking for orphan process with PID: 2072
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - zombiecheck | Checking for orphan process with PID: 1755
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - zombiecheck | Checking for orphan process with PID: 1788
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - zombiecheck | Checking for orphan process with PID: 1662
[task 2021-01-06T17:41:14.438Z] 17:41:14     INFO - Stopping web server
[task 2021-01-06T17:41:14.459Z] 17:41:14     INFO - Stopping web socket server
[task 2021-01-06T17:41:14.479Z] 17:41:14     INFO - Stopping ssltunnel
[task 2021-01-06T17:41:14.500Z] 17:41:14  WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2021-01-06T17:41:14.500Z] 17:41:14     INFO - runtests.py | Running tests: end.
[task 2021-01-06T17:41:14.567Z] 17:41:14     INFO - Buffered messages finished
[task 2021-01-06T17:41:14.568Z] 17:41:14     INFO -  TEST-INFO | checking window state
[task 2021-01-06T17:41:14.568Z] 17:41:14     INFO -  Browser Chrome Test Summary
[task 2021-01-06T17:41:14.568Z] 17:41:14     INFO -  	Passed: 0
[task 2021-01-06T17:41:14.568Z] 17:41:14     INFO -  	Failed: 0
[task 2021-01-06T17:41:14.568Z] 17:41:14     INFO -  	Todo: 0
[task 2021-01-06T17:41:14.568Z] 17:41:14     INFO -  	Mode: e10s
[task 2021-01-06T17:41:14.568Z] 17:41:14     INFO -  *** End BrowserChrome Test Results ***
[task 2021-01-06T17:41:14.568Z] 17:41:14     INFO - Buffered messages finished
[task 2021-01-06T17:41:14.568Z] 17:41:14     INFO - SUITE-END | took 1500s
[task 2021-01-06T17:41:14.645Z] 17:41:14    ERROR - Return code: 1```

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux1804-64-tsan: 1

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

Comment 2

[BugBot [:suhaib / :marco]]

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

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• linux1804-64-tsan: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1685371&startday=2021-02-22&endday=2021-02-28&tree=all

Comment 4

[BugBot [:suhaib / :marco]]

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

Comment 5

[Natalia Csoregi [:nataliaCs]]

https://treeherder.mozilla.org/logviewer?job_id=334286653&repo=autoland&lineNumber=2947

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-tsan: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1685371&startday=2021-03-22&endday=2021-03-28&tree=all

Comment 7

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-tsan: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1685371&startday=2021-03-29&endday=2021-04-04&tree=all

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-tsan: 1
  • opt: 1

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

Comment 9

[BugBot [:suhaib / :marco]]

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