1666870 - Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/get_title/get.py | expected OK

Status: RESOLVED DUPLICATE of bug 1498944

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: archaeopteryx [at] coole-files.de
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=316045331&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/bxZe1sUDRa6gTlfZcWprtw/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-09-18T06:42:32.844Z] 06:42:32     INFO - WebDriver HTTP server listening at http://127.0.0.1:52835/
[task 2020-09-18T06:42:32.845Z] 06:42:32     INFO - TEST-START | /webdriver/tests/get_title/get.py
[task 2020-09-18T06:42:33.132Z] 06:42:33     INFO - STDOUT: ============================= test session starts =============================
[task 2020-09-18T06:42:33.132Z] 06:42:33     INFO - STDOUT: platform win32 -- Python 2.7.15, pytest-unknown, py-1.5.2, pluggy-0.5.3.dev -- Z:\task_1600410978\build\venv\Scripts\python.exe
[task 2020-09-18T06:42:33.132Z] 06:42:33     INFO - STDOUT: rootdir: Z:\task_1600410978\build, inifile:
[task 2020-09-18T06:42:33.132Z] 06:42:33     INFO - STDOUT: collecting ... 
[task 2020-09-18T06:42:33.141Z] 06:42:33     INFO - STDOUT: collected 7 items
[task 2020-09-18T06:42:33.141Z] 06:42:33     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/get_title/get.py::test_payload 
[task 2020-09-18T06:42:33.151Z] 06:42:33     INFO - PID 3716 | 1600411353141	webdriver::server	DEBUG	-> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"binary": "Z:\\task_1600410978\\build\\application\\firefox\\firefox.exe", "prefs": {"network.process.enabled": false, "toolkit.asyncshutdown.log": true, "network.dns.localDomains": "www1.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op88.web-platform.test,op36.not-web-platform.test,op53.not-web-platform.test,op50.not-web-platform.test,xn--lve-6lad.www.web-platform.test,op98.web-platform.test,op24.not-web-platform.test,op31.not-web-platform.test,op95.not-web-platform.test,op85.web-platform.test,op83.not-web-platform.test,www2.not-web-platform.test,xn--lve-6lad.www.not-web-platform.test,op73.not-web-platform.test,op8.web-platform.test,www2.www2.not-web-platform.test,op89.web-platform.test,op66.web-platform.test,xn--lve-6lad.web-platform.test,op19.not-web-platform.test,www1.www2.web-platform.test,op72.web-platform.test,op24.web-platform.test,op21.not-web-platform.test,xn--lve-6lad.not-web-platform.test,op41.web-platform.test,op79.web-platform.test,op81.not-web-platform.test,op70.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.not-web-platform.test,op78.not-web-platform.test,op6.not-web-platform.test,www1.www.not-web-platform.test,op40.not-web-platform.test,op25.not-web-platform.test,op3.not-web-platform.test,op65.not-web-platform.test,op91.web-platform.test,www.www2.web-platform.test,op80.not-web-platform.test,op59.web-platform.test,op52.not-web-platform.test,xn--lve-6lad.xn--lve-6lad.web-platform.test,op68.not-web-platform.test,op45.not-web-platform.test,op71.not-web-platform.test,op72.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.web-platform.test,op39.web-platform.test,op90.not-web-platform.test,op60.web-platform.test,op58.web-platform.test,op28.web-platform.test,www1.web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.web-platform.test,op14.web-platform.test,op89.not-web-platform.test,op69.web-platform.test,op49.not-web-platform.test,op40.web-platform.test,op2.not-web-platform.test,op5.not-web-platform.test,www.www2.not-web-platform.test,op77.not-web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op7.web-platform.test,op74.web-platform.test,op79.not-web-platform.test,op82.not-web-platform.test,www.www1.web-platform.test,op12.not-web-platform.test,op39.not-web-platform.test,op31.web-platform.test,www.not-web-platform.test,www.www.not-web-platform.test,op44.not-web-platform.test,www1.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.web-platform.test,op58.not-web-platform.test,op14.not-web-platform.test,op30.not-web-platform.test,op62.not-web-platform.test,op61.not-web-platform.test,op92.not-web-platform.test,www2.xn--lve-6lad.web-platform.test,op29.not-web-platform.test,op18.web-platform.test,op73.web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op77.web-platform.test,op12.web-platform.test,op54.web-platform.test,op63.web-platform.test,op71.web-platform.test,www2.www1.not-web-platform.test,op95.web-platform.test,op16.web-platform.test,op36.web-platform.test,op27.web-platform.test,www.www.web-platform.test,op98.not-web-platform.test,op64.not-web-platform.test,op29.web-platform.test,op9.web-platform.test,op26.not-web-platform.test,op94.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.not-web-platform.test,op44.web-platform.test,op94.not-web-platform.test,op33.web-platform.test,op38.not-web-platform.test,op33.not-web-platform.test,op84.web-platform.test,www1.www1.not-web-platform.test,op23.not-web-platform.test,op57.not-web-platform.test,op54.not-web-platform.test,op85.not-web-platform.test,www2.www2.web-platform.test,op46.not-web-platform.test,op97.not-web-platform.test,op32.web-platform.test,op61.web-platform.test,op70.web-platform.test,www2.web-platform.test,op32.not-web-platform.test,op60.not-web-platform.test,op4.web-platform.test,op43.web-platform.test,op7.not-web-platform.test,op78.web-platform.test,op26.web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op96.not-web-platform.test,op51.not-web-platform.test,op41.not-web-platform.test,op76.web-platform.test,op52.web-platform.test,op99.web-platform.test,op35.not-web-platform.test,op99.not-web-platform.test,op86.web-platform.test,not-web-platform.test,op42.not-web-platform.test,op46.web-platform.test,op67.not-web-platform.test,op17.web-platform.test,op90.web-platform.test,op93.web-platform.test,op37.not-web-platform.test,op48.not-web-platform.test,op10.web-platform.test,op55.not-web-platform.test,op4.not-web-platform.test,www1.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op55.web-platform.test,xn--lve-6lad.www2.web-platform.test,op47.web-platform.test,op51.web-platform.test,op45.web-platform.test,op80.web-platform.test,op68.web-platform.test,op49.web-platform.test,op57.web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op56.not-web-platform.test,op35.web-platform.test,op84.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op34.not-web-platform.test,op6.web-platform.test,web-platform.test,op67.web-platform.test,op69.not-web-platform.test,op11.not-web-platform.test,op93.not-web-platform.test,www1.www.web-platform.test,op86.not-web-platform.test,op8.not-web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op92.web-platform.test,xn--lve-6lad.www1.not-web-platform.test,op15.web-platform.test,op13.not-web-platform.test,op13.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.web-platform.test,op75.web-platform.test,op20.not-web-platform.test,op76.not-web-platform.test,op64.web-platform.test,op97.web-platform.test,op37.web-platform.test,op56.web-platform.test,op62.web-platform.test,op82.web-platform.test,op25.web-platform.test,op11.web-platform.test,www.xn--lve-6lad.not-web-platform.test,www2.www1.web-platform.test,op27.not-web-platform.test,op50.web-platform.test,op17.not-web-platform.test,op38.web-platform.test,www2.www.not-web-platform.test,xn--lve-6lad.www1.web-platform.test,op75.not-web-platform.test,op83.web-platform.test,op81.web-platform.test,op15.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.not-web-platform.test,op20.web-platform.test,op3.web-platform.test,www1.www2.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op2.web-platform.test,op21.web-platform.test,op23.web-platform.test,op42.web-platform.test,op47.not-web-platform.test,www1.www1.web-platform.test,op18.not-web-platform.test,op22.web-platform.test,xn--lve-6lad.xn--lve-6lad.not-web-platform.test,op63.not-web-platform.test,op28.not-web-platform.test,op22.not-web-platform.test,op65.web-platform.test,www.www1.not-web-platform.test,www1.xn--lve-6lad.web-platform.test,op43.not-web-platform.test,op66.not-web-platform.test,www2.www.web-platform.test,op96.web-platform.test,op91.not-web-platform.test,www.xn--lve-6lad.web-platform.test,op1.web-platform.test,op74.not-web-platform.test,op87.web-platform.test,op59.not-web-platform.test,op19.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.not-web-platform.test,op9.not-web-platform.test,op88.not-web-platform.test,op53.web-platform.test,www2.xn--lve-6lad.not-web-platform.test,op87.not-web-platform.test,op30.web-platform.test,op10.not-web-platform.test,op48.web-platform.test,op16.not-web-platform.test,op34.web-platform.test,op1.not-web-platform.test,www.web-platform.test,op5.web-platform.test,www1.xn--lve-6lad.not-web-platform.test,xn--lve-6lad.www2.not-web-platform.test", "media.peerconnection.mtransport_process": false}}}}}
[task 2020-09-18T06:42:33.151Z] 06:42:33     INFO - PID 3716 | 1600411353142	geckodriver::capabilities	DEBUG	Trying to read firefox version from ini files
[task 2020-09-18T06:42:33.152Z] 06:42:33     INFO - PID 3716 | 1600411353143	geckodriver::capabilities	DEBUG	Found version 82.0a1
[task 2020-09-18T06:42:33.154Z] 06:42:33     INFO - PID 3716 | 1600411353147	mozrunner::runner	INFO	Running command: "Z:\\task_1600410978\\build\\application\\firefox\\firefox.exe" "--marionette" "-foreground" "-no-remote" "-profile" "C:\\Users\\task_1600410978\\AppData\\Local\\Temp\\rust_mozprofileIEXjgZ"
[task 2020-09-18T06:42:33.154Z] 06:42:33     INFO - PID 3716 | 1600411353149	geckodriver::marionette	DEBUG	Waiting 60s to connect to browser on 127.0.0.1:2828
[task 2020-09-18T06:42:33.339Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker OS.File: flush pending requests, warn about unclosed files, shut down service. for phase xpcom-will-shutdown
[task 2020-09-18T06:42:33.339Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker OS.File: flush I/O queued before profileBeforeChange for phase profile-before-change
[task 2020-09-18T06:42:33.339Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker AddonManager: shutting down. for phase profile-before-change
[task 2020-09-18T06:42:33.364Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker ClientManagerService: start destroying IPC actors early for phase xpcom-will-shutdown
[task 2020-09-18T06:42:33.443Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker Flush WebExtension StartupCache for phase profile-before-change
[task 2020-09-18T06:42:33.574Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker JSON store: writing data for phase AddonManager: Waiting for providers to shut down.
[task 2020-09-18T06:42:33.574Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2020-09-18T06:42:33.574Z] 06:42:33     INFO - PID 3716 | DEBUG: Completed blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2020-09-18T06:42:33.584Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker XPIProvider shutdown for phase quit-application-granted
[task 2020-09-18T06:42:33.584Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker XPIProvider for phase AddonManager: Waiting for providers to shut down.
[task 2020-09-18T06:42:33.584Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker PluginProvider for phase AddonManager: Waiting for providers to shut down.
[task 2020-09-18T06:42:33.584Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker ServiceWorkerRegistrar: Flushing data for phase profile-before-change
[task 2020-09-18T06:42:33.584Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker CrashMonitor: Writing notifications to file after receiving profile-before-change for phase OS.File: Waiting for clients before profileBeforeChange
[task 2020-09-18T06:42:33.685Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2020-09-18T06:42:33.685Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker EnvironmentAddonBuilder for phase AddonManager: Waiting to start provider shutdown.
[task 2020-09-18T06:42:33.703Z] 06:42:33     INFO - PID 3716 | DEBUG: Adding blocker RemoteSettingsClient - finish IDB access. for phase profile-before-change
[task 2020-09-18T06:42:33.703Z] 06:42:33     INFO - PID 3716 | 1600411353697	Marionette	TRACE	Marionette enabled
[task 2020-09-18T06:42:33.763Z] 06:42:33     INFO - PID 3716 | 1600411353751	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2020-09-18T06:43:02.855Z] 06:43:02     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/get_title/get.py | expected OK```

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Missing marionette-startup-requested observer notification due to a hanging startup of Firefox.

Comment 2

[BMO Automation]

Moving bug to Remote Protocol::Marionette component per bug 1815831.