Closed
Bug 1677750
Opened 4 years ago
Closed 3 years ago
Frequent windows10 ccov TEST-UNEXPECTED-TIMEOUT | /_mozilla/webdriver/new_session/debugger_address.py | expected OK
Categories
(Remote Protocol :: Marionette, defect, P5)
Tracking
(firefox84 unaffected, firefox85 disabled, firefox118 disabled)
RESOLVED
FIXED
85 Branch
| Tracking | Status | |
|---|---|---|
| firefox84 | --- | unaffected |
| firefox85 | --- | disabled |
| firefox118 | --- | disabled |
People
(Reporter: intermittent-bug-filer, Assigned: whimboo)
References
(Blocks 1 open bug, Regression)
Details
(Keywords: intermittent-failure, regression)
Attachments
(1 file)
Filed by: cbrindusan [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=322031671&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/FL0jiJ0xRySuNxcbyHfDUg/runs/0/artifacts/public/logs/live_backing.log
[task 2020-11-17T12:21:46.448Z] 12:21:46 INFO - TEST-START | /_mozilla/webdriver/new_session/debugger_address.py
[task 2020-11-17T12:21:46.776Z] 12:21:46 INFO - STDOUT: ============================= test session starts =============================
[task 2020-11-17T12:21:46.776Z] 12:21:46 INFO - STDOUT: platform win32 -- Python 2.7.15, pytest-unknown, py-1.5.2, pluggy-0.5.3.dev -- Z:\task_1605612265\build\venv\Scripts\python.exe
[task 2020-11-17T12:21:46.776Z] 12:21:46 INFO - STDOUT: rootdir: Z:\task_1605612265\build, inifile:
[task 2020-11-17T12:21:46.776Z] 12:21:46 INFO - STDOUT: collecting ...
[task 2020-11-17T12:21:46.781Z] 12:21:46 INFO - STDOUT: collected 3 items
[task 2020-11-17T12:21:46.781Z] 12:21:46 INFO - STDOUT: tests/web-platform/mozilla/tests/webdriver/new_session/debugger_address.py::test_debugger_address_not_set
[task 2020-11-17T12:21:46.788Z] 12:21:46 INFO - PID 1252 | 1605615706780 webdriver::server DEBUG -> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"binary": "Z:\\task_1605612265\\build\\application\\firefox\\firefox.exe", "prefs": {"network.process.enabled": false, "media.peerconnection.mtransport_process": false, "layers.d3d11.enable-blacklist": false, "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", "toolkit.asyncshutdown.log": true}}}}}
[task 2020-11-17T12:21:46.788Z] 12:21:46 INFO - PID 1252 | 1605615706781 geckodriver::capabilities DEBUG Trying to read firefox version from ini files
[task 2020-11-17T12:21:46.788Z] 12:21:46 INFO - PID 1252 | 1605615706782 geckodriver::capabilities DEBUG Found version 85.0a1
[task 2020-11-17T12:21:46.793Z] 12:21:46 INFO - PID 1252 | 1605615706786 mozrunner::runner INFO Running command: "Z:\\task_1605612265\\build\\application\\firefox\\firefox.exe" "--marionette" "-foreground" "-no-remote" "-profile" "C:\\Users\\task_1605612265\\AppData\\Local\\Temp\\rust_mozprofileNqnk4h"
[task 2020-11-17T12:21:46.793Z] 12:21:46 INFO - PID 1252 | 1605615706787 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1:2828
[task 2020-11-17T12:21:47.242Z] 12:21:47 INFO - PID 1252 | DEBUG: Adding blocker OS.File: flush pending requests, warn about unclosed files, shut down service. for phase xpcom-will-shutdown
[task 2020-11-17T12:21:47.242Z] 12:21:47 INFO - PID 1252 | DEBUG: Adding blocker OS.File: flush I/O queued before profileBeforeChange for phase profile-before-change
[task 2020-11-17T12:21:47.261Z] 12:21:47 INFO - PID 1252 | DEBUG: Adding blocker AddonManager: shutting down. for phase profile-before-change
[task 2020-11-17T12:21:47.344Z] 12:21:47 INFO - PID 1252 | DEBUG: Adding blocker ClientManagerService: start destroying IPC actors early for phase xpcom-will-shutdown
[task 2020-11-17T12:21:47.567Z] 12:21:47 INFO - PID 1252 | DEBUG: Adding blocker Flush WebExtension StartupCache for phase profile-before-change
[task 2020-11-17T12:21:47.977Z] 12:21:47 INFO - PID 1252 | DEBUG: Adding blocker JSON store: writing data for phase AddonManager: Waiting for providers to shut down.
[task 2020-11-17T12:21:47.982Z] 12:21:47 INFO - PID 1252 | DEBUG: Adding blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2020-11-17T12:21:47.987Z] 12:21:47 INFO - PID 1252 | DEBUG: Completed blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2020-11-17T12:21:48.007Z] 12:21:48 INFO - PID 1252 | DEBUG: Adding blocker XPIProvider shutdown for phase quit-application-granted
[task 2020-11-17T12:21:48.012Z] 12:21:48 INFO - PID 1252 | DEBUG: Adding blocker XPIProvider for phase AddonManager: Waiting for providers to shut down.
[task 2020-11-17T12:21:48.012Z] 12:21:48 INFO - PID 1252 | DEBUG: Adding blocker PluginProvider for phase AddonManager: Waiting for providers to shut down.
[task 2020-11-17T12:21:48.013Z] 12:21:48 INFO - PID 1252 | DEBUG: Adding blocker ServiceWorkerRegistrar: Flushing data for phase profile-before-change
[task 2020-11-17T12:21:48.031Z] 12:21:48 INFO - PID 1252 | DEBUG: Adding blocker CrashMonitor: Writing notifications to file after receiving profile-before-change for phase OS.File: Waiting for clients before profileBeforeChange
[task 2020-11-17T12:21:48.090Z] 12:21:48 INFO - PID 1252 | DEBUG: Adding blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2020-11-17T12:21:48.155Z] 12:21:48 INFO - PID 1252 | DEBUG: Adding blocker EnvironmentAddonBuilder for phase AddonManager: Waiting to start provider shutdown.
[task 2020-11-17T12:21:48.194Z] 12:21:48 INFO - PID 1252 | DEBUG: Adding blocker RemoteSettingsClient - finish IDB access. for phase profile-before-change
[task 2020-11-17T12:21:48.203Z] 12:21:48 INFO - PID 1252 | 1605615708193 Marionette TRACE Marionette enabled
[task 2020-11-17T12:21:48.447Z] 12:21:48 INFO - PID 1252 | 1605615708437 Marionette TRACE Received observer notification toplevel-window-ready
[task 2020-11-17T12:21:49.102Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker MediaShutdownManager: shutdown for phase profile-before-change
[task 2020-11-17T12:21:49.180Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker JSON store: writing data for phase profile-before-change
[task 2020-11-17T12:21:49.180Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker JSON store: writing data for phase profile-before-change
[task 2020-11-17T12:21:49.182Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker Flush AddonRepository for phase profile-before-change
[task 2020-11-17T12:21:49.202Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker Remote Settings profile-before-change for phase profile-before-change
[task 2020-11-17T12:21:49.592Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker GMPProvider for phase AddonManager: Waiting for providers to shut down.
[task 2020-11-17T12:21:49.611Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker PluginFinder: finding plugins to load for phase profile-change-teardown
[task 2020-11-17T12:21:49.611Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker ContentParent: id=1d7674f5000 for phase xpcom-will-shutdown
[task 2020-11-17T12:21:49.611Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker ContentParent: id=1d7674f5000 for phase profile-before-change
[task 2020-11-17T12:21:49.793Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker ServiceWorkerShutdownBlocker: shutting down Service Workers for phase profile-change-teardown
[task 2020-11-17T12:21:49.832Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker ContentParent: id=1d7682a8000 for phase xpcom-will-shutdown[task 2020-11-17T12:21:49.832Z] 12:21:49 INFO - PID 1252 | DEBUG: Adding blocker ContentParent: id=1d7682a8000 for phase profile-before-change
[task 2020-11-17T12:21:50.430Z] 12:21:50 INFO - PID 1252 | DEBUG: Adding blocker Places Clients shutdown for phase profile-change-teardown
[task 2020-11-17T12:21:50.430Z] 12:21:50 INFO - PID 1252 | DEBUG: Adding blocker Places Connection shutdown for phase profile-before-change
[task 2020-11-17T12:21:50.470Z] 12:21:50 INFO - PID 1252 | DEBUG: Adding blocker PageActions: purging unregistered actions from cache for phase profile-before-change
[task 2020-11-17T12:21:50.572Z] 12:21:50 INFO - PID 1252 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new Error("", "(unknown module)"))
[task 2020-11-17T12:21:50.615Z] 12:21:50 INFO - PID 1252 | DEBUG: Adding blocker Sqlite.jsm shutdown blocker for phase profile-before-change
[task 2020-11-17T12:21:50.615Z] 12:21:50 INFO - PID 1252 | DEBUG: Adding blocker content-prefs.sqlite#0: waiting for shutdown for phase Sqlite.jsm: wait until all connections are closed
[task 2020-11-17T12:21:50.615Z] 12:21:50 INFO - PID 1252 | DEBUG: Adding blocker Closing ContentPrefService2 connection. for phase Sqlite.jsm: wait until all clients have completed their task
[task 2020-11-17T12:21:50.637Z] 12:21:50 INFO - PID 1252 | DEBUG: Adding blocker Transaction (0) for phase content-prefs.sqlite#0: waiting for clients
[task 2020-11-17T12:21:50.757Z] 12:21:50 INFO - PID 1252 | DEBUG: Adding blocker sanitize.js: Sanitize on shutdown for phase Places Clients shutdown
[task 2020-11-17T12:21:50.918Z] 12:21:50 INFO - PID 1252 | DEBUG: Adding blocker DoHController: clear state and remove observers for phase profile-before-change
[task 2020-11-17T12:21:51.122Z] 12:21:51 INFO - PID 1252 | DEBUG: Adding blocker JSON store: writing data for phase profile-before-change
[task 2020-11-17T12:21:51.224Z] 12:21:51 INFO - PID 1252 | DEBUG: Completed blocker Transaction (0) for phase content-prefs.sqlite#0: waiting for clients
[task 2020-11-17T12:21:51.289Z] 12:21:51 INFO - PID 1252 | DEBUG: Adding blocker Transaction (1) for phase content-prefs.sqlite#0: waiting for clients
[task 2020-11-17T12:21:51.289Z] 12:21:51 INFO - PID 1252 | DEBUG: Adding blocker Transaction (2) for phase content-prefs.sqlite#0: waiting for clients
[task 2020-11-17T12:21:51.352Z] 12:21:51 INFO - PID 1252 | DEBUG: Adding blocker IOUtils Blocker for phase profile-before-change
[task 2020-11-17T12:21:51.395Z] 12:21:51 INFO - PID 1252 | DEBUG: Adding blocker DownloadAutoSaveView: writing data for phase profile-before-change
[task 2020-11-17T12:21:51.546Z] 12:21:51 INFO - PID 1252 | DEBUG: Adding blocker Places Expiration: shutdown for phase Places Connection shutdown
[task 2020-11-17T12:21:51.576Z] 12:21:51 INFO - PID 1252 | DEBUG: Completed blocker Transaction (1) for phase content-prefs.sqlite#0: waiting for clients[task 2020-11-17T12:22:39.671Z] 12:22:39 INFO - PID 1252 | DEBUG: Starting phase profile-before-change-telemetry
[task 2020-11-17T12:22:39.671Z] 12:22:39 INFO - PID 1252 | DEBUG: Spinning the event loop
[task 2020-11-17T12:22:39.852Z] 12:22:39 INFO - PID 1252 | DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-17T12:22:39.862Z] 12:22:39 INFO - PID 1252 | DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-17T12:22:39.881Z] 12:22:39 INFO - PID 1252 | DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-17T12:22:39.899Z] 12:22:39 INFO - PID 1252 | DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-17T12:22:39.909Z] 12:22:39 INFO - PID 1252 | DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-17T12:22:39.934Z] 12:22:39 INFO - PID 1252 | DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-17T12:22:39.934Z] 12:22:39 INFO - PID 1252 | DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-17T12:22:39.939Z] 12:22:39 INFO - PID 1252 | DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-17T12:22:39.944Z] 12:22:39 INFO - PID 1252 | DEBUG: Completed blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2020-11-17T12:22:39.945Z] 12:22:39 INFO - PID 1252 | DEBUG: Finished phase profile-before-change-telemetry
[task 2020-11-17T12:22:39.946Z] 12:22:39 INFO - PID 1252 | 1605615759939 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2020-11-17T12:22:39.946Z] 12:22:39 INFO - PID 1252 | 1605615759940 Marionette DEBUG Resetting recommended pref apz.content_response_timeout
[task 2020-11-17T12:22:39.947Z] 12:22:39 INFO - PID 1252 | 1605615759940 Marionette DEBUG Resetting recommended pref browser.contentblocking.introCount
[task 2020-11-17T12:22:39.948Z] 12:22:39 INFO - PID 1252 | 1605615759941 Marionette DEBUG Resetting recommended pref browser.download.panel.shown
[task 2020-11-17T12:22:39.948Z] 12:22:39 INFO - PID 1252 | 1605615759941 Marionette DEBUG Resetting recommended pref browser.newtabpage.enabled
[task 2020-11-17T12:22:39.949Z] 12:22:39 INFO - PID 1252 | 1605615759943 Marionette DEBUG Resetting recommended pref browser.pagethumbnails.capturing_disabled
[task 2020-11-17T12:22:39.950Z] 12:22:39 INFO - PID 1252 | 1605615759943 Marionette DEBUG Resetting recommended pref browser.search.update
[task 2020-11-17T12:22:39.950Z] 12:22:39 INFO - PID 1252 | 1605615759943 Marionette DEBUG Resetting recommended pref browser.tabs.disableBackgroundZombification
[task 2020-11-17T12:22:39.951Z] 12:22:39 INFO - PID 1252 | 1605615759944 Marionette DEBUG Resetting recommended pref browser.tabs.remote.separatePrivilegedContentProcess
[task 2020-11-17T12:22:39.952Z] 12:22:39 INFO - PID 1252 | 1605615759944 Marionette DEBUG Resetting recommended pref browser.tabs.unloadOnLowMemory
[task 2020-11-17T12:22:39.953Z] 12:22:39 INFO - PID 1252 | 1605615759945 Marionette DEBUG Resetting recommended pref browser.tabs.warnOnCloseOtherTabs
[task 2020-11-17T12:22:39.953Z] 12:22:39 INFO - PID 1252 | 1605615759945 Marionette DEBUG Resetting recommended pref browser.tabs.warnOnOpen
[task 2020-11-17T12:22:39.954Z] 12:22:39 INFO - PID 1252 | 1605615759945 Marionette DEBUG Resetting recommended pref browser.toolbars.bookmarks.visibility
[task 2020-11-17T12:22:39.954Z] 12:22:39 INFO - PID 1252 | 1605615759946 Marionette DEBUG Resetting recommended pref browser.usedOnWindows10.introURL
[task 2020-11-17T12:22:39.955Z] 12:22:39 INFO - PID 1252 | 1605615759946 Marionette DEBUG Resetting recommended pref browser.urlbar.suggest.searches
[task 2020-11-17T12:22:39.956Z] 12:22:39 INFO - PID 1252 | 1605615759948 Marionette DEBUG Resetting recommended pref datareporting.policy.dataSubmissionPolicyAccepted
[task 2020-11-17T12:22:39.956Z] 12:22:39 INFO - PID 1252 | 1605615759949 Marionette DEBUG Resetting recommended pref dom.disable_beforeunload
[task 2020-11-17T12:22:39.957Z] 12:22:39 INFO - PID 1252 | 1605615759949 Marionette DEBUG Resetting recommended pref dom.disable_open_during_load
[task 2020-11-17T12:22:39.958Z] 12:22:39 INFO - PID 1252 | 1605615759949 Marionette DEBUG Resetting recommended pref dom.file.createInChild
[task 2020-11-17T12:22:39.958Z] 12:22:39 INFO - PID 1252 | 1605615759950 Marionette DEBUG Resetting recommended pref dom.max_chrome_script_run_time
[task 2020-11-17T12:22:39.959Z] 12:22:39 INFO - PID 1252 | 1605615759950 Marionette DEBUG Resetting recommended pref dom.max_script_run_time
[task 2020-11-17T12:22:39.960Z] 12:22:39 INFO - PID 1252 | 1605615759952 Marionette DEBUG Resetting recommended pref dom.push.connection.enabled
[task 2020-11-17T12:22:39.960Z] 12:22:39 INFO - PID 1252 | 1605615759952 Marionette DEBUG Resetting recommended pref extensions.getAddons.cache.enabled
[task 2020-11-17T12:22:39.961Z] 12:22:39 INFO - PID 1252 | 1605615759953 Marionette DEBUG Resetting recommended pref extensions.getAddons.discovery.api_url
[task 2020-11-17T12:22:39.961Z] 12:22:39 INFO - PID 1252 | 1605615759953 Marionette DEBUG Resetting recommended pref network.http.prompt-temp-redirect
[task 2020-11-17T12:22:39.961Z] 12:22:39 INFO - PID 1252 | 1605615759953 Marionette DEBUG Resetting recommended pref privacy.trackingprotection.enabled
[task 2020-11-17T12:22:39.961Z] 12:22:39 INFO - PID 1252 | 1605615759953 Marionette DEBUG Resetting recommended pref security.fileuri.strict_origin_policy[task 2020-11-17T12:22:39.962Z] 12:22:39 INFO - PID 1252 | 1605615759954 Marionette DEBUG Resetting recommended pref security.notification_enable_delay
[task 2020-11-17T12:22:39.962Z] 12:22:39 INFO - PID 1252 | 1605615759954 Marionette DEBUG Resetting recommended pref signon.autofillForms
[task 2020-11-17T12:22:39.962Z] 12:22:39 INFO - PID 1252 | 1605615759956 Marionette DEBUG Resetting recommended pref signon.rememberSignons
[task 2020-11-17T12:22:39.964Z] 12:22:39 INFO - PID 1252 | 1605615759959 Marionette DEBUG Marionette stopped listening
[task 2020-11-17T12:22:39.964Z] 12:22:39 INFO - PID 1252 | DEBUG: Starting phase xpcom-will-shutdown
[task 2020-11-17T12:22:39.964Z] 12:22:39 INFO - PID 1252 | DEBUG: Spinning the event loop
[task 2020-11-17T12:22:40.053Z] 12:22:40 INFO - PID 1252 | DEBUG: Completed blocker OS.File: flush pending requests, warn about unclosed files, shut down service. for phase xpcom-will-shutdown
[task 2020-11-17T12:22:40.078Z] 12:22:40 INFO - PID 1252 | DEBUG: Finished phase xpcom-will-shutdown
[task 2020-11-17T12:22:40.083Z] 12:22:40 INFO - PID 1252 |
[task 2020-11-17T12:22:40.088Z] 12:22:40 INFO - PID 1252 | ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-11-17T12:22:40.094Z] 12:22:40 INFO - PID 1252 |
[task 2020-11-17T12:22:40.094Z] 12:22:40 INFO - PID 1252 | DEBUG: Starting phase web-workers-shutdown
[task 2020-11-17T12:22:40.094Z] 12:22:40 INFO - PID 1252 | DEBUG: Spinning the event loop
[task 2020-11-17T12:22:40.095Z] 12:22:40 INFO - PID 1252 | DEBUG: Finished phase web-workers-shutdown
[task 2020-11-17T12:22:40.278Z] 12:22:40 INFO - PID 1252 | 1605615760249 RemoteAgent ERROR unable to stop listener: [Exception... "Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIWindowMediator.getEnumerator]" nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)" location: "JS frame :: chrome://remote/content/observers/TargetObserver.jsm :: stop :: line 59" data: no] Stack trace: stop()@TargetObserver.jsm:59
[task 2020-11-17T12:22:40.278Z] 12:22:40 INFO - PID 1252 | unwatchForTabs()@TargetList.jsm:71
[task 2020-11-17T12:22:40.278Z] 12:22:40 INFO - PID 1252 | unwatchForTargets()@TargetList.jsm:38
[task 2020-11-17T12:22:40.279Z] 12:22:40 INFO - PID 1252 | destructor()@TargetList.jsm:110
[task 2020-11-17T12:22:40.279Z] 12:22:40 INFO - PID 1252 | close()@RemoteAgent.jsm:123
[task 2020-11-17T12:22:41.467Z] 12:22:41 INFO - TEST-UNEXPECTED-TIMEOUT | /_mozilla/webdriver/new_session/debugger_address.py | expected OK```
|
||
Updated•4 years ago
|
Component: General → geckodriver
Summary: Intermittent TEST-UNEXPECTED-TIMEOUT | mozilla/tests/webdriver/new_session/debugger_address.py | expected OK → Frequent windows10 TEST-UNEXPECTED-TIMEOUT | mozilla/tests/webdriver/new_session/debugger_address.py | expected OK
|
Assignee | |
Comment 1•4 years ago
|
||
Note the following delay in startup:
[task 2020-11-17T12:21:51.576Z] 12:21:51 INFO - PID 1252 | DEBUG: Completed blocker Transaction (1) for phase content-prefs.sqlite#0: waiting for clients[task 2020-11-17T12:22:39.671Z] 12:22:39 INFO - PID 1252 | DEBUG: Starting phase profile-before-change-telemetry
[task 2020-11-17T12:22:39.671Z] 12:22:39 INFO - PID 1252 | DEBUG: Spinning the event loop
..
[task 2020-11-17T12:22:39.944Z] 12:22:39 INFO - PID 1252 | DEBUG: Completed blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2020-11-17T12:22:39.945Z] 12:22:39 INFO - PID 1252 | DEBUG: Finished phase profile-before-change-telemetry
[task 2020-11-17T12:22:39.946Z] 12:22:39 INFO - PID 1252 | 1605615759939 Marionette TRACE Received observer notification xpcom-will-shutdown
We are spending 48s after Starting phase profile-before-change-telemetry and before Spinning the event loop. And then Firefox just shutdown.
This failure can be seen since the test has been added via bug 1669218. I will try to run that job a couple of times with Pernosco enabled. Maybe we can figure out what's happening here. Also note this is only happening for opt/ccov builds. As such Marco might be interested in.
I will do a try push once the branch is open again.
Blocks: 1669746
status-firefox84:
--- → affected
status-firefox85:
--- → affected
Regressed by: 1669218
Summary: Frequent windows10 TEST-UNEXPECTED-TIMEOUT | mozilla/tests/webdriver/new_session/debugger_address.py | expected OK → Frequent windows10 ccov TEST-UNEXPECTED-TIMEOUT | mozilla/tests/webdriver/new_session/debugger_address.py | expected OK
|
|
Assignee | |
Comment 2•4 years ago
|
||
|
||
Updated•4 years ago
|
Summary: Frequent windows10 ccov TEST-UNEXPECTED-TIMEOUT | mozilla/tests/webdriver/new_session/debugger_address.py | expected OK → Frequent windows10 ccov TEST-UNEXPECTED-TIMEOUT | /_mozilla/webdriver/new_session/debugger_address.py | expected OK
|
|
Assignee | |
Comment 3•4 years ago
|
||
I always forget that Pernosco only works on Linux. Marco, I assume we should mark this test as flaky for ccov builds? It's not clear to me why it's hanging given that we use the same command line arguments also for all the other tests. Do you know of a similar issue while running other tests?
Flags: needinfo?(mcastelluccio)
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 5•3 years ago
|
||
Is there any chance this test causes Firefox to be restarted multiple times? That could be one reason why it takes so long (the ccov builds are super slow at shutdown, as they need to output the coverage counters in a lot of files).
Flags: needinfo?(mcastelluccio)
|
|
Assignee | |
Comment 6•3 years ago
|
||
Yes, each test in this file has to restart Firefox. Each of the Firefox sessions is very-short lived. So I assume that we should just skip them for ccov?
Flags: needinfo?(mcastelluccio)
|
|
||
Comment 7•3 years ago
|
||
(In reply to Henrik Skupin (:whimboo) [⌚️UTC+2] from comment #6)
Yes, each test in this file has to restart Firefox. Each of the Firefox sessions is very-short lived. So I assume that we should just skip them for ccov?
I think that's the best course of action. This test is bound to be super slow under ccov.
Flags: needinfo?(mcastelluccio)
|
|
Assignee | |
Comment 8•3 years ago
|
||
Ok, so given that this only happens for ccov builds on Windows, lets only disable the tests there.
OS: Unspecified → Windows
Hardware: Unspecified → All
|
|
Assignee | |
Comment 9•3 years ago
|
||
|
||
Updated•3 years ago
|
Assignee: nobody → hskupin
Status: NEW → ASSIGNED
|
||
Comment 10•3 years ago
|
||
Pushed by hskupin@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/ff2a53ac9e8b [wdspec] Disable debugger_address.py for code coverage builds on Windows. r=webdriver-reviewers,marco,jgraham
|
|
||
Comment 11•3 years ago
|
||
| bugherder | ||
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → 85 Branch
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 13•3 years ago
|
||
The patch landed in nightly and beta is affected.
:whimboo, is this bug important enough to require an uplift?
If not please set status_beta to wontfix.
For more information, please visit auto_nag documentation.
Flags: needinfo?(hskupin)
|
||
Updated•3 years ago
|
Flags: needinfo?(hskupin)
|
|
Assignee | |
Comment 14•2 years ago
|
||
This bug should not have been closed because the patch just disabled the test but didn't fix it. As it looks like I'm not allowed to reopen this bug.
Ryan, do you have a way to reopen?
Flags: needinfo?(ryanvm)
|
|
||
Updated•2 years ago
|
Keywords: regression
|
|
Assignee | |
Comment 16•2 years ago
|
||
I talked with dkl and it's a expected behavior right now for any kind of user. I filed bug 1790825 to allow reopening of old bugs by users with at least edit permissions. Will reopen once that bug is fixed.
|
||
Comment 17•1 year ago
|
||
Moving bug to Remote Protocol::Marionette component per bug 1815831.
Component: geckodriver → Marionette
Product: Testing → Remote Protocol
|
|
Assignee | |
Comment 18•8 months ago
|
||
Glob or dkl could one of you please reopen the bug? I would prefer that compared to cloning because web-platform-tests have metadata that include this bug as reference. Thanks.
|
||
Comment 19•8 months ago
|
||
It isn't possible to reopen bugs that were closed so long ago, even for admins.
You'll have to file a new bug.
Flags: needinfo?(glob)
Flags: needinfo?(dkl)
|
|
Assignee | |
Comment 20•8 months ago
|
||
Ok, thanks. Then there is bug 1849672 now.
You need to log in
before you can comment on or make changes to this bug.
Description
•