1889802 - Intermittent browser/components/search/test/marionette/telemetry/test_ping_submitted.py TestPingSubmitted.test_ping_submit_on_start | single tracking bug

Status: NEW

(Firefox :: Search, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=453548887&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/UDd2stGuTx6fvL6Zb1Ygzw/runs/0/artifacts/public/logs/live_backing.log

---

[task 2024-04-04T21:02:22.421Z] 21:02:22     INFO -  TEST-START | browser/components/search/test/marionette/telemetry/test_ping_submitted.py TestPingSubmitted.test_ping_submit_on_start
[task 2024-04-04T21:02:22.423Z] 21:02:22     INFO -  1712264542423	Marionette	DEBUG	Accepted connection 4 from 127.0.0.1:65088
[task 2024-04-04T21:02:22.425Z] 21:02:22     INFO -  1712264542425	Marionette	DEBUG	4 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2024-04-04T21:02:22.427Z] 21:02:22     INFO -  1712264542427	Marionette	DEBUG	Waiting for initial application window
[task 2024-04-04T21:02:22.428Z] 21:02:22     INFO -  1712264542428	RemoteAgent	TRACE	[9] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=40000 waitForExplicitStart=false
[task 2024-04-04T21:02:22.429Z] 21:02:22     INFO -  1712264542429	RemoteAgent	TRACE	[9] ProgressListener Setting unload timer (40000ms)
[task 2024-04-04T21:02:22.430Z] 21:02:22     INFO -  1712264542429	RemoteAgent	TRACE	[9] Document already finished loading: about:blank
[task 2024-04-04T21:02:22.430Z] 21:02:22     INFO -  1712264542429	RemoteAgent	TRACE	[9] ProgressListener Stop: has error=false
[task 2024-04-04T21:02:22.434Z] 21:02:22     INFO -  1712264542433	Marionette	DEBUG	4 <- [1,1,null,{"sessionId":"1ddefb61-aaa3-41b7-8595-d0ec0db9d186","capabilities":{"browserName":"firefox","browserVersion":"126.0a1","platformName":"windows","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:126.0) Gecko/20100101 Firefox/126.0","moz:accessibilityChecks":false,"moz:buildID":"20240404193558","moz:headless":false,"moz:platformVersion":"10.0","moz:processID":1392,"moz:profile":"C:\\Users\\task_171226225948577\\AppData\\Local\\Temp\\tmphf_1zdtr.mozrunner","moz:shutdownTimeout":300000,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2024-04-04T21:02:22.435Z] 21:02:22     INFO -  1712264542435	Marionette	DEBUG	4 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2024-04-04T21:02:22.437Z] 21:02:22     INFO -  1712264542436	Marionette	DEBUG	4 <- [1,2,null,{"value":null}]
[task 2024-04-04T21:02:22.438Z] 21:02:22     INFO -  1712264542437	Marionette	DEBUG	4 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2024-04-04T21:02:22.438Z] 21:02:22     INFO -  1712264542438	Marionette	DEBUG	4 <- [1,3,null,{"value":null}]
[task 2024-04-04T21:02:22.439Z] 21:02:22     INFO -  1712264542439	Marionette	DEBUG	4 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2024-04-04T21:02:22.440Z] 21:02:22     INFO -  1712264542440	Marionette	DEBUG	4 <- [1,4,null,{"value":null}]
[task 2024-04-04T21:02:22.442Z] 21:02:22     INFO -  1712264542442	Marionette	DEBUG	4 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-04-04T21:02:22.442Z] 21:02:22     INFO -  1712264542442	Marionette	DEBUG	4 <- [1,5,null,{"value":null}]
[task 2024-04-04T21:02:22.443Z] 21:02:22     INFO -  1712264542443	Marionette	DEBUG	4 -> [0,6,"Marionette:GetContext",{}]
[task 2024-04-04T21:02:22.443Z] 21:02:22     INFO -  1712264542443	Marionette	DEBUG	4 <- [1,6,null,{"value":"chrome"}]
[task 2024-04-04T21:02:22.445Z] 21:02:22     INFO -  1712264542444	Marionette	DEBUG	4 -> [0,7,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-04-04T21:02:22.445Z] 21:02:22     INFO -  1712264542445	Marionette	DEBUG	4 <- [1,7,null,{"value":null}]
[task 2024-04-04T21:02:22.447Z] 21:02:22     INFO -  1712264542447	Marionette	DEBUG	4 -> [0,8,"WebDriver:ExecuteScript",{"script":"let prefInterface = Components.classes[\"@mozilla.org/preferences-service;1\"]\n                                              .g ... ref).toString();\n                    case prefInterface.PREF_INVALID:\n                        return false;\n                }","args":[],"newSandbox":true,"sandbox":"default","line":1021,"filename":"D:\\task_171226225948577\\build\\venv\\Lib\\site-packages\\marionette_driver\\marionette.py"}]
[task 2024-04-04T21:02:22.469Z] 21:02:22     INFO -  1712264542469	RemoteAgent	TRACE	WebDriverProcessData actor created for PID 1392
[task 2024-04-04T21:02:22.474Z] 21:02:22     INFO -  1712264542474	Marionette	TRACE	[1] MarionetteCommands actor created for window id 2
[task 2024-04-04T21:02:22.487Z] 21:02:22     INFO -  1712264542487	Marionette	DEBUG	4 <- [1,8,null,{"value":true}]
[task 2024-04-04T21:02:22.491Z] 21:02:22     INFO -  1712264542490	Marionette	DEBUG	4 -> [0,9,"WebDriver:ExecuteScript",{"script":"let prefInterface = Components.classes[\"@mozilla.org/preferences-service;1\"]\n                                              .g ... ref).toString();\n                    case prefInterface.PREF_INVALID:\n                        return false;\n                }","args":[],"newSandbox":true,"sandbox":"default","line":1021,"filename":"D:\\task_171226225948577\\build\\venv\\Lib\\site-packages\\marionette_driver\\marionette.py"}]
[task 2024-04-04T21:02:22.496Z] 21:02:22     INFO -  1712264542496	Marionette	DEBUG	4 <- [1,9,null,{"value":false}]
[task 2024-04-04T21:02:22.500Z] 21:02:22     INFO -  1712264542500	Marionette	DEBUG	4 -> [0,10,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-04-04T21:02:22.501Z] 21:02:22     INFO -  1712264542500	Marionette	DEBUG	4 <- [1,10,null,{"value":null}]
[task 2024-04-04T21:02:22.502Z] 21:02:22     INFO -  1712264542502	Marionette	DEBUG	4 -> [0,11,"Marionette:GetContext",{}]
[task 2024-04-04T21:02:22.502Z] 21:02:22     INFO -  1712264542502	Marionette	DEBUG	4 <- [1,11,null,{"value":"chrome"}]
[task 2024-04-04T21:02:22.503Z] 21:02:22     INFO -  1712264542503	Marionette	DEBUG	4 -> [0,12,"WebDriver:DeleteSession",{}]
[task 2024-04-04T21:02:22.504Z] 21:02:22     INFO -  1712264542504	Marionette	TRACE	[1] MarionetteCommands actor destroyed for window id 2
[task 2024-04-04T21:02:22.507Z] 21:02:22     INFO -  1712264542507	Marionette	DEBUG	4 <- [1,12,null,{"value":null}]
[task 2024-04-04T21:02:23.027Z] 21:02:23     INFO -  Application command: D:\task_171226225948577\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile C:\Users\task_171226225948577\AppData\Local\Temp\tmp95p_mhm9.mozrunner
[task 2024-04-04T21:02:24.653Z] 21:02:24     INFO -  1712264544667	Marionette	INFO	Marionette enabled
[task 2024-04-04T21:02:24.670Z] 21:02:24     INFO -  1712264544677	Marionette	TRACE	Received observer notification final-ui-startup
[task 2024-04-04T21:02:25.419Z] 21:02:25     INFO -  1712264545419	Marionette	INFO	Listening on port 2828
[task 2024-04-04T21:02:25.427Z] 21:02:25     INFO -  1712264545427	Marionette	DEBUG	Marionette is listening
[task 2024-04-04T21:02:25.489Z] 21:02:25     INFO -  1712264545489	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:65093
[task 2024-04-04T21:02:25.544Z] 21:02:25     INFO -  1712264545553	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:65096
[task 2024-04-04T21:02:25.555Z] 21:02:25     INFO -  1712264545554	Marionette	DEBUG	Closed connection 0
[task 2024-04-04T21:02:25.654Z] 21:02:25     INFO -  1712264545657	Marionette	DEBUG	Closed connection 1
[task 2024-04-04T21:02:25.659Z] 21:02:25     INFO -  1712264545658	Marionette	DEBUG	Accepted connection 2 from 127.0.0.1:65097
[task 2024-04-04T21:02:26.529Z] 21:02:26     INFO -  1712264546531	Marionette	DEBUG	2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2024-04-04T21:02:26.544Z] 21:02:26     INFO -  1712264546553	Marionette	DEBUG	Waiting for initial application window
[task 2024-04-04T21:02:30.684Z] 21:02:30     INFO -  console.debug: SearchService: "init"
[task 2024-04-04T21:02:31.112Z] 21:02:31     INFO -  console.debug: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open `C:\\Users\\task_171226225948577\\AppData\\Local\\Temp\\tmp95p_mhm9.mozrunner\\search.json.mozlz4': file does not exist (NS_ERROR_FILE_NOT_FOUND)", (void 0)))
[task 2024-04-04T21:02:31.653Z] 21:02:31     INFO -  console.debug: SearchService: "#handleIgnoreListUpdated"
[task 2024-04-04T21:02:32.893Z] 21:02:32     INFO -  console.debug: SearchEngineSelector: "fetchEngineConfiguration en-US:default:default:::Firefox:126.0a1"
[task 2024-04-04T21:02:32.897Z] 21:02:32     INFO -  console.debug: SearchEngineSelector: "fetchEngineConfiguration: google,ddg,bing,wikipedia"
[task 2024-04-04T21:02:32.897Z] 21:02:32     INFO -  console.debug: SearchService: "#loadEngines: start"
[task 2024-04-04T21:02:32.898Z] 21:02:32     INFO -  console.debug: SearchService: "#loadEnginesFromConfig"
[task 2024-04-04T21:02:32.899Z] 21:02:32     INFO -  console.debug: SearchService: "_makeEngineFromConfig:" ({name:"Google", urls:{search:{base:"https://www.google.com/search", params:[{name:"client", value:"{partnerCode}"}, {name:"channel", experimentConfig:"google_channel_row"}], searchTermParamName:"q"}, trending:{base:"https://www.google.com/complete/search", method:"GET", params:[{name:"client", value:"firefox"}, {name:"channel", value:"ftr"}], searchTermParamName:"q"}, suggestions:{base:"https://www.google.com/complete/search", params:[{name:"client", value:"firefox"}, {name:"channel", experimentConfig:"search_rich_suggestions"}], searchTermParamName:"q"}}, aliases:["google"], partnerCode:"firefox-b-d", classification:"general", identifier:"google", telemetrySuffix:"b-d", webExtension:{locale:"default", id:"[e-mail]"}})
[task 2024-04-04T21:02:32.923Z] 21:02:32     INFO -  console.debug: SearchService: "#addEngineToStore: Adding engine:" "Google"
[task 2024-04-04T21:02:32.925Z] 21:02:32     INFO -  console.debug: SearchService: "_makeEngineFromConfig:" ({name:"DuckDuckGo", urls:{search:{base:"https://duckduckgo.com/", params:[{name:"t", value:"{partnerCode}"}], searchTermParamName:"q"}, suggestions:{base:"https://ac.duckduckgo.com/ac/", params:[{name:"type", value:"list"}], searchTermParamName:"q"}}, aliases:["duckduckgo", "ddg"], partnerCode:"ffab", classification:"general", identifier:"ddg", webExtension:{locale:"default", id:"[e-mail]"}})
[task 2024-04-04T21:02:32.926Z] 21:02:32     INFO -  console.debug: SearchService: "#addEngineToStore: Adding engine:" "DuckDuckGo"
[task 2024-04-04T21:02:32.927Z] 21:02:32     INFO -  console.debug: SearchService: "_makeEngineFromConfig:" ({name:"Bing", urls:{search:{base:"https://www.bing.com/search", params:[{name:"pc", value:"{partnerCode}"}, {name:"form", searchAccessPoint:{newtab:"MOZTSB", homepage:"MOZSPG", searchbar:"MOZSBR", addressbar:"MOZLBR", contextmenu:"MOZCON"}}], searchTermParamName:"q"}, trending:{base:"https://www.bing.com/osjson.aspx"}, suggestions:{base:"https://www.bing.com/osjson.aspx", params:[{name:"form", value:"OSDJAS"}], searchTermParamName:"query"}}, aliases:["bing"], partnerCode:"MOZI", classification:"general", identifier:"bing", webExtension:{locale:"default", id:"[e-mail]"}})
[task 2024-04-04T21:02:32.928Z] 21:02:32     INFO -  console.debug: SearchService: "#addEngineToStore: Adding engine:" "Bing"
[task 2024-04-04T21:02:32.929Z] 21:02:32     INFO -  console.debug: SearchService: "_makeEngineFromConfig:" ({name:"Wikipedia (en)", urls:{search:{base:"https://en.wikipedia.org/wiki/Special:Search", params:[{name:"sourceid", value:"Mozilla-search"}], searchTermParamName:"search"}, suggestions:{base:"https://en.wikipedia.org/w/api.php", params:[{name:"action", value:"opensearch"}], searchTermParamName:"search"}}, aliases:["wikipedia"], classification:"unknown", identifier:"wikipedia", webExtension:{locale:"default", id:"[e-mail]"}})
[task 2024-04-04T21:02:32.930Z] 21:02:32     INFO -  console.debug: SearchService: "#addEngineToStore: Adding engine:" "Wikipedia (en)"
[task 2024-04-04T21:02:32.930Z] 21:02:32     INFO -  console.debug: SearchService: "#loadStartupEngines: loading" 0 "engines reported by AddonManager startup"
[task 2024-04-04T21:02:32.930Z] 21:02:32     INFO -  console.debug: SearchService: "#loadEngines: done"
[task 2024-04-04T21:02:32.984Z] 21:02:32     INFO -  console.debug: SearchService: "Completed #init"
[task 2024-04-04T21:02:32.986Z] 21:02:32     INFO -  console.debug: SearchService: "#buildSortedEngineList: using default orders"
[task 2024-04-04T21:02:33.021Z] 21:02:33     INFO -  console.debug: SearchService: "getEngines: getting all engines"
[task 2024-04-04T21:02:34.532Z] 21:02:34     INFO -  console.debug: SearchService: "removeWebExtensionEngine:" "[e-mail]"
[task 2024-04-04T21:02:34.533Z] 21:02:34     INFO -  console.debug: SearchService: "getEngines: getting all engines for" "[e-mail]"
[task 2024-04-04T21:02:35.331Z] 21:02:35     INFO -  console.debug: SearchTelemetry: "Initialize SERP categorizer."
[task 2024-04-04T21:02:35.332Z] 21:02:35     INFO -  console.debug: SearchTelemetry: "Initializing domain-to-categories map."
[task 2024-04-04T21:02:35.332Z] 21:02:35     INFO -  console.debug: SearchTelemetry: "Setting up domain-to-categories map."
[task 2024-04-04T21:02:35.332Z] 21:02:35     INFO -  console.debug: SearchTelemetry: "Initializing domain-to-categories store."
[task 2024-04-04T21:02:35.343Z] 21:02:35     INFO -  console.debug: SearchTelemetry: "Create store."
[task 2024-04-04T21:02:35.472Z] 21:02:35     INFO -  console.debug: SearchSettings: "batchTask: Invalidating engine settings"
[task 2024-04-04T21:02:35.473Z] 21:02:35     INFO -  console.debug: SearchSettings: "_write: Writing to settings file."
[task 2024-04-04T21:02:35.480Z] 21:02:35     INFO -  console.debug: SearchSettings: "_write: settings file written to disk."
[task 2024-04-04T21:02:35.662Z] 21:02:35     INFO -  1712264555661	Marionette	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2024-04-04T21:02:35.684Z] 21:02:35     INFO -  1712264555684	RemoteAgent	TRACE	[9] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=40000 waitForExplicitStart=false
[task 2024-04-04T21:02:35.685Z] 21:02:35     INFO -  1712264555685	RemoteAgent	TRACE	[9] ProgressListener Setting unload timer (40000ms)
[task 2024-04-04T21:02:35.686Z] 21:02:35     INFO -  1712264555685	RemoteAgent	TRACE	[9] Document already finished loading: about:blank
[task 2024-04-04T21:02:35.686Z] 21:02:35     INFO -  1712264555685	RemoteAgent	TRACE	[9] ProgressListener Stop: has error=false
[task 2024-04-04T21:02:35.768Z] 21:02:35     INFO -  1712264555766	Marionette	DEBUG	2 <- [1,1,null,{"sessionId":"3582d136-ae2f-4a8f-aaa6-91388fb77097","capabilities":{"browserName":"firefox","browserVersion":"126.0a1","platformName":"windows","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:126.0) Gecko/20100101 Firefox/126.0","moz:accessibilityChecks":false,"moz:buildID":"20240404193558","moz:headless":false,"moz:platformVersion":"10.0","moz:processID":3856,"moz:profile":"C:\\Users\\task_171226225948577\\AppData\\Local\\Temp\\tmp95p_mhm9.mozrunner","moz:shutdownTimeout":300000,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2024-04-04T21:02:35.791Z] 21:02:35     INFO -  1712264555785	Marionette	DEBUG	2 -> [0,2,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-04-04T21:02:35.792Z] 21:02:35     INFO -  1712264555786	Marionette	DEBUG	2 <- [1,2,null,{"value":null}]
[task 2024-04-04T21:02:35.793Z] 21:02:35     INFO -  console.debug: SearchTelemetry: "Initialized domain-to-categories store."
[task 2024-04-04T21:02:35.799Z] 21:02:35     INFO -  1712264555797	Marionette	DEBUG	2 -> [0,3,"WebDriver:ExecuteScript",{"script":"Glean.serp.categorization.record({\n            organic_category: \"3\",\n            organic_num_domains: \"1\",\n            organ ... vider: \"example\",\n            tagged: \"true\",\n            num_ads_clicked: \"0\",\n            num_ads_visible: \"2\",\n        });","args":[],"newSandbox":true,"sandbox":"default","line":27,"filename":"D:\\task_171226225948577\\build\\tests\\marionette\\tests\\browser\\components\\search\\test\\marionette\\telemetry\\test_ping_submitted.py"}]
[task 2024-04-04T21:02:35.838Z] 21:02:35     INFO -  1712264555837	RemoteAgent	TRACE	WebDriverProcessData actor created for PID 3856
[task 2024-04-04T21:02:35.842Z] 21:02:35     INFO -  1712264555842	Marionette	TRACE	[1] MarionetteCommands actor created for window id 2
[task 2024-04-04T21:02:35.864Z] 21:02:35     INFO -  1712264555863	Marionette	DEBUG	2 <- [1,3,null,{"value":null}]
[task 2024-04-04T21:02:35.865Z] 21:02:35     INFO -  console.debug: SearchTelemetry: "No records found for domain-to-categories map."
[task 2024-04-04T21:02:35.865Z] 21:02:35     INFO -  console.debug: SearchTelemetry: "Initialized domain-to-categories map."
[task 2024-04-04T21:02:35.865Z] 21:02:35     INFO -  console.debug: SearchTelemetry: "Initializing categorization event scheduler."
[task 2024-04-04T21:02:35.870Z] 21:02:35     INFO -  1712264555869	Marionette	DEBUG	2 -> [0,4,"WebDriver:ExecuteScript",{"script":"return Glean.serp.categorization.testGetValue()?.length ?? 0;","args":[],"newSandbox":true,"sandbox":"default","line":52,"filename":"D:\\task_171226225948577\\build\\tests\\marionette\\tests\\browser\\components\\search\\test\\marionette\\telemetry\\test_ping_submitted.py"}]
[task 2024-04-04T21:02:35.886Z] 21:02:35     INFO -  1712264555886	Marionette	DEBUG	2 <- [1,4,null,{"value":0}]
[task 2024-04-04T21:02:35.889Z] 21:02:35     INFO -  1712264555889	Marionette	DEBUG	2 -> [0,5,"Marionette:GetContext",{}]
[task 2024-04-04T21:02:35.889Z] 21:02:35     INFO -  1712264555889	Marionette	DEBUG	2 <- [1,5,null,{"value":"chrome"}]
[task 2024-04-04T21:02:35.891Z] 21:02:35     INFO -  1712264555891	Marionette	DEBUG	2 -> [0,6,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-04-04T21:02:35.892Z] 21:02:35     INFO -  1712264555892	Marionette	DEBUG	2 <- [1,6,null,{"value":null}]
[task 2024-04-04T21:02:35.894Z] 21:02:35     INFO -  1712264555894	Marionette	DEBUG	2 -> [0,7,"WebDriver:TakeScreenshot",{"id":null,"full":true,"hash":false,"scroll":true}]
[task 2024-04-04T21:02:36.019Z] 21:02:36     INFO -  1712264556019	Marionette	DEBUG	2 <- [1,7,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABQAAAAPQCAYAAABpCtbiAAAgAElEQVR4XuzdC7ildV0v8P/AzDDDzQtYKIhYIFgIgihwpFLTx9STWpm3o/TkNe9aXo7nKCp2HkMtU ... +AQIECBAgQIAAAQIECBAgQIBAW8AB2O5XOgIECBAgQIAAAQIECBAgQIAAgXMBB+D5AMQnQIAAAQIECBAgQIAAAQIECBBoCwzTtXVq5b5GzQAAAABJRU5ErkJggg=="}]
[task 2024-04-04T21:02:36.024Z] 21:02:36     INFO -  1712264556024	Marionette	DEBUG	2 -> [0,8,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-04-04T21:02:36.025Z] 21:02:36     INFO -  1712264556025	Marionette	DEBUG	2 <- [1,8,null,{"value":null}]
[task 2024-04-04T21:02:36.030Z] 21:02:36     INFO -  1712264556029	Marionette	DEBUG	2 -> [0,9,"Marionette:GetContext",{}]
[task 2024-04-04T21:02:36.030Z] 21:02:36     INFO -  1712264556030	Marionette	DEBUG	2 <- [1,9,null,{"value":"chrome"}]
[task 2024-04-04T21:02:36.034Z] 21:02:36     INFO -  1712264556034	Marionette	DEBUG	2 -> [0,10,"Marionette:SetContext",{"value":"content"}]
[task 2024-04-04T21:02:36.034Z] 21:02:36     INFO -  1712264556034	Marionette	DEBUG	2 <- [1,10,null,{"value":null}]
[task 2024-04-04T21:02:36.036Z] 21:02:36     INFO -  1712264556036	Marionette	DEBUG	2 -> [0,11,"WebDriver:GetPageSource",{}]
[task 2024-04-04T21:02:36.053Z] 21:02:36     INFO -  1712264556052	RemoteAgent	TRACE	WebDriverProcessData actor created for PID 6096
[task 2024-04-04T21:02:36.060Z] 21:02:36     INFO -  1712264556060	Marionette	TRACE	[9] MarionetteCommands actor created for window id 4294967297
[task 2024-04-04T21:02:36.072Z] 21:02:36     INFO -  1712264556072	Marionette	DEBUG	2 <- [1,11,null,{"value":"<html><head></head><body></body></html>"}]
[task 2024-04-04T21:02:36.079Z] 21:02:36     INFO -  1712264556079	Marionette	DEBUG	2 -> [0,12,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-04-04T21:02:36.079Z] 21:02:36     INFO -  1712264556079	Marionette	DEBUG	2 <- [1,12,null,{"value":null}]
[task 2024-04-04T21:02:36.082Z] 21:02:36    ERROR -  TEST-UNEXPECTED-FAIL | browser/components/search/test/marionette/telemetry/test_ping_submitted.py TestPingSubmitted.test_ping_submit_on_start | AssertionError: 0 != 1 : Should have recorded a SERP categorization event before restart.
[task 2024-04-04T21:02:36.083Z] 21:02:36     INFO -  Traceback (most recent call last):
[task 2024-04-04T21:02:36.083Z] 21:02:36     INFO -    File "D:\task_171226225948577\build\venv\Lib\site-packages\marionette_harness\marionette_test\testcases.py", line 198, in run
[task 2024-04-04T21:02:36.084Z] 21:02:36     INFO -      testMethod()
[task 2024-04-04T21:02:36.084Z] 21:02:36     INFO -    File "D:\task_171226225948577\build\tests\marionette\tests\browser\components\search\test\marionette\telemetry\test_ping_submitted.py", line 51, in test_ping_submit_on_start
[task 2024-04-04T21:02:36.084Z] 21:02:36     INFO -      self.assertEqual(
[task 2024-04-04T21:02:36.084Z] 21:02:36     INFO -  TEST-INFO took 13661ms
[task 2024-04-04T21:02:36.085Z] 21:02:36     INFO -  1712264556084	Marionette	DEBUG	2 -> [0,13,"WebDriver:DeleteSession",{}]
[task 2024-04-04T21:02:36.086Z] 21:02:36     INFO -  1712264556086	Marionette	TRACE	[1] MarionetteCommands actor destroyed for window id 2
[task 2024-04-04T21:02:36.086Z] 21:02:36     INFO -  1712264556086	Marionette	TRACE	[9] MarionetteCommands actor destroyed for window id 4294967297
[task 2024-04-04T21:02:36.092Z] 21:02:36     INFO -  1712264556091	Marionette	DEBUG	2 <- [1,13,null,{"value":null}]
[task 2024-04-04T21:02:36.096Z] 21:02:36     INFO -  TEST-START | browser/components/search/test/marionette/test_engines_on_restart.py TestEnginesOnRestart.test_engines

Comment 2

[Intermittent Failures Robot]

6 failures in 3805 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 4
• mozilla-central: 2

Platform and build breakdown:

• windows11-64-2009-asan-qr: 2
  • opt: 2
• windows11-32-2009-qr: 1
  • opt: 1
• windows11-64-2009-qr: 2
  • opt: 2
• windows11-64-2009-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1889802&startday=2024-04-01&endday=2024-04-07&tree=all

Comment 3

[Intermittent Failures Robot]

6 failures in 3235 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 4
• mozilla-central: 2

Platform and build breakdown:

• windows11-64-2009-qr: 3
  • debug: 3
• windows11-32-2009-qr: 2
  • opt: 1
  • debug: 1
• windows11-64-2009-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1889802&startday=2024-04-08&endday=2024-04-14&tree=all

Comment 4

[Intermittent Failures Robot]

11 failures in 4252 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 6
• autoland: 4
• try: 1

Platform and build breakdown:

• windows11-32-2009-qr: 4
  • debug: 2
  • opt: 2
• windows11-32-2009-shippable-qr: 3
  • opt: 3
• windows11-64-2009-shippable-qr: 2
  • opt: 2
• windows11-64-2009-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1889802&startday=2024-04-15&endday=2024-04-21&tree=all

Comment 5

[Intermittent Failures Robot]

5 failures in 4336 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 4
• mozilla-central: 1

Platform and build breakdown:

• windows11-32-2009-qr: 2
  • opt: 1
  • debug: 1
• windows11-64-2009-qr: 2
  • opt: 2
• windows11-32-2009-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1889802&startday=2024-04-22&endday=2024-04-28&tree=all