Open
Bug 1944382
Opened 19 days ago
Updated 7 days ago
Intermittent telemetry/marionette/tests/client/test_fog_usage_reporting.py TestUsageReporting.test_enabled_state_after_restart | AssertionError: '<random>' != '<other random>'
Categories
(Toolkit :: Telemetry, defect, P1)
Toolkit
Telemetry
Tracking
()
ASSIGNED
People
(Reporter: intermittent-bug-filer, Assigned: janerik)
References
Details
(Keywords: intermittent-failure)
Filed by: sstanca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=492191602&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Rl8Npkj_RxC5wDCSkOgIRA/runs/0/artifacts/public/logs/live_backing.log
[task 2025-01-28T18:42:53.743Z] 18:42:53 INFO - 1738089773742 Toolkit.Telemetry TRACE TelemetryEnvironment::_updateAddons: addons differ
[task 2025-01-28T18:42:53.744Z] 18:42:53 INFO - 1738089773743 Toolkit.Telemetry TRACE TelemetryEnvironment::_startWatchingPrefs - [object Map]
[task 2025-01-28T18:42:53.822Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117edc0]: I/glean_core::* [glean_core::upload] Ping 444198ae-e989-4854-bb40-6053b6f09354 successfully sent 200.
[task 2025-01-28T18:42:53.823Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117edc0]: I/glean_core::* [glean_core::upload::directory] File was deleted /builds/worker/workspace/build/tmpoahh6h59.mozrunner/datareporting/glean/pending_pings/444198ae-e989-4854-bb40-6053b6f09354
[task 2025-01-28T18:42:53.823Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117edc0]: I/glean_core::* [glean_core::upload] New upload task with id 05934474-5062-40a8-b829-566a5d974b48 (path: /submit/firefox-desktop/usage-reporting/1/05934474-5062-40a8-b829-566a5d974b48)
[task 2025-01-28T18:42:53.823Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117edc0]: I/fog_control::* [fog_control::init::viaduct_uploader] FOG viaduct uploader uploading to Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("localhost")), port: Some(43730), path: "/submit/firefox-desktop/usage-reporting/1/05934474-5062-40a8-b829-566a5d974b48", query: None, fragment: None }
[task 2025-01-28T18:42:53.841Z] 18:42:53 INFO - fog_ping_server pings_handler received 'usage-reporting' ping
[task 2025-01-28T18:42:53.851Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117edc0]: I/glean_core::* [glean_core::upload] Ping 05934474-5062-40a8-b829-566a5d974b48 successfully sent 200.
[task 2025-01-28T18:42:53.851Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117edc0]: I/glean_core::* [glean_core::upload::directory] File was deleted /builds/worker/workspace/build/tmpoahh6h59.mozrunner/datareporting/glean/pending_pings/05934474-5062-40a8-b829-566a5d974b48
[task 2025-01-28T18:42:53.851Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117edc0]: I/glean_core::* [glean_core::upload] No more pings to upload! You are done.
[task 2025-01-28T18:42:53.866Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117eca0]: I/glean_core::* [glean_core::ping] Collecting baseline
[task 2025-01-28T18:42:53.872Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117eca0]: I/glean_core::* [glean_core::upload::directory] Processing ping at: /builds/worker/workspace/build/tmpoahh6h59.mozrunner/datareporting/glean/pending_pings/8fe47946-7d1b-4ba7-acf4-be1007a2a517
[task 2025-01-28T18:42:53.873Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117eca0]: I/glean_core::* [glean_core::metrics::ping] The ping 'baseline' was submitted and will be sent as soon as possible
[task 2025-01-28T18:42:53.873Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117eca0]: I/glean_core::* [glean_core::metrics::ping] The ping 'baseline' is being used to schedule other pings: ["fx-accounts", "usage-reporting"]
[task 2025-01-28T18:42:53.874Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117eca0]: I/glean_core::* [glean_core::ping] Collecting fx-accounts
[task 2025-01-28T18:42:53.875Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117eca0]: I/glean_core::* [glean_core::ping] Storage for fx-accounts empty. Bailing out.
[task 2025-01-28T18:42:53.875Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117eca0]: I/glean_core::* [glean_core::metrics::ping] No content for ping 'fx-accounts', therefore no ping queued.
[task 2025-01-28T18:42:53.875Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117eca0]: I/glean_core::* [glean_core::ping] Collecting usage-reporting
[task 2025-01-28T18:42:53.876Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117eca0]: I/glean_core::* [glean_core::upload::directory] Processing ping at: /builds/worker/workspace/build/tmpoahh6h59.mozrunner/datareporting/glean/pending_pings/0f611acc-6417-4847-a19d-3f172bf452de
[task 2025-01-28T18:42:53.876Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117eca0]: I/glean_core::* [glean_core::metrics::ping] The ping 'usage-reporting' was submitted and will be sent as soon as possible
[task 2025-01-28T18:42:53.879Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f269117eca0]: W/glean_core::* [glean_core::error_recording] fog.initialization: Timespan value already recorded. New value discarded.
[task 2025-01-28T18:42:53.879Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f2691b583a0]: I/glean_core::* [glean_core::upload] New upload task with id 8fe47946-7d1b-4ba7-acf4-be1007a2a517 (path: /submit/firefox-desktop/baseline/1/8fe47946-7d1b-4ba7-acf4-be1007a2a517)
[task 2025-01-28T18:42:53.880Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f2691b583a0]: I/fog_control::* [fog_control::init::viaduct_uploader] FOG viaduct uploader uploading to Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("localhost")), port: Some(43730), path: "/submit/firefox-desktop/baseline/1/8fe47946-7d1b-4ba7-acf4-be1007a2a517", query: None, fragment: None }
[task 2025-01-28T18:42:53.892Z] 18:42:53 INFO - fog_ping_server pings_handler received 'baseline' ping
[task 2025-01-28T18:42:53.897Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f2691b583a0]: I/glean_core::* [glean_core::upload] Ping 8fe47946-7d1b-4ba7-acf4-be1007a2a517 successfully sent 200.
[task 2025-01-28T18:42:53.898Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f2691b583a0]: I/glean_core::* [glean_core::upload::directory] File was deleted /builds/worker/workspace/build/tmpoahh6h59.mozrunner/datareporting/glean/pending_pings/8fe47946-7d1b-4ba7-acf4-be1007a2a517
[task 2025-01-28T18:42:53.898Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f2691b583a0]: I/glean_core::* [glean_core::upload] New upload task with id 0f611acc-6417-4847-a19d-3f172bf452de (path: /submit/firefox-desktop/usage-reporting/1/0f611acc-6417-4847-a19d-3f172bf452de)
[task 2025-01-28T18:42:53.898Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f2691b583a0]: I/fog_control::* [fog_control::init::viaduct_uploader] FOG viaduct uploader uploading to Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("localhost")), port: Some(43730), path: "/submit/firefox-desktop/usage-reporting/1/0f611acc-6417-4847-a19d-3f172bf452de", query: None, fragment: None }
[task 2025-01-28T18:42:53.901Z] 18:42:53 INFO - fog_ping_server pings_handler received 'usage-reporting' ping
[task 2025-01-28T18:42:53.921Z] 18:42:53 INFO - 1738089773920 Marionette TRACE Received observer notification browser-idle-startup-tasks-finished
[task 2025-01-28T18:42:53.925Z] 18:42:53 INFO - 1738089773924 RemoteAgent TRACE [3] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=5000 waitForExplicitStart=false
[task 2025-01-28T18:42:53.925Z] 18:42:53 INFO - 1738089773924 RemoteAgent TRACE [3] ProgressListener Setting unload timer (5000ms)
[task 2025-01-28T18:42:53.926Z] 18:42:53 INFO - 1738089773924 RemoteAgent TRACE [3] Wait for initial navigation: isInitial=false, isLoadingDocument=false
[task 2025-01-28T18:42:53.926Z] 18:42:53 INFO - 1738089773925 RemoteAgent TRACE [3] Document already finished loading: about:blank
[task 2025-01-28T18:42:53.928Z] 18:42:53 INFO - 1738089773925 RemoteAgent TRACE [3] ProgressListener Stop: has error=false url=about:blank
[task 2025-01-28T18:42:53.930Z] 18:42:53 INFO - 1738089773929 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"82d49ff6-3c84-4419-8815-06d4b4b47b6d","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"136.0a1","platformName":"linux","unhandledPromptBehavior":"dismiss and notify","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:136.0) Gecko/20100101 Firefox/136.0","moz:buildID":"20250128161837","moz:headless":false,"moz:platformVersion":"4.4.0-1014-aws","moz:processID":5856,"moz:profile":"/builds/worker/workspace/build/tmpoahh6h59.mozrunner","moz:shutdownTimeout":60000,"pageLoadStrategy":"normal","timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"setWindowRect":true,"strictFileInteractability":true,"moz:accessibilityChecks":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2025-01-28T18:42:53.933Z] 18:42:53 INFO - 1738089773932 Marionette DEBUG 1 -> [0,2,"Marionette:SetContext",{"value":"content"}]
[task 2025-01-28T18:42:53.933Z] 18:42:53 INFO - 1738089773932 Marionette DEBUG 1 <- [1,2,null,{"value":null}]
[task 2025-01-28T18:42:53.936Z] 18:42:53 INFO - 1738089773935 Marionette DEBUG 1 -> [0,3,"Marionette:GetContext",{}]
[task 2025-01-28T18:42:53.936Z] 18:42:53 INFO - 1738089773935 Marionette DEBUG 1 <- [1,3,null,{"value":"content"}]
[task 2025-01-28T18:42:53.937Z] 18:42:53 INFO - 1738089773936 Marionette DEBUG 1 -> [0,4,"Marionette:SetContext",{"value":"chrome"}]
[task 2025-01-28T18:42:53.937Z] 18:42:53 INFO - 1738089773936 Marionette DEBUG 1 <- [1,4,null,{"value":null}]
[task 2025-01-28T18:42:53.941Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f2691b583a0]: I/glean_core::* [glean_core::upload::directory] File was deleted /builds/worker/workspace/build/tmpoahh6h59.mozrunner/datareporting/glean/pending_pings/0f611acc-6417-4847-a19d-3f172bf452de
[task 2025-01-28T18:42:53.941Z] 18:42:53 INFO - [Parent 5856: Unnamed thread 7f2691b583a0]: I/glean_core::* [glean_core::upload] No more pings to upload! You are done.
[task 2025-01-28T18:42:53.943Z] 18:42:53 INFO - 1738089773942 RemoteAgent TRACE WebDriverProcessData actor created for PID 5856
[task 2025-01-28T18:42:53.943Z] 18:42:53 INFO - 1738089773943 Marionette TRACE [1] MarionetteCommands actor created for window id 2
[task 2025-01-28T18:42:53.994Z] 18:42:53 INFO - 1738089773993 Marionette DEBUG 1 <- [1,5,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABQAAAAQQCAYAAAC9RfbYAAAgAElEQVR4XuzdCdQkZXkv8Hf2FTAXBQlcURwxCgg6KsimuCTKNagxRkRAjCbGBJGIUa4XcUs8ShRNM ... AcbmiESBAgAABAgQIECBAgAABAgQIEHAA2gABAgQIECBAgAABAgQIECBAgACBsYADcFyuaAQIECBAgAABAgQIECBAgAABAgQCEHXqQJnLPLMAAAAASUVORK5CYII="}]
[task 2025-01-28T18:42:53.999Z] 18:42:53 INFO - 1738089773998 Marionette DEBUG 1 -> [0,6,"Marionette:SetContext",{"value":"content"}]
[task 2025-01-28T18:42:53.999Z] 18:42:53 INFO - 1738089773998 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2025-01-28T18:42:54.000Z] 18:42:54 INFO - 1738089774000 Marionette DEBUG 1 -> [0,7,"Marionette:GetContext",{}]
[task 2025-01-28T18:42:54.001Z] 18:42:54 INFO - 1738089774000 Marionette DEBUG 1 <- [1,7,null,{"value":"content"}]
[task 2025-01-28T18:42:54.003Z] 18:42:54 INFO - 1738089774002 Marionette DEBUG 1 -> [0,8,"Marionette:SetContext",{"value":"content"}]
[task 2025-01-28T18:42:54.004Z] 18:42:54 INFO - 1738089774003 Marionette DEBUG 1 <- [1,8,null,{"value":null}]
[task 2025-01-28T18:42:54.009Z] 18:42:54 INFO - 1738089774005 Marionette DEBUG 1 -> [0,9,"WebDriver:GetPageSource",{}]
[task 2025-01-28T18:42:54.009Z] 18:42:54 INFO - 1738089774008 RemoteAgent TRACE WebDriverProcessData actor created for PID 5994
[task 2025-01-28T18:42:54.011Z] 18:42:54 INFO - 1738089774011 Marionette TRACE [3] MarionetteCommands actor created for window id 8589934593
[task 2025-01-28T18:42:54.013Z] 18:42:54 INFO - 1738089774013 Marionette DEBUG 1 <- [1,9,null,{"value":"<html><head></head><body></body></html>"}]
[task 2025-01-28T18:42:54.015Z] 18:42:54 INFO - 1738089774014 Marionette DEBUG 1 -> [0,10,"Marionette:SetContext",{"value":"content"}]
[task 2025-01-28T18:42:54.015Z] 18:42:54 INFO - 1738089774015 Marionette DEBUG 1 <- [1,10,null,{"value":null}]
[task 2025-01-28T18:42:54.057Z] 18:42:54 INFO - TEST-UNEXPECTED-FAIL | telemetry/marionette/tests/client/test_fog_usage_reporting.py TestUsageReporting.test_enabled_state_after_restart | AssertionError: '7986a732-c281-42f0-b22e-e8a9e98343e1' != '8b82e925-b73c-4b87-9bf1-8ad8205093b6'
[task 2025-01-28T18:42:54.057Z] 18:42:54 INFO - - 7986a732-c281-42f0-b22e-e8a9e98343e1
[task 2025-01-28T18:42:54.057Z] 18:42:54 INFO - + 8b82e925-b73c-4b87-9bf1-8ad8205093b6
[task 2025-01-28T18:42:54.057Z] 18:42:54 INFO - Traceback (most recent call last):
[task 2025-01-28T18:42:54.057Z] 18:42:54 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_harness/marionette_test/testcases.py", line 198, in run
[task 2025-01-28T18:42:54.057Z] 18:42:54 INFO - testMethod()
[task 2025-01-28T18:42:54.057Z] 18:42:54 INFO - File "/builds/worker/workspace/build/tests/telemetry/marionette/tests/client/test_fog_usage_reporting.py", line 168, in test_enabled_state_after_restart
[task 2025-01-28T18:42:54.058Z] 18:42:54 INFO - self.assertEqual(usage_id1, usage_id2)
[task 2025-01-28T18:42:54.058Z] 18:42:54 INFO - TEST-INFO took 14596ms
[task 2025-01-28T18:42:54.058Z] 18:42:54 INFO - 1738089774022 Marionette DEBUG 1 -> [0,11,"Marionette:GetContext",{}]
[task 2025-01-28T18:42:54.058Z] 18:42:54 INFO - 1738089774022 Marionette DEBUG 1 <- [1,11,null,{"value":"content"}]
[task 2025-01-28T18:42:54.058Z] 18:42:54 INFO - 1738089774023 Marionette DEBUG 1 -> [0,12,"Marionette:SetContext",{"value":"chrome"}]
[task 2025-01-28T18:42:54.058Z] 18:42:54 INFO - 1738089774023 Marionette DEBUG 1 <- [1,12,null,{"value":null}]
[task 2025-01-28T18:42:54.058Z] 18:42:54 INFO - 1738089774026 Marionette DEBUG 1 -> [0,13,"WebDriver:GetWindowHandles",{}]
[task 2025-01-28T18:42:54.058Z] 18:42:54 INFO - 1738089774026 Marionette DEBUG 1 <- [1,13,null,["165f60de-cbea-471e-88ae-7bc5a7027534"]]
[task 2025-01-28T18:42:54.059Z] 18:42:54 INFO - 1738089774028 Marionette DEBUG 1 -> [0,14,"Marionette:SetContext",{"value":"content"}]
[task 2025-01-28T18:42:54.060Z] 18:42:54 INFO - 1738089774028 Marionette DEBUG 1 <- [1,14,null,{"value":null}]
[task 2025-01-28T18:42:54.060Z] 18:42:54 INFO - 1738089774029 Marionette DEBUG 1 -> [0,15,"Marionette:GetContext",{}]
[task 2025-01-28T18:42:54.060Z] 18:42:54 INFO - 1738089774029 Marionette DEBUG 1 <- [1,15,null,{"value":"content"}]
[task 2025-01-28T18:42:54.061Z] 18:42:54 INFO - 1738089774035 Marionette DEBUG 1 -> [0,16,"Marionette:SetContext",{"value":"content"}]
[task 2025-01-28T18:42:54.061Z] 18:42:54 INFO - 1738089774035 Marionette DEBUG 1 <- [1,16,null,{"value":null}]
[task 2025-01-28T18:42:54.061Z] 18:42:54 INFO - 1738089774036 Marionette DEBUG 1 -> [0,17,"WebDriver:GetWindowHandles",{}]
[task 2025-01-28T18:42:54.062Z] 18:42:54 INFO - 1738089774036 Marionette DEBUG 1 <- [1,17,null,["1f82f4eb-d1f1-4742-bfb8-ae28825623f7"]]
[task 2025-01-28T18:42:54.062Z] 18:42:54 INFO - 1738089774039 Marionette DEBUG 1 -> [0,18,"Marionette:SetContext",{"value":"content"}]
[task 2025-01-28T18:42:54.063Z] 18:42:54 INFO - 1738089774039 Marionette DEBUG 1 <- [1,18,null,{"value":null}]
[task 2025-01-28T18:42:54.524Z] 18:42:54 INFO - 1738089774524 Toolkit.Telemetry TRACE TelemetryEnvironment::observe - aTopic: browser-search-service, aData: write-prevented-when-settings-unchanged
[task 2025-01-28T18:42:54.525Z] 18:42:54 INFO - 1738089774524 Toolkit.Telemetry TRACE TelemetryEnvironment::observe - aTopic: browser-search-service, aData: write-settings-to-disk-complete
[task 2025-01-28T18:42:54.526Z] 18:42:54 INFO - 1738089774524 Toolkit.Telemetry TRACE TelemetryController::observe - content-process-ready-for-script notified.
[task 2025-01-28T18:42:54.526Z] 18:42:54 INFO - 1738089774525 Toolkit.Telemetry CONFIG TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2025-01-28T18:42:54.657Z] 18:42:54 INFO - TEST-START | telemetry/marionette/tests/client/test_fog_usage_reporting.py TestUsageReporting.test_existing_profile_inherits_general_preference
|
Assignee | |
Updated•16 days ago
|
Assignee: nobody → jrediger
Status: NEW → ASSIGNED
Priority: P5 → P1
|
||
Updated•16 days ago
|
Summary: Intermittent telemetry/marionette/tests/client/test_fog_usage_reporting.py TestUsageReporting.test_enabled_state_after_restart | AssertionError: '7986a732-c281-42f0-b22e-e8a9e98343e1' != '8b82e925-b73c-4b87-9bf1-8ad8205093b6' → Intermittent telemetry/marionette/tests/client/test_fog_usage_reporting.py TestUsageReporting.test_enabled_state_after_restart | AssertionError: '<random>' != '<other random>'
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
You need to log in
before you can comment on or make changes to this bug.
Description
•