Closed Bug 1610709 Opened 4 years ago Closed 4 years ago

Intermittent browser/components/newtab/test/browser/browser_highlights_section.js | Uncaught exception - Should render activity stream content - threw exception: [Exception... "(null)" nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)"

Categories

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

Product:
Firefox
Component:
New Tab Page
Type:
defect

Tracking

()

Status:
RESOLVED WORKSFORME

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Filed by: nerli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=285864528&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/XQg-tjp3QxSQLQfXX24KgQ/runs/0/artifacts/public/logs/live_backing.log

[task 2020-01-22T00:14:17.071Z] 00:14:17 INFO - TEST-START | browser/components/newtab/test/browser/browser_highlights_section.js
[task 2020-01-22T00:14:20.790Z] 00:14:20 INFO - GECKO(10252) | JavaScript error: chrome://mochitests/content/browser/browser/components/newtab/test/browser/head.js, line 186: TypeError: content.document.getElementById(...) is null
[task 2020-01-22T00:14:20.790Z] 00:14:20 INFO - TEST-INFO | started process screenshot
[task 2020-01-22T00:14:20.848Z] 00:14:20 INFO - TEST-INFO | screenshot: exit 0
[task 2020-01-22T00:14:20.848Z] 00:14:20 INFO - Buffered messages logged at 00:14:17
[task 2020-01-22T00:14:20.849Z] 00:14:20 INFO - Entering test bound check_highlights_cards
[task 2020-01-22T00:14:20.849Z] 00:14:20 INFO - Buffered messages finished
[task 2020-01-22T00:14:20.849Z] 00:14:20 INFO - TEST-UNEXPECTED-FAIL | browser/components/newtab/test/browser/browser_highlights_section.js | Uncaught exception - Should render activity stream content - threw exception: [Exception... "(null)" nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)" location: "<unknown>" data: no]
[task 2020-01-22T00:14:20.850Z] 00:14:20 INFO - Leaving test bound check_highlights_cards
[task 2020-01-22T00:14:20.850Z] 00:14:20 INFO - Entering test bound check_highlights_context_menu
[task 2020-01-22T00:14:20.850Z] 00:14:20 INFO - Console message: [JavaScript Error: "TypeError: content.document.getElementById(...) is null" {file: "chrome://mochitests/content/browser/browser/components/newtab/test/browser/head.js" line: 186}]
[task 2020-01-22T00:14:21.317Z] 00:14:21 INFO - Console message: [JavaScript Error: "getScreenshot(https://mozilla0.com/nowNew) failed: TypeError: NetworkError when attempting to fetch resource." {file: "resource://activity-stream/lib/Screenshots.jsm" line: 59}]
[task 2020-01-22T00:14:21.317Z] 00:14:21 INFO - getScreenshotForURL@resource://activity-stream/lib/Screenshots.jsm:59:10
[task 2020-01-22T00:14:21.317Z] 00:14:21 INFO -
[task 2020-01-22T00:14:21.449Z] 00:14:21 INFO - TEST-PASS | browser/components/newtab/test/browser/browser_highlights_section.js | Should find a visible context menu - true == true -
[task 2020-01-22T00:14:21.493Z] 00:14:21 INFO - Leaving test bound check_highlights_context_menu
[task 2020-01-22T00:14:21.493Z] 00:14:21 INFO - Entering test bound check_highlights_context_menu
[task 2020-01-22T00:14:22.029Z] 00:14:22 INFO - Console message: [JavaScript Error: "getScreenshot(https://mozilla0.com/nowNew) failed: TypeError: NetworkError when attempting to fetch resource." {file: "resource://activity-stream/lib/Screenshots.jsm" line: 59}]
[task 2020-01-22T00:14:22.029Z] 00:14:22 INFO - getScreenshotForURL@resource://activity-stream/lib/Screenshots.jsm:59:10
[task 2020-01-22T00:14:22.029Z] 00:14:22 INFO -
[task 2020-01-22T00:14:22.147Z] 00:14:22 INFO - TEST-PASS | browser/components/newtab/test/browser/browser_highlights_section.js | there should be 1 bookmark icon - 1 == 1 -
[task 2020-01-22T00:14:22.157Z] 00:14:22 INFO - TEST-PASS | browser/components/newtab/test/browser/browser_highlights_section.js | Should find a visible context menu - true == true -
[task 2020-01-22T00:14:22.280Z] 00:14:22 INFO - Leaving test bound check_highlights_context_menu
[task 2020-01-22T00:14:22.339Z] 00:14:22 INFO - GECKO(10252) | MEMORY STAT | vsize 2104221MB | vsizeMaxContiguous 66780523MB | residentFast 359MB | heapAllocated 178MB
[task 2020-01-22T00:14:22.339Z] 00:14:22 INFO - TEST-OK | browser/components/newtab/test/browser/browser_highlights_section.js | took 5262ms
[task 2020-01-22T00:14:22.339Z] 00:14:22 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-01-22T00:14:22.339Z] 00:14:22 INFO - TEST-UNEXPECTED-FAIL | browser/components/newtab/test/browser/browser_highlights_section.js | Found an unexpected tab at the end of test run: about:blank -
[task 2020-01-22T00:14:22.357Z] 00:14:22 INFO - checking window state

This seems to be a regression from https://bugzilla.mozilla.org/show_bug.cgi?id=1609160
Scott, could you please take a look at this?

Flags: needinfo?(sdowne)
Regressed by: 1609160
Assignee: nobody → sdowne
Flags: needinfo?(sdowne)

Not sure I'm making sense of the regression.

The code the regression removes (an if statement) would have been false during tests anyway. So at first glance, the tests before and after the patch would be running the same logic, so I'm struggling to figure out how we could have regressed this.

But also seems like a race condition, so maybe that check was somehow giving it just enough time to win the race? Removing it, exposed the race condition. I'll pull at that thread for a bit.

A few questions:

How confident are we that 1609160 is the cause? Like, does the build/error log show that commit as the last commit, or are we doing a rough estimate based on the date/time? I only ask because verifying/reproducing this seems to be not obvious, and would like to see if I can get an understanding on the level of confidence before digging in too much, otherwise I could put time into looking at other similar patches. (I'm also not super experienced on this system used for this kind of error)

Is this only happening on beta? Or have we seen it happen on nightly too?

Is there a way I can see these intermittent errors happening real time or daily, or do I need to wait for the 7 day Intermittent Failures Robot updates?

Thanks!

(In the mean time I'm going to keep trying to see if I can force a failure by poking around a possible existing race condition on beta)

Flags: needinfo?(nerli)

(In reply to Scott [:thecount] Downe from comment #3)

A few questions:

How confident are we that 1609160 is the cause? Like, does the build/error log show that commit as the last commit, or are we doing a rough estimate based on the date/time? I only ask because verifying/reproducing this seems to be not obvious, and would like to see if I can get an understanding on the level of confidence before digging in too much, otherwise I could put time into looking at other similar patches. (I'm also not super experienced on this system used for this kind of error)

This first appeared on the push which included bug 1609160 on mozilla-beta

Is this only happening on beta? Or have we seen it happen on nightly too?

This is happening only on beta

Is there a way I can see these intermittent errors happening real time or daily, or do I need to wait for the 7 day Intermittent Failures Robot updates?

You can check intermittent failure rate by accessing the OF here: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2020-01-16&endday=2020-01-23&tree=all&bug=1610709 and you don't need to wait 7 days. OF failures show up after several minutes after we classify them in TH.

Thanks!

(In the mean time I'm going to keep trying to see if I can force a failure by poking around a possible existing race condition on beta)

Hi Scott, answers are inline.

Recent changes on this file are from https://hg.mozilla.org/releases/mozilla-beta/rev/7d76a0d3d4027b6a0571a19c20e9956ba3b30120
Kris please take a look.

Flags: needinfo?(nerli) → needinfo?(kmaglione+bmo)
Regressed by: 1596918
No longer regressed by: 1609160
Has Regression Range: --- → yes
Keywords: regression
Assignee: sdowne → nobody
Status: NEW → RESOLVED
Closed: 4 years ago
Flags: needinfo?(kmaglione+bmo)
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.