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:"google@search.mozilla.org"}})
[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:"ddg@search.mozilla.org"}})
[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:"bing@search.mozilla.org"}})
[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:"wikipedia@search.mozilla.org"}})
[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:" "screenshots@mozilla.org"
[task 2024-04-04T21:02:34.533Z] 21:02:34 INFO - console.debug: SearchService: "getEngines: getting all engines for" "screenshots@mozilla.org"
[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
Description
•