Closed Bug 1948452 Opened 1 year ago Closed 1 year ago

Intermittent dom/canvas/test/test_bug232227.html (finished) | single tracking bug

Categories

(Core :: Graphics: Canvas2D, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, intermittent-testcase)

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


[task 2025-02-15T06:46:05.613Z] 06:46:05     INFO - TEST-START | dom/canvas/test/test_bug232227.html
[task 2025-02-15T06:46:05.712Z] 06:46:05     INFO - GECKO(3467) | MEMORY STAT | vsize 35815MB | residentFast 64MB | heapAllocated 8MB
[task 2025-02-15T06:46:05.712Z] 06:46:05     INFO - TEST-OK | dom/canvas/test/test_bug232227.html | took 95ms
[task 2025-02-15T06:52:15.781Z] 06:52:15     INFO - TEST-UNEXPECTED-TIMEOUT | dom/canvas/test/test_bug232227.html (finished) | application timed out after 370 seconds with no output
[task 2025-02-15T06:52:15.781Z] 06:52:15     INFO - TEST-INFO 
[task 2025-02-15T06:52:15.782Z] 06:52:15     INFO - Buffered messages finished
[task 2025-02-15T06:52:15.782Z] 06:52:15  WARNING - Force-terminating active process(es).
[task 2025-02-15T06:52:15.782Z] 06:52:15  WARNING - profiler Attempting to start the profiler to help with diagnosing the hang.
[task 2025-02-15T06:52:15.783Z] 06:52:15     INFO - profiler Sending SIGUSR1 to pid 3467 start the profiler.
[task 2025-02-15T06:52:15.783Z] 06:52:15     INFO - profiler Waiting 10s to capture a profile...
[task 2025-02-15T06:52:25.915Z] 06:52:25     INFO - profiler Sending SIGUSR2 to pid 3467 stop the profiler.
[task 2025-02-15T06:52:25.915Z] 06:52:25     INFO - profiler Wait 10s for Firefox to write the profile to disk.
[task 2025-02-15T06:52:36.063Z] 06:52:36     INFO - profiler Symbolicating profile in /opt/worker/tasks/task_173959852446972/build/blobber_upload_dir
[task 2025-02-15T06:52:36.064Z] 06:52:36     INFO - profiler Looking inside symbols dir: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/CY2XG40lTrWkfKf5OLmNeQ/artifacts/public/build/target.crashreporter-symbols.zip)
[task 2025-02-15T06:52:36.064Z] 06:52:36     INFO - profiler Symbolicating profile: /opt/worker/tasks/task_173959852446972/build/blobber_upload_dir/profile_0_3467.json
[task 2025-02-15T06:52:36.064Z] 06:52:36     INFO - profiler Symbolicating the performance profile... This could take a couple of minutes.
[task 2025-02-15T06:52:37.008Z] 06:52:37     INFO - Determining child pids from psutil...
[task 2025-02-15T06:52:37.015Z] 06:52:37     INFO - [3468, 3469, 3477, 3478, 3481, 3562, 3563, 3569]
[task 2025-02-15T06:52:37.015Z] 06:52:37     INFO - ==> process 3467 launched child process 3468
<...>
[task 2025-02-15T06:56:37.864Z] 06:56:37     INFO - zombiecheck | Checking for orphan process with PID: 3569
[task 2025-02-15T06:56:37.864Z] 06:56:37     INFO - Stopping web server
[task 2025-02-15T06:56:37.864Z] 06:56:37     INFO - Server shut down.
[task 2025-02-15T06:56:37.865Z] 06:56:37     INFO - Web server killed.
[task 2025-02-15T06:56:37.865Z] 06:56:37     INFO - Stopping web socket server
[task 2025-02-15T06:56:37.865Z] 06:56:37     INFO - Stopping ssltunnel
[task 2025-02-15T06:56:37.866Z] 06:56:37     INFO - runtests.py | Running tests: end.
[task 2025-02-15T06:56:37.866Z] 06:56:37     INFO - Buffered messages finished
[task 2025-02-15T06:56:37.867Z] 06:56:37     INFO - Running manifest: dom/events/test/clipboard/mochitest.toml
[task 2025-02-15T06:56:38.050Z] 06:56:38     INFO - PID 4027 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2025-02-15T06:56:38.050Z] 06:56:38     INFO - 
[task 2025-02-15T06:56:38.098Z] 06:56:38     INFO - MochitestServer : launching ['/opt/worker/tasks/task_173959852446972/build/tests/bin/xpcshell', '-g', '/opt/worker/tasks/task_173959852446972/build/application/Firefox Nightly.app/Contents/Resources', '-e', "const _PROFILE_PATH = '/var/folders/3r/j0y9jzd96x901dfxx7_zj4fr0000jb/T/tmp_tuzq22i.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false; const _HTTPD_PATH = '/opt/worker/tasks/task_173959852446972/build/tests/bin/components';", '-f', '/opt/worker/tasks/task_173959852446972/build/tests/mochitest/server.js']
[task 2025-02-15T06:56:38.098Z] 06:56:38     INFO - runtests.py | Server pid: 4029
[task 2025-02-15T06:56:38.102Z] 06:56:38     INFO - runtests.py | Websocket server pid: 4030
[task 2025-02-15T06:56:38.107Z] 06:56:38     INFO - runtests.py | SSL tunnel pid: 4031
[task 2025-02-15T06:56:38.294Z] 06:56:38     INFO - use http3 server: 0
[task 2025-02-15T06:56:38.295Z] 06:56:38     INFO - runtests.py | Running with scheme: http
[task 2025-02-15T06:56:38.296Z] 06:56:38     INFO - runtests.py | Running with e10s: True
[task 2025-02-15T06:56:38.296Z] 06:56:38     INFO - runtests.py | Running with fission: True
[task 2025-02-15T06:56:38.296Z] 06:56:38     INFO - runtests.py | Running with cross-origin iframes: True
[task 2025-02-15T06:56:38.297Z] 06:56:38     INFO - runtests.py | Running with socketprocess_e10s: False
[task 2025-02-15T06:56:38.297Z] 06:56:38     INFO - runtests.py | Running tests: start.
[task 2025-02-15T06:56:38.297Z] 06:56:38     INFO - 
[task 2025-02-15T06:56:38.314Z] 06:56:38     INFO - Application command: /opt/worker/tasks/task_173959852446972/build/application/Firefox Nightly.app/Contents/MacOS/firefox -marionette -foreground -profile /var/folders/3r/j0y9jzd96x901dfxx7_zj4fr0000jb/T/tmp_tuzq22i.mozrunner
[task 2025-02-15T06:56:38.320Z] 06:56:38     INFO - runtests.py | Application pid: 4032
[task 2025-02-15T06:56:38.320Z] 06:56:38     INFO - TEST-INFO | started process GECKO(4032)
[task 2025-02-15T06:56:38.640Z] 06:56:38     INFO - GECKO(4032) | 1739602598639	Marionette	INFO	Marionette enabled
[task 2025-02-15T06:56:38.978Z] 06:56:38     INFO - GECKO(4032) | 1739602598977	Marionette	TRACE	Received observer notification final-ui-startup
[task 2025-02-15T06:56:39.041Z] 06:56:39     INFO - GECKO(4032) | 1739602599040	Marionette	INFO	Listening on port 2828
[task 2025-02-15T06:56:39.042Z] 06:56:39     INFO - GECKO(4032) | 1739602599041	Marionette	DEBUG	Marionette is listening
[task 2025-02-15T06:56:39.050Z] 06:56:39     INFO - GECKO(4032) | 1739602599049	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:49645
[task 2025-02-15T06:56:39.199Z] 06:56:39     INFO - GECKO(4032) | 1739602599199	Marionette	DEBUG	Closed connection 0
[task 2025-02-15T06:56:39.211Z] 06:56:39     INFO - GECKO(4032) | 1739602599210	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:49646
[task 2025-02-15T06:56:39.336Z] 06:56:39     INFO - GECKO(4032) | 1739602599335	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2025-02-15T06:56:39.342Z] 06:56:39     INFO - GECKO(4032) | 1739602599341	Marionette	DEBUG	Waiting for initial application window
[task 2025-02-15T06:56:41.166Z] 06:56:41     INFO - GECKO(4032) | 1739602601165	Marionette	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2025-02-15T06:56:41.170Z] 06:56:41     INFO - GECKO(4032) | 1739602601169	RemoteAgent	TRACE	[10] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=5000 waitForExplicitStart=false
[task 2025-02-15T06:56:41.170Z] 06:56:41     INFO - GECKO(4032) | 1739602601169	RemoteAgent	TRACE	[10] ProgressListener Setting unload timer (5000ms)
[task 2025-02-15T06:56:41.171Z] 06:56:41     INFO - GECKO(4032) | 1739602601169	RemoteAgent	TRACE	[10] Wait for initial navigation: isInitial=false, isLoadingDocument=false
[task 2025-02-15T06:56:41.171Z] 06:56:41     INFO - GECKO(4032) | 1739602601169	RemoteAgent	TRACE	[10] Document already finished loading: about:blank
[task 2025-02-15T06:56:41.171Z] 06:56:41     INFO - GECKO(4032) | 1739602601169	RemoteAgent	TRACE	[10] ProgressListener Stop: has error=false url=about:blank
[task 2025-02-15T06:56:41.178Z] 06:56:41     INFO - GECKO(4032) | 1739602601176	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"e32e03f3-8810-4e4c-8fac-5fa05a84acc3","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"137.0a1","platformName":"mac","unhandledPromptBehavior":"dismiss and notify","userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:137.0) Gecko/20100101 Firefox/137.0","moz:buildID":"20250215043440","moz:headless":false,"moz:platformVersion":"23.6.0","moz:processID":4032,"moz:profile":"/var/folders/3r/j0y9jzd96x901dfxx7_zj4fr0000jb/T/tmp_tuzq22i.mozrunner","moz:shutdownTimeout":60000,"pageLoadStrategy":"normal","timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"setWindowRect":true,"strictFileInteractability":true,"moz:accessibilityChecks":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2025-02-15T06:56:41.187Z] 06:56:41     INFO - GECKO(4032) | 1739602601186	Marionette	DEBUG	1 -> [0,2,"Addon:Install",{"path":"/var/folders/3r/j0y9jzd96x901dfxx7_zj4fr0000jb/T/tmpcbcm2flw.zip","temporary":false}]
[task 2025-02-15T06:56:41.217Z] 06:56:41     INFO - GECKO(4032) | 1739602601216	Marionette	DEBUG	1 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2025-02-15T06:56:41.238Z] 06:56:41     INFO - GECKO(4032) | 1739602601237	Marionette	DEBUG	1 -> [0,3,"Addon:Install",{"path":"/var/folders/3r/j0y9jzd96x901dfxx7_zj4fr0000jb/T/tmp1czvpsy7.zip","temporary":false}]
[task 2025-02-15T06:56:41.252Z] 06:56:41     INFO - GECKO(4032) | 1739602601251	Marionette	DEBUG	1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2025-02-15T06:56:41.253Z] 06:56:41     INFO - GECKO(4032) | 1739602601252	Marionette	DEBUG	1 -> [0,4,"Marionette:GetContext",{}]
[task 2025-02-15T06:56:41.253Z] 06:56:41     INFO - GECKO(4032) | 1739602601252	Marionette	DEBUG	1 <- [1,4,null,{"value":"content"}]
[task 2025-02-15T06:56:41.254Z] 06:56:41     INFO - GECKO(4032) | 1739602601253	Marionette	DEBUG	1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2025-02-15T06:56:41.254Z] 06:56:41     INFO - GECKO(4032) | 1739602601253	Marionette	DEBUG	1 <- [1,5,null,{"value":null}]
[task 2025-02-15T06:56:41.256Z] 06:56:41     INFO - GECKO(4032) | 1739602601254	Marionette	DEBUG	1 -> [0,6,"WebDriver:ExecuteScript",{"script":"/* This Source Code Form is subject to the terms of the Mozilla Public\n * License, v. 2.0. If a copy of the MPL was not distr ... s which flavor and url to load.\nlet ev = new CustomEvent(\"mochitest-load\", { detail: [flavor, url] });\nwin.dispatchEvent(ev);","args":[{"flavor":"mochitest","testUrl":"http://mochi.xorigin-test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory= ... ar%2Ffolders%2F3r%2Fj0y9jzd96x901dfxx7_zj4fr0000jb%2FT&cleanupCrashes=true&xOriginTests=true&ignorePrefsFile=ignorePrefs.json"}],"newSandbox":true,"sandbox":"default","line":2171,"filename":"tests/mochitest/runtests.py"}]
[task 2025-02-15T06:56:41.257Z] 06:56:41     INFO - GECKO(4032) | 1739602601257	RemoteAgent	TRACE	WebDriverProcessData actor created for PID 4032
[task 2025-02-15T06:56:41.258Z] 06:56:41     INFO - GECKO(4032) | 1739602601257	Marionette	TRACE	[2] MarionetteCommands actor created for window id 4
[task 2025-02-15T06:56:41.262Z] 06:56:41     INFO - GECKO(4032) | 1739602601261	Marionette	DEBUG	1 <- [1,6,null,{"value":null}]
[task 2025-02-15T06:56:41.267Z] 06:56:41     INFO - GECKO(4032) | 1739602601266	Marionette	DEBUG	1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2025-02-15T06:56:41.267Z] 06:56:41     INFO - GECKO(4032) | 1739602601266	Marionette	DEBUG	1 <- [1,7,null,{"value":null}]
[task 2025-02-15T06:56:41.271Z] 06:56:41     INFO - GECKO(4032) | 1739602601270	Marionette	DEBUG	1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2025-02-15T06:56:41.271Z] 06:56:41     INFO - GECKO(4032) | 1739602601270	Marionette	TRACE	[2] MarionetteCommands actor destroyed for window id 4
[task 2025-02-15T06:56:41.272Z] 06:56:41     INFO - GECKO(4032) | 1739602601271	Marionette	DEBUG	1 <- [1,8,null,{"value":null}]
[task 2025-02-15T06:56:41.272Z] 06:56:41     INFO - runtests.py | Waiting for browser...
[task 2025-02-15T06:56:41.273Z] 06:56:41     INFO - GECKO(4032) | 1739602601272	Marionette	DEBUG	Closed connection 1
[task 2025-02-15T06:56:41.361Z] 06:56:41     INFO - SimpleTest START
[task 2025-02-15T06:56:41.362Z] 06:56:41     INFO - Dumping test context:
[task 2025-02-15T06:56:41.362Z] 06:56:41     INFO -   fission.autostart=true
[task 2025-02-15T06:56:41.363Z] 06:56:41     INFO - TEST-START | dom/events/test/clipboard/test_paste_image.html
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.