Closed
Bug 1760270
Opened 3 years ago
Closed 3 years ago
Intermittent TEST-UNEXPECTED-TIMEOUT | dom/html/test/test_fullscreen-api.html | application timed out after 370 seconds with no output
Categories
(Core :: DOM: Core & HTML, defect, P5)
Core
DOM: Core & HTML
Tracking
()
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=371502733&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/IfV9eV6MQqWv4s_Tndok7A/runs/0/artifacts/public/logs/live_backing.log
[task 2022-03-18T07:23:15.831Z] 07:23:15 INFO - TEST-START | dom/html/test/test_fullscreen-api.html
[task 2022-03-18T07:23:26.484Z] 07:23:26 INFO - GECKO(2415) | JavaScript error: resource:///actors/DOMFullscreenParent.jsm, line 185: Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized
[task 2022-03-18T07:23:27.026Z] 07:23:27 INFO - GECKO(2415) | JavaScript error: resource:///actors/DOMFullscreenParent.jsm, line 155: Error: TelemetryStopwatch: finishing nonexisting stopwatch. Histogram: "FULLSCREEN_CHANGE_MS", key: ""
[task 2022-03-18T07:33:42.652Z] 07:33:42 INFO - Buffered messages logged at 07:23:16
[task 2022-03-18T07:33:42.673Z] 07:33:42 INFO - TEST-PASS | dom/html/test/test_fullscreen-api.html | A valid string reason is expected
[task 2022-03-18T07:33:42.680Z] 07:33:42 INFO - TEST-PASS | dom/html/test/test_fullscreen-api.html | Reason cannot be empty
[task 2022-03-18T07:33:42.681Z] 07:33:42 INFO - TEST-PASS | dom/html/test/test_fullscreen-api.html | Shouldn't be able to set window fullscreen from content
[task 2022-03-18T07:33:42.681Z] 07:33:42 INFO - Run test file_fullscreen-multiple.html
[task 2022-03-18T07:33:42.681Z] 07:33:42 INFO - Buffered messages logged at 07:23:21
[task 2022-03-18T07:33:42.681Z] 07:33:42 INFO - must wait for focus
[task 2022-03-18T07:33:42.682Z] 07:33:42 INFO - Were focused
[task 2022-03-18T07:33:42.682Z] 07:33:42 INFO - Buffered messages logged at 07:23:26
[task 2022-03-18T07:33:42.682Z] 07:33:42 INFO - must wait for focus
[task 2022-03-18T07:33:42.683Z] 07:33:42 INFO - Buffered messages logged at 07:23:31
[task 2022-03-18T07:33:42.683Z] 07:33:42 INFO - must wait for focus
[task 2022-03-18T07:33:42.683Z] 07:33:42 INFO - Buffered messages logged at 07:23:32
[task 2022-03-18T07:33:42.683Z] 07:33:42 INFO - TEST-PASS | dom/html/test/test_fullscreen-api.html | [multiple] Both windows should be fullscreen concurrently
[task 2022-03-18T07:33:42.683Z] 07:33:42 INFO - Waiting for focus to return to main window
[task 2022-03-18T07:33:42.684Z] 07:33:42 INFO - Buffered messages finished
[task 2022-03-18T07:33:42.684Z] 07:33:42 ERROR - TEST-UNEXPECTED-TIMEOUT | dom/html/test/test_fullscreen-api.html | application timed out after 370 seconds with no output
[task 2022-03-18T07:33:42.684Z] 07:33:42 ERROR - Force-terminating active process(es).
[task 2022-03-18T07:33:42.685Z] 07:33:42 INFO - Determining child pids from psutil...
[task 2022-03-18T07:33:42.701Z] 07:33:42 INFO - [2455, 2493, 2551, 2591, 2840, 2871, 2902, 2926]
[task 2022-03-18T07:33:42.753Z] 07:33:42 INFO - ==> process 2415 launched child process 2431
[task 2022-03-18T07:33:42.757Z] 07:33:42 INFO - ==> process 2415 launched child process 2493
[task 2022-03-18T07:33:42.758Z] 07:33:42 INFO - ==> process 2415 launched child process 2520
[task 2022-03-18T07:33:42.758Z] 07:33:42 INFO - ==> process 2415 launched child process 2551
[task 2022-03-18T07:33:42.758Z] 07:33:42 INFO - ==> process 2415 launched child process 2591
[task 2022-03-18T07:33:42.759Z] 07:33:42 INFO - ==> process 2415 launched child process 2612
[task 2022-03-18T07:33:42.759Z] 07:33:42 INFO - ==> process 2415 launched child process 2643
[task 2022-03-18T07:33:42.759Z] 07:33:42 INFO - ==> process 2415 launched child process 2649
[task 2022-03-18T07:33:42.760Z] 07:33:42 INFO - ==> process 2415 launched child process 2705
[task 2022-03-18T07:33:42.760Z] 07:33:42 INFO - ==> process 2415 launched child process 2731
[task 2022-03-18T07:33:42.760Z] 07:33:42 INFO - ==> process 2415 launched child process 2778
[task 2022-03-18T07:33:42.761Z] 07:33:42 INFO - ==> process 2415 launched child process 2808
[task 2022-03-18T07:33:42.761Z] 07:33:42 INFO - ==> process 2415 launched child process 2840
[task 2022-03-18T07:33:42.761Z] 07:33:42 INFO - ==> process 2415 launched child process 2871
[task 2022-03-18T07:33:42.761Z] 07:33:42 INFO - ==> process 2415 launched child process 2902
[task 2022-03-18T07:33:42.762Z] 07:33:42 INFO - ==> process 2415 launched child process 2926
[task 2022-03-18T07:33:42.762Z] 07:33:42 INFO - Found child pids: {2455, 2431, 2520, 2731, 2871, 2926, 2808, 2705, 2643, 2612, 2902, 2551, 2840, 2649, 2778, 2493, 2591}
[task 2022-03-18T07:33:42.762Z] 07:33:42 INFO - Failed to get child procs
[task 2022-03-18T07:33:42.762Z] 07:33:42 INFO - Killing process: 2455
[task 2022-03-18T07:33:42.768Z] 07:33:42 INFO - TEST-INFO | started process screentopng
[task 2022-03-18T07:33:43.656Z] 07:33:43 INFO - TEST-INFO | screentopng: exit 0
[task 2022-03-18T07:33:43.657Z] 07:33:43 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:13.686Z] 07:34:13 INFO - failed to kill pid 2455 after 30s
[task 2022-03-18T07:34:13.687Z] 07:34:13 INFO - Killing process: 2431
[task 2022-03-18T07:34:13.687Z] 07:34:13 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:13.688Z] 07:34:13 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:13.688Z] 07:34:13 INFO - Error: Failed to kill process 2431: psutil.NoSuchProcess no process found with pid 2431
[task 2022-03-18T07:34:13.691Z] 07:34:13 INFO - Killing process: 2520
[task 2022-03-18T07:34:13.691Z] 07:34:13 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:13.691Z] 07:34:13 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:13.691Z] 07:34:13 INFO - Error: Failed to kill process 2520: psutil.NoSuchProcess no process found with pid 2520
[task 2022-03-18T07:34:13.691Z] 07:34:13 INFO - Killing process: 2731
[task 2022-03-18T07:34:13.691Z] 07:34:13 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:13.691Z] 07:34:13 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:13.691Z] 07:34:13 INFO - Error: Failed to kill process 2731: psutil.NoSuchProcess no process found with pid 2731
[task 2022-03-18T07:34:13.691Z] 07:34:13 INFO - Killing process: 2871
[task 2022-03-18T07:34:13.691Z] 07:34:13 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:13.691Z] 07:34:13 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:43.713Z] 07:34:43 INFO - failed to kill pid 2871 after 30s
[task 2022-03-18T07:34:43.714Z] 07:34:43 INFO - Killing process: 2926
[task 2022-03-18T07:34:43.714Z] 07:34:43 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:43.714Z] 07:34:43 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.147Z] 07:34:45 INFO - psutil found pid 2926 dead
[task 2022-03-18T07:34:45.147Z] 07:34:45 INFO - Killing process: 2808
[task 2022-03-18T07:34:45.147Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.149Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.150Z] 07:34:45 INFO - Error: Failed to kill process 2808: psutil.NoSuchProcess no process found with pid 2808
[task 2022-03-18T07:34:45.150Z] 07:34:45 INFO - Killing process: 2705
[task 2022-03-18T07:34:45.150Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.150Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.150Z] 07:34:45 INFO - Error: Failed to kill process 2705: psutil.NoSuchProcess no process found with pid 2705
[task 2022-03-18T07:34:45.150Z] 07:34:45 INFO - Killing process: 2643
[task 2022-03-18T07:34:45.155Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.155Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.156Z] 07:34:45 INFO - Error: Failed to kill process 2643: psutil.NoSuchProcess no process found with pid 2643
[task 2022-03-18T07:34:45.156Z] 07:34:45 INFO - Killing process: 2612
[task 2022-03-18T07:34:45.156Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.157Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.157Z] 07:34:45 INFO - Error: Failed to kill process 2612: psutil.NoSuchProcess no process found with pid 2612
[task 2022-03-18T07:34:45.158Z] 07:34:45 INFO - Killing process: 2902
[task 2022-03-18T07:34:45.158Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.159Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.294Z] 07:34:45 INFO - psutil found pid 2902 dead
[task 2022-03-18T07:34:45.295Z] 07:34:45 INFO - Killing process: 2551
[task 2022-03-18T07:34:45.296Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.297Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.353Z] 07:34:45 INFO - psutil found pid 2551 dead
[task 2022-03-18T07:34:45.353Z] 07:34:45 INFO - Killing process: 2840
[task 2022-03-18T07:34:45.353Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.353Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.696Z] 07:34:45 INFO - psutil found pid 2840 dead
[task 2022-03-18T07:34:45.696Z] 07:34:45 INFO - Killing process: 2649
[task 2022-03-18T07:34:45.696Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.696Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.696Z] 07:34:45 INFO - Error: Failed to kill process 2649: psutil.NoSuchProcess no process found with pid 2649
[task 2022-03-18T07:34:45.696Z] 07:34:45 INFO - Killing process: 2778
[task 2022-03-18T07:34:45.697Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.697Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.697Z] 07:34:45 INFO - Error: Failed to kill process 2778: psutil.NoSuchProcess no process found with pid 2778
[task 2022-03-18T07:34:45.697Z] 07:34:45 INFO - Killing process: 2493
[task 2022-03-18T07:34:45.697Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.697Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.697Z] 07:34:45 INFO - Error: Failed to kill process 2493: psutil.NoSuchProcess no process found with pid 2493
[task 2022-03-18T07:34:45.697Z] 07:34:45 INFO - Killing process: 2591
[task 2022-03-18T07:34:45.698Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.698Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:34:45.792Z] 07:34:45 INFO - psutil found pid 2591 dead
[task 2022-03-18T07:34:45.792Z] 07:34:45 INFO - Killing process: 2415
[task 2022-03-18T07:34:45.793Z] 07:34:45 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-18T07:34:45.793Z] 07:34:45 INFO - Can't trigger Breakpad, just killing process
[task 2022-03-18T07:35:15.806Z] 07:35:15 INFO - psutil found pid 2415 dead
[task 2022-03-18T07:35:15.807Z] 07:35:15 INFO - failed to kill pid 2871 after 30s
[task 2022-03-18T07:35:15.808Z] 07:35:15 INFO - failed to kill pid 2455 after 30s
[task 2022-03-18T07:35:15.808Z] 07:35:15 INFO - psutil found pid 2415 dead
[task 2022-03-18T07:35:15.809Z] 07:35:15 INFO - TEST-INFO | Main app process: exit 0
[task 2022-03-18T07:35:15.809Z] 07:35:15 INFO - runtests.py | Application ran for: 0:17:44.711807
[task 2022-03-18T07:35:15.809Z] 07:35:15 INFO - zombiecheck | Reading PID log: /tmp/tmptylv32t2pidlog
[task 2022-03-18T07:35:15.810Z] 07:35:15 INFO - ==> process 2415 launched child process 2431
[task 2022-03-18T07:35:15.810Z] 07:35:15 INFO - ==> process 2415 launched child process 2493
[task 2022-03-18T07:35:15.810Z] 07:35:15 INFO - ==> process 2415 launched child process 2520
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2551
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2591
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2612
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2643
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2649
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2705
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2731
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2778
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2808
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2840
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2871
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2902
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - ==> process 2415 launched child process 2926
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2431
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2731
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2871
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2926
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2808
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2705
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2840
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2643
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2612
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2902
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2551
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2520
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2649
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2778
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2493
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - zombiecheck | Checking for orphan process with PID: 2591
[task 2022-03-18T07:35:15.811Z] 07:35:15 INFO - Stopping web server
[task 2022-03-18T07:35:15.820Z] 07:35:15 INFO - Server shut down.
[task 2022-03-18T07:35:15.864Z] 07:35:15 INFO - Web server killed.
[task 2022-03-18T07:35:15.865Z] 07:35:15 INFO - Stopping web socket server
[task 2022-03-18T07:35:15.885Z] 07:35:15 INFO - Stopping ssltunnel
[task 2022-03-18T07:35:15.905Z] 07:35:15 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2022-03-18T07:35:15.906Z] 07:35:15 INFO - runtests.py | Running tests: end.
[task 2022-03-18T07:35:15.979Z] 07:35:15 INFO - Buffered messages finished
[task 2022-03-18T07:35:15.980Z] 07:35:15 INFO - Running manifest: dom/serviceworkers/test/mochitest-dFPI.ini:dom/serviceworkers/test/mochitest-common.ini
[task 2022-03-18T07:35:15.980Z] 07:35:15 INFO - The following extra prefs will be set:
[task 2022-03-18T07:35:15.980Z] 07:35:15 INFO - network.cookie.cookieBehavior=5
[task 2022-03-18T07:35:16.100Z] 07:35:16 INFO - Setting pipeline to PAUSED ...
[task 2022-03-18T07:35:16.101Z] 07:35:16 INFO - Pipeline is PREROLLING ...
[task 2022-03-18T07:35:16.105Z] 07:35:16 INFO - Pipeline is PREROLLED ...
[task 2022-03-18T07:35:16.105Z] 07:35:16 INFO - Setting pipeline to PLAYING ...
[task 2022-03-18T07:35:16.105Z] 07:35:16 INFO - New clock: GstSystemClock
[task 2022-03-18T07:35:16.139Z] 07:35:16 INFO - Got EOS from element "pipeline0".
[task 2022-03-18T07:35:16.139Z] 07:35:16 INFO - Execution ended after 0:00:00.033476320
[task 2022-03-18T07:35:16.140Z] 07:35:16 INFO - Setting pipeline to PAUSED ...
[task 2022-03-18T07:35:16.140Z] 07:35:16 INFO - Setting pipeline to READY ...
[task 2022-03-18T07:35:16.140Z] 07:35:16 INFO - (gst-launch-1.0:3020): GStreamer-CRITICAL **: 07:35:16.138: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2022-03-18T07:35:16.140Z] 07:35:16 INFO - Setting pipeline to NULL ...
[task 2022-03-18T07:35:16.140Z] 07:35:16 INFO - Freeing pipeline ...
[task 2022-03-18T07:35:16.275Z] 07:35:16 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-03-18T07:35:16.738Z] 07:35:16 INFO - PID 3030 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2022-03-18T07:35:16.982Z] 07:35:16 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-03-18T07:35:16.985Z] 07:35:16 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-03-18T07:35:16.990Z] 07:35:16 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/tmpdvotgay0.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-03-18T07:35:16.991Z] 07:35:16 INFO - runtests.py | Server pid: 3039
[task 2022-03-18T07:35:16.994Z] 07:35:16 INFO - runtests.py | Websocket server pid: 3042
[task 2022-03-18T07:35:17.002Z] 07:35:17 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-03-18T07:35:17.002Z] 07:35:17 INFO - runtests.py | SSL tunnel pid: 3046
[task 2022-03-18T07:35:17.853Z] 07:35:17 INFO - runtests.py | Running with scheme: http
[task 2022-03-18T07:35:17.854Z] 07:35:17 INFO - runtests.py | Running with e10s: True
[task 2022-03-18T07:35:17.854Z] 07:35:17 INFO - runtests.py | Running with fission: True
[task 2022-03-18T07:35:17.854Z] 07:35:17 INFO - runtests.py | Running with cross-origin iframes: False
[task 2022-03-18T07:35:17.854Z] 07:35:17 INFO - runtests.py | Running with serviceworker_e10s: True
[task 2022-03-18T07:35:17.854Z] 07:35:17 INFO - runtests.py | Running with socketprocess_e10s: False
[task 2022-03-18T07:35:17.855Z] 07:35:17 INFO - runtests.py | Running tests: start.
[task 2022-03-18T07:35:17.855Z] 07:35:17 INFO -
[task 2022-03-18T07:35:17.862Z] 07:35:17 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmpdvotgay0.mozrunner
[task 2022-03-18T07:35:17.869Z] 07:35:17 INFO - runtests.py | Application pid: 3067
[task 2022-03-18T07:35:17.870Z] 07:35:17 INFO - TEST-INFO | started process GECKO(3067)
[task 2022-03-18T07:35:22.496Z] 07:35:22 INFO - GECKO(3067) | 1647588922495 Marionette INFO Marionette enabled
[task 2022-03-18T07:35:23.367Z] 07:35:23 INFO - GECKO(3067) | 1647588923366 Marionette TRACE Received observer notification toplevel-window-ready
[task 2022-03-18T07:35:35.455Z] 07:35:35 INFO - GECKO(3067) | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmpdvotgay0.mozrunner/search.json.mozlz4", (void 0)))
[task 2022-03-18T07:35:42.373Z] 07:35:42 INFO - GECKO(3067) | 1647588942372 Marionette TRACE Received observer notification marionette-startup-requested
[task 2022-03-18T07:35:42.374Z] 07:35:42 INFO - GECKO(3067) | 1647588942373 Marionette TRACE Waiting until startup recorder finished recording startup scripts...
[task 2022-03-18T07:35:42.561Z] 07:35:42 INFO - GECKO(3067) | 1647588942560 Marionette TRACE All scripts recorded.
[task 2022-03-18T07:35:42.581Z] 07:35:42 INFO - GECKO(3067) | 1647588942580 Marionette INFO Listening on port 2828
[task 2022-03-18T07:35:42.583Z] 07:35:42 INFO - GECKO(3067) | 1647588942582 Marionette DEBUG Marionette is listening
[task 2022-03-18T07:35:42.782Z] 07:35:42 INFO - GECKO(3067) | 1647588942781 Marionette DEBUG Accepted connection 0 from 127.0.0.1:55230
[task 2022-03-18T07:35:42.808Z] 07:35:42 INFO - GECKO(3067) | 1647588942807 Marionette DEBUG Accepted connection 1 from 127.0.0.1:55232
[task 2022-03-18T07:35:42.810Z] 07:35:42 INFO - GECKO(3067) | 1647588942809 Marionette DEBUG Closed connection 0
[task 2022-03-18T07:35:42.915Z] 07:35:42 INFO - GECKO(3067) | 1647588942914 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-03-18T07:35:43.027Z] 07:35:43 INFO - GECKO(3067) | 1647588943026 RemoteAgent TRACE [24] Document already finished loading: about:blank
[task 2022-03-18T07:35:43.065Z] 07:35:43 INFO - GECKO(3067) | 1647588943064 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"ddef936e-8361-4cf8-9c2e-75ec5f024d4d","capabilities":{"browserName":"firefox","browserVersion":"100.0 ... .mozrunner","moz:shutdownTimeout":360000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2022-03-18T07:35:43.185Z] 07:35:43 INFO - GECKO(3067) | 1647588943184 Marionette DEBUG 1 -> [0,2,"Addon:Install",{"path":"/tmp/tmprrkq3kxi.zip","temporary":false}]
[task 2022-03-18T07:35:43.647Z] 07:35:43 INFO - GECKO(3067) | 1647588943645 Marionette DEBUG 1 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2022-03-18T07:35:43.694Z] 07:35:43 INFO - GECKO(3067) | 1647588943692 Marionette DEBUG 1 -> [0,3,"Addon:Install",{"path":"/tmp/tmp4b9evqh9.zip","temporary":false}]
[task 2022-03-18T07:35:43.888Z] 07:35:43 INFO - GECKO(3067) | 1647588943887 Marionette DEBUG 1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2022-03-18T07:35:43.913Z] 07:35:43 INFO - GECKO(3067) | 1647588943912 Marionette DEBUG 1 -> [0,4,"Marionette:GetContext",{}]
[task 2022-03-18T07:35:43.915Z] 07:35:43 INFO - GECKO(3067) | 1647588943914 Marionette DEBUG 1 <- [1,4,null,{"value":"content"}]
[task 2022-03-18T07:35:43.922Z] 07:35:43 INFO - GECKO(3067) | 1647588943921 Marionette DEBUG 1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-03-18T07:35:43.924Z] 07:35:43 INFO - GECKO(3067) | 1647588943923 Marionette DEBUG 1 <- [1,5,null,{"value":null}]
[task 2022-03-18T07:35:43.933Z] 07:35:43 INFO - GECKO(3067) | 1647588943932 Marionette DEBUG 1 -> [0,6,"WebDriver:ExecuteScript",{"script":"/* This Source Code Form is subject to the terms of the Mozilla Public\n * License, ... ry=%2Ftmp&cleanupCrashes=true"}],"newSandbox":true,"sandbox":"default","line":1989,"filename":"tests/mochitest/runtests.py"}]
[task 2022-03-18T07:35:43.972Z] 07:35:43 INFO - GECKO(3067) | 1647588943970 Marionette TRACE [7] MarionetteCommands actor created for window id 2
[task 2022-03-18T07:35:44.019Z] 07:35:44 INFO - GECKO(3067) | 1647588944018 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2022-03-18T07:35:44.080Z] 07:35:44 INFO - GECKO(3067) | 1647588944075 Marionette DEBUG 1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2022-03-18T07:35:44.082Z] 07:35:44 INFO - GECKO(3067) | 1647588944077 Marionette DEBUG 1 <- [1,7,null,{"value":null}]
[task 2022-03-18T07:35:44.139Z] 07:35:44 INFO - GECKO(3067) | 1647588944134 Marionette DEBUG 1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2022-03-18T07:35:44.162Z] 07:35:44 INFO - GECKO(3067) | 1647588944161 Marionette DEBUG 1 <- [1,8,null,{"value":null}]
[task 2022-03-18T07:35:44.170Z] 07:35:44 INFO - runtests.py | Waiting for browser...
[task 2022-03-18T07:35:44.176Z] 07:35:44 INFO - GECKO(3067) | 1647588944175 Marionette DEBUG Closed connection 1
[task 2022-03-18T07:35:46.623Z] 07:35:46 INFO - SimpleTest START
[task 2022-03-18T07:35:46.631Z] 07:35:46 INFO - Dumping test context:
[task 2022-03-18T07:35:46.631Z] 07:35:46 INFO - fission.autostart=true
[task 2022-03-18T07:35:46.680Z] 07:35:46 INFO - TEST-START | dom/serviceworkers/test/test_async_waituntil.html
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•3 years ago
|
||
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.
Description
•