Closed
Bug 1767620
Opened 2 years ago
Closed 2 years ago
Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/element_send_keys/events.py | expected OK
Categories
(Remote Protocol :: Marionette, defect, P5)
Remote Protocol
Marionette
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1630162
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: bszekely [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=376786889&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/T_NGwW_CSCC9zUuz5d4sHA/runs/0/artifacts/public/logs/live_backing.log
[task 2022-05-04T10:44:20.658Z] 10:44:20 INFO - STDOUT: ============================= test session starts ==============================
[task 2022-05-04T10:44:20.660Z] 10:44:20 INFO - STDOUT: platform linux -- Python 3.6.9, pytest-6.1.1, py-1.5.2, pluggy-unknown -- /builds/worker/workspace/build/venv/bin/python
[task 2022-05-04T10:44:20.663Z] 10:44:20 INFO - STDOUT: rootdir: /builds/worker/workspace/build
[task 2022-05-04T10:44:20.664Z] 10:44:20 INFO - STDOUT: plugins: asyncio-0.14.0
[task 2022-05-04T10:44:20.665Z] 10:44:20 INFO - STDOUT: collecting ...
[task 2022-05-04T10:44:20.679Z] 10:44:20 INFO - PID 8731 | 1651661060677 webdriver::server DEBUG -> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"args": ["--profile", "/tmp/tmponlfkuu7.mozrunner"], "binary": "/builds/worker/workspace/build/application/firefox/firefox"}}}}
[task 2022-05-04T10:44:20.680Z] 10:44:20 INFO - STDOUT: collected 5 items
[task 2022-05-04T10:44:20.681Z] 10:44:20 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/element_send_keys/events.py::test_file_upload
[task 2022-05-04T10:44:20.681Z] 10:44:20 INFO - PID 8731 | 1651661060677 geckodriver::capabilities DEBUG Trying to read firefox version from ini files
[task 2022-05-04T10:44:20.681Z] 10:44:20 INFO - PID 8731 | 1651661060677 geckodriver::capabilities DEBUG Found version 102.0a1
[task 2022-05-04T10:44:20.681Z] 10:44:20 INFO - PID 8731 | 1651661060678 geckodriver::browser DEBUG Backing up prefs to "/tmp/tmponlfkuu7.mozrunner/user.geckodriver_backup"
[task 2022-05-04T10:44:20.685Z] 10:44:20 INFO - PID 8731 | 1651661060684 mozrunner::runner INFO Running command: "/builds/worker/workspace/build/application/firefox/firefox" "--marionette" "--profile" "/tmp/tmponlfkuu7.mozrunner" "-no-remote"
[task 2022-05-04T10:44:20.686Z] 10:44:20 INFO - PID 8731 | 1651661060684 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1
[task 2022-05-04T10:44:20.687Z] 10:44:20 INFO - PID 8731 | 1651661060684 geckodriver::browser TRACE Failed to open /tmp/tmponlfkuu7.mozrunner/MarionetteActivePort
[task 2022-05-04T10:44:20.687Z] 10:44:20 INFO - PID 8731 | 1651661060684 geckodriver::marionette TRACE Retrying in 100ms
[task 2022-05-04T10:44:20.732Z] 10:44:20 INFO - PID 8731 | [CodeCoverage] Setting handlers for process 9014.
[task 2022-05-04T10:44:20.786Z] 10:44:20 INFO - PID 8731 | 1651661060784 geckodriver::browser TRACE Failed to open /tmp/tmponlfkuu7.mozrunner/MarionetteActivePort
[task 2022-05-04T10:44:20.786Z] 10:44:20 INFO - PID 8731 | 1651661060784 geckodriver::marionette TRACE Retrying in 100ms
[task 2022-05-04T10:44:20.887Z] 10:44:20 INFO - PID 8731 | 1651661060885 geckodriver::browser TRACE Failed to open /tmp/tmponlfkuu7.mozrunner/MarionetteActivePort
[task 2022-05-04T10:44:20.887Z] 10:44:20 INFO - PID 8731 | 1651661060885 geckodriver::marionette TRACE Retrying in 100ms
[task 2022-05-04T10:44:20.987Z] 10:44:20 INFO - PID 8731 | 1651661060985 geckodriver::browser TRACE Failed to open /tmp/tmponlfkuu7.mozrunner/MarionetteActivePort
[task 2022-05-04T10:44:20.987Z] 10:44:20 INFO - PID 8731 | 1651661060985 geckodriver::marionette TRACE Retrying in 100ms
[task 2022-05-04T10:44:21.087Z] 10:44:21 INFO - PID 8731 | 1651661061085 geckodriver::browser TRACE Failed to open /tmp/tmponlfkuu7.mozrunner/MarionetteActivePort
[task 2022-05-04T10:44:21.087Z] 10:44:21 INFO - PID 8731 | 1651661061085 geckodriver::marionette TRACE Retrying in 100ms
[task 2022-05-04T10:44:21.187Z] 10:44:21 INFO - PID 8731 | 1651661061185 geckodriver::browser TRACE Failed to open /tmp/tmponlfkuu7.mozrunner/MarionetteActivePort
[task 2022-05-04T10:44:21.187Z] 10:44:21 INFO - PID 8731 | 1651661061185 geckodriver::marionette TRACE Retrying in 100ms
[task 2022-05-04T10:44:21.286Z] 10:44:21 INFO - PID 8731 | 1651661061285 geckodriver::browser TRACE Failed to open /tmp/tmponlfkuu7.mozrunner/MarionetteActivePort
[task 2022-05-04T10:44:21.287Z] 10:44:21 INFO - PID 8731 | 1651661061285 geckodriver::marionette TRACE Retrying in 100ms
[task 2022-05-04T10:44:21.386Z] 10:44:21 INFO - PID 8731 | 1651661061385 geckodriver::browser TRACE Failed to open /tmp/tmponlfkuu7.mozrunner/MarionetteActivePort
[task 2022-05-04T10:44:21.387Z] 10:44:21 INFO - PID 8731 | 1651661061385 geckodriver::marionette TRACE Retrying in 100ms
[task 2022-05-04T10:44:21.486Z] 10:44:21 INFO - PID 8731 | 1651661061485 geckodriver::browser TRACE Failed to open /tmp/tmponlfkuu7.mozrunner/MarionetteActivePort
[task 2022-05-04T10:44:21.487Z] 10:44:21 INFO - PID 8731 | 1651661061485 geckodriver::marionette TRACE Retrying in 100ms
[task 2022-05-04T10:44:21.586Z] 10:44:21 INFO - PID 8731 | 1651661061586 geckodriver::browser TRACE Failed to open /tmp/tmponlfkuu7.mozrunner/MarionetteActivePort
[task 2022-05-04T10:44:21.587Z] 10:44:21 INFO - PID 8731 | 1651661061586 geckodriver::marionette TRACE Retrying in 100ms
<...>
[task 2022-05-04T10:44:28.373Z] 10:44:28 INFO - PID 8731 | 1651661068361 Marionette DEBUG 0 -> [0,104,"WebDriver:GetWindowHandle",{}]
[task 2022-05-04T10:44:28.373Z] 10:44:28 INFO - PID 8731 | 1651661068362 Marionette DEBUG 0 <- [1,104,null,{"value":"c4a86302-c3ae-4129-8a75-2143c1c547d3"}]
[task 2022-05-04T10:44:28.374Z] 10:44:28 INFO - PID 8731 | 1651661068362 webdriver::server DEBUG <- 200 OK {"value":"c4a86302-c3ae-4129-8a75-2143c1c547d3"}
[task 2022-05-04T10:44:28.375Z] 10:44:28 INFO - PID 8731 | 1651661068364 webdriver::server DEBUG -> GET /session/82ca072a-7779-4472-b1d8-071e31bf7a29/window/handles
[task 2022-05-04T10:44:28.375Z] 10:44:28 INFO - PID 8731 | 1651661068364 Marionette DEBUG 0 -> [0,105,"WebDriver:GetWindowHandles",{}]
[task 2022-05-04T10:44:28.376Z] 10:44:28 INFO - PID 8731 | 1651661068365 Marionette DEBUG 0 <- [1,105,null,["c4a86302-c3ae-4129-8a75-2143c1c547d3"]]
[task 2022-05-04T10:44:28.376Z] 10:44:28 INFO - PID 8731 | 1651661068366 webdriver::server DEBUG <- 200 OK {"value":["c4a86302-c3ae-4129-8a75-2143c1c547d3"]}
[task 2022-05-04T10:44:28.377Z] 10:44:28 INFO - PID 8731 | 1651661068367 webdriver::server DEBUG -> POST /session/82ca072a-7779-4472-b1d8-071e31bf7a29/window {"handle": "c4a86302-c3ae-4129-8a75-2143c1c547d3"}
[task 2022-05-04T10:44:28.378Z] 10:44:28 INFO - PID 8731 | 1651661068368 Marionette DEBUG 0 -> [0,106,"WebDriver:SwitchToWindow",{"handle":"c4a86302-c3ae-4129-8a75-2143c1c547d3"}]
[task 2022-05-04T10:44:28.378Z] 10:44:28 INFO - PID 8731 | 1651661068369 Marionette DEBUG 0 <- [1,106,null,{"value":null}]
[task 2022-05-04T10:44:28.379Z] 10:44:28 INFO - PID 8731 | 1651661068369 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2022-05-04T10:44:28.380Z] 10:44:28 INFO - PID 8731 | 1651661068371 webdriver::server DEBUG -> POST /session/82ca072a-7779-4472-b1d8-071e31bf7a29/window/rect {"width": 800, "height": 600}
[task 2022-05-04T10:44:28.381Z] 10:44:28 INFO - PID 8731 | 1651661068372 Marionette DEBUG 0 -> [0,107,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2022-05-04T10:44:28.382Z] 10:44:28 INFO - PID 8731 | 1651661068377 Marionette DEBUG 0 <- [1,107,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2022-05-04T10:44:28.383Z] 10:44:28 INFO - PID 8731 | 1651661068378 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2022-05-04T10:44:28.383Z] 10:44:28 INFO - PID 8731 | 1651661068380 webdriver::server DEBUG -> POST /session/82ca072a-7779-4472-b1d8-071e31bf7a29/frame {"id": null}
[task 2022-05-04T10:44:28.384Z] 10:44:28 INFO - PID 8731 | 1651661068382 Marionette DEBUG 0 -> [0,108,"WebDriver:SwitchToFrame",{"id":null}]
[task 2022-05-04T10:44:28.386Z] 10:44:28 INFO - PID 8731 | 1651661068385 Marionette DEBUG 0 <- [1,108,null,{"value":null}]
[task 2022-05-04T10:44:28.387Z] 10:44:28 INFO - PID 8731 | 1651661068385 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2022-05-04T10:44:28.389Z] 10:44:28 INFO - PID 8731 | 1651661068388 webdriver::server DEBUG -> DELETE /session/82ca072a-7779-4472-b1d8-071e31bf7a29
[task 2022-05-04T10:44:28.390Z] 10:44:28 INFO - PID 8731 | 1651661068389 Marionette DEBUG 0 -> [0,109,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2022-05-04T10:44:28.391Z] 10:44:28 INFO - PID 8731 | 1651661068390 Marionette INFO Stopped listening on port 34382
[task 2022-05-04T10:44:28.506Z] 10:44:28 INFO - PID 8731 | 1651661068505 Marionette TRACE Received observer notification quit-application
[task 2022-05-04T10:44:28.507Z] 10:44:28 INFO - PID 8731 | 1651661068505 Marionette TRACE Received observer notification quit-application
[task 2022-05-04T10:44:28.508Z] 10:44:28 INFO - PID 8731 | 1651661068505 Marionette DEBUG Marionette stopped listening
[task 2022-05-04T10:44:28.512Z] 10:44:28 INFO - PID 8731 | 1651661068511 Marionette DEBUG 0 <- [1,109,null,{"cause":"shutdown","forced":false}]
[task 2022-05-04T10:44:28.565Z] 10:44:28 INFO - PID 8731 | 1651661068564 webdriver::server DEBUG Teardown session
[task 2022-05-04T10:44:28.575Z] 10:44:28 INFO - PID 8731 | 1651661068573 Marionette DEBUG Closed connection 0
[task 2022-05-04T10:44:43.511Z] 10:44:43 INFO - PID 8731 | console.error: (new Error("SessionFile is closed", "resource:///modules/sessionstore/SessionFile.jsm", 379))
[task 2022-05-04T10:44:46.469Z] 10:44:46 INFO - PID 8731 | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"ContentParent: id=7f63e8015d00","state":{"remoteTypePrefix":"prealloc"},"filename":"/builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp","lineNumber":3633,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:162"]},{"name":"ContentParent: id=7f63df0ec000","state":{"remoteTypePrefix":"prealloc"},"filename":"/builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp","lineNumber":3633,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:162"]}] Barrier: profile-before-change
[task 2022-05-04T10:45:15.590Z] 10:45:15 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/element_send_keys/events.py | expected OK
[task 2022-05-04T10:45:15.612Z] 10:45:15 INFO - TEST-INFO took 55004ms
[task 2022-05-04T10:45:15.671Z] 10:45:15 INFO - Closing logging queue
[task 2022-05-04T10:45:15.672Z] 10:45:15 INFO - queue closed
[task 2022-05-04T10:45:15.682Z] 10:45:15 INFO - PID 9246 | 1651661115680 geckodriver INFO Listening on 127.0.0.1:44804
[task 2022-05-04T10:45:15.683Z] 10:45:15 INFO - Starting runner
[task 2022-05-04T10:45:16.009Z] 10:45:16 INFO - TEST-START | /webdriver/tests/element_send_keys/file_upload.py
|
||
Comment 1•2 years ago
|
||
Firefox hangs during shutdown.
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → DUPLICATE
|
||
Comment 2•1 year ago
|
||
Moving bug to Remote Protocol::Marionette component per bug 1815831.
Component: geckodriver → Marionette
Product: Testing → Remote Protocol
You need to log in
before you can comment on or make changes to this bug.
Description
•