Closed Bug 1750229 Opened 3 years ago Closed 3 years ago

Intermittent toolkit/components/viewsource/test/browser/browser_bug713810.js | application terminated with exit code 1

Categories

(Toolkit :: View Source, defect, P5)

Product:
Toolkit
Component:
View Source
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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

[task 2022-01-14T14:55:49.207Z] 14:55:49     INFO - TEST-START | toolkit/components/viewsource/test/browser/browser_bug713810.js
[task 2022-01-14T14:55:49.758Z] 14:55:49     INFO - GECKO(16099) | [CodeCoverage] Setting handlers for process 16354.
[task 2022-01-14T14:55:49.816Z] 14:55:49     INFO - GECKO(16099) | [CodeCoverage] Setting handlers for process 16358.
[task 2022-01-14T14:55:49.825Z] 14:55:49     INFO - GECKO(16099) | [CodeCoverage] Setting handlers for process 16356.
[task 2022-01-14T14:55:50.455Z] 14:55:50     INFO - GECKO(16099) | Gdk-Message: 14:55:50.454: firefox: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.
[task 2022-01-14T14:55:50.477Z] 14:55:50     INFO - GECKO(16099) | Exiting due to channel error.
[task 2022-01-14T14:55:50.493Z] 14:55:50     INFO - GECKO(16099) | Exiting due to channel error.
[task 2022-01-14T14:55:50.494Z] 14:55:50     INFO - GECKO(16099) | Exiting due to channel error.
[task 2022-01-14T14:55:50.494Z] 14:55:50     INFO - GECKO(16099) | Exiting due to channel error.
[task 2022-01-14T14:55:50.494Z] 14:55:50     INFO - GECKO(16099) | Exiting due to channel error.
[task 2022-01-14T14:55:50.494Z] 14:55:50     INFO - GECKO(16099) | Exiting due to channel error.
[task 2022-01-14T14:55:50.494Z] 14:55:50     INFO - GECKO(16099) | Exiting due to channel error.
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - TEST-INFO | Main app process: exit 1
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - Buffered messages logged at 14:55:49
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - Entering test bound 
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "data:text/html,<html xmlns="http://www.w3.org/1999/xhtml"><body><p>This is a paragraph.</p></body></html>" line: 0}]
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - Buffered messages logged at 14:55:50
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "view-source:data:text/html;charset=utf-8,%3Cp%3E%EF%B7%90This%20is%20a%20paragraph.%EF%B7%AF%3C%2Fp%3E" line: 0}]
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - TEST-PASS | toolkit/components/viewsource/test/browser/browser_bug713810.js | Correct source for text/html - "<p>This is a paragraph.</p>" == "<p>This is a paragraph.</p>" - 
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - Buffered messages finished
[task 2022-01-14T14:55:50.517Z] 14:55:50    ERROR - TEST-UNEXPECTED-FAIL | toolkit/components/viewsource/test/browser/browser_bug713810.js | application terminated with exit code 1
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - runtests.py | Application ran for: 0:00:07.920566
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - zombiecheck | Reading PID log: /tmp/tmp4mz7v2zlpidlog
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - ==> process 16099 launched child process 16122
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - ==> process 16099 launched child process 16177
[task 2022-01-14T14:55:50.517Z] 14:55:50     INFO - ==> process 16099 launched child process 16180
[task 2022-01-14T14:55:50.519Z] 14:55:50     INFO - ==> process 16099 launched child process 16252
[task 2022-01-14T14:55:50.520Z] 14:55:50     INFO - ==> process 16099 launched child process 16281
[task 2022-01-14T14:55:50.520Z] 14:55:50     INFO - ==> process 16099 launched child process 16282
[task 2022-01-14T14:55:50.520Z] 14:55:50     INFO - ==> process 16099 launched child process 16354
[task 2022-01-14T14:55:50.521Z] 14:55:50     INFO - ==> process 16099 launched child process 16356
[task 2022-01-14T14:55:50.521Z] 14:55:50     INFO - ==> process 16099 launched child process 16358
[task 2022-01-14T14:55:50.521Z] 14:55:50     INFO - zombiecheck | Checking for orphan process with PID: 16354
[task 2022-01-14T14:55:50.522Z] 14:55:50     INFO - zombiecheck | Checking for orphan process with PID: 16356
[task 2022-01-14T14:55:50.522Z] 14:55:50     INFO - zombiecheck | Checking for orphan process with PID: 16358
[task 2022-01-14T14:55:50.522Z] 14:55:50     INFO - zombiecheck | Checking for orphan process with PID: 16177
[task 2022-01-14T14:55:50.523Z] 14:55:50     INFO - zombiecheck | Checking for orphan process with PID: 16180
[task 2022-01-14T14:55:50.523Z] 14:55:50     INFO - zombiecheck | Checking for orphan process with PID: 16281
[task 2022-01-14T14:55:50.523Z] 14:55:50     INFO - zombiecheck | Checking for orphan process with PID: 16122
[task 2022-01-14T14:55:50.524Z] 14:55:50     INFO - zombiecheck | Checking for orphan process with PID: 16252
[task 2022-01-14T14:55:50.524Z] 14:55:50     INFO - zombiecheck | Checking for orphan process with PID: 16282
[task 2022-01-14T14:55:50.524Z] 14:55:50     INFO - Stopping web server
[task 2022-01-14T14:55:50.525Z] 14:55:50     INFO - Server shut down.
[task 2022-01-14T14:55:50.541Z] 14:55:50     INFO - Web server killed.
[task 2022-01-14T14:55:50.542Z] 14:55:50     INFO - Stopping web socket server
[task 2022-01-14T14:55:50.561Z] 14:55:50     INFO - Stopping ssltunnel
[task 2022-01-14T14:55:50.582Z] 14:55:50  WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2022-01-14T14:55:50.583Z] 14:55:50     INFO - runtests.py | Running tests: end.
[task 2022-01-14T14:55:50.632Z] 14:55:50     INFO - Buffered messages finished
[task 2022-01-14T14:55:50.632Z] 14:55:50     INFO - Running manifest: toolkit/crashreporter/test/browser/browser.ini
[task 2022-01-14T14:55:50.650Z] 14:55:50     INFO -  Setting pipeline to PAUSED ...
[task 2022-01-14T14:55:50.650Z] 14:55:50     INFO -  Pipeline is PREROLLING ...
[task 2022-01-14T14:55:50.652Z] 14:55:50     INFO -  Pipeline is PREROLLED ...
[task 2022-01-14T14:55:50.652Z] 14:55:50     INFO -  Setting pipeline to PLAYING ...
[task 2022-01-14T14:55:50.652Z] 14:55:50     INFO -  New clock: GstSystemClock
[task 2022-01-14T14:55:50.685Z] 14:55:50     INFO -  Got EOS from element "pipeline0".
[task 2022-01-14T14:55:50.686Z] 14:55:50     INFO -  Execution ended after 0:00:00.033459517
[task 2022-01-14T14:55:50.686Z] 14:55:50     INFO -  Setting pipeline to PAUSED ...
[task 2022-01-14T14:55:50.686Z] 14:55:50     INFO -  Setting pipeline to READY ...
[task 2022-01-14T14:55:50.686Z] 14:55:50     INFO -  (gst-launch-1.0:16449): GStreamer-CRITICAL **: 14:55:50.685: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2022-01-14T14:55:50.686Z] 14:55:50     INFO -  Setting pipeline to NULL ...
[task 2022-01-14T14:55:50.687Z] 14:55:50     INFO -  Freeing pipeline ...
[task 2022-01-14T14:55:50.930Z] 14:55:50     INFO - PID 16459 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2022-01-14T14:55:51.077Z] 14:55:51     INFO - MochitestServer : launching ['/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/tmp4vbaa2ky.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 2022-01-14T14:55:51.078Z] 14:55:51     INFO - runtests.py | Server pid: 16469
[task 2022-01-14T14:55:51.082Z] 14:55:51     INFO - runtests.py | Websocket server pid: 16472
[task 2022-01-14T14:55:51.090Z] 14:55:51     INFO - runtests.py | SSL tunnel pid: 16476
[task 2022-01-14T14:55:51.178Z] 14:55:51     INFO -  [CodeCoverage] Setting handlers for process 16469.
[task 2022-01-14T14:55:51.242Z] 14:55:51     INFO - runtests.py | Running with scheme: http
[task 2022-01-14T14:55:51.242Z] 14:55:51     INFO - runtests.py | Running with e10s: True
[task 2022-01-14T14:55:51.242Z] 14:55:51     INFO - runtests.py | Running with fission: True
[task 2022-01-14T14:55:51.243Z] 14:55:51     INFO - runtests.py | Running with cross-origin iframes: False
[task 2022-01-14T14:55:51.243Z] 14:55:51     INFO - runtests.py | Running with serviceworker_e10s: True
[task 2022-01-14T14:55:51.243Z] 14:55:51     INFO - runtests.py | Running with socketprocess_e10s: False
[task 2022-01-14T14:55:51.243Z] 14:55:51     INFO - runtests.py | Running tests: start.
[task 2022-01-14T14:55:51.243Z] 14:55:51     INFO - 
[task 2022-01-14T14:55:51.298Z] 14:55:51     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmp4vbaa2ky.mozrunner
[task 2022-01-14T14:55:51.305Z] 14:55:51     INFO - runtests.py | Application pid: 16497
[task 2022-01-14T14:55:51.306Z] 14:55:51     INFO - TEST-INFO | started process GECKO(16497)
[task 2022-01-14T14:55:51.363Z] 14:55:51     INFO - GECKO(16497) | [CodeCoverage] Setting handlers for process 16497.
[task 2022-01-14T14:55:52.073Z] 14:55:52     INFO - GECKO(16497) | 1642172152072	Marionette	INFO	Marionette enabled
[task 2022-01-14T14:55:52.195Z] 14:55:52     INFO - GECKO(16497) | 1642172152181	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2022-01-14T14:55:53.448Z] 14:55:53     INFO - GECKO(16497) | [CodeCoverage] Setting handlers for process 16575.
[task 2022-01-14T14:55:53.574Z] 14:55:53     INFO - GECKO(16497) | [CodeCoverage] Setting handlers for process 16578.
[task 2022-01-14T14:55:54.399Z] 14:55:54     INFO - GECKO(16497) | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmp4vbaa2ky.mozrunner/search.json.mozlz4", (void 0)))
[task 2022-01-14T14:55:55.569Z] 14:55:55     INFO - GECKO(16497) | [CodeCoverage] Setting handlers for process 16653.
[task 2022-01-14T14:55:55.736Z] 14:55:55     INFO - GECKO(16497) | 1642172155735	Marionette	TRACE	Received observer notification marionette-startup-requested
[task 2022-01-14T14:55:55.736Z] 14:55:55     INFO - GECKO(16497) | 1642172155735	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
[task 2022-01-14T14:55:55.765Z] 14:55:55     INFO - GECKO(16497) | 1642172155764	Marionette	TRACE	All scripts recorded.
[task 2022-01-14T14:55:55.770Z] 14:55:55     INFO - GECKO(16497) | 1642172155769	Marionette	INFO	Listening on port 2828
[task 2022-01-14T14:55:55.771Z] 14:55:55     INFO - GECKO(16497) | 1642172155770	Marionette	DEBUG	Marionette is listening
[task 2022-01-14T14:55:55.853Z] 14:55:55     INFO - GECKO(16497) | 1642172155852	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:34600
[task 2022-01-14T14:55:55.858Z] 14:55:55     INFO - GECKO(16497) | 1642172155857	Marionette	DEBUG	Closed connection 0
[task 2022-01-14T14:55:55.858Z] 14:55:55     INFO - GECKO(16497) | 1642172155857	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:34602
[task 2022-01-14T14:55:55.870Z] 14:55:55     INFO - GECKO(16497) | 1642172155869	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-01-14T14:55:55.885Z] 14:55:55     INFO - GECKO(16497) | 1642172155884	RemoteAgent	TRACE	Initial navigation already completed
[task 2022-01-14T14:55:55.893Z] 14:55:55     INFO - GECKO(16497) | 1642172155892	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"2a3abbdb-0f30-4a5c-a842-9f5edcf12a72","capabilities":{"browserName":"firefox","browserVersion":"98.0a ... y.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2022-01-14T14:55:55.950Z] 14:55:55     INFO - GECKO(16497) | 1642172155948	Marionette	DEBUG	1 -> [0,2,"Addon:Install",{"path":"/tmp/tmpfi5ls3wa.zip","temporary":false}]
[task 2022-01-14T14:55:56.078Z] 14:55:56     INFO - GECKO(16497) | 1642172156077	Marionette	DEBUG	1 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2022-01-14T14:55:56.102Z] 14:55:56     INFO - GECKO(16497) | 1642172156101	Marionette	DEBUG	1 -> [0,3,"Addon:Install",{"path":"/tmp/tmp5beoxrzl.zip","temporary":false}]
[task 2022-01-14T14:55:56.153Z] 14:55:56     INFO - GECKO(16497) | 1642172156152	Marionette	DEBUG	1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2022-01-14T14:55:56.158Z] 14:55:56     INFO - GECKO(16497) | 1642172156157	Marionette	DEBUG	1 -> [0,4,"Marionette:GetContext",{}]
[task 2022-01-14T14:55:56.159Z] 14:55:56     INFO - GECKO(16497) | 1642172156159	Marionette	DEBUG	1 <- [1,4,null,{"value":"content"}]
[task 2022-01-14T14:55:56.162Z] 14:55:56     INFO - GECKO(16497) | 1642172156161	Marionette	DEBUG	1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-01-14T14:55:56.163Z] 14:55:56     INFO - GECKO(16497) | 1642172156162	Marionette	DEBUG	1 <- [1,5,null,{"value":null}]
[task 2022-01-14T14:55:56.176Z] 14:55:56     INFO - GECKO(16497) | 1642172156165	Marionette	DEBUG	1 -> [0,6,"WebDriver:ExecuteScript",{"script":"/* This Source Code Form is subject to the terms of the Mozilla Public\n * License, ... hrome","testUrl":"about:blank"}],"newSandbox":true,"sandbox":"default","line":1945,"filename":"tests/mochitest/runtests.py"}]
[task 2022-01-14T14:55:56.176Z] 14:55:56     INFO - GECKO(16497) | 1642172156170	Marionette	TRACE	[7] MarionetteCommands actor created for window id 2
[task 2022-01-14T14:55:56.210Z] 14:55:56     INFO - GECKO(16497) | 1642172156209	Marionette	TRACE	Received observer notification domwindowopened
[task 2022-01-14T14:55:56.217Z] 14:55:56     INFO - GECKO(16497) | 1642172156216	Marionette	DEBUG	1 <- [1,6,null,{"value":null}]
[task 2022-01-14T14:55:56.219Z] 14:55:56     INFO - GECKO(16497) | 1642172156218	Marionette	DEBUG	1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-14T14:55:56.221Z] 14:55:56     INFO - GECKO(16497) | 1642172156219	Marionette	DEBUG	1 <- [1,7,null,{"value":null}]
[task 2022-01-14T14:55:56.264Z] 14:55:56     INFO - GECKO(16497) | 1642172156260	Marionette	DEBUG	1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2022-01-14T14:55:56.265Z] 14:55:56     INFO - GECKO(16497) | 1642172156263	Marionette	DEBUG	1 <- [1,8,null,{"value":null}]
[task 2022-01-14T14:55:56.292Z] 14:55:56     INFO - runtests.py | Waiting for browser...
[task 2022-01-14T14:55:56.314Z] 14:55:56     INFO - GECKO(16497) | 1642172156312	Marionette	DEBUG	Closed connection 1
[task 2022-01-14T14:55:56.594Z] 14:55:56     INFO - GECKO(16497) | [CodeCoverage] Setting handlers for process 16678.
[task 2022-01-14T14:55:56.663Z] 14:55:56     INFO - TEST-START | toolkit/crashreporter/test/browser/browser_aboutCrashes.js

This started to fail on tier 1: https://treeherder.mozilla.org/logviewer?job_id=365972369&repo=autoland&lineNumber=3541

Summary: Intermittent [tier 2] toolkit/components/viewsource/test/browser/browser_bug713810.js | application terminated with exit code 1 → Intermittent toolkit/components/viewsource/test/browser/browser_bug713810.js | application terminated with exit code 1

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

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.