Closed
Bug 1707100
Opened 4 years ago
Closed 4 years ago
Intermittent telemetry/marionette/tests/client/test_search_counts_across_sessions.py TestSearchCounts.test_search_counts | AssertionError: 'af738e45-c767-374d-b222-e6bf5532fa1b' is not None
Categories
(Toolkit :: Telemetry, defect, P5)
Toolkit
Telemetry
Tracking
()
RESOLVED
DUPLICATE
of bug 1608807
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: assertion, intermittent-failure)
Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=337487286&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/fdAHXpphQEu6xOIlvz1SMg/runs/0/artifacts/public/logs/live_backing.log
[task 2021-04-22T20:36:24.217Z] 20:36:24 INFO - TEST-START | telemetry/marionette/tests/client/test_search_counts_across_sessions.py TestSearchCounts.test_search_counts
[task 2021-04-22T20:36:24.217Z] 20:36:24 INFO - Application command: /opt/worker/tasks/task_161912368830776/build/application/Firefox.app/Contents/MacOS/firefox -no-remote -marionette -foreground -profile /opt/worker/tasks/task_161912368830776/build/tmpqfo6zrmh.mozrunner
[task 2021-04-22T20:36:24.451Z] 20:36:24 INFO - 1619123784450 Toolkit.Telemetry TRACE TelemetryController::observe - profile-after-change notified.
[task 2021-04-22T20:36:24.451Z] 20:36:24 INFO - 1619123784450 Toolkit.Telemetry TRACE TelemetryController::setupTelemetry
[task 2021-04-22T20:36:24.451Z] 20:36:24 INFO - 1619123784451 Toolkit.Telemetry TRACE TelemetryReportingPolicy::setup
[task 2021-04-22T20:36:24.452Z] 20:36:24 INFO - 1619123784451 Toolkit.Telemetry CONFIG TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2021-04-22T20:36:24.452Z] 20:36:24 INFO - 1619123784451 Toolkit.Telemetry TRACE TelemetrySession::earlyInit
[task 2021-04-22T20:36:24.455Z] 20:36:24 INFO - 1619123784455 Toolkit.Telemetry INFO TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-04-22T20:36:24.455Z] 20:36:24 INFO - 1619123784455 Toolkit.Telemetry TRACE UpdatePing::init - enabled: true
[task 2021-04-22T20:36:24.458Z] 20:36:24 INFO - 1619123784458 Toolkit.Telemetry TRACE TelemetryEnvironment::constructor
[task 2021-04-22T20:36:24.505Z] 20:36:24 INFO - 1619123784505 Toolkit.Telemetry TRACE TelemetryEnvironment::_getGFXData - Only one display adapter detected.
[task 2021-04-22T20:36:24.506Z] 20:36:24 INFO - 1619123784506 Toolkit.Telemetry TRACE TelemetryEnvironment::_updateSearchEngine - ignoring early call
[task 2021-04-22T20:36:24.506Z] 20:36:24 INFO - 1619123784506 Toolkit.Telemetry TRACE TelemetryEnvironment::_updateAddons
[task 2021-04-22T20:36:24.507Z] 20:36:24 INFO - 1619123784507 Toolkit.Telemetry TRACE TelemetryEnvironment::registerChangeListener for CrashAnnotator
[task 2021-04-22T20:36:24.514Z] 20:36:24 INFO - 1619123784514 Marionette INFO Marionette enabled
[task 2021-04-22T20:36:24.607Z] 20:36:24 INFO - 1619123784606 Marionette TRACE Received observer notification toplevel-window-ready
[task 2021-04-22T20:36:24.620Z] 20:36:24 INFO - 1619123784620 Toolkit.Telemetry TRACE TelemetryEnvironment::_updateAddons: addons differ
[task 2021-04-22T20:36:24.954Z] 20:36:24 INFO - 1619123784953 Toolkit.Telemetry TRACE TelemetryController::observe - app-startup notified.
[task 2021-04-22T20:36:24.954Z] 20:36:24 INFO - 1619123784954 Toolkit.Telemetry CONFIG TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2021-04-22T20:36:25.009Z] 20:36:25 INFO - 1619123785008 Toolkit.Telemetry TRACE TelemetryEnvironment::observe - aTopic: compositor:created, aData: null
[task 2021-04-22T20:36:25.038Z] 20:36:25 INFO - 1619123785038 Toolkit.Telemetry TRACE TelemetrySession::observe - xul-window-visible notified.
[task 2021-04-22T20:36:25.054Z] 20:36:25 INFO - 1619123785054 Toolkit.Telemetry TRACE TelemetryController::observe - app-startup notified.
[task 2021-04-22T20:36:25.055Z] 20:36:25 INFO - 1619123785054 Toolkit.Telemetry CONFIG TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2021-04-22T20:36:28.292Z] 20:36:28 INFO - 1619123788289 Marionette DEBUG Closed connection 0
[task 2021-04-22T20:36:28.293Z] 20:36:28 INFO - 1619123788289 Marionette DEBUG Accepted connection 1 from 127.0.0.1:49607
[task 2021-04-22T20:36:28.293Z] 20:36:28 INFO - 1619123788290 Toolkit.Telemetry TRACE TelemetrySend::Scheduler::_doSendTask - bailing out after sending, shutdown: false, pendingPingCount: 0
[task 2021-04-22T20:36:28.293Z] 20:36:28 INFO - 1619123788292 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-04-22T20:36:28.297Z] 20:36:28 INFO - 1619123788296 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"e8f5dcd7-951c-5447-9c1f-854a5a5397c8","capabilities":{"browserName":"firefox","browserVersion":"89.0" ... /tmpqfo6zrmh.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2021-04-22T20:36:28.298Z] 20:36:28 INFO - 1619123788298 Marionette DEBUG 1 -> [0,2,"Marionette:SetContext",{"value":"content"}]
[task 2021-04-22T20:36:28.298Z] 20:36:28 INFO - 1619123788298 Marionette DEBUG 1 <- [1,2,null,{"value":null}]
[task 2021-04-22T20:36:28.301Z] 20:36:28 INFO - 1619123788301 Marionette DEBUG 1 -> [0,3,"Marionette:GetContext",{}]
[task 2021-04-22T20:36:28.301Z] 20:36:28 INFO - 1619123788301 Marionette DEBUG 1 <- [1,3,null,{"value":"content"}]
[task 2021-04-22T20:36:28.302Z] 20:36:28 INFO - 1619123788302 Marionette DEBUG 1 -> [0,4,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-04-22T20:36:28.303Z] 20:36:28 INFO - 1619123788302 Marionette DEBUG 1 <- [1,4,null,{"value":null}]
[task 2021-04-22T20:36:28.304Z] 20:36:28 INFO - 1619123788303 Toolkit.Telemetry TRACE TelemetryEnvironment::_updateAddons
[task 2021-04-22T20:36:28.306Z] 20:36:28 INFO - 1619123788306 Toolkit.Telemetry TRACE TelemetryEnvironment::_updateAddons: addons differ
[task 2021-04-22T20:36:28.306Z] 20:36:28 INFO - 1619123788306 Toolkit.Telemetry TRACE TelemetryEnvironment::_startWatchingPrefs - [object Map]
[task 2021-04-22T20:36:28.307Z] 20:36:28 INFO - 1619123788307 Marionette DEBUG 1 -> [0,5,"WebDriver:TakeScreenshot",{"id":null,"full":true,"hash":false,"scroll":true}]
[task 2021-04-22T20:36:28.308Z] 20:36:28 INFO - 1619123788308 Marionette TRACE [15] MarionetteCommands actor created for window id 4
[task 2021-04-22T20:36:28.372Z] 20:36:28 INFO - 1619123788371 Marionette DEBUG 1 <- [1,5,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABQAAAAPNCAYAAADWQsenAAAgAElEQVR4nOzdaXSTdf7//7n5O+eL95JzMHdA5zTC/0wVB76WowydYQA3H ... AEAAAAgBwTAAEAAAAgxwRAAAAAAMgxARAAAAAAckwABAAAAIAcEwABAAAAIMcEQAAAAADIMQEQAAAAAHJMAAQAAACAHPv/SFWAsUVYCJAAAAAASUVORK5CYII="}]
[task 2021-04-22T20:36:28.374Z] 20:36:28 INFO - 1619123788374 Marionette DEBUG 1 -> [0,6,"Marionette:SetContext",{"value":"content"}]
[task 2021-04-22T20:36:28.374Z] 20:36:28 INFO - 1619123788374 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2021-04-22T20:36:28.375Z] 20:36:28 INFO - 1619123788374 Marionette DEBUG 1 -> [0,7,"Marionette:GetContext",{}]
[task 2021-04-22T20:36:28.375Z] 20:36:28 INFO - 1619123788375 Marionette DEBUG 1 <- [1,7,null,{"value":"content"}]
[task 2021-04-22T20:36:28.375Z] 20:36:28 INFO - 1619123788375 Marionette DEBUG 1 -> [0,8,"Marionette:SetContext",{"value":"content"}]
[task 2021-04-22T20:36:28.376Z] 20:36:28 INFO - 1619123788375 Marionette DEBUG 1 <- [1,8,null,{"value":null}]
[task 2021-04-22T20:36:28.376Z] 20:36:28 INFO - 1619123788376 Marionette DEBUG 1 -> [0,9,"WebDriver:GetPageSource",{}]
[task 2021-04-22T20:36:28.376Z] 20:36:28 INFO - 1619123788376 Marionette TRACE [31] MarionetteCommands actor created for window id 14
[task 2021-04-22T20:36:28.377Z] 20:36:28 INFO - 1619123788376 Marionette DEBUG 1 <- [1,9,null,{"value":"<html xmlns=\"http://www.w3.org/1999/xhtml\" dir=\"ltr\" lang=\"en-US\"><head>\n <meta charset=\"utf-8\" ... bout:webrtc\">about:webrtc</a></li><li><a href=\"about:welcome\">about:welcome</a></li></ul>\n </div>\n\n\n</body></html>"}]
[task 2021-04-22T20:36:28.377Z] 20:36:28 INFO - 1619123788377 Marionette DEBUG 1 -> [0,10,"Marionette:SetContext",{"value":"content"}]
[task 2021-04-22T20:36:28.378Z] 20:36:28 INFO - 1619123788377 Marionette DEBUG 1 <- [1,10,null,{"value":null}]
[task 2021-04-22T20:36:28.379Z] 20:36:28 INFO - Child process with id "1043" has been marked as detached because it is no longer in the managed process group. Keeping reference to the process id "1049" which is the new child process.
[task 2021-04-22T20:36:28.520Z] 20:36:28 INFO - TEST-UNEXPECTED-FAIL | telemetry/marionette/tests/client/test_search_counts_across_sessions.py TestSearchCounts.test_search_counts | AssertionError: 'af738e45-c767-374d-b222-e6bf5532fa1b' is not None
[task 2021-04-22T20:36:28.520Z] 20:36:28 INFO - Traceback (most recent call last):
[task 2021-04-22T20:36:28.520Z] 20:36:28 INFO - File "/opt/worker/tasks/task_161912368830776/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 214, in run
[task 2021-04-22T20:36:28.520Z] 20:36:28 INFO - testMethod()
[task 2021-04-22T20:36:28.520Z] 20:36:28 INFO - File "/opt/worker/tasks/task_161912368830776/build/tests/telemetry/marionette/tests/client/test_search_counts_across_sessions.py", line 88, in test_search_counts
[task 2021-04-22T20:36:28.520Z] 20:36:28 INFO - self.assertIsNone(ping1_info["previousSubsessionId"])
[task 2021-04-22T20:36:28.521Z] 20:36:28 INFO - TEST-INFO took 4162ms
[task 2021-04-22T20:36:28.521Z] 20:36:28 INFO - 1619123788461 Marionette DEBUG 1 -> [0,11,"WebDriver:GetChromeWindowHandles",{}]
[task 2021-04-22T20:36:28.521Z] 20:36:28 INFO - 1619123788462 Marionette DEBUG 1 <- [1,11,null,["15"]]
[task 2021-04-22T20:36:28.521Z] 20:36:28 INFO - 1619123788462 Marionette DEBUG 1 -> [0,12,"WebDriver:GetWindowHandles",{}]
[task 2021-04-22T20:36:28.521Z] 20:36:28 INFO - 1619123788462 Marionette DEBUG 1 <- [1,12,null,["31"]]
[task 2021-04-22T20:36:28.649Z] 20:36:28 INFO - 1619123788648 Toolkit.Telemetry TRACE TelemetryController::observe - app-startup notified.
[task 2021-04-22T20:36:28.649Z] 20:36:28 INFO - 1619123788649 Toolkit.Telemetry CONFIG TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2021-04-22T20:36:28.769Z] 20:36:28 INFO - pingserver Stopped http server on localhost:8000```
|
||
Comment 1•4 years ago
|
||
Seems rather likely that this is a dupe of bug 1608807
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → DUPLICATE
| Comment hidden (Intermittent Failures Robot) |
You need to log in
before you can comment on or make changes to this bug.
Description
•