Closed Bug 1702913 Opened 5 years ago Closed 4 years ago

Intermittent toolkit/components/antitracking/test/browser/browser_socialtracking_save_image.js | application terminated with exit code 1

Categories

(Core :: Privacy: Anti-Tracking, defect, P5)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1775741

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=335380353&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/FbOOZhPrQzWdZRoHYI-rKg/runs/0/artifacts/public/logs/live_backing.log


[task 2021-04-04T00:36:12.927Z] 00:36:12     INFO - TEST-OK | toolkit/components/antitracking/test/browser/browser_socialtracking.js | took 590ms
[task 2021-04-04T00:36:12.942Z] 00:36:12     INFO - checking window state
[task 2021-04-04T00:36:12.946Z] 00:36:12     INFO - TEST-START | toolkit/components/antitracking/test/browser/browser_socialtracking_save_image.js
[task 2021-04-04T00:36:13.370Z] 00:36:13     INFO - GECKO(6462) | Gdk-Message: 00:36:13.362: firefox: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.
[task 2021-04-04T00:36:13.405Z] 00:36:13     INFO - GECKO(6462) | Exiting due to channel error.
[task 2021-04-04T00:36:13.407Z] 00:36:13     INFO - GECKO(6462) | Exiting due to channel error.
[task 2021-04-04T00:36:13.409Z] 00:36:13     INFO - GECKO(6462) | Exiting due to channel error.
[task 2021-04-04T00:36:13.410Z] 00:36:13     INFO - GECKO(6462) | Exiting due to channel error.
[task 2021-04-04T00:36:13.411Z] 00:36:13     INFO - GECKO(6462) | Exiting due to channel error.
[task 2021-04-04T00:36:13.412Z] 00:36:13     INFO - GECKO(6462) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2021-04-04T00:36:13.413Z] 00:36:13     INFO - GECKO(6462) | Exiting due to channel error.
[task 2021-04-04T00:36:13.414Z] 00:36:13     INFO - GECKO(6462) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2021-04-04T00:36:13.415Z] 00:36:13     INFO - GECKO(6462) | Exiting due to channel error.
[task 2021-04-04T00:36:13.416Z] 00:36:13     INFO - GECKO(6462) | Exiting due to channel error.
[task 2021-04-04T00:36:13.473Z] 00:36:13     INFO - TEST-INFO | Main app process: exit 1
[task 2021-04-04T00:36:13.475Z] 00:36:13     INFO - Buffered messages logged at 00:36:12
[task 2021-04-04T00:36:13.476Z] 00:36:13     INFO - Entering test bound setup
[task 2021-04-04T00:36:13.477Z] 00:36:13     INFO - Setting up the prefs.
[task 2021-04-04T00:36:13.477Z] 00:36:13     INFO - Setting MockFilePicker.
[task 2021-04-04T00:36:13.478Z] 00:36:13     INFO - Leaving test bound setup
[task 2021-04-04T00:36:13.479Z] 00:36:13     INFO - Entering test bound 
[task 2021-04-04T00:36:13.480Z] 00:36:13     INFO - Open a new tab for testing
[task 2021-04-04T00:36:13.480Z] 00:36:13     INFO - Buffered messages logged at 00:36:13
[task 2021-04-04T00:36:13.480Z] 00:36:13     INFO - Open the context menu.
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - Global property added while loading chrome://browser/content/nsContextMenu.js: screenshotsDisabled
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - Triggering the save process.
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - Wait until the save is finished.
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - MockFilePicker showCallback
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - TEST-PASS | toolkit/components/antitracking/test/browser/browser_socialtracking_save_image.js | Image should have been downloaded successfully - 
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - Close the context menu.
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - Buffered messages finished
[task 2021-04-04T00:36:13.481Z] 00:36:13    ERROR - TEST-UNEXPECTED-FAIL | toolkit/components/antitracking/test/browser/browser_socialtracking_save_image.js | application terminated with exit code 1
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - runtests.py | Application ran for: 0:12:53.029240
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - zombiecheck | Reading PID log: /tmp/tmpOuwgEIpidlog
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - ==> process 6462 launched child process 6482
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - ==> process 6462 launched child process 6523
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - ==> process 6462 launched child process 6537
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - ==> process 6462 launched child process 6624
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - ==> process 6462 launched child process 6661
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - ==> process 6462 launched child process 6689
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - ==> process 6462 launched child process 6720
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - ==> process 6462 launched child process 6798
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - ==> process 6462 launched child process 7755
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - ==> process 6462 launched child process 7814
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - zombiecheck | Checking for orphan process with PID: 6624
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - zombiecheck | Checking for orphan process with PID: 6689
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - zombiecheck | Checking for orphan process with PID: 6661
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - zombiecheck | Checking for orphan process with PID: 7814
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - zombiecheck | Checking for orphan process with PID: 6537
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - zombiecheck | Checking for orphan process with PID: 7755
[task 2021-04-04T00:36:13.481Z] 00:36:13     INFO - zombiecheck | Checking for orphan process with PID: 6798
[task 2021-04-04T00:36:13.487Z] 00:36:13     INFO - zombiecheck | Checking for orphan process with PID: 6482
[task 2021-04-04T00:36:13.488Z] 00:36:13     INFO - zombiecheck | Checking for orphan process with PID: 6720
[task 2021-04-04T00:36:13.488Z] 00:36:13     INFO - zombiecheck | Checking for orphan process with PID: 6523
[task 2021-04-04T00:36:13.488Z] 00:36:13     INFO - Stopping web server
[task 2021-04-04T00:36:13.488Z] 00:36:13     INFO - Server shut down.
[task 2021-04-04T00:36:13.511Z] 00:36:13     INFO - Web server killed.
[task 2021-04-04T00:36:13.512Z] 00:36:13     INFO - Stopping web socket server
[task 2021-04-04T00:36:13.532Z] 00:36:13     INFO - Stopping ssltunnel
[task 2021-04-04T00:36:13.552Z] 00:36:13  WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2021-04-04T00:36:13.553Z] 00:36:13     INFO - runtests.py | Running tests: end.
[task 2021-04-04T00:36:13.576Z] 00:36:13     INFO - Buffered messages finished
[task 2021-04-04T00:36:13.577Z] 00:36:13     INFO - Running manifest: toolkit/components/mozprotocol/tests/browser.ini
[task 2021-04-04T00:36:13.605Z] 00:36:13     INFO -  Setting pipeline to PAUSED ...
[task 2021-04-04T00:36:13.605Z] 00:36:13     INFO -  Pipeline is PREROLLING ...
[task 2021-04-04T00:36:13.606Z] 00:36:13     INFO -  Pipeline is PREROLLED ...
[task 2021-04-04T00:36:13.607Z] 00:36:13     INFO -  Setting pipeline to PLAYING ...
[task 2021-04-04T00:36:13.607Z] 00:36:13     INFO -  New clock: GstSystemClock
[task 2021-04-04T00:36:13.645Z] 00:36:13     INFO -  Got EOS from element "pipeline0".
[task 2021-04-04T00:36:13.645Z] 00:36:13     INFO -  Execution ended after 0:00:00.033360911
[task 2021-04-04T00:36:13.645Z] 00:36:13     INFO -  Setting pipeline to PAUSED ...
[task 2021-04-04T00:36:13.645Z] 00:36:13     INFO -  Setting pipeline to READY ...
[task 2021-04-04T00:36:13.645Z] 00:36:13     INFO -  (gst-launch-1.0:8269): GStreamer-CRITICAL **: 00:36:13.639: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2021-04-04T00:36:13.645Z] 00:36:13     INFO -  Setting pipeline to NULL ...
[task 2021-04-04T00:36:13.645Z] 00:36:13     INFO -  Freeing pipeline ...
[task 2021-04-04T00:36:14.062Z] 00:36:14     INFO - PID 8285 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2021-04-04T00:36:14.105Z] 00:36:14     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/tmpi7z8jw.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 2021-04-04T00:36:14.105Z] 00:36:14     INFO - runtests.py | Server pid: 8288
[task 2021-04-04T00:36:14.129Z] 00:36:14     INFO - runtests.py | Websocket server pid: 8291
[task 2021-04-04T00:36:14.149Z] 00:36:14     INFO - runtests.py | SSL tunnel pid: 8296
[task 2021-04-04T00:36:14.205Z] 00:36:14     INFO - runtests.py | Running with scheme: http
[task 2021-04-04T00:36:14.206Z] 00:36:14     INFO - runtests.py | Running with e10s: True
[task 2021-04-04T00:36:14.206Z] 00:36:14     INFO - runtests.py | Running with fission: False
[task 2021-04-04T00:36:14.207Z] 00:36:14     INFO - runtests.py | Running with cross-origin iframes: False
[task 2021-04-04T00:36:14.207Z] 00:36:14     INFO - runtests.py | Running with serviceworker_e10s: True
[task 2021-04-04T00:36:14.207Z] 00:36:14     INFO - runtests.py | Running with socketprocess_e10s: False
[task 2021-04-04T00:36:14.207Z] 00:36:14     INFO - runtests.py | Running tests: start.
[task 2021-04-04T00:36:14.207Z] 00:36:14     INFO - 
[task 2021-04-04T00:36:14.248Z] 00:36:14     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmpi7z8jw.mozrunner
[task 2021-04-04T00:36:14.263Z] 00:36:14     INFO - runtests.py | Application pid: 8312
[task 2021-04-04T00:36:14.263Z] 00:36:14     INFO - TEST-INFO | started process GECKO(8312)
[task 2021-04-04T00:36:14.721Z] 00:36:14     INFO - GECKO(8312) | 1617496574715	Marionette	INFO	Marionette enabled
[task 2021-04-04T00:36:14.797Z] 00:36:14     INFO - GECKO(8312) | 1617496574787	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2021-04-04T00:36:16.510Z] 00:36:16     INFO - GECKO(8312) | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new Error("", "(unknown module)"))
[task 2021-04-04T00:36:17.316Z] 00:36:17     INFO - GECKO(8312) | 1617496577310	Marionette	TRACE	Received observer notification marionette-startup-requested
[task 2021-04-04T00:36:17.317Z] 00:36:17     INFO - GECKO(8312) | 1617496577310	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
[task 2021-04-04T00:36:17.333Z] 00:36:17     INFO - GECKO(8312) | 1617496577323	Marionette	TRACE	All scripts recorded.
[task 2021-04-04T00:36:17.334Z] 00:36:17     INFO - GECKO(8312) | 1617496577324	Marionette	INFO	Listening on port 2828
[task 2021-04-04T00:36:17.335Z] 00:36:17     INFO - GECKO(8312) | 1617496577324	Marionette	DEBUG	Marionette is listening
[task 2021-04-04T00:36:17.381Z] 00:36:17     INFO - GECKO(8312) | 1617496577376	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:47760
[task 2021-04-04T00:36:17.381Z] 00:36:17     INFO - GECKO(8312) | 1617496577379	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:47762
[task 2021-04-04T00:36:17.381Z] 00:36:17     INFO - GECKO(8312) | 1617496577379	Marionette	DEBUG	Closed connection 0
[task 2021-04-04T00:36:17.389Z] 00:36:17     INFO - GECKO(8312) | 1617496577387	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-04-04T00:36:17.404Z] 00:36:17     INFO - GECKO(8312) | 1617496577399	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"22ce3688-696d-47d6-8b5f-eefe226d6aba","capabilities":{"browserName":"firefox","browserVersion":"88.0" ... mp/tmpi7z8jw.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2021-04-04T00:36:17.433Z] 00:36:17     INFO - GECKO(8312) | 1617496577427	Marionette	DEBUG	1 -> [0,2,"Addon:Install",{"path":"/tmp/tmpEtMHj3.zip","temporary":false}]
[task 2021-04-04T00:36:17.572Z] 00:36:17     INFO - GECKO(8312) | 1617496577564	Marionette	DEBUG	1 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2021-04-04T00:36:17.592Z] 00:36:17     INFO - GECKO(8312) | 1617496577589	Marionette	DEBUG	1 -> [0,3,"Addon:Install",{"path":"/tmp/tmpoiwX6Z.zip","temporary":false}]
[task 2021-04-04T00:36:17.612Z] 00:36:17     INFO - GECKO(8312) | 1617496577610	Marionette	DEBUG	1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2021-04-04T00:36:17.616Z] 00:36:17     INFO - GECKO(8312) | 1617496577611	Marionette	DEBUG	1 -> [0,4,"Marionette:GetContext",{}]
[task 2021-04-04T00:36:17.618Z] 00:36:17     INFO - GECKO(8312) | 1617496577612	Marionette	DEBUG	1 <- [1,4,null,{"value":"content"}]
[task 2021-04-04T00:36:17.618Z] 00:36:17     INFO - GECKO(8312) | 1617496577613	Marionette	DEBUG	1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-04-04T00:36:17.619Z] 00:36:17     INFO - GECKO(8312) | 1617496577613	Marionette	DEBUG	1 <- [1,5,null,{"value":null}]
[task 2021-04-04T00:36:17.620Z] 00:36:17     INFO - GECKO(8312) | 1617496577616	Marionette	DEBUG	1 -> [0,6,"WebDriver:ExecuteScript",{"script":"/* This Source Code Form is subject to the terms of the Mozilla Public\n * License, ... testUrl":"about:blank","flavor":"browser-chrome"}],"filename":"tests/mochitest/runtests.py","sandbox":"default","line":1933}]
[task 2021-04-04T00:36:17.636Z] 00:36:17     INFO - GECKO(8312) | 1617496577624	Marionette	TRACE	[7] MarionetteCommands actor created for window id 2
[task 2021-04-04T00:36:17.638Z] 00:36:17     INFO - GECKO(8312) | 1617496577627	Marionette	TRACE	[19] MarionetteEvents actor created for window id 2147483649
[task 2021-04-04T00:36:17.666Z] 00:36:17     INFO - GECKO(8312) | 1617496577657	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2021-04-04T00:36:17.670Z] 00:36:17     INFO - GECKO(8312) | 1617496577657	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2021-04-04T00:36:17.673Z] 00:36:17     INFO - GECKO(8312) | 1617496577670	Marionette	DEBUG	1 <- [1,6,null,{"value":null}]
[task 2021-04-04T00:36:17.693Z] 00:36:17     INFO - GECKO(8312) | 1617496577684	Marionette	TRACE	[19] MarionetteEvents actor created for window id 2147483650
[task 2021-04-04T00:36:17.734Z] 00:36:17     INFO - GECKO(8312) | 1617496577732	Marionette	DEBUG	1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2021-04-04T00:36:17.740Z] 00:36:17     INFO - GECKO(8312) | 1617496577734	Marionette	DEBUG	1 <- [1,7,null,{"value":null}]
[task 2021-04-04T00:36:17.776Z] 00:36:17     INFO - runtests.py | Waiting for browser...
[task 2021-04-04T00:36:17.776Z] 00:36:17     INFO - GECKO(8312) | 1617496577766	Marionette	DEBUG	1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2021-04-04T00:36:17.776Z] 00:36:17     INFO - GECKO(8312) | 1617496577772	Marionette	DEBUG	1 <- [1,8,null,{"value":null}]
[task 2021-04-04T00:36:17.778Z] 00:36:17     INFO - GECKO(8312) | 1617496577775	Marionette	DEBUG	Closed connection 1
[task 2021-04-04T00:36:17.860Z] 00:36:17     INFO - GECKO(8312) | 1617496577858	Marionette	TRACE	[39] MarionetteEvents actor created for window id 6442450945
[task 2021-04-04T00:36:17.861Z] 00:36:17     INFO - GECKO(8312) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'MarionetteEvents'
[task 2021-04-04T00:36:18.081Z] 00:36:18     INFO - TEST-START | toolkit/components/mozprotocol/tests/browser_mozprotocol.js
[task 2021-04-04T00:36:18.572Z] 00:36:18     INFO - GECKO(8312) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2021-04-04T00:36:18.573Z] 00:36:18     INFO - GECKO(8312) | MEMORY STAT | vsize 2767MB | residentFast 269MB | heapAllocated 107MB
[task 2021-04-04T00:36:18.573Z] 00:36:18     INFO - TEST-OK | toolkit/components/mozprotocol/tests/browser_mozprotocol.js | took 496ms
[task 2021-04-04T00:36:18.601Z] 00:36:18     INFO - checking window state
[task 2021-04-04T00:36:18.912Z] 00:36:18     INFO - GECKO(8312) | ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-04-04T00:36:19.974Z] 00:36:19     INFO - GECKO(8312) | Completed ShutdownLeaks collections in process 8460
[task 2021-04-04T00:36:19.975Z] 00:36:19     INFO - GECKO(8312) | Completed ShutdownLeaks collections in process 8491
[task 2021-04-04T00:36:19.990Z] 00:36:19     INFO - GECKO(8312) | Completed ShutdownLeaks collections in process 8393
[task 2021-04-04T00:36:19.990Z] 00:36:19     INFO - GECKO(8312) | Completed ShutdownLeaks collections in process 8378
[task 2021-04-04T00:36:20.167Z] 00:36:20     INFO - GECKO(8312) | Completed ShutdownLeaks collections in process 8312
[task 2021-04-04T00:36:20.168Z] 00:36:20     INFO - TEST-START | Shutdown```
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.