1868526 - Intermittent browser/components/sessionstore/test/marionette/test_restore_manually.py TestSessionRestoreManually.test_restore | single tracking bug

Status: RESOLVED FIXED

(Firefox :: Session Restore, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2023-12-06T07:49:03.331Z] 07:49:03     INFO -  console.warn: SessionStore: "waiting on 1 windows to be restored before sending restore complete notifications."
[task 2023-12-06T07:49:03.724Z] 07:49:03     INFO -  1701848943723	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2023-12-06T07:49:03.842Z] 07:49:03     INFO -  1701848943842	Marionette	DEBUG	1 -> [0,6,"WebDriver:GetWindowHandles",{}]
[task 2023-12-06T07:49:03.845Z] 07:49:03     INFO -  1701848943843	Marionette	DEBUG	1 <- [1,6,null,["3d531010-5b50-4eb6-b449-d2d15f08a368","3457ac67-6a98-4395-b724-c5635a128355"]]
[task 2023-12-06T07:49:03.901Z] 07:49:03     INFO -  1701848943901	Marionette	DEBUG	1 -> [0,7,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-12-06T07:49:03.903Z] 07:49:03     INFO -  1701848943902	Marionette	DEBUG	1 <- [1,7,null,{"value":null}]
[task 2023-12-06T07:49:03.921Z] 07:49:03     INFO -  1701848943920	Marionette	DEBUG	1 -> [0,8,"WebDriver:ExecuteScript",{"script":"const lazy = {};\n                ChromeUtils.defineESModuleGetters(lazy, {\n                    SessionStore: \"resource:///mod ...              });\n                let state = SessionStore.getCurrentState()\n                return state.windows[1][\"height\"]","args":[],"newSandbox":true,"sandbox":"default","line":121,"filename":"tests/browser/components/sessionstore/test/marionette/test_restore_manually.py"}]
[task 2023-12-06T07:49:03.930Z] 07:49:03     INFO -  1701848943930	Marionette	DEBUG	1 <- [1,8,null,{"value":1040}]
[task 2023-12-06T07:49:03.937Z] 07:49:03     INFO -  1701848943937	Marionette	DEBUG	1 -> [0,9,"Marionette:GetContext",{}]
[task 2023-12-06T07:49:03.939Z] 07:49:03     INFO -  1701848943938	Marionette	DEBUG	1 <- [1,9,null,{"value":"chrome"}]
[task 2023-12-06T07:49:03.960Z] 07:49:03     INFO -  1701848943959	Marionette	DEBUG	1 -> [0,10,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-12-06T07:49:03.961Z] 07:49:03     INFO -  1701848943959	Marionette	DEBUG	1 <- [1,10,null,{"value":null}]
[task 2023-12-06T07:49:03.964Z] 07:49:03     INFO -  1701848943963	Marionette	DEBUG	1 -> [0,11,"WebDriver:TakeScreenshot",{"id":null,"full":true,"hash":false,"scroll":true}]
[task 2023-12-06T07:49:04.024Z] 07:49:04     INFO -  1701848944023	Marionette	DEBUG	1 <- [1,11,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABQAAAAQQCAYAAAC9RfbYAAAgAElEQVR4XuzdC9QsZ1kn+ndn70AuYIBckIuTyM1DAA9CiA4uLuLokAzJiOgRwxDWQscQLoFFMiMww ... aJ0CAAAECBAgQIECAAAECBAgQINAKCICtv3cCBAgQIECAAAECBAgQIECAAAECVwEB8MprnAABAgQIECBAgAABAgQIECBAgEArMEtJ+devCyuEAAAAAElFTkSuQmCC"}]
[task 2023-12-06T07:49:04.035Z] 07:49:04     INFO -  1701848944034	Marionette	DEBUG	1 -> [0,12,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-12-06T07:49:04.036Z] 07:49:04     INFO -  1701848944035	Marionette	DEBUG	1 <- [1,12,null,{"value":null}]
[task 2023-12-06T07:49:04.038Z] 07:49:04     INFO -  1701848944037	Marionette	DEBUG	1 -> [0,13,"Marionette:GetContext",{}]
[task 2023-12-06T07:49:04.038Z] 07:49:04     INFO -  1701848944038	Marionette	DEBUG	1 <- [1,13,null,{"value":"chrome"}]
[task 2023-12-06T07:49:04.042Z] 07:49:04     INFO -  1701848944041	Marionette	DEBUG	1 -> [0,14,"Marionette:SetContext",{"value":"content"}]
[task 2023-12-06T07:49:04.042Z] 07:49:04     INFO -  1701848944042	Marionette	DEBUG	1 <- [1,14,null,{"value":null}]
[task 2023-12-06T07:49:04.046Z] 07:49:04     INFO -  1701848944046	Marionette	DEBUG	1 -> [0,15,"WebDriver:GetPageSource",{}]
[task 2023-12-06T07:49:04.050Z] 07:49:04     INFO -  1701848944049	RemoteAgent	TRACE	WebDriverProcessData actor created for PID 5875
[task 2023-12-06T07:49:04.053Z] 07:49:04     INFO -  1701848944053	Marionette	TRACE	[3] MarionetteCommands actor created for window id 2147483650
[task 2023-12-06T07:49:04.057Z] 07:49:04     INFO -  1701848944056	Marionette	DEBUG	1 <- [1,15,null,{"value":"<html><head><title>sit</title></head><body></body></html>"}]
[task 2023-12-06T07:49:04.058Z] 07:49:04     INFO -  1701848944058	Marionette	DEBUG	1 -> [0,16,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-12-06T07:49:04.059Z] 07:49:04     INFO -  1701848944059	Marionette	DEBUG	1 <- [1,16,null,{"value":null}]
[task 2023-12-06T07:49:04.128Z] 07:49:04     INFO - TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/marionette/test_restore_manually.py TestSessionRestoreManually.test_restore | AssertionError: 1040 != 500 : Second window has been restored to the correct height.
[task 2023-12-06T07:49:04.130Z] 07:49:04     INFO - Traceback (most recent call last):
[task 2023-12-06T07:49:04.131Z] 07:49:04     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 198, in run
[task 2023-12-06T07:49:04.132Z] 07:49:04     INFO -     testMethod()
[task 2023-12-06T07:49:04.133Z] 07:49:04     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/browser/components/sessionstore/test/marionette/test_restore_manually.py", line 124, in test_restore
[task 2023-12-06T07:49:04.134Z] 07:49:04     INFO -     "Second window has been restored to the correct height.",
[task 2023-12-06T07:49:04.135Z] 07:49:04     INFO - TEST-INFO took 13504ms
[task 2023-12-06T07:49:04.135Z] 07:49:04     INFO -  1701848944080	Marionette	DEBUG	1 -> [0,17,"Marionette:GetContext",{}]
[task 2023-12-06T07:49:04.139Z] 07:49:04     INFO -  1701848944080	Marionette	DEBUG	1 <- [1,17,null,{"value":"chrome"}]
[task 2023-12-06T07:49:04.142Z] 07:49:04     INFO -  1701848944083	Marionette	DEBUG	1 -> [0,18,"WebDriver:DeleteSession",{}]
[task 2023-12-06T07:49:04.145Z] 07:49:04     INFO -  1701848944084	Marionette	TRACE	[3] MarionetteCommands actor destroyed for window id 2147483650
[task 2023-12-06T07:49:04.148Z] 07:49:04     INFO -  1701848944084	Marionette	TRACE	[1] MarionetteCommands actor destroyed for window id 2
[task 2023-12-06T07:49:04.151Z] 07:49:04     INFO -  1701848944087	Marionette	DEBUG	1 <- [1,18,null,{"value":null}]
[task 2023-12-06T07:49:04.156Z] 07:49:04     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -no-remote -marionette -profile /tmp/tmpmzb29bmy.mozrunner
[task 2023-12-06T07:49:04.690Z] 07:49:04     INFO -  ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-12-06T07:49:04.713Z] 07:49:04     INFO -  1701848944713	Marionette	INFO	Marionette enabled
[task 2023-12-06T07:49:04.715Z] 07:49:04     INFO -  1701848944715	Marionette	TRACE	Received observer notification final-ui-startup
[task 2023-12-06T07:49:04.764Z] 07:49:04     INFO -  ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-12-06T07:49:04.786Z] 07:49:04     INFO -  1701848944786	RemoteAgent	WARN	PollPromise timed out after 5000 ms
[task 2023-12-06T07:49:04.788Z] 07:49:04     INFO -  1701848944788	Marionette	INFO	Listening on port 2828
[task 2023-12-06T07:49:04.790Z] 07:49:04     INFO -  1701848944789	Marionette	DEBUG	Marionette is listening
[task 2023-12-06T07:49:04.803Z] 07:49:04     INFO -  1701848944802	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:44662
[task 2023-12-06T07:49:04.823Z] 07:49:04     INFO -  1701848944823	Marionette	DEBUG	Closed connection 0
[task 2023-12-06T07:49:04.826Z] 07:49:04     INFO -  1701848944825	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:44664
[task 2023-12-06T07:49:04.960Z] 07:49:04     INFO -  1701848944959	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2023-12-06T07:49:04.964Z] 07:49:04     INFO -  1701848944963	Marionette	DEBUG	Waiting for initial application window
[task 2023-12-06T07:49:08.277Z] 07:49:08     INFO -  console.error: ({})
[task 2023-12-06T07:49:09.315Z] 07:49:09     INFO -  1701848949314	Marionette	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2023-12-06T07:49:09.333Z] 07:49:09     INFO -  1701848949333	RemoteAgent	TRACE	[9] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=5000 waitForExplicitStart=false
[task 2023-12-06T07:49:09.336Z] 07:49:09     INFO -  1701848949335	RemoteAgent	TRACE	[9] ProgressListener Setting unload timer (5000ms)
[task 2023-12-06T07:49:09.338Z] 07:49:09     INFO -  1701848949337	RemoteAgent	TRACE	[9] Document already finished loading: about:blank
[task 2023-12-06T07:49:09.339Z] 07:49:09     INFO -  1701848949338	RemoteAgent	TRACE	[9] ProgressListener Stop: has error=false
[task 2023-12-06T07:49:09.394Z] 07:49:09     INFO -  1701848949392	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"f26d1f6a-5e27-43ad-8ff5-40b99104c08c","capabilities":{"browserName":"firefox","browserVersion":"122.0a1","platformName":"linux","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20231206051837","moz:headless":false,"moz:platformVersion":"4.4.0-1014-aws","moz:processID":6042,"moz:profile":"/tmp/tmpmzb29bmy.mozrunner","moz:shutdownTimeout":60000,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2023-12-06T07:49:09.404Z] 07:49:09     INFO -  1701848949403	Marionette	DEBUG	1 -> [0,2,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-12-06T07:49:09.409Z] 07:49:09     INFO -  1701848949404	Marionette	DEBUG	1 <- [1,2,null,{"value":null}]
[task 2023-12-06T07:49:09.413Z] 07:49:09     INFO -  1701848949405	Marionette	DEBUG	1 -> [0,3,"Marionette:GetContext",{}]
[task 2023-12-06T07:49:09.417Z] 07:49:09     INFO -  1701848949405	Marionette	DEBUG	1 <- [1,3,null,{"value":"chrome"}]
[task 2023-12-06T07:49:09.423Z] 07:49:09     INFO -  1701848949418	Marionette	DEBUG	1 -> [0,4,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-12-06T07:49:09.428Z] 07:49:09     INFO -  1701848949419	Marionette	DEBUG	1 <- [1,4,null,{"value":null}]
[task 2023-12-06T07:49:09.432Z] 07:49:09     INFO -  1701848949420	Marionette	DEBUG	1 -> [0,5,"WebDriver:GetWindowHandles",{}]
[task 2023-12-06T07:49:09.436Z] 07:49:09     INFO -  1701848949420	Marionette	DEBUG	1 <- [1,5,null,["29789c12-7067-4c86-a75b-4a884ecf7867"]]
[task 2023-12-06T07:49:09.440Z] 07:49:09     INFO -  1701848949421	Marionette	DEBUG	1 -> [0,6,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-12-06T07:49:09.444Z] 07:49:09     INFO -  1701848949422	Marionette	DEBUG	1 <- [1,6,null,{"value":null}]
[task 2023-12-06T07:49:09.448Z] 07:49:09     INFO -  1701848949422	Marionette	DEBUG	1 -> [0,7,"Marionette:GetContext",{}]
[task 2023-12-06T07:49:09.452Z] 07:49:09     INFO -  1701848949422	Marionette	DEBUG	1 <- [1,7,null,{"value":"chrome"}]
[task 2023-12-06T07:49:09.456Z] 07:49:09     INFO -  1701848949437	Marionette	DEBUG	1 -> [0,8,"Marionette:SetContext",{"value":"content"}]
[task 2023-12-06T07:49:09.460Z] 07:49:09     INFO -  1701848949439	Marionette	DEBUG	1 <- [1,8,null,{"value":null}]
[task 2023-12-06T07:49:09.464Z] 07:49:09     INFO -  1701848949441	Marionette	DEBUG	1 -> [0,9,"WebDriver:GetWindowHandles",{}]
[task 2023-12-06T07:49:09.468Z] 07:49:09     INFO -  1701848949443	Marionette	DEBUG	1 <- [1,9,null,["cd0d87d3-8384-4b00-8dea-2ba262bb12e2"]]
[task 2023-12-06T07:49:09.472Z] 07:49:09     INFO -  1701848949446	Marionette	DEBUG	1 -> [0,10,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-12-06T07:49:09.476Z] 07:49:09     INFO -  1701848949447	Marionette	DEBUG	1 <- [1,10,null,{"value":null}]
[task 2023-12-06T07:49:09.479Z] 07:49:09     INFO -  1701848949449	Marionette	DEBUG	1 -> [0,11,"WebDriver:DeleteSession",{}]
[task 2023-12-06T07:49:09.483Z] 07:49:09     INFO - TEST-START | browser/components/sessionstore/test/marionette/test_restore_manually_with_pinned_tabs.py TestSessionRestoreWithPinnedTabs.test_no_restore_with_quit

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1863692

:sclements, since you are the author of the regressor, bug 1863692, could you take a look?

For more information, please visit BugBot documentation.

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1
• autoland: 4

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1
• linux1804-64-qr: 4
  • opt: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1868526&startday=2023-12-04&endday=2023-12-10&tree=all

Comment 3

[Sarah Clements [:sclements]]

Attachment: Bug 1868526 - Add event listener and promise for window resize r=sfoster

• Update test_restore_manually marionette test to account for intermittent failure on linux

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 5
• try: 1

Platform and build breakdown:

• linux1804-64-qr: 5
  • opt: 4
  • debug: 1
• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1868526&startday=2023-12-11&endday=2023-12-17&tree=all

Comment 5

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/183202f2eb05
Add event listener and promise for window resize r=sfoster,sessionstore-reviewers

Comment 6

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1863692

Comment 7

[Cristina Horotan [:chorotan]]

https://hg.mozilla.org/mozilla-central/rev/183202f2eb05

Comment 8

[BugBot [:suhaib / :marco/ :calixte]]

The patch landed in nightly and beta is affected.
:sclements, is this bug important enough to require an uplift?

• If yes, please nominate the patch for beta approval.
• If no, please set status-firefox122 to wontfix.

For more information, please visit BugBot documentation.

Comment 9

[Cosmin Sabou [:CosminS]]

Still failing after latest changes: failure log, treeherder link.

Comment 10

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1863692

Comment 11

[Cosmin Sabou [:CosminS]]

Turns out they were from Bug 1783521 and they're fixed by commit: https://hg.mozilla.org/integration/autoland/rev/ede008f65ded6409ee06a55d2b43c6b8c42cc852. Please ignore latest failures here.
Leaving ni regarding comment 8.

Comment 12

[Donal Meehan [:dmeehan]]

This is a test-only change, and does not require an uplift request.
I'll push it to beta later today for 122.

Comment 13

[Pulsebot]

https://hg.mozilla.org/releases/mozilla-beta/rev/a8af2199feab

Comment 14

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 1
• mozilla-central: 1
• autoland: 9

Platform and build breakdown:

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

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1868526&startday=2023-12-18&endday=2023-12-24&tree=all