1679967 - Intermittent browser/components/newtab/test/browser/abouthomecache/browser_shutdown_timeout.js | Uncaught exception - undefined - threw exception: [Exception... "Component returned failure code: 0x80470002 (NS_BASE_STREAM_CLOSED) [nsIInputStream.available

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

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

---

[task 2020-12-01T10:05:32.558Z] 10:05:32     INFO - TEST-START | browser/components/newtab/test/browser/abouthomecache/browser_shutdown_timeout.js
[task 2020-12-01T10:05:39.375Z] 10:05:39     INFO - Ensuring cache bytes are available
[task 2020-12-01T10:05:39.375Z] 10:05:39     INFO - Console message: 1606817138415	AboutHomeStartupCache	TRACE	Cache entry is available.
[task 2020-12-01T10:05:39.376Z] 10:05:39     INFO - Console message: 1606817138416	AboutHomeStartupCache	TRACE	Connecting nsICacheEntry to pipes.
[task 2020-12-01T10:05:39.377Z] 10:05:39     INFO - Console message: 1606817138417	AboutHomeStartupCache	TRACE	
[task 2020-12-01T10:05:39.380Z] 10:05:39     INFO - Console message: 1606817138417	AboutHomeStartupCache	DEBUG	Cache meta data does not exist. Closing streams.
[task 2020-12-01T10:05:39.381Z] 10:05:39     INFO - Buffered messages finished
[task 2020-12-01T10:05:39.382Z] 10:05:39     INFO - TEST-UNEXPECTED-FAIL | browser/components/newtab/test/browser/abouthomecache/browser_shutdown_timeout.js | Uncaught exception - undefined - threw exception: [Exception... "Component returned failure code: 0x80470002 (NS_BASE_STREAM_CLOSED) [nsIInputStream.available]"  nsresult: "0x80470002 (NS_BASE_STREAM_CLOSED)"  location: "JS frame :: chrome://mochitests/content/browser/browser/components/newtab/test/browser/abouthomecache/head.js :: <TOP_LEVEL> :: line 130"  data: no]
[task 2020-12-01T10:05:39.383Z] 10:05:39     INFO - Leaving test bound test_shutdown_timeout
[task 2020-12-01T10:05:39.383Z] 10:05:39     INFO - GECKO(3071) | MEMORY STAT | vsize 3044MB | residentFast 339MB | heapAllocated 93MB
[task 2020-12-01T10:05:39.384Z] 10:05:39     INFO - TEST-OK | browser/components/newtab/test/browser/abouthomecache/browser_shutdown_timeout.js | took 6231ms
[task 2020-12-01T10:05:39.384Z] 10:05:39     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-12-01T10:05:39.385Z] 10:05:39     INFO - TEST-UNEXPECTED-FAIL | browser/components/newtab/test/browser/abouthomecache/browser_shutdown_timeout.js | Found an unexpected tab at the end of test run: about:home - 
[task 2020-12-01T10:05:39.385Z] 10:05:39     INFO - GECKO(3071) | [Child 3346, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111 (NS_ERROR_NOT_AVAILABLE): file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1349
[task 2020-12-01T10:05:39.386Z] 10:05:39     INFO - GECKO(3071) | [Child 3219: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f9766498c00 == 1 [pid = 3219] [id = 5]
[task 2020-12-01T10:05:39.389Z] 10:05:39     INFO - GECKO(3071) | [Child 3219: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f97664b7200) [pid = 3219] [serial = 11] [outer = (nil)]
[task 2020-12-01T10:05:39.389Z] 10:05:39     INFO - GECKO(3071) | [Child 3219: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f976649c000) [pid = 3219] [serial = 12] [outer = 0x7f97664b7200]
[task 2020-12-01T10:05:39.390Z] 10:05:39     INFO - checking window state```

Comment 1

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

4 failures so far.

Comment 2

[Intermittent Failures Robot]

23 failures in 787 pushes (0.029 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 3
• autoland: 20

Platform breakdown:

• linux1804-64-tsan: 1
• linux1804-64: 22

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1679967&startday=2020-12-02&endday=2020-12-02&tree=all

Comment 4

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

Attachment: Bug 1679967 - Make sure about:home shutdown timer is used for tests that expect it. r?emalysz!

For debug builds, it seems we'd unexpectedly hit the AboutHomeStartupCache shutdown
timer when simulating shutdowns, which would put the cache entry into a half-written
state that risked confusing later tests.

This patch now makes sure that only tests that exercise/expect the timeout will hit it.
We also make sure to clear the cache of any half-written state after the
browser_shutdown_timeout.js test runs.

Comment 5

[Intermittent Failures Robot]

51 failures in 3712 pushes (0.014 failures/push) were associated with this bug in the last 7 days.

This is the #20 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 44
• mozilla-central: 6
• try: 1

Platform breakdown:

• linux1804-64: 47
• linux1804-64-tsan: 1
• windows10-64: 1
• windows10-64-qr: 1
• linux1804-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1679967&startday=2020-11-30&endday=2020-12-06&tree=all

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c1f177305ce9
Make sure about:home shutdown timer is used for tests that expect it. r=emalysz

Comment 7

[Dorel Luca [:dluca]]

https://hg.mozilla.org/mozilla-central/rev/c1f177305ce9

Comment 9

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 7
• try: 2

Platform breakdown:

• linux1804-64: 9

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1679967&startday=2020-12-07&endday=2020-12-13&tree=all