Closed Bug 1471070 Opened 7 years ago Closed 7 years ago

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

Categories

(Firefox :: WebPayments UI, defect)

Product:
Firefox
Component:
WebPayments UI
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: csabou [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=184804084&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/TzyMnNuTS8-z9fVJjekhew/runs/0/artifacts/public/logs/live_backing.log [task 2018-06-25T22:22:03.743Z] 22:22:03 INFO - TEST-OK | browser/components/payments/test/browser/browser_total.js | took 5119ms [task 2018-06-25T22:22:03.819Z] 22:22:03 INFO - checking window state [task 2018-06-25T22:22:06.923Z] 22:22:06 INFO - GECKO(1591) | Completed ShutdownLeaks collections in process 1644 [task 2018-06-25T22:22:08.602Z] 22:22:08 INFO - GECKO(1591) | Completed ShutdownLeaks collections in process 1682 [task 2018-06-25T22:22:09.037Z] 22:22:09 INFO - GECKO(1591) | Completed ShutdownLeaks collections in process 1591 [task 2018-06-25T22:22:09.037Z] 22:22:09 INFO - TEST-START | Shutdown [task 2018-06-25T22:22:09.038Z] 22:22:09 INFO - Browser Chrome Test Summary [task 2018-06-25T22:22:09.047Z] 22:22:09 INFO - Passed: 629 [task 2018-06-25T22:22:09.047Z] 22:22:09 INFO - Failed: 0 [task 2018-06-25T22:22:09.048Z] 22:22:09 INFO - Todo: 1 [task 2018-06-25T22:22:09.048Z] 22:22:09 INFO - Mode: e10s [task 2018-06-25T22:22:09.049Z] 22:22:09 INFO - *** End BrowserChrome Test Results *** [task 2018-06-25T22:22:09.272Z] 22:22:09 INFO - GECKO(1591) | Completed ShutdownLeaks collections in process 1711 [task 2018-06-25T22:22:10.633Z] 22:22:10 INFO - GECKO(1591) | 1529965330628 Marionette DEBUG Received observer notification xpcom-will-shutdown [task 2018-06-25T22:22:10.637Z] 22:22:10 INFO - GECKO(1591) | 1529965330632 Marionette INFO Stopped listening on port 2828 [task 2018-06-25T22:22:10.645Z] 22:22:10 INFO - GECKO(1591) | 1529965330636 Marionette DEBUG Remote service is inactive [task 2018-06-25T22:22:13.306Z] 22:22:13 INFO - GECKO(1591) | ----------------------------------------------------- [task 2018-06-25T22:22:13.306Z] 22:22:13 INFO - GECKO(1591) | Suppressions used: [task 2018-06-25T22:22:13.306Z] 22:22:13 INFO - GECKO(1591) | count bytes template [task 2018-06-25T22:22:13.308Z] 22:22:13 INFO - GECKO(1591) | 701 22200 nsComponentManagerImpl [task 2018-06-25T22:22:13.309Z] 22:22:13 INFO - GECKO(1591) | 6 1248 mozJSComponentLoader::LoadModule [task 2018-06-25T22:22:13.313Z] 22:22:13 INFO - GECKO(1591) | 611 17713 libfontconfig.so [task 2018-06-25T22:22:13.313Z] 22:22:13 INFO - GECKO(1591) | 1 29 libglib-2.0.so [task 2018-06-25T22:22:13.313Z] 22:22:13 INFO - GECKO(1591) | ----------------------------------------------------- [task 2018-06-25T22:22:14.040Z] 22:22:14 INFO - GECKO(1591) | ----------------------------------------------------- [task 2018-06-25T22:22:14.042Z] 22:22:14 INFO - GECKO(1591) | Suppressions used: [task 2018-06-25T22:22:14.044Z] 22:22:14 INFO - GECKO(1591) | count bytes template [task 2018-06-25T22:22:14.045Z] 22:22:14 INFO - GECKO(1591) | 701 22200 nsComponentManagerImpl [task 2018-06-25T22:22:14.046Z] 22:22:14 INFO - GECKO(1591) | 5 1040 mozJSComponentLoader::LoadModule [task 2018-06-25T22:22:14.047Z] 22:22:14 INFO - GECKO(1591) | 611 17713 libfontconfig.so [task 2018-06-25T22:22:14.049Z] 22:22:14 INFO - GECKO(1591) | 1 29 libglib-2.0.so [task 2018-06-25T22:22:14.050Z] 22:22:14 INFO - GECKO(1591) | ----------------------------------------------------- [task 2018-06-25T22:22:14.211Z] 22:22:14 INFO - GECKO(1591) | ----------------------------------------------------- [task 2018-06-25T22:22:14.211Z] 22:22:14 INFO - GECKO(1591) | Suppressions used: [task 2018-06-25T22:22:14.211Z] 22:22:14 INFO - GECKO(1591) | count bytes template [task 2018-06-25T22:22:14.211Z] 22:22:14 INFO - GECKO(1591) | 701 22200 nsComponentManagerImpl [task 2018-06-25T22:22:14.211Z] 22:22:14 INFO - GECKO(1591) | 5 1040 mozJSComponentLoader::LoadModule [task 2018-06-25T22:22:14.211Z] 22:22:14 INFO - GECKO(1591) | 611 17713 libfontconfig.so [task 2018-06-25T22:22:14.211Z] 22:22:14 INFO - GECKO(1591) | 1 29 libglib-2.0.so [task 2018-06-25T22:22:14.211Z] 22:22:14 INFO - GECKO(1591) | ----------------------------------------------------- [task 2018-06-25T22:22:14.835Z] 22:22:14 INFO - GECKO(1591) | ----------------------------------------------------- [task 2018-06-25T22:22:14.837Z] 22:22:14 INFO - GECKO(1591) | Suppressions used: [task 2018-06-25T22:22:14.838Z] 22:22:14 INFO - GECKO(1591) | count bytes template [task 2018-06-25T22:22:14.839Z] 22:22:14 INFO - GECKO(1591) | 701 22200 nsComponentManagerImpl [task 2018-06-25T22:22:14.840Z] 22:22:14 INFO - GECKO(1591) | 5 1040 mozJSComponentLoader::LoadModule [task 2018-06-25T22:22:14.843Z] 22:22:14 INFO - GECKO(1591) | 611 17713 libfontconfig.so [task 2018-06-25T22:22:14.844Z] 22:22:14 INFO - GECKO(1591) | 1 29 libglib-2.0.so [task 2018-06-25T22:22:14.845Z] 22:22:14 INFO - GECKO(1591) | ----------------------------------------------------- [task 2018-06-25T22:22:16.361Z] 22:22:16 INFO - GECKO(1591) | ----------------------------------------------------- [task 2018-06-25T22:22:16.361Z] 22:22:16 INFO - GECKO(1591) | Suppressions used: [task 2018-06-25T22:22:16.367Z] 22:22:16 INFO - GECKO(1591) | count bytes template [task 2018-06-25T22:22:16.367Z] 22:22:16 INFO - GECKO(1591) | 713 22568 nsComponentManagerImpl [task 2018-06-25T22:22:16.367Z] 22:22:16 INFO - GECKO(1591) | 44 9152 mozJSComponentLoader::LoadModule [task 2018-06-25T22:22:16.367Z] 22:22:16 INFO - GECKO(1591) | 611 17509 libfontconfig.so [task 2018-06-25T22:22:16.367Z] 22:22:16 INFO - GECKO(1591) | 8 352 _PR_Getfd [task 2018-06-25T22:22:16.367Z] 22:22:16 INFO - GECKO(1591) | 1 29 libglib-2.0.so [task 2018-06-25T22:22:16.367Z] 22:22:16 INFO - GECKO(1591) | ----------------------------------------------------- [task 2018-06-25T22:28:26.379Z] 22:28:26 INFO - Buffered messages finished [task 2018-06-25T22:28:26.380Z] 22:28:26 ERROR - TEST-UNEXPECTED-TIMEOUT | browser/components/payments/test/browser/browser_total.js | application timed out after 370 seconds with no output [task 2018-06-25T22:28:26.383Z] 22:28:26 ERROR - Force-terminating active process(es). [task 2018-06-25T22:28:26.385Z] 22:28:26 INFO - Determining child pids from psutil... [task 2018-06-25T22:28:26.386Z] 22:28:26 INFO - [] [task 2018-06-25T22:28:26.389Z] 22:28:26 INFO - ==> process 1591 launched child process 1609 [task 2018-06-25T22:28:26.390Z] 22:28:26 INFO - ==> process 1591 launched child process 1644 [task 2018-06-25T22:28:26.393Z] 22:28:26 INFO - ==> process 1591 launched child process 1682 [task 2018-06-25T22:28:26.394Z] 22:28:26 INFO - ==> process 1591 launched child process 1711 [task 2018-06-25T22:28:26.395Z] 22:28:26 INFO - ==> process 1591 launched child process 1740 [task 2018-06-25T22:28:26.397Z] 22:28:26 INFO - Found child pids: set([1609, 1682, 1644, 1740, 1711]) [task 2018-06-25T22:28:26.398Z] 22:28:26 INFO - Failed to get child procs [task 2018-06-25T22:28:26.399Z] 22:28:26 INFO - Killing process: 1609 [task 2018-06-25T22:28:26.401Z] 22:28:26 INFO - TEST-INFO | started process screentopng [task 2018-06-25T22:28:27.074Z] 22:28:27 INFO - TEST-INFO | screentopng: exit 0 [task 2018-06-25T22:28:27.076Z] 22:28:27 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T22:28:57.108Z] 22:28:57 INFO - failed to kill pid 1609 after 30s [task 2018-06-25T22:28:57.110Z] 22:28:57 INFO - Killing process: 1682 [task 2018-06-25T22:28:57.111Z] 22:28:57 INFO - Not taking screenshot here: see the one that was previously logged [task 2018-06-25T22:28:57.116Z] 22:28:57 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T22:28:57.117Z] 22:28:57 INFO - Error: Failed to kill process 1682: psutil.NoSuchProcess no process found with pid 1682 [task 2018-06-25T22:28:57.118Z] 22:28:57 INFO - Killing process: 1644 [task 2018-06-25T22:28:57.119Z] 22:28:57 INFO - Not taking screenshot here: see the one that was previously logged [task 2018-06-25T22:28:57.120Z] 22:28:57 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T22:28:57.121Z] 22:28:57 INFO - Error: Failed to kill process 1644: psutil.NoSuchProcess no process found with pid 1644 [task 2018-06-25T22:28:57.122Z] 22:28:57 INFO - Killing process: 1740 [task 2018-06-25T22:28:57.123Z] 22:28:57 INFO - Not taking screenshot here: see the one that was previously logged [task 2018-06-25T22:28:57.124Z] 22:28:57 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T22:28:57.125Z] 22:28:57 INFO - Error: Failed to kill process 1740: psutil.NoSuchProcess no process found with pid 1740 [task 2018-06-25T22:28:57.125Z] 22:28:57 INFO - Killing process: 1711 [task 2018-06-25T22:28:57.126Z] 22:28:57 INFO - Not taking screenshot here: see the one that was previously logged [task 2018-06-25T22:28:57.127Z] 22:28:57 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T22:28:57.128Z] 22:28:57 INFO - Error: Failed to kill process 1711: psutil.NoSuchProcess no process found with pid 1711 [task 2018-06-25T22:28:57.128Z] 22:28:57 INFO - Killing process: 1591 [task 2018-06-25T22:28:57.136Z] 22:28:57 INFO - Not taking screenshot here: see the one that was previously logged [task 2018-06-25T22:28:57.136Z] 22:28:57 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T22:28:57.136Z] 22:28:57 INFO - psutil found pid 1591 dead [task 2018-06-25T22:28:57.136Z] 22:28:57 INFO - psutil found pid 1591 dead [task 2018-06-25T22:28:57.137Z] 22:28:57 WARNING - runtests.py | Failed to get app exit code - running/crashed? [task 2018-06-25T22:28:57.137Z] 22:28:57 INFO - TEST-INFO | Main app process: exit 0 [task 2018-06-25T22:28:57.137Z] 22:28:57 INFO - runtests.py | Application ran for: 0:08:39.170146 [task 2018-06-25T22:28:57.137Z] 22:28:57 INFO - zombiecheck | Reading PID log: /tmp/tmpOz87PUpidlog [task 2018-06-25T22:28:57.137Z] 22:28:57 INFO - ==> process 1591 launched child process 1609 [task 2018-06-25T22:28:57.138Z] 22:28:57 INFO - ==> process 1591 launched child process 1644 [task 2018-06-25T22:28:57.138Z] 22:28:57 INFO - ==> process 1591 launched child process 1682 [task 2018-06-25T22:28:57.138Z] 22:28:57 INFO - ==> process 1591 launched child process 1711 [task 2018-06-25T22:28:57.139Z] 22:28:57 INFO - ==> process 1591 launched child process 1740 [task 2018-06-25T22:28:57.140Z] 22:28:57 INFO - zombiecheck | Checking for orphan process with PID: 1609 [task 2018-06-25T22:28:57.141Z] 22:28:57 INFO - zombiecheck | Checking for orphan process with PID: 1682 [task 2018-06-25T22:28:57.143Z] 22:28:57 INFO - zombiecheck | Checking for orphan process with PID: 1644 [task 2018-06-25T22:28:57.144Z] 22:28:57 INFO - zombiecheck | Checking for orphan process with PID: 1740 [task 2018-06-25T22:28:57.145Z] 22:28:57 INFO - zombiecheck | Checking for orphan process with PID: 1711 [task 2018-06-25T22:28:57.146Z] 22:28:57 INFO - Stopping web server
Whiteboard: [webpayments] [triage]
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
Priority: P5 → --
Whiteboard: [webpayments] [triage]
You need to log in before you can comment on or make changes to this bug.