Closed
Bug 1727850
Opened 4 years ago
Closed 4 years ago
Intermittent testing/firefox-ui/tests/functional/sessionstore/test_restore_windows_after_windows_shutdown.py TestWindowsShutdownForcedSessionRestore.test_os_restart | AssertionError: Items in the first set but not the second:
Categories
(Testing :: Firefox UI Tests, defect, P5)
Testing
Firefox UI Tests
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1727691
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: assertion, intermittent-failure)
Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=349723020&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/MxUYwluQT-i0myhRpuKexw/runs/0/artifacts/public/logs/live_backing.log
[task 2021-08-26T23:16:10.437Z] 23:16:10 INFO - TEST-START | testing/firefox-ui/tests/functional/sessionstore/test_restore_windows_after_windows_shutdown.py TestWindowsShutdownForcedSessionRestore.test_os_restart
[task 2021-08-26T23:16:10.437Z] 23:16:10 INFO - 1630019770436 Marionette DEBUG Accepted connection 2 from 127.0.0.1:50571
[task 2021-08-26T23:16:10.437Z] 23:16:10 INFO - 1630019770437 Marionette DEBUG 2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-08-26T23:16:10.438Z] 23:16:10 INFO - 1630019770438 Marionette DEBUG 2 <- [1,1,null,{"sessionId":"dc662631-7b1b-4e37-9b86-dbefab1b1794","capabilities":{"browserName":"firefox","browserVersion":"93.0a ... o.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2021-08-26T23:16:10.439Z] 23:16:10 INFO - 1630019770439 Marionette DEBUG 2 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-08-26T23:16:10.439Z] 23:16:10 INFO - 1630019770439 Marionette DEBUG 2 <- [1,2,null,{"value":null}]
[task 2021-08-26T23:16:10.440Z] 23:16:10 INFO - 1630019770439 Marionette DEBUG 2 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2021-08-26T23:16:10.440Z] 23:16:10 INFO - 1630019770440 Marionette DEBUG 2 <- [1,3,null,{"value":null}]
[task 2021-08-26T23:16:10.440Z] 23:16:10 INFO - 1630019770440 Marionette DEBUG 2 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2021-08-26T23:16:10.440Z] 23:16:10 INFO - 1630019770440 Marionette DEBUG 2 <- [1,4,null,{"value":null}]
[task 2021-08-26T23:16:10.441Z] 23:16:10 INFO - 1630019770441 Marionette DEBUG 2 -> [0,5,"WebDriver:GetChromeWindowHandle",{}]
[task 2021-08-26T23:16:10.441Z] 23:16:10 INFO - 1630019770441 Marionette DEBUG 2 <- [1,5,null,{"value":"fbb1c962-50c7-4cbb-805b-4e64b2925b61"}]
[task 2021-08-26T23:16:10.442Z] 23:16:10 INFO - 1630019770442 Marionette DEBUG 2 -> [0,6,"WebDriver:GetChromeWindowHandles",{}]
[task 2021-08-26T23:16:10.442Z] 23:16:10 INFO - 1630019770442 Marionette DEBUG 2 <- [1,6,null,["fbb1c962-50c7-4cbb-805b-4e64b2925b61"]]
[task 2021-08-26T23:16:10.444Z] 23:16:10 INFO - 1630019770444 Marionette DEBUG 2 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2021-08-26T23:16:10.445Z] 23:16:10 INFO - 1630019770444 Marionette DEBUG 2 <- [1,7,null,{"value":"67e7ca20-6c31-402c-ba14-781c5c5eeee9"}]
[task 2021-08-26T23:16:10.445Z] 23:16:10 INFO - 1630019770445 Marionette DEBUG 2 -> [0,8,"WebDriver:GetWindowHandles",{}]
[task 2021-08-26T23:16:10.445Z] 23:16:10 INFO - 1630019770445 Marionette DEBUG 2 <- [1,8,null,["67e7ca20-6c31-402c-ba14-781c5c5eeee9"]]
[task 2021-08-26T23:16:10.446Z] 23:16:10 INFO - 1630019770446 Marionette DEBUG 2 -> [0,9,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-08-26T23:16:10.446Z] 23:16:10 INFO - 1630019770446 Marionette DEBUG 2 <- [1,9,null,{"value":null}]
[task 2021-08-26T23:16:10.447Z] 23:16:10 INFO - 1630019770447 Marionette DEBUG 2 -> [0,10,"Marionette:GetContext",{}]
[task 2021-08-26T23:16:10.447Z] 23:16:10 INFO - 1630019770447 Marionette DEBUG 2 <- [1,10,null,{"value":"chrome"}]
[task 2021-08-26T23:16:10.447Z] 23:16:10 INFO - 1630019770447 Marionette DEBUG 2 -> [0,11,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-08-26T23:16:10.448Z] 23:16:10 INFO - 1630019770447 Marionette DEBUG 2 <- [1,11,null,{"value":null}]
[task 2021-08-26T23:16:10.449Z] 23:16:10 INFO - 1630019770449 Marionette DEBUG 2 -> [0,12,"WebDriver:ExecuteScript",{"script":"let prefInterface = Components.classes[\"@mozilla.org/preferences-service;1\"]\n ... efault","line":878,"filename":"Z:\\task_163001923520035\\build\\venv\\lib\\site-packages\\marionette_driver\\marionette.py"}]
[task 2021-08-26T23:16:10.450Z] 23:16:10 INFO - 1630019770450 Marionette TRACE [7] MarionetteCommands actor created for window id 2
[task 2021-08-26T23:16:10.451Z] 23:16:10 INFO - 1630019770451 Marionette DEBUG 2 <- [1,12,null,{"value":false}]
[task 2021-08-26T23:16:10.452Z] 23:16:10 INFO - 1630019770452 Marionette DEBUG 2 -> [0,13,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-08-26T23:16:10.452Z] 23:16:10 INFO - 1630019770452 Marionette DEBUG 2 <- [1,13,null,{"value":null}]
[task 2021-08-26T23:16:10.452Z] 23:16:10 INFO - 1630019770452 Marionette DEBUG 2 -> [0,14,"Marionette:GetContext",{}]
[task 2021-08-26T23:16:10.452Z] 23:16:10 INFO - 1630019770452 Marionette DEBUG 2 <- [1,14,null,{"value":"chrome"}]
[task 2021-08-26T23:16:10.453Z] 23:16:10 INFO - 1630019770453 Marionette DEBUG 2 -> [0,15,"WebDriver:DeleteSession",{}]
[task 2021-08-26T23:16:10.453Z] 23:16:10 INFO - 1630019770453 Marionette DEBUG 2 <- [1,15,null,{"value":null}]
[task 2021-08-26T23:16:10.454Z] 23:16:10 INFO - 1630019770453 Marionette DEBUG Closed connection 2
[task 2021-08-26T23:16:10.542Z] 23:16:10 INFO - Application command: Z:\task_163001923520035\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile Z:\task_163001923520035\build\tmp2pheiq37.mozrunner
[task 2021-08-26T23:16:10.931Z] 23:16:10 INFO - 1630019770940 Marionette INFO Marionette enabled
[task 2021-08-26T23:16:10.985Z] 23:16:10 INFO - 1630019770997 Marionette TRACE Received observer notification toplevel-window-ready
[task 2021-08-26T23:16:12.264Z] 23:16:12 INFO - console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at Z:\\task_163001923520035\\build\\tmp2pheiq37.mozrunner\\search.json.mozlz4", (void 0)))
[task 2021-08-26T23:16:12.966Z] 23:16:12 INFO - 1630019772977 Marionette TRACE Received observer notification marionette-startup-requested
[task 2021-08-26T23:16:12.978Z] 23:16:12 INFO - 1630019772977 Marionette TRACE Waiting until startup recorder finished recording startup scripts...
[task 2021-08-26T23:16:12.989Z] 23:16:12 INFO - 1630019772989 Marionette TRACE All scripts recorded.
[task 2021-08-26T23:16:12.990Z] 23:16:12 INFO - 1630019772990 Marionette INFO Listening on port 2828
[task 2021-08-26T23:16:12.991Z] 23:16:12 INFO - 1630019772991 Marionette DEBUG Marionette is listening
[task 2021-08-26T23:16:13.050Z] 23:16:13 INFO - 1630019773065 Marionette DEBUG Accepted connection 0 from 127.0.0.1:50596
[task 2021-08-26T23:16:13.067Z] 23:16:13 INFO - 1630019773067 Marionette DEBUG Closed connection 0
[task 2021-08-26T23:16:13.068Z] 23:16:13 INFO - 1630019773067 Marionette DEBUG Accepted connection 1 from 127.0.0.1:50597
[task 2021-08-26T23:16:13.081Z] 23:16:13 INFO - 1630019773087 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-08-26T23:16:13.098Z] 23:16:13 INFO - 1630019773098 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"f4e57e31-72c6-4094-a884-31013ef11295","capabilities":{"browserName":"firefox","browserVersion":"93.0a ... 7.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2021-08-26T23:16:13.100Z] 23:16:13 INFO - 1630019773100 Marionette DEBUG 1 -> [0,2,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-08-26T23:16:13.100Z] 23:16:13 INFO - 1630019773100 Marionette DEBUG 1 <- [1,2,null,{"value":null}]
[task 2021-08-26T23:16:13.100Z] 23:16:13 INFO - 1630019773101 Marionette DEBUG 1 -> [0,3,"WebDriver:GetChromeWindowHandle",{}]
[task 2021-08-26T23:16:13.101Z] 23:16:13 INFO - 1630019773101 Marionette DEBUG 1 <- [1,3,null,{"value":"9587e7eb-ecb9-4101-806e-02c373ca4649"}]
[task 2021-08-26T23:16:13.101Z] 23:16:13 INFO - 1630019773101 Marionette DEBUG 1 -> [0,4,"Marionette:GetContext",{}]
[task 2021-08-26T23:16:13.101Z] 23:16:13 INFO - 1630019773101 Marionette DEBUG 1 <- [1,4,null,{"value":"chrome"}]
[task 2021-08-26T23:16:13.102Z] 23:16:13 INFO - 1630019773102 Marionette DEBUG 1 -> [0,5,"Marionette:SetContext",{"value":"content"}]
[task 2021-08-26T23:16:13.102Z] 23:16:13 INFO - 1630019773102 Marionette DEBUG 1 <- [1,5,null,{"value":null}]
[task 2021-08-26T23:16:13.102Z] 23:16:13 INFO - 1630019773103 Marionette DEBUG 1 -> [0,6,"WebDriver:Navigate",{"url":"http://127.0.0.1:49821/layout/mozilla.html"}]
[task 2021-08-26T23:16:13.107Z] 23:16:13 INFO - 1630019773107 Marionette TRACE [19] Received event beforeunload for about:home
[task 2021-08-26T23:16:13.117Z] 23:16:13 INFO - 1630019773117 Marionette TRACE Remoteness change detected. Set new top-level browsing context to 19
[task 2021-08-26T23:16:13.119Z] 23:16:13 INFO - 1630019773119 Marionette TRACE [19] Received event pagehide for about:home
[task 2021-08-26T23:16:13.131Z] 23:16:13 INFO - 1630019773133 Marionette TRACE [19] Received event beforeunload for about:blank
[task 2021-08-26T23:16:13.147Z] 23:16:13 INFO - 1630019773146 Marionette TRACE [19] Received event pagehide for about:blank
[task 2021-08-26T23:16:13.160Z] 23:16:13 INFO - 1630019773164 Marionette TRACE [19] Received event DOMContentLoaded for http://127.0.0.1:49821/layout/mozilla.html
[task 2021-08-26T23:16:13.167Z] 23:16:13 INFO - 1630019773173 Marionette TRACE [19] Received event pageshow for http://127.0.0.1:49821/layout/mozilla.html
[task 2021-08-26T23:16:13.174Z] 23:16:13 INFO - 1630019773173 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2021-08-26T23:16:13.176Z] 23:16:13 INFO - 1630019773176 Marionette DEBUG 1 -> [0,7,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-08-26T23:16:13.177Z] 23:16:13 INFO - 1630019773176 Marionette DEBUG 1 <- [1,7,null,{"value":null}]
[task 2021-08-26T23:16:13.177Z] 23:16:13 INFO - 1630019773177 Marionette DEBUG 1 -> [0,8,"WebDriver:GetChromeWindowHandles",{}]
[task 2021-08-26T23:16:13.178Z] 23:16:13 INFO - 1630019773177 Marionette DEBUG 1 <- [1,8,null,["9587e7eb-ecb9-4101-806e-02c373ca4649"]]
[task 2021-08-26T23:16:13.178Z] 23:16:13 INFO - 1630019773178 Marionette DEBUG 1 -> [0,9,"WebDriver:GetWindowHandles",{}]
[task 2021-08-26T23:16:13.179Z] 23:16:13 INFO - 1630019773178 Marionette DEBUG 1 <- [1,9,null,["44d40258-c8b6-4a33-86cc-870dea47305b"]]
[task 2021-08-26T23:16:13.179Z] 23:16:13 INFO - 1630019773179 Marionette DEBUG 1 -> [0,10,"WebDriver:NewWindow",{"type":"window","focus":false,"private":false}]
[task 2021-08-26T23:16:13.182Z] 23:16:13 INFO - 1630019773181 Marionette TRACE Received observer notification domwindowopened
[task 2021-08-26T23:16:13.186Z] 23:16:13 INFO - 1630019773186 Marionette TRACE Received DOM event activate for [object Window]
[task 2021-08-26T23:16:13.186Z] 23:16:13 INFO - 1630019773186 Marionette TRACE Received DOM event focus for [object HTMLDocument]
[task 2021-08-26T23:16:13.382Z] 23:16:13 INFO - 1630019773389 Marionette TRACE Received observer notification browser-delayed-startup-finished
[task 2021-08-26T23:16:13.389Z] 23:16:13 INFO - 1630019773390 Marionette TRACE Received event beforeunload for about:blank
[task 2021-08-26T23:16:13.397Z] 23:16:13 INFO - 1630019773398 Marionette TRACE Received DOM event activate for [object Window]
[task 2021-08-26T23:16:13.398Z] 23:16:13 INFO - 1630019773398 Marionette TRACE Received DOM event focus for [object HTMLDocument]
[task 2021-08-26T23:16:13.402Z] 23:16:13 INFO - 1630019773402 Marionette TRACE Received event pagehide for about:blank
[task 2021-08-26T23:16:13.414Z] 23:16:13 INFO - 1630019773426 Marionette TRACE Received event DOMContentLoaded for about:home
[task 2021-08-26T23:16:13.426Z] 23:16:13 INFO - 1630019773426 Marionette TRACE Received event pageshow for about:home
[task 2021-08-26T23:16:13.427Z] 23:16:13 INFO - 1630019773427 Marionette DEBUG 1 <- [1,10,null,{"handle":"beb2abea-abcb-48b5-8fbd-69473e0169d6","type":"window"}]
[task 2021-08-26T23:16:13.429Z] 23:16:13 INFO - 1630019773429 Marionette DEBUG 1 -> [0,11,"WebDriver:GetChromeWindowHandles",{}]
[task 2021-08-26T23:16:13.430Z] 23:16:13 INFO - 1630019773430 Marionette DEBUG 1 <- [1,11,null,["9587e7eb-ecb9-4101-806e-02c373ca4649","3b983ada-d1c5-48d3-988b-976af8115797"]]
[task 2021-08-26T23:16:13.430Z] 23:16:13 INFO - 1630019773430 Marionette DEBUG 1 -> [0,12,"WebDriver:GetChromeWindowHandles",{}]
[task 2021-08-26T23:16:13.431Z] 23:16:13 INFO - 1630019773431 Marionette DEBUG 1 <- [1,12,null,["9587e7eb-ecb9-4101-806e-02c373ca4649","3b983ada-d1c5-48d3-988b-976af8115797"]]
<...>
[task 2021-08-26T23:16:18.155Z] 23:16:18 INFO - 1630019778155 Marionette DEBUG 2 -> [0,32,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-08-26T23:16:18.155Z] 23:16:18 INFO - 1630019778155 Marionette DEBUG 2 <- [1,32,null,{"value":null}]
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - TEST-UNEXPECTED-FAIL | testing/firefox-ui/tests/functional/sessionstore/test_restore_windows_after_windows_shutdown.py TestWindowsShutdownForcedSessionRestore.test_os_restart | AssertionError: Items in the first set but not the second:
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - ('http://127.0.0.1:49821/layout/mozilla_governance.html', 'about:blank')
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - Items in the second set but not the first:
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - ('http://127.0.0.1:49821/layout/mozilla_governance.html', 'http://127.0.0.1:49821/layout/mozilla_grants.html') : Non private browsing windows should have
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - been restored. Expected {('http://127.0.0.1:49821/layout/mozilla.html',), ('http://127.0.0.1:49821/layout/mozilla_organizations.html', 'http://127.0.0.1:49821/layout/mozilla_community.html'), ('http://127.0.0.1:49821/layout/mozilla_governance.html', 'http://127.0.0.1:49821/layout/mozilla_grants.html')}, got {('http://127.0.0.1:49821/layout/mozilla.html',), ('http://127.0.0.1:49821/layout/mozilla_organizations.html', 'http://127.0.0.1:49821/layout/mozilla_community.html'), ('http://127.0.0.1:49821/layout/mozilla_governance.html', 'about:blank')}.
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - Traceback (most recent call last):
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - File "Z:\task_163001923520035\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 202, in run
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - testMethod()
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - File "Z:\task_163001923520035\build\tests\firefox-ui\tests\testing\firefox-ui\tests\functional\sessionstore\test_restore_windows_after_windows_shutdown.py", line 63, in test_os_restart
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - self.windows_shutdown_with_variety(restart_by_os=True, expect_restore=True)
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - File "Z:\task_163001923520035\build\tests\firefox-ui\tests\testing\firefox-ui\tests\functional\sessionstore\session_store_test_case.py", line 381, in windows_shutdown_with_variety
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - self.assertEqual(
[task 2021-08-26T23:16:18.177Z] 23:16:18 INFO - TEST-INFO took 7720ms
[task 2021-08-26T23:16:18.178Z] 23:16:18 INFO - 1630019778172 Marionette DEBUG 2 -> [0,33,"Marionette:GetContext",{}]
[task 2021-08-26T23:16:18.178Z] 23:16:18 INFO - 1630019778172 Marionette DEBUG 2 <- [1,33,null,{"value":"chrome"}]
[task 2021-08-26T23:16:18.178Z] 23:16:18 INFO - 1630019778172 Marionette DEBUG 2 -> [0,34,"WebDriver:DeleteSession",{}]
[task 2021-08-26T23:16:18.178Z] 23:16:18 INFO - 1630019778173 Marionette DEBUG 2 <- [1,34,null,{"value":null}]
[task 2021-08-26T23:16:18.179Z] 23:16:18 INFO - 1630019778174 Marionette DEBUG Closed connection 2
[task 2021-08-26T23:16:18.279Z] 23:16:18 INFO - Application command: Z:\task_163001923520035\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile Z:\task_163001923520035\build\tmpdhp02oqg.mozrunner
[task 2021-08-26T23:16:18.688Z] 23:16:18 INFO - 1630019778698 Marionette INFO Marionette enabled
[task 2021-08-26T23:16:18.748Z] 23:16:18 INFO - 1630019778755 Marionette TRACE Received observer notification toplevel-window-ready
[task 2021-08-26T23:16:19.996Z] 23:16:19 INFO - console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at Z:\\task_163001923520035\\build\\tmpdhp02oqg.mozrunner\\search.json.mozlz4", (void 0)))
[task 2021-08-26T23:16:20.761Z] 23:16:20 INFO - 1630019780762 Marionette TRACE Received observer notification marionette-startup-requested
[task 2021-08-26T23:16:20.763Z] 23:16:20 INFO - 1630019780763 Marionette TRACE Waiting until startup recorder finished recording startup scripts...
[task 2021-08-26T23:16:20.771Z] 23:16:20 INFO - 1630019780772 Marionette TRACE All scripts recorded.
[task 2021-08-26T23:16:20.773Z] 23:16:20 INFO - 1630019780773 Marionette INFO Listening on port 2828
[task 2021-08-26T23:16:20.773Z] 23:16:20 INFO - 1630019780774 Marionette DEBUG Marionette is listening
[task 2021-08-26T23:16:21.346Z] 23:16:21 INFO - 1630019781353 Marionette DEBUG Accepted connection 0 from 127.0.0.1:50704
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
||
Updated•4 years ago
|
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → DUPLICATE
You need to log in
before you can comment on or make changes to this bug.
Description
•