Closed
Bug 1471056
Opened 6 years ago
Closed 5 years ago
Intermittent TEST-UNEXPECTED-TIMEOUT | dom/payments/test/browser_payment_in_different_tabs.js | application timed out after 370 seconds with no output
Categories
(Core :: DOM: Web Payments, defect, P4)
Core
DOM: Web Payments
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure, Whiteboard: [webpayments-other])
Filed by: csabou [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=184799606&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/Xry7V6nUSSOc5JIkTFUbBA/runs/0/artifacts/public/logs/live_backing.log [task 2018-06-25T21:45:09.717Z] 21:45:09 INFO - TEST-OK | dom/payments/test/browser_payment_in_different_tabs.js | took 5166ms [task 2018-06-25T21:45:09.796Z] 21:45:09 INFO - checking window state [task 2018-06-25T21:45:12.253Z] 21:45:12 INFO - GECKO(3151) | Completed ShutdownLeaks collections in process 3244 [task 2018-06-25T21:45:12.310Z] 21:45:12 INFO - GECKO(3151) | Completed ShutdownLeaks collections in process 3297 [task 2018-06-25T21:45:12.371Z] 21:45:12 INFO - GECKO(3151) | Completed ShutdownLeaks collections in process 3273 [task 2018-06-25T21:45:12.528Z] 21:45:12 INFO - GECKO(3151) | Completed ShutdownLeaks collections in process 3203 [task 2018-06-25T21:45:13.174Z] 21:45:13 INFO - GECKO(3151) | Completed ShutdownLeaks collections in process 3151 [task 2018-06-25T21:45:13.175Z] 21:45:13 INFO - TEST-START | Shutdown [task 2018-06-25T21:45:13.177Z] 21:45:13 INFO - Browser Chrome Test Summary [task 2018-06-25T21:45:13.178Z] 21:45:13 INFO - Passed: 38 [task 2018-06-25T21:45:13.179Z] 21:45:13 INFO - Failed: 0 [task 2018-06-25T21:45:13.180Z] 21:45:13 INFO - Todo: 0 [task 2018-06-25T21:45:13.181Z] 21:45:13 INFO - Mode: e10s [task 2018-06-25T21:45:13.181Z] 21:45:13 INFO - *** End BrowserChrome Test Results *** [task 2018-06-25T21:45:15.048Z] 21:45:15 INFO - GECKO(3151) | 1529963115041 Marionette DEBUG Received observer notification xpcom-will-shutdown [task 2018-06-25T21:45:15.048Z] 21:45:15 INFO - GECKO(3151) | 1529963115044 Marionette INFO Stopped listening on port 2828 [task 2018-06-25T21:45:15.050Z] 21:45:15 INFO - GECKO(3151) | 1529963115044 Marionette DEBUG Remote service is inactive [task 2018-06-25T21:45:16.640Z] 21:45:16 INFO - GECKO(3151) | ----------------------------------------------------- [task 2018-06-25T21:45:16.644Z] 21:45:16 INFO - GECKO(3151) | Suppressions used: [task 2018-06-25T21:45:16.645Z] 21:45:16 INFO - GECKO(3151) | count bytes template [task 2018-06-25T21:45:16.645Z] 21:45:16 INFO - GECKO(3151) | 638 20352 nsComponentManagerImpl [task 2018-06-25T21:45:16.645Z] 21:45:16 INFO - GECKO(3151) | 2 416 mozJSComponentLoader::LoadModule [task 2018-06-25T21:45:16.646Z] 21:45:16 INFO - GECKO(3151) | 611 17713 libfontconfig.so [task 2018-06-25T21:45:16.646Z] 21:45:16 INFO - GECKO(3151) | 1 29 libglib-2.0.so [task 2018-06-25T21:45:16.646Z] 21:45:16 INFO - GECKO(3151) | ----------------------------------------------------- [task 2018-06-25T21:45:16.868Z] 21:45:16 INFO - GECKO(3151) | ----------------------------------------------------- [task 2018-06-25T21:45:16.870Z] 21:45:16 INFO - GECKO(3151) | Suppressions used: [task 2018-06-25T21:45:16.870Z] 21:45:16 INFO - GECKO(3151) | count bytes template [task 2018-06-25T21:45:16.870Z] 21:45:16 INFO - GECKO(3151) | 638 20352 nsComponentManagerImpl [task 2018-06-25T21:45:16.874Z] 21:45:16 INFO - GECKO(3151) | 3 624 mozJSComponentLoader::LoadModule [task 2018-06-25T21:45:16.875Z] 21:45:16 INFO - GECKO(3151) | 611 17713 libfontconfig.so [task 2018-06-25T21:45:16.875Z] 21:45:16 INFO - GECKO(3151) | 1 29 libglib-2.0.so [task 2018-06-25T21:45:16.875Z] 21:45:16 INFO - GECKO(3151) | ----------------------------------------------------- [task 2018-06-25T21:45:17.095Z] 21:45:17 INFO - GECKO(3151) | ----------------------------------------------------- [task 2018-06-25T21:45:17.095Z] 21:45:17 INFO - GECKO(3151) | Suppressions used: [task 2018-06-25T21:45:17.095Z] 21:45:17 INFO - GECKO(3151) | count bytes template [task 2018-06-25T21:45:17.095Z] 21:45:17 INFO - GECKO(3151) | 638 20352 nsComponentManagerImpl [task 2018-06-25T21:45:17.096Z] 21:45:17 INFO - GECKO(3151) | 3 624 mozJSComponentLoader::LoadModule [task 2018-06-25T21:45:17.096Z] 21:45:17 INFO - GECKO(3151) | 611 17713 libfontconfig.so [task 2018-06-25T21:45:17.096Z] 21:45:17 INFO - GECKO(3151) | 1 29 libglib-2.0.so [task 2018-06-25T21:45:17.097Z] 21:45:17 INFO - GECKO(3151) | ----------------------------------------------------- [task 2018-06-25T21:45:17.275Z] 21:45:17 INFO - GECKO(3151) | ----------------------------------------------------- [task 2018-06-25T21:45:17.275Z] 21:45:17 INFO - GECKO(3151) | Suppressions used: [task 2018-06-25T21:45:17.275Z] 21:45:17 INFO - GECKO(3151) | count bytes template [task 2018-06-25T21:45:17.276Z] 21:45:17 INFO - GECKO(3151) | 638 20352 nsComponentManagerImpl [task 2018-06-25T21:45:17.276Z] 21:45:17 INFO - GECKO(3151) | 5 1040 mozJSComponentLoader::LoadModule [task 2018-06-25T21:45:17.277Z] 21:45:17 INFO - GECKO(3151) | 611 17713 libfontconfig.so [task 2018-06-25T21:45:17.278Z] 21:45:17 INFO - GECKO(3151) | 1 29 libglib-2.0.so [task 2018-06-25T21:45:17.278Z] 21:45:17 INFO - GECKO(3151) | ----------------------------------------------------- [task 2018-06-25T21:45:19.168Z] 21:45:19 INFO - GECKO(3151) | ----------------------------------------------------- [task 2018-06-25T21:45:19.168Z] 21:45:19 INFO - GECKO(3151) | Suppressions used: [task 2018-06-25T21:45:19.172Z] 21:45:19 INFO - GECKO(3151) | count bytes template [task 2018-06-25T21:45:19.172Z] 21:45:19 INFO - GECKO(3151) | 650 20720 nsComponentManagerImpl [task 2018-06-25T21:45:19.174Z] 21:45:19 INFO - GECKO(3151) | 40 8320 mozJSComponentLoader::LoadModule [task 2018-06-25T21:45:19.174Z] 21:45:19 INFO - GECKO(3151) | 611 17509 libfontconfig.so [task 2018-06-25T21:45:19.174Z] 21:45:19 INFO - GECKO(3151) | 8 352 _PR_Getfd [task 2018-06-25T21:45:19.174Z] 21:45:19 INFO - GECKO(3151) | 1 29 libglib-2.0.so [task 2018-06-25T21:45:19.175Z] 21:45:19 INFO - GECKO(3151) | ----------------------------------------------------- [task 2018-06-25T21:51:29.183Z] 21:51:29 INFO - Buffered messages finished [task 2018-06-25T21:51:29.184Z] 21:51:29 ERROR - TEST-UNEXPECTED-TIMEOUT | dom/payments/test/browser_payment_in_different_tabs.js | application timed out after 370 seconds with no output [task 2018-06-25T21:51:29.186Z] 21:51:29 ERROR - Force-terminating active process(es). [task 2018-06-25T21:51:29.189Z] 21:51:29 INFO - Determining child pids from psutil... [task 2018-06-25T21:51:29.193Z] 21:51:29 INFO - [] [task 2018-06-25T21:51:29.194Z] 21:51:29 INFO - ==> process 3151 launched child process 3169 [task 2018-06-25T21:51:29.195Z] 21:51:29 INFO - ==> process 3151 launched child process 3203 [task 2018-06-25T21:51:29.197Z] 21:51:29 INFO - ==> process 3151 launched child process 3244 [task 2018-06-25T21:51:29.198Z] 21:51:29 INFO - ==> process 3151 launched child process 3273 [task 2018-06-25T21:51:29.199Z] 21:51:29 INFO - ==> process 3151 launched child process 3297 [task 2018-06-25T21:51:29.201Z] 21:51:29 INFO - Found child pids: set([3297, 3169, 3203, 3244, 3273]) [task 2018-06-25T21:51:29.202Z] 21:51:29 INFO - Failed to get child procs [task 2018-06-25T21:51:29.204Z] 21:51:29 INFO - Killing process: 3297 [task 2018-06-25T21:51:29.205Z] 21:51:29 INFO - TEST-INFO | started process screentopng [task 2018-06-25T21:51:29.871Z] 21:51:29 INFO - TEST-INFO | screentopng: exit 0 [task 2018-06-25T21:51:29.873Z] 21:51:29 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T21:51:29.874Z] 21:51:29 INFO - Error: Failed to kill process 3297: psutil.NoSuchProcess no process found with pid 3297 [task 2018-06-25T21:51:29.876Z] 21:51:29 INFO - Killing process: 3169 [task 2018-06-25T21:51:29.877Z] 21:51:29 INFO - Not taking screenshot here: see the one that was previously logged [task 2018-06-25T21:51:29.878Z] 21:51:29 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T21:51:59.899Z] 21:51:59 INFO - failed to kill pid 3169 after 30s [task 2018-06-25T21:51:59.899Z] 21:51:59 INFO - Killing process: 3203 [task 2018-06-25T21:51:59.900Z] 21:51:59 INFO - Not taking screenshot here: see the one that was previously logged [task 2018-06-25T21:51:59.900Z] 21:51:59 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T21:51:59.901Z] 21:51:59 INFO - Error: Failed to kill process 3203: psutil.NoSuchProcess no process found with pid 3203 [task 2018-06-25T21:51:59.902Z] 21:51:59 INFO - Killing process: 3244 [task 2018-06-25T21:51:59.902Z] 21:51:59 INFO - Not taking screenshot here: see the one that was previously logged [task 2018-06-25T21:51:59.903Z] 21:51:59 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T21:51:59.904Z] 21:51:59 INFO - Error: Failed to kill process 3244: psutil.NoSuchProcess no process found with pid 3244 [task 2018-06-25T21:51:59.904Z] 21:51:59 INFO - Killing process: 3273 [task 2018-06-25T21:51:59.905Z] 21:51:59 INFO - Not taking screenshot here: see the one that was previously logged [task 2018-06-25T21:51:59.906Z] 21:51:59 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T21:51:59.906Z] 21:51:59 INFO - Error: Failed to kill process 3273: psutil.NoSuchProcess no process found with pid 3273 [task 2018-06-25T21:51:59.907Z] 21:51:59 INFO - Killing process: 3151 [task 2018-06-25T21:51:59.907Z] 21:51:59 INFO - Not taking screenshot here: see the one that was previously logged [task 2018-06-25T21:51:59.908Z] 21:51:59 INFO - Can't trigger Breakpad, just killing process [task 2018-06-25T21:51:59.916Z] 21:51:59 INFO - psutil found pid 3151 dead [task 2018-06-25T21:51:59.922Z] 21:51:59 INFO - psutil found pid 3151 dead [task 2018-06-25T21:51:59.923Z] 21:51:59 WARNING - runtests.py | Failed to get app exit code - running/crashed? [task 2018-06-25T21:51:59.924Z] 21:51:59 INFO - TEST-INFO | Main app process: exit 0 [task 2018-06-25T21:51:59.924Z] 21:51:59 INFO - runtests.py | Application ran for: 0:07:07.660392 [task 2018-06-25T21:51:59.925Z] 21:51:59 INFO - zombiecheck | Reading PID log: /tmp/tmpGOdi0dpidlog [task 2018-06-25T21:51:59.926Z] 21:51:59 INFO - ==> process 3151 launched child process 3169 [task 2018-06-25T21:51:59.927Z] 21:51:59 INFO - ==> process 3151 launched child process 3203 [task 2018-06-25T21:51:59.928Z] 21:51:59 INFO - ==> process 3151 launched child process 3244 [task 2018-06-25T21:51:59.929Z] 21:51:59 INFO - ==> process 3151 launched child process 3273 [task 2018-06-25T21:51:59.930Z] 21:51:59 INFO - ==> process 3151 launched child process 3297 [task 2018-06-25T21:51:59.931Z] 21:51:59 INFO - zombiecheck | Checking for orphan process with PID: 3297 [task 2018-06-25T21:51:59.931Z] 21:51:59 INFO - zombiecheck | Checking for orphan process with PID: 3169 [task 2018-06-25T21:51:59.931Z] 21:51:59 INFO - zombiecheck | Checking for orphan process with PID: 3203 [task 2018-06-25T21:51:59.933Z] 21:51:59 INFO - zombiecheck | Checking for orphan process with PID: 3244 [task 2018-06-25T21:51:59.933Z] 21:51:59 INFO - zombiecheck | Checking for orphan process with PID: 3273 [task 2018-06-25T21:51:59.934Z] 21:51:59 INFO - Stopping web server [task 2018-06-25T21:51:59.950Z] 21:51:59 INFO - Stopping web socket server [task 2018-06-25T21:51:59.966Z] 21:51:59 INFO - Stopping ssltunnel [task 2018-06-25T21:51:59.986Z] 21:51:59 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! [task 2018-06-25T21:51:59.987Z] 21:51:59 INFO - runtests.py | Running tests: end. [task 2018-06-25T21:52:00.003Z] 21:52:00 INFO - Buffered messages finished [task 2018-06-25T21:52:00.005Z] 21:52:00 INFO - Running manifest: extensions/cookie/test/browser.ini [task 2018-06-25T21:52:00.006Z] 21:52:00 INFO - The following extra prefs will be set: [task 2018-06-25T21:52:00.007Z] 21:52:00 INFO - dom.animations-api.core.enabled=true [task 2018-06-25T21:52:00.043Z] 21:52:00 INFO - Setting pipeline to PAUSED ... [task 2018-06-25T21:52:00.045Z] 21:52:00 INFO - Pipeline is PREROLLING ... [task 2018-06-25T21:52:00.045Z] 21:52:00 INFO - Pipeline is PREROLLED ... [task 2018-06-25T21:52:00.046Z] 21:52:00 INFO - Setting pipeline to PLAYING ... [task 2018-06-25T21:52:00.047Z] 21:52:00 INFO - New clock: GstSystemClock [task 2018-06-25T21:52:00.076Z] 21:52:00 INFO - Got EOS from element "pipeline0". [task 2018-06-25T21:52:00.076Z] 21:52:00 INFO - Execution ended after 0:00:00.033107122 [task 2018-06-25T21:52:00.076Z] 21:52:00 INFO - Setting pipeline to PAUSED ... [task 2018-06-25T21:52:00.076Z] 21:52:00 INFO - Setting pipeline to READY ... [task 2018-06-25T21:52:00.077Z] 21:52:00 INFO - (gst-launch-1.0:3334): GStreamer-CRITICAL **: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed [task 2018-06-25T21:52:00.078Z] 21:52:00 INFO - Setting pipeline to NULL ... [task 2018-06-25T21:52:00.079Z] 21:52:00 INFO - Freeing pipeline ... [task 2018-06-25T21:52:00.121Z] 21:52:00 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer [task 2018-06-25T21:52:00.127Z] 21:52:00 INFO - INFO | runtests.py | ASan running in default memory configuration [task 2018-06-25T21:52:00.329Z] 21:52:00 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL [task 2018-06-25T21:52:00.492Z] 21:52:00 INFO - Increasing default timeout to 90 seconds [task 2018-06-25T21:52:00.492Z] 21:52:00 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer [task 2018-06-25T21:52:00.500Z] 21:52:00 INFO - LSan enabled. [task 2018-06-25T21:52:00.501Z] 21:52:00 INFO - LSan using suppression file /builds/worker/workspace/build/tests/mochitest/lsan_suppressions.txt [task 2018-06-25T21:52:00.503Z] 21:52:00 INFO - INFO | runtests.py | ASan running in default memory configuration [task 2018-06-25T21:52:00.503Z] 21:52:00 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer [task 2018-06-25T21:52:00.506Z] 21:52:00 INFO - INFO | runtests.py | ASan running in default memory configuration [task 2018-06-25T21:52:00.523Z] 21:52:00 INFO - MochitestServer : launching [u'/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-f', '/builds/worker/workspace/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpyLNZL7.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js'] [task 2018-06-25T21:52:00.523Z] 21:52:00 INFO - runtests.py | Server pid: 3363 [task 2018-06-25T21:52:00.540Z] 21:52:00 INFO - runtests.py | Websocket server pid: 3366 [task 2018-06-25T21:52:00.540Z] 21:52:00 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer [task 2018-06-25T21:52:00.561Z] 21:52:00 INFO - INFO | runtests.py | ASan running in default memory configuration [task 2018-06-25T21:52:00.590Z] 21:52:00 INFO - runtests.py | SSL tunnel pid: 3371 [task 2018-06-25T21:52:00.994Z] 21:52:00 INFO - runtests.py | Running with e10s: True [task 2018-06-25T21:52:00.995Z] 21:52:00 INFO - runtests.py | Running tests: start.
|
||
Updated•6 years ago
|
Component: DOM → DOM: Web Payments
|
||
Updated•6 years ago
|
Whiteboard: [webpayments] [triage]
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 3•6 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
|
|
||
Updated•6 years ago
|
Whiteboard: [webpayments] [triage]
|
||
Comment 4•6 years ago
|
||
New occurrence: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=unclassified&group_state=expanded&selectedJob=201073886&searchStr=linux%2Cdebug%2Cmochitests%2Cwith%2Ce10s%2Ctest-linux32%2Fdebug-mochitest-browser-chrome-e10s-11%2Cm-e10s%28bc11%29
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
||
Updated•6 years ago
|
Priority: P5 → P3
|
|
||
Updated•6 years ago
|
Whiteboard: [webpayments-other]
|
|
||
Updated•6 years ago
|
Priority: P3 → P4
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 9•5 years ago
|
||
Status: REOPENED → RESOLVED
Closed: 6 years ago → 5 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•