Open Bug 1787024 Opened 4 years ago Updated 8 days ago

Intermittent browser/components/sessionstore/test/browser_async_remove_tab.js | single tracking bug

Categories

(Firefox :: Session Restore, defect, P3)

Product:
Firefox
Component:
Session Restore
Type:
defect

Tracking

()

People

(Reporter: jmaher, Unassigned, NeedInfo)

References

Details

(Keywords: intermittent-failure, intermittent-testcase, leave-open, Whiteboard: [retriggered][stockwell disabled])

Attachments

(1 file, 2 obsolete files)

Bug 1787024 - disable test browser_async_remove_tab.js for frequent failures. r=#intermittent-reviewers
48 bytes, text/x-phabricator-request
Details | Review
No description provided.

Additional information about this bug failures and frequency patterns can be found by running: ./mach test-info failure-report --bug 1787024

Update:

There have been 35 failures within the last 7 days

  • 24 failures on Linux 18.04 x64 WebRender debug/opt
  • 1 failure on Linux 18.04 x64 WebRender Shippable opt
  • 1 failure on Linux 18.04 x64 WebRender tsan opt
  • 1 failure on OS X 10.15 WebRender debug
  • 2 failures on Windows 11 x86 22H2 WebRender debug
  • 2 failures on Windows 11 x64 22H2 CCov WebRender opt
  • 2 failures on Windows 11 x64 22H2 WebRender debug
  • 2 failures on Windows 11 x64 22H2 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=409262989&repo=autoland&lineNumber=10636

[task 2023-03-17T11:13:09.364Z] 11:13:09     INFO - TEST-PASS | browser/components/sessionstore/test/browser_async_remove_tab.js | browser is remote - 
[task 2023-03-17T11:13:09.364Z] 11:13:09     INFO - Buffered messages logged at 11:10:11
[task 2023-03-17T11:13:09.366Z] 11:13:09     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "https://example.com/" line: 0}]
[task 2023-03-17T11:13:09.366Z] 11:13:09     INFO - Buffered messages logged at 11:10:56
[task 2023-03-17T11:13:09.367Z] 11:13:09     INFO - Console message: [JavaScript Error: "1679051456459	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates" {file: "resource://gre/modules/Log.sys.mjs" line: 722}]
[task 2023-03-17T11:13:09.367Z] 11:13:09     INFO - append@resource://gre/modules/Log.sys.mjs:722:12
[task 2023-03-17T11:13:09.367Z] 11:13:09     INFO - log@resource://gre/modules/Log.sys.mjs:376:16
[task 2023-03-17T11:13:09.367Z] 11:13:09     INFO - error@resource://gre/modules/Log.sys.mjs:384:10
[task 2023-03-17T11:13:09.367Z] 11:13:09     INFO - updateSystemAddons/res<@resource://gre/modules/addons/XPIInstall.jsm:4104:25
[task 2023-03-17T11:13:09.368Z] 11:13:09     INFO - promise callback*updateSystemAddons@resource://gre/modules/addons/XPIInstall.jsm:4104:7
[task 2023-03-17T11:13:09.368Z] 11:13:09     INFO - async*XPIProvider[meth]@resource://gre/modules/addons/XPIProvider.jsm:3325:33
[task 2023-03-17T11:13:09.368Z] 11:13:09     INFO - backgroundUpdateCheck/buPromise<@resource://gre/modules/AddonManager.jsm:1320:13
[task 2023-03-17T11:13:09.368Z] 11:13:09     INFO - backgroundUpdateCheck@resource://gre/modules/AddonManager.jsm:1328:7
[task 2023-03-17T11:13:09.368Z] 11:13:09     INFO - backgroundUpdateTimerHandler@resource://gre/modules/AddonManager.jsm:3737:26
[task 2023-03-17T11:13:09.368Z] 11:13:09     INFO - notify@resource://gre/modules/addonManager.js:171:25
[task 2023-03-17T11:13:09.368Z] 11:13:09     INFO - TM_notify/<@resource://gre/modules/UpdateTimerManager.jsm:230:50
[task 2023-03-17T11:13:09.368Z] 11:13:09     INFO - TM_notify@resource://gre/modules/UpdateTimerManager.jsm:312:7
[task 2023-03-17T11:13:09.369Z] 11:13:09     INFO - 
[task 2023-03-17T11:13:09.369Z] 11:13:09     INFO - Buffered messages finished
[task 2023-03-17T11:13:09.370Z] 11:13:09     INFO - TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_async_remove_tab.js | Test timed out - 
[task 2023-03-17T11:13:09.370Z] 11:13:09     INFO - GECKO(1567) | MEMORY STAT | vsize 3518MB | residentFast 555MB | heapAllocated 225MB
[task 2023-03-17T11:13:09.371Z] 11:13:09     INFO - TEST-OK | browser/components/sessionstore/test/browser_async_remove_tab.js | took 180110ms
[task 2023-03-17T11:13:09.371Z] 11:13:09     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-03-17T11:13:09.373Z] 11:13:09     INFO - TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_async_remove_tab.js | Found a tab after previous test timed out: https://example.com/ -

DĂŁo, can you help us assign this to someone?
Thank you.

Flags: needinfo?(dao+bmo)
Whiteboard: [retriggered] → [retriggered][stockwell needswork:owner]

There have been 30 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-asan-qr
  • linux1804-64-qr
  • macosx1015-64-qr
  • windows11-64-2009-qr
  • windows11-64-2009-shippable-qr

Update:

There have been 32 total failures within the last 7 days:

  • 21 failures on Linux 18.04 x64 WebRender debug/ opt
  • 1 failure on Linux 18.04 x64 WebRender Shippable opt
  • 4 failures on Linux 18.04 x64 WebRender tsan opt
  • 4 failures on OS X 10.15 WebRender debug
  • 2 failures on Windows 11 x64 22H2 WebRender debug

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=419730689&repo=mozilla-central&lineNumber=3113

Whiteboard: [retriggered][stockwell unknown] → [retriggered][stockwell needswork:owner]
Flags: needinfo?(dao+bmo)

Update

There have been 36 failures within the last 7 days:

  • 7 failures on Linux 18.04 x64 WebRender asan opt
  • 12 failures on Linux 18.04 x64 WebRender debug
  • 1 failure on Linux 18.04 x64 WebRender Shippable opt
  • 1 failure on Linux 18.04 x64 WebRender tsan opt
  • 4 failures on OS X 10.15 WebRender debug
  • 3 failures on Windows 11 x86 22H2 WebRender debug
  • 2 failures on Windows 11 x64 22H2 CCov WebRender opt
  • 6 failures on Windows 11 x64 22H2 WebRender debug/opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=426510140&repo=autoland&lineNumber=10014

[task 2023-08-18T20:16:55.007Z] 20:16:55     INFO - TEST-PASS | browser/components/sessionstore/test/browser_async_remove_tab.js | browser is remote - 
[task 2023-08-18T20:16:55.008Z] 20:16:55     INFO - Buffered messages finished
[task 2023-08-18T20:16:55.009Z] 20:16:55     INFO - TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_async_remove_tab.js | Test timed out - 
[task 2023-08-18T20:16:55.010Z] 20:16:55     INFO - GECKO(1566) | MEMORY STAT | vsize 3651MB | residentFast 675MB | heapAllocated 325MB
[task 2023-08-18T20:16:55.010Z] 20:16:55     INFO - TEST-OK | browser/components/sessionstore/test/browser_async_remove_tab.js | took 91045ms
[task 2023-08-18T20:16:55.011Z] 20:16:55     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-08-18T20:16:55.012Z] 20:16:55     INFO - TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_async_remove_tab.js | Found a tab after previous test timed out: about:blank -

DĂŁo, can you help us assign this to someone?
Thank you.

Flags: needinfo?(dao+bmo)

Update

There have been 35 failures within the last 7 days:

  • 10 failures on Linux 18.04 x64 WebRender asan opt
  • 14 failures on Linux 18.04 x64 WebRender debug
  • 2 failures on Linux 18.04 x64 WebRender tsan opt
  • 1 failure on OS X 10.15 WebRender debug
  • 3 failures on Windows 11 x86 22H2 WebRender debug
  • 5 failures on Windows 11 x64 22H2 WebRender debug

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=427640132&repo=mozilla-central&lineNumber=31376

Update

There have been 37 failures within the last 7 days:

  • 7 failures on Linux 18.04 x64 WebRender asan opt
  • 10 failures on Linux 18.04 x64 WebRender debug/opt
  • 1 failure on Linux 18.04 x64 WebRender tsan opt
  • 8 failures on OS X 10.15 WebRender debug/opt
  • 10 failures on Windows 11 x64 22H2 WebRender debug

Recent failure: https://treeherder.mozilla.org/logviewer?job_id=430137547&repo=mozilla-central&lineNumber=7001

Attachment #9386180 - Attachment is obsolete: true
Assignee: nobody → agoloman
Status: NEW → ASSIGNED
Assignee: agoloman → nobody
Status: ASSIGNED → NEW
Assignee: nobody → agoloman
Status: NEW → ASSIGNED
Assignee: agoloman → nobody
Status: ASSIGNED → NEW
Keywords: leave-open
Attachment #9445250 - Attachment is obsolete: true
Pushed by agoloman@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/cc0114ffb5bc disable test browser_async_remove_tab.js for frequent failures. r=sessionstore-reviewers,dao DONTBUILD
Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell disabled]

Hi, Joel! When it should be disabled on linux opt, we can still see it failing on tree. Any idea why this test still fails?

Flags: needinfo?(jmaher)

a typo in the skip-if, there is processor == 'x84_64' and it needs to be processor == 'x86_64'

Flags: needinfo?(jmaher)
Pushed by agoloman@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/ba12217be2ed fix typo in manifest file. a=typo-fix
Pushed by csabou@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/0a04bc0a6b19 Disable browser_async_remove_tab.js also on linux ASan for frequent failures. a=test-only

hey Vincent, since you're the last one touching this file, could you please take a look at this?

failure log -> https://treeherder.mozilla.org/logviewer?job_id=547635417&repo=autoland&task=IMPfuMLYQ0mZ7CxD2dRTxg.0

Flags: needinfo?(vhilla)

I only touched the test when changing browserLoaded in August 25, therefore I'm not familiar with this test.

The test was added in bug 1109875 10 years ago, assignee and reviewer are inactive and has been intermittent for 9 years already, see bug 1254852.

It doesn't reproduce locally on Linux opt / debug. Also not with ASan.

I've requested Pernosco to reproduce it from try, but it failed.

Pernosco session from local, passing run as a reference: https://pernos.co/debug/3UZtBwahI3OV3AaHFsfufQ/index.html

Try run with logging enabled, sadly no reproduction: https://treeherder.mozilla.org/jobs?repo=try&revision=d720650f9d5d6e926a5cd01e4db465533d2375d9

save_worthy_tabs_remote_final times out for promiseOnHistoryReplaceEntry. Interestingly, I don't see failures for dont_save_empty_tabs_final. It seems like nsISHistoryListener::OnHistoryReplaceEntry sometimes isn't called when loading something on top of about:blank.

Looking at the failure graph, the frequency increased end of 2025, possibly related to bug 543435 which changed timing for about:blank. Especially my change https://phabricator.services.mozilla.com/D237598 might be relevant. Though the subtest failed in the same way beforehand.

Ideas

  • promiseOnHistoryReplaceEntry should probably throw / fail the test if !sessionHistory.
  • save_worthy_tabs_remote_final could do some checks on the SH, like that there is a transient about:blank entry.

I'll put up patch.

Flags: needinfo?(vhilla)
See Also: → 1971272, sync-about-blank
See Also: → 2015415

My patch didn't help. I've retriggered the test a few more times hoping to get a reproduction with logging in https://treeherder.mozilla.org/jobs?repo=try&revision=d720650f9d5d6e926a5cd01e4db465533d2375d9

Maybe it's random, but I was only able to get it reproduced running the whole test suite, i.e. not limiting to browser/components/sessionstore/test/

SH, DocShell Log:

TEST-START | browser/components/sessionstore/test/browser_async_remove_tab.js
 D/SessionHistory nsDocShell::IsSameDocumentNavigation 23fe700f800 false, document is uncommitted initial
 D/SessionHistory Setting the loading entry on nsDocShell 23fe700f800 to about:blank
 D/nsDocShell nsDocShell[23fe700f800]::DoURILoad sync about:blank onto initial about:blank. Document[23fe7b48b00]
 D/SessionHistory nsDocShell 23fe700f800 MoveLoadingToActiveEntry
 D/SessionHistory Moving the loading entry to the active entry on nsDocShell 23fe700f800 to about:blank
 D/SessionHistory nsSHistory 218aea50a10
 D/SessionHistory >+- 0 SH Entry 218b561c670 shared:12884901901 {da8d57d3-ad6c-4955-934a-f61dad159fc3} 64
 D/SessionHistory         URL = about:blank
 D/SessionHistory         Title = about:blank
 D/SessionHistory         Name =
 D/SessionHistory         Transient = true
 D/SessionHistory         Is in BFCache = false
 D/SessionHistory         Has User Interaction = false
 D/SessionHistory         Navigation key = {1b936266-c0c4-4558-8e5a-eccf3ef51e02}
 D/SessionHistory nsDocShell::IsSameDocumentNavigation 23fe700f800 NavBetweenSameDoc=0
 D/SessionHistory nsDocShell::IsSameDocumentNavigation 23fe700f800 !LoadIsFromSessionHistory=true !PostDataStream: true mSameExceptHashes: false mNewURIHasRef: false
 D/SessionHistory nsDocShell 23fe700f800 unloading, remove dynamic subframe entries
 D/SessionHistory nsDocShell 23fe700f800 unloading, no active entries
 D/SessionHistory nsDocShell::IsSameDocumentNavigation 1df66641c00 false, document is uncommitted initial
 D/SessionHistory Setting the loading entry on nsDocShell 1df66641c00 to https://example.com/
 D/SessionHistory nsDocShell 1df66641c00 unloading, remove dynamic subframe entries
 D/SessionHistory nsDocShell 1df66641c00 unloading, no active entries
 D/SessionHistory nsDocShell 1df66641c00 SetCurrentDocState 0
 D/SessionHistory document 1df66641c00 Embed
 D/SessionHistory nsDocShell 1df66641c00 MoveLoadingToActiveEntry
 D/SessionHistory Moving the loading entry to the active entry on nsDocShell 1df66641c00 to https://example.com/
 D/SessionHistory nsSHistory 218aea50a10
 D/SessionHistory >+- 0 SH Entry 218b52233a0 shared:76 {da8d57d3-ad6c-4955-934a-f61dad159fc3} 65
 D/SessionHistory         URL = https://example.com/
 D/SessionHistory         Title = https://example.com/
 D/SessionHistory         Name =
 D/SessionHistory         Transient = false
 D/SessionHistory         Is in BFCache = false
 D/SessionHistory         Has User Interaction = false
 D/SessionHistory         Navigation key = {3b1df044-9ccd-48ac-8af1-4343717cd914}
TEST-INFO | started process screenshot
TEST-INFO | screenshot: exit 0
Buffered messages logged at 08:22:16
Entering test save_worthy_tabs_remote_final
TEST-PASS | browser/components/sessionstore/test/browser_async_remove_tab.js | save_worthy_tabs_remote_final - browser is remote
TEST-PASS | browser/components/sessionstore/test/browser_async_remove_tab.js | save_worthy_tabs_remote_final - Should have one SH entry
TEST-PASS | browser/components/sessionstore/test/browser_async_remove_tab.js | save_worthy_tabs_remote_final - Should be about:blank SH entry
TEST-PASS | browser/components/sessionstore/test/browser_async_remove_tab.js | save_worthy_tabs_remote_final - Initial about:blank SH entry should be marked for replacement
Buffered messages finished
TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_async_remove_tab.js | save_worthy_tabs_remote_final - Test timed out
TEST-UNEXPECTED-TIMEOUT | browser/components/sessionstore/test/browser_async_remove_tab.js | Test timed out

This log looks exactly the same as when the test passes.

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: