1767283 - Intermittent browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | Test timed out | | Found a tab after previous test timed out: about:home -

Status: RESOLVED DUPLICATE of bug 1784671

(Firefox :: New Tab Page, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2022-05-02T13:24:44.046Z] 13:24:44     INFO - TEST-START | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js
[task 2022-05-02T13:24:44.428Z] 13:24:44     INFO - GECKO(1929) | console.warn: "data:image/png;base64,iVBORw0KGgoAAAANSUhEUgAAAGQAAABkCAYAAABw4pVUAAAA/UlEQVR4nO3RMQ0AMAzAsPIn3d5DsBw2gkiZJWV+B/AyJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQmAP4K6zWNUjE4wAAAABJRU5ErkJggg== is not allowed for anchor targets."
[task 2022-05-02T13:24:49.973Z] 13:24:49     INFO - GECKO(1929) | console.warn: "data:image/png;base64,iVBORw0KGgoAAAANSUhEUgAAAGQAAABkCAYAAABw4pVUAAAA/UlEQVR4nO3RMQ0AMAzAsPIn3d5DsBw2gkiZJWV+B/AyJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQGENiDIkxJMaQmAP4K6zWNUjE4wAAAABJRU5ErkJggg== is not allowed for anchor targets."
[task 2022-05-02T13:25:06.021Z] 13:25:06     INFO - GECKO(1929) | 2022-05-02 13:25:06.020 firefox[1929:34075] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.firefox.savedState/window_1.data: No such file or directory (2)
[task 2022-05-02T13:25:29.155Z] 13:25:29     INFO - TEST-INFO | started process screencapture
[task 2022-05-02T13:25:29.243Z] 13:25:29     INFO - TEST-INFO | screencapture: exit 0
[task 2022-05-02T13:25:29.243Z] 13:25:29     INFO - Buffered messages logged at 13:24:44
[task 2022-05-02T13:25:29.243Z] 13:25:29     INFO - Entering test bound test_locale_change
[task 2022-05-02T13:25:29.243Z] 13:25:29     INFO - Simulating restart of the browser
[task 2022-05-02T13:25:29.244Z] 13:25:29     INFO - Simulating shutdown write
[task 2022-05-02T13:25:29.244Z] 13:25:29     INFO - Console message: 1651497884383	AboutHomeStartupCache	TRACE	Never wrote a cache this session. Arming cache task.
[task 2022-05-02T13:25:29.245Z] 13:25:29     INFO - Console message: 1651497884383	AboutHomeStartupCache	TRACE	Finalizing cache task on shutdown
[task 2022-05-02T13:25:29.245Z] 13:25:29     INFO - Console message: 1651497884383	AboutHomeStartupCache	TRACE	Caching now.
[task 2022-05-02T13:25:29.246Z] 13:25:29     INFO - Console message: 1651497884383	AboutHomeStartupCache	TRACE	Parent is requesting Activity Stream state object.
[task 2022-05-02T13:25:29.246Z] 13:25:29     INFO - Console message: 1651497884383	AboutHomeStartupCache	TRACE	Parent is requesting cache streams.
[task 2022-05-02T13:25:29.247Z] 13:25:29     INFO - Console message: 1651497884384	AboutHomeStartupCache	TRACE	Skipping timeout mechanism.
[task 2022-05-02T13:25:29.247Z] 13:25:29     INFO - Console message: 1651497884478	AboutHomeStartupCache	TRACE	Parent received cache streams.
[task 2022-05-02T13:25:29.247Z] 13:25:29     INFO - Console message: 1651497884478	AboutHomeStartupCache	TRACE	Got cache streams.
[task 2022-05-02T13:25:29.248Z] 13:25:29     INFO - Console message: 1651497884478	AboutHomeStartupCache	TRACE	Populating cache.
[task 2022-05-02T13:25:29.248Z] 13:25:29     INFO - Console message: 1651497884478	AboutHomeStartupCache	TRACE	Populating the cache. Dooming old entry.
[task 2022-05-02T13:25:29.249Z] 13:25:29     INFO - Console message: 1651497884478	AboutHomeStartupCache	TRACE	Clearing the cache.
[task 2022-05-02T13:25:29.249Z] 13:25:29     INFO - Console message: 1651497884478	AboutHomeStartupCache	TRACE	Opening the page output stream.
[task 2022-05-02T13:25:29.250Z] 13:25:29     INFO - Console message: 1651497884478	AboutHomeStartupCache	INFO	Writing the page cache.
[task 2022-05-02T13:25:29.251Z] 13:25:29     INFO - Console message: 1651497884500	AboutHomeStartupCache	TRACE	Writing the page data is complete. Now opening the script output stream.
[task 2022-05-02T13:25:29.251Z] 13:25:29     INFO - Console message: 1651497884500	AboutHomeStartupCache	INFO	Writing the script cache.
[task 2022-05-02T13:25:29.252Z] 13:25:29     INFO - Shutdown write done
[task 2022-05-02T13:25:29.253Z] 13:25:29     INFO - Waiting for AboutHomeStartupCacheChild to uninit
[task 2022-05-02T13:25:29.253Z] 13:25:29     INFO - Console message: 1651497884532	AboutHomeStartupCache	TRACE	Writing the script cache is done. Setting version.
[task 2022-05-02T13:25:29.254Z] 13:25:29     INFO - Console message: 1651497884532	AboutHomeStartupCache	TRACE	Version is set to 20220502095353.
[task 2022-05-02T13:25:29.254Z] 13:25:29     INFO - Console message: 1651497884532	AboutHomeStartupCache	INFO	Caching of page and script is done.
[task 2022-05-02T13:25:29.255Z] 13:25:29     INFO - Console message: 1651497884532	AboutHomeStartupCache	TRACE	populateCache has finished.
[task 2022-05-02T13:25:29.255Z] 13:25:29     INFO - Console message: 1651497884532	AboutHomeStartupCache	TRACE	Done writing to cache.
[task 2022-05-02T13:25:29.255Z] 13:25:29     INFO - Console message: 1651497884532	AboutHomeStartupCache	TRACE	Done blocking shutdown.
[task 2022-05-02T13:25:29.256Z] 13:25:29     INFO - Console message: 1651497884532	AboutHomeStartupCache	TRACE	onShutdown is exiting
[task 2022-05-02T13:25:29.256Z] 13:25:29     INFO - Console message: 1651497884532	AboutHomeStartupCache	TRACE	Uninitialized.
[task 2022-05-02T13:25:29.257Z] 13:25:29     INFO - AboutHomeStartupCacheChild uninitted
[task 2022-05-02T13:25:29.257Z] 13:25:29     INFO - Waiting for AboutHomeStartupCache cache entry
[task 2022-05-02T13:25:29.257Z] 13:25:29     INFO - Got AboutHomeStartupCache cache entry
[task 2022-05-02T13:25:29.258Z] 13:25:29     INFO - Ensuring cache bytes are available
[task 2022-05-02T13:25:29.258Z] 13:25:29     INFO - Console message: 1651497884535	AboutHomeStartupCache	TRACE	Initting.
[task 2022-05-02T13:25:29.259Z] 13:25:29     INFO - Console message: 1651497884535	AboutHomeStartupCache	TRACE	Constructing pipes.
[task 2022-05-02T13:25:29.259Z] 13:25:29     INFO - Console message: 1651497884535	AboutHomeStartupCache	TRACE	Cache entry is available.
[task 2022-05-02T13:25:29.259Z] 13:25:29     INFO - Console message: 1651497884535	AboutHomeStartupCache	TRACE	Connecting nsICacheEntry to pipes.
[task 2022-05-02T13:25:29.260Z] 13:25:29     INFO - Console message: 1651497884535	AboutHomeStartupCache	TRACE	
[task 2022-05-02T13:25:29.260Z] 13:25:29     INFO - Console message: 1651497884535	AboutHomeStartupCache	INFO	Version retrieved is: 20220502095353
[task 2022-05-02T13:25:29.261Z] 13:25:29     INFO - Console message: 1651497884535	AboutHomeStartupCache	TRACE	Connecting page stream to pipe.
[task 2022-05-02T13:25:29.261Z] 13:25:29     INFO - Console message: 1651497884535	AboutHomeStartupCache	TRACE	Connecting script stream to pipe.
[task 2022-05-02T13:25:29.261Z] 13:25:29     INFO - Console message: 1651497884535	AboutHomeStartupCache	TRACE	Streams connected to pipes.
[task 2022-05-02T13:25:29.262Z] 13:25:29     INFO - Console message: 1651497884536	AboutHomeStartupCache	TRACE	Initialized.
[task 2022-05-02T13:25:29.262Z] 13:25:29     INFO - Console message: 1651497884536	AboutHomeStartupCache	TRACE	A privileged about content process is launching with ID 2.
[task 2022-05-02T13:25:29.263Z] 13:25:29     INFO - Console message: 1651497884536	AboutHomeStartupCache	INFO	Sending input streams down to content process.
[task 2022-05-02T13:25:29.263Z] 13:25:29     INFO - Console message: 1651497884536	AboutHomeStartupCache	INFO	Page stream connected to pipe.
[task 2022-05-02T13:25:29.264Z] 13:25:29     INFO - Console message: 1651497884536	AboutHomeStartupCache	INFO	Script stream connected to pipe.
[task 2022-05-02T13:25:29.264Z] 13:25:29     INFO - Waiting for about:home to load
[task 2022-05-02T13:25:29.264Z] 13:25:29     INFO - Console message: 1651497884756	AboutHomeStartupCache	TRACE	Received usage result. Success = true
[task 2022-05-02T13:25:29.265Z] 13:25:29     INFO - about:home loaded
[task 2022-05-02T13:25:29.265Z] 13:25:29     INFO - TEST-PASS | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | There should be page scripts. - true == true - 
[task 2022-05-02T13:25:29.266Z] 13:25:29     INFO - TEST-PASS | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | Found about:home?jscache script tag, indicating the cached doc - "about:home?jscache" == "about:home?jscache" - 
[task 2022-05-02T13:25:29.266Z] 13:25:29     INFO - TEST-PASS | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | Should have found window.__FROM_STARTUP_CACHE__ - true == true - 
[task 2022-05-02T13:25:29.267Z] 13:25:29     INFO - TEST-PASS | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | Should have found activity-stream class on <body> element - true == true - 
[task 2022-05-02T13:25:29.267Z] 13:25:29     INFO - TEST-PASS | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | Should have found the Discovery Stream top sites. - {} == true - 
[task 2022-05-02T13:25:29.268Z] 13:25:29     INFO - TEST-PASS | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | Expected the right value set to browser.startup.abouthome_cache_result scalar. - 6 == 6 - 
[task 2022-05-02T13:25:29.268Z] 13:25:29     INFO - Simulating restart of the browser
[task 2022-05-02T13:25:29.268Z] 13:25:29     INFO - Intentionally skipping shutdown write
[task 2022-05-02T13:25:29.269Z] 13:25:29     INFO - Waiting for AboutHomeStartupCacheChild to uninit
[task 2022-05-02T13:25:29.269Z] 13:25:29     INFO - Console message: 1651497884800	AboutHomeStartupCache	TRACE	Clearing the cache.
[task 2022-05-02T13:25:29.270Z] 13:25:29     INFO - Console message: 1651497884802	AboutHomeStartupCache	TRACE	Uninitialized.
[task 2022-05-02T13:25:29.270Z] 13:25:29     INFO - AboutHomeStartupCacheChild uninitted
[task 2022-05-02T13:25:29.270Z] 13:25:29     INFO - Waiting for AboutHomeStartupCache cache entry
[task 2022-05-02T13:25:29.271Z] 13:25:29     INFO - Console message: 1651497884822	AboutHomeStartupCache	TRACE	Initting.
[task 2022-05-02T13:25:29.271Z] 13:25:29     INFO - Console message: 1651497884822	AboutHomeStartupCache	TRACE	Constructing pipes.
[task 2022-05-02T13:25:29.272Z] 13:25:29     INFO - Console message: 1651497884822	AboutHomeStartupCache	TRACE	Initialized.
[task 2022-05-02T13:25:29.272Z] 13:25:29     INFO - Console message: 1651497884822	AboutHomeStartupCache	TRACE	A privileged about content process is launching with ID 2.
[task 2022-05-02T13:25:29.272Z] 13:25:29     INFO - Console message: 1651497884823	AboutHomeStartupCache	INFO	Sending input streams down to content process.
[task 2022-05-02T13:25:29.273Z] 13:25:29     INFO - Console message: 1651497884825	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-05-02T13:25:29.273Z] 13:25:29     INFO - Console message: 1651497884825	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-05-02T13:25:29.274Z] 13:25:29     INFO - Console message: 1651497884826	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-05-02T13:25:29.274Z] 13:25:29     INFO - Console message: 1651497884826	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-05-02T13:25:29.275Z] 13:25:29     INFO - Console message: 1651497884827	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-05-02T13:25:29.275Z] 13:25:29     INFO - Console message: 1651497884827	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-05-02T13:25:29.275Z] 13:25:29     INFO - Buffered messages logged at 13:24:49
[task 2022-05-02T13:25:29.276Z] 13:25:29     INFO - Console message: 1651497889920	AboutHomeStartupCache	TRACE	Caching now.
[task 2022-05-02T13:25:29.276Z] 13:25:29     INFO - Console message: 1651497889920	AboutHomeStartupCache	TRACE	Parent is requesting Activity Stream state object.
[task 2022-05-02T13:25:29.277Z] 13:25:29     INFO - Console message: 1651497889920	AboutHomeStartupCache	TRACE	Parent is requesting cache streams.
[task 2022-05-02T13:25:29.277Z] 13:25:29     INFO - Console message: 1651497889976	AboutHomeStartupCache	TRACE	Parent received cache streams.
[task 2022-05-02T13:25:29.277Z] 13:25:29     INFO - Console message: 1651497889976	AboutHomeStartupCache	TRACE	Got cache streams.
[task 2022-05-02T13:25:29.278Z] 13:25:29     INFO - Console message: 1651497889976	AboutHomeStartupCache	TRACE	Populating cache.
[task 2022-05-02T13:25:29.278Z] 13:25:29     INFO - Buffered messages finished
[task 2022-05-02T13:25:29.279Z] 13:25:29     INFO - TEST-UNEXPECTED-FAIL | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | Test timed out - 
[task 2022-05-02T13:25:29.279Z] 13:25:29     INFO - GECKO(1929) | MEMORY STAT | vsize 8644MB | residentFast 285MB | heapAllocated 111MB
[task 2022-05-02T13:25:29.279Z] 13:25:29     INFO - TEST-OK | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | took 45111ms
[task 2022-05-02T13:25:29.280Z] 13:25:29     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-05-02T13:25:29.280Z] 13:25:29     INFO - TEST-UNEXPECTED-FAIL | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | Found a tab after previous test timed out: about:home - 
[task 2022-05-02T13:25:29.281Z] 13:25:29     INFO - checking window state
[task 2022-05-02T13:25:29.281Z] 13:25:29     INFO - TEST-START | browser/components/newtab/test/browser/abouthomecache/browser_no_cache.js

Comment 1

[Cosmin Sabou [:CosminS]]

This first failed on a beta-sim before central to beta merge on 2022-05-02 and now it's failing on beta.
Could it be from the changes in Bug 1756407 - https://hg.mozilla.org/releases/mozilla-beta/rev/63083b88a46d21e5b8215c26d23bdaa252f5a976 or maybe Bug 1766156 - https://hg.mozilla.org/releases/mozilla-beta/rev/344c426713d991ece5c263e835c35bbd1c876690?

Comment 2

[Gabriele Svelto [:gsvelto] (PTO)]

I've had a look again at the changes in bug 1756407 and I don't see anything that should affect this. CC'ing Alexandre who wrote the patch in case he has more ideas.

Comment 3

[:gerard-majax]

My code is only touching exception handler code, and changing tabcrashed tests, not newtab ones , i dont see how it could be connected.

Comment 4

[:gerard-majax]

Also it seems that this is a opt test failure, my tests only runs on debug builds so they could not have had an impact on the running on this one. It's difficult to read the layers on this test so i dont know yet if it somehow uses crashing of a tab at some point.

Comment 5

[:gerard-majax]

I found about bug 62174 where there is a lot of recent activity around live locale switching, that sounds much more probable of a root cause. Maybe Greg can have a look ?

Comment 6

[:gerard-majax]

https://searchfox.org/mozilla-central/rev/997a56b018662e2940c99bbaf57a6ac9d1aa5422/browser/components/BrowserGlue.jsm#5686 is hit but not https://searchfox.org/mozilla-central/rev/997a56b018662e2940c99bbaf57a6ac9d1aa5422/browser/components/BrowserGlue.jsm#5876 so it likely means https://searchfox.org/mozilla-central/rev/997a56b018662e2940c99bbaf57a6ac9d1aa5422/browser/components/BrowserGlue.jsm#5872 is not resolving ?

Comment 7

[:Gijs (he/him)]

I think Mike is more likely to be of use here as he knows more about the about home startup cache. I don't think either of the suspects in comment #1 are at all plausible.

But I also concur with comment #5 - given the test that is failing and the recent changes to locale switching, that seems a lot more plausible.

If this fails reproducibly (which is what it looks like), bisecting the portion of central that we think the failure is related to with beta sims might be the quickest way of identifying a culprit. Cosmin, what was the last beta sim that didn't see this issue?

Comment 8

[Cosmin Sabou [:CosminS]]

The pushlog from last good revision and first bad is this one: https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=a3002a9b4204308cd68ca46d7aeb140f0ba497f7&tochange=822ee75b26834841c2b1cd11d64d061205c8166f
That's where I got the above two suspicions from.

Comment 9

[:gerard-majax]

I tried and failed to repro: https://treeherder.mozilla.org/jobs?repo=try&revision=392789ff51a54c9865b5d2db3c351d72222e8f0b

Comment 10

[:gerard-majax]

(In reply to Cosmin Sabou [:CosminS] from comment #8)

The pushlog from last good revision and first bad is this one: https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=a3002a9b4204308cd68ca46d7aeb140f0ba497f7&tochange=822ee75b26834841c2b1cd11d64d061205c8166f
That's where I got the above two suspicions from.

I see l10n related changes as well in this push: https://bugzilla.mozilla.org/show_bug.cgi?id=1751836

Comment 11

[Cosmin Sabou [:CosminS]]

(In reply to Alexandre LISSY :gerard-majax from comment #9)

I tried and failed to repro: https://treeherder.mozilla.org/jobs?repo=try&revision=392789ff51a54c9865b5d2db3c351d72222e8f0b

This needs to be tested under beta conditions using https://wiki.mozilla.org/Sheriffing/How_To/Beta_simulations#TRUNK_AS_EARLY_BETA.

Comment 12

[Mike Conley (:mconley) (:⚙️)]

So some context about what this test is testing and what might be breaking it:

We have a feature enabled only in Nightly called the about:home startup cache. It's job is to cache the contents of about:home so that we can quickly retrieve it on startup instead of generating it dynamically. You can read up on how it works here. The test in question, browser_locale_change.js, tests that we properly cleary that cache if the locale switches, since we don't want a cached about:home in the wrong language to appear at the next startup.

This is the observer notification that we wait for in the parent process to notice that the locale has changed: https://searchfox.org/mozilla-central/rev/997a56b018662e2940c99bbaf57a6ac9d1aa5422/browser/components/BrowserGlue.jsm#6205-6208

That observer appears to be hit - I can see that in the log. What interesting is that here in the test, we simulate a restart, and as part of that, re-initialize the AboutHomeStartupCache and wait for the HTTP cache entry to become available.

That entry never seems to show up. If it did, we'd see this message being logged after the reinitialization.

Has something changed the behaviour of the HTTP cache in the regression range? dragana or eguloien, could the patches for bug 1758524 changed how likely it is that the HTTP cache return a nsICacheEntry via nsICacheEntryOpenCallback after calling asyncOpenURI like this?: https://searchfox.org/mozilla-central/rev/997a56b018662e2940c99bbaf57a6ac9d1aa5422/browser/components/BrowserGlue.jsm#5498-5509

Comment 13

[Mike Conley (:mconley) (:⚙️)]

Here's a try push doing a beta simulation, just running the abouthomecache test directory, with the HTTP cache logging enabled: https://treeherder.mozilla.org/#/jobs?repo=try&revision=734ffe8525e2099417711886dc1be12bdd159e74

Comment 14

[Greg Tatum [:gregtatum]]

A lot of my work in live language switching was in cache invalidation, so it's possible there are behavior changes with that work.

I recall running into some startup cache issues in Bug 1755181.

I don't have much context for the specific assertion that's failing.

Comment 15

[Mike Conley (:mconley) (:⚙️)]

Hm - I wasn't able to reproduce when pushing to try: https://treeherder.mozilla.org/jobs?repo=try&revision=734ffe8525e2099417711886dc1be12bdd159e74

Did I trigger this beta simulation incorrectly, Cosmin?

Comment 16

[Dragana Damjanovic [:dragana]]

Bug 1758524 does not change or touch the code related to caching. I do not believe that causes the issue.

If someone can reproduce this locally can we get HTTP logging?

Comment 17

[Cosmin Sabou [:CosminS]]

(In reply to Mike Conley (:mconley) (:⚙️) from comment #15)

Hm - I wasn't able to reproduce when pushing to try: https://treeherder.mozilla.org/jobs?repo=try&revision=734ffe8525e2099417711886dc1be12bdd159e74

Did I trigger this beta simulation incorrectly, Cosmin?

This looks good to me. Weird thing is this hasn't happened in the last two days: https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2022-04-29&endday=2022-05-06&tree=all&bug=1767283
Triggered the devedition jobs on mac and windows on Mike's push but didn't fail.
Last failure on beta was here. Hasn't failed on beta-sims either.

Comment 18

[Intermittent Failures Robot]

21 failures in 3540 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 4
• mozilla-beta: 17

Platform and build breakdown:

• macosx1015-64-shippable-qr: 6
  • opt: 6
• windows10-64-2004-shippable-qr: 5
  • opt: 5
• macosx1015-64-devedition-qr: 7
  • opt: 7
• linux1804-64-qr: 1
  • debug: 1
• windows10-64-2004-devedition-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767283&startday=2022-05-02&endday=2022-05-08&tree=all

Comment 19

[:Gijs (he/him)]

(In reply to Cosmin Sabou [:CosminS] from comment #17)

(In reply to Mike Conley (:mconley) (:⚙️) from comment #15)

Hm - I wasn't able to reproduce when pushing to try: https://treeherder.mozilla.org/jobs?repo=try&revision=734ffe8525e2099417711886dc1be12bdd159e74

Did I trigger this beta simulation incorrectly, Cosmin?

This looks good to me. Weird thing is this hasn't happened in the last two days: https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2022-04-29&endday=2022-05-06&tree=all&bug=1767283
Triggered the devedition jobs on mac and windows on Mike's push but didn't fail.
Last failure on beta was here. Hasn't failed on beta-sims either.

Do we have a "fix" window on central/autoland as well as beta for when this stopped happening on real and simulated beta pushes? Between those it feels like we should be able to figure out what fixed it...

Comment 20

[Cosmin Sabou [:CosminS]]

For beta this is the range with last bad - first good.

The pushlog from central between last bad beta-sim and first good one is this.

The common changes would be these on beta https://hg.mozilla.org/releases/mozilla-beta/rev/761022932bd782c9757c1c4ee171d05543fbcf9f and these on central https://hg.mozilla.org/mozilla-central/rev/7bb9efa58526a297b185bfcb1d64dfa4dee020f9.

Comment 21

[:Gijs (he/him)]

(In reply to Cosmin Sabou [:CosminS] from comment #20)

For beta this is the range with last bad - first good.

The pushlog from central between last bad beta-sim and first good one is this.

The common changes would be these on beta https://hg.mozilla.org/releases/mozilla-beta/rev/761022932bd782c9757c1c4ee171d05543fbcf9f and these on central https://hg.mozilla.org/mozilla-central/rev/7bb9efa58526a297b185bfcb1d64dfa4dee020f9.

That makes... very little sense. Aryx - do we just close this as incomplete? Or was there an infra change that corresponds to these windows? Anything else we can do here?

Comment 22

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Skip it for !nightly_build?

Comment 23

[:Gijs (he/him)]

(In reply to Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout) from comment #22)

Skip it for !nightly_build?

I'm afraid I don't quite follow why that would help here - can you elaborate on why you're suggesting that?

Comment 24

[Mike Conley (:mconley) (:⚙️)]

So, correct me if I'm wrong here, but my understanding is that this test is now mysteriously passing on beta simulations. So maybe this is an INCOMPLETE?

Comment 25

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Retriggers still fail on pushes on which they failed initially - this should not be from an infra change. Without further insights, either the future failures (it will likely switch back to a permafail at some point) can continue to be classified with this bug or the test could be skipped on beta where it fails.

Comment 26

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 4
• try: 1

Platform and build breakdown:

• macosx1100-64-shippable-qr: 3
  • opt: 3
• macosx1015-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767283&startday=2022-06-27&endday=2022-07-03&tree=all

Comment 27

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 4

Platform and build breakdown:

• macosx1015-64-shippable-qr: 2
  • opt: 2
• windows10-64-2004-qr: 1
  • debug: 1
• macosx1100-64-shippable-qr: 1
  • opt: 1

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

Comment 28

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 1
• try: 2

Platform and build breakdown:

• macosx1015-64-shippable-qr: 2
  • opt: 2
• macosx1015-64-qr: 1
  • debug: 1

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

Comment 29

[Intermittent Failures Robot]

1 failures in 3497 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • debug: 1

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

Comment 30

[Cosmin Sabou [:CosminS]]

This is now failing on trunk also: https://treeherder.mozilla.org/logviewer?job_id=386090403&repo=autoland

[task 2022-08-02T07:48:31.720Z] 07:48:31     INFO - TEST-PASS | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | Expected the right value set to browser.startup.abouthome_cache_result scalar. - 6 == 6 - 
[task 2022-08-02T07:48:31.720Z] 07:48:31     INFO - Simulating restart of the browser
[task 2022-08-02T07:48:31.724Z] 07:48:31     INFO - Intentionally skipping shutdown write
[task 2022-08-02T07:48:31.724Z] 07:48:31     INFO - Waiting for AboutHomeStartupCacheChild to uninit
[task 2022-08-02T07:48:31.725Z] 07:48:31     INFO - Console message: 1659426394007	AboutHomeStartupCache	TRACE	Clearing the cache.
[task 2022-08-02T07:48:31.725Z] 07:48:31     INFO - Console message: 1659426394038	AboutHomeStartupCache	TRACE	Uninitialized.
[task 2022-08-02T07:48:31.726Z] 07:48:31     INFO - AboutHomeStartupCacheChild uninitted
[task 2022-08-02T07:48:31.726Z] 07:48:31     INFO - Waiting for AboutHomeStartupCache cache entry
[task 2022-08-02T07:48:31.728Z] 07:48:31     INFO - Console message: 1659426394330	AboutHomeStartupCache	TRACE	Initting.
[task 2022-08-02T07:48:31.729Z] 07:48:31     INFO - Console message: 1659426394330	AboutHomeStartupCache	TRACE	Constructing pipes.
[task 2022-08-02T07:48:31.730Z] 07:48:31     INFO - Console message: 1659426394332	AboutHomeStartupCache	TRACE	Initialized.
[task 2022-08-02T07:48:31.731Z] 07:48:31     INFO - Console message: 1659426394332	AboutHomeStartupCache	TRACE	A privileged about content process is launching with ID 2.
[task 2022-08-02T07:48:31.732Z] 07:48:31     INFO - Console message: 1659426394332	AboutHomeStartupCache	INFO	Sending input streams down to content process.
[task 2022-08-02T07:48:31.733Z] 07:48:31     INFO - Console message: 1659426394357	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-08-02T07:48:31.733Z] 07:48:31     INFO - Console message: 1659426394362	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-08-02T07:48:31.734Z] 07:48:31     INFO - Console message: 1659426394366	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-08-02T07:48:31.734Z] 07:48:31     INFO - Console message: 1659426394370	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-08-02T07:48:31.735Z] 07:48:31     INFO - Console message: 1659426394378	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-08-02T07:48:31.735Z] 07:48:31     INFO - Console message: 1659426394382	AboutHomeStartupCache	TRACE	Preloaded about:newtab was updated.
[task 2022-08-02T07:48:31.736Z] 07:48:31     INFO - Buffered messages logged at 07:46:39
[task 2022-08-02T07:48:31.736Z] 07:48:31     INFO - Console message: 1659426399383	AboutHomeStartupCache	TRACE	Caching now.
[task 2022-08-02T07:48:31.737Z] 07:48:31     INFO - Console message: 1659426399384	AboutHomeStartupCache	TRACE	Parent is requesting Activity Stream state object.
[task 2022-08-02T07:48:31.738Z] 07:48:31     INFO - Console message: 1659426399384	AboutHomeStartupCache	TRACE	Parent is requesting cache streams.
[task 2022-08-02T07:48:31.738Z] 07:48:31     INFO - Buffered messages logged at 07:46:40
[task 2022-08-02T07:48:31.739Z] 07:48:31     INFO - Console message: 1659426400075	AboutHomeStartupCache	TRACE	Parent received cache streams.
[task 2022-08-02T07:48:31.739Z] 07:48:31     INFO - Console message: 1659426400075	AboutHomeStartupCache	TRACE	Got cache streams.
[task 2022-08-02T07:48:31.740Z] 07:48:31     INFO - Console message: 1659426400076	AboutHomeStartupCache	TRACE	Populating cache.
[task 2022-08-02T07:48:31.740Z] 07:48:31     INFO - Buffered messages finished
[task 2022-08-02T07:48:31.740Z] 07:48:31     INFO - TEST-UNEXPECTED-FAIL | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | Test timed out - 
[task 2022-08-02T07:48:31.741Z] 07:48:31     INFO - GECKO(4041) | MEMORY STAT | vsize 130551251MB | residentFast 950MB
[task 2022-08-02T07:48:31.741Z] 07:48:31     INFO - TEST-OK | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | took 120075ms
[task 2022-08-02T07:48:31.742Z] 07:48:31     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-08-02T07:48:31.742Z] 07:48:31     INFO - TEST-UNEXPECTED-FAIL | browser/components/newtab/test/browser/abouthomecache/browser_locale_change.js | Found a tab after previous test timed out: about:home - 
[task 2022-08-02T07:48:31.743Z] 07:48:31     INFO - checking window state
[task 2022-08-02T07:48:31.743Z] 07:48:31     INFO - TEST-START | browser/components/newtab/test/browser/abouthomecache/browser_no_cache.js
[task 2022-08-02T07:48:32.149Z] 07:48:32     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-08-02T07:48:32.150Z] 07:48:32     INFO - Buffered messages logged at 07:48:31
[task 2022-08-02T07:48:32.153Z] 07:48:32     INFO - Entering test bound test_no_cache
[task 2022-08-02T07:48:32.153Z] 07:48:32     INFO - Console message: 1659426511874	AboutHomeStartupCache	TRACE	Received usage result. Success = false
[task 2022-08-02T07:48:32.154Z] 07:48:32     INFO - Buffered messages logged at 07:48:32
[task 2022-08-02T07:48:32.155Z] 07:48:32     INFO - Test is clearing the cache
[task 2022-08-02T07:48:32.155Z] 07:48:32     INFO - Buffered messages finished
[task 2022-08-02T07:48:32.156Z] 07:48:32     INFO - TEST-UNEXPECTED-FAIL | browser/components/newtab/test/browser/abouthomecache/browser_no_cache.js | Uncaught exception in test - at resource:///modules/BrowserGlue.jsm:6169 - TypeError: can't access property "recreate", this._cacheEntry is null
[task 2022-08-02T07:48:32.156Z] 07:48:32     INFO - Stack trace:
[task 2022-08-02T07:48:32.157Z] 07:48:32     INFO - clearCache@resource:///modules/BrowserGlue.jsm:6169:5
[task 2022-08-02T07:48:32.157Z] 07:48:32     INFO - clearCache@chrome://mochitests/content/browser/browser/components/newtab/test/browser/abouthomecache/head.js:209:25
[task 2022-08-02T07:48:32.158Z] 07:48:32     INFO - test_no_cache/<@chrome://mochitests/content/browser/browser/components/newtab/test/browser/abouthomecache/browser_no_cache.js:14:11
[task 2022-08-02T07:48:32.158Z] 07:48:32     INFO - withNewTab@resource://testing-common/BrowserTestUtils.jsm:151:24
[task 2022-08-02T07:48:32.158Z] 07:48:32     INFO - Leaving test bound test_no_cache
[task 2022-08-02T07:48:32.158Z] 07:48:32     INFO - Console message: 1659426512144	AboutHomeStartupCache	TRACE	Clearing the cache.
[task 2022-08-02T07:48:33.191Z] 07:48:33     INFO - GECKO(4041) | MEMORY STAT | vsize 130551267MB | residentFast 954MB
[task 2022-08-02T07:48:33.191Z] 07:48:33     INFO - TEST-OK | browser/components/newtab/test/browser/abouthomecache/browser_no_cache.js | took 1541ms
[task 2022-08-02T07:48:33.192Z] 07:48:33     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-08-02T07:48:33.193Z] 07:48:33     INFO - TEST-UNEXPECTED-FAIL | browser/components/newtab/test/browser/abouthomecache/browser_no_cache.js | Found an unexpected tab at the end of test run: about:home - 

Comment 31

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1
• mozilla-central: 1
• mozilla-beta: 1

Platform and build breakdown:

• linux1804-64-tsan-qr: 2
  • opt: 2
• macosx1015-64-shippable-qr: 1
  • opt: 1

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