Open Bug 1539947 Opened 10 months ago Updated Last month

Intermittent toolkit/components/thumbnails/test/browser_thumbnails_update.js | we have a green thumbnail - Got 0,0,0, expected 0,255,0

Categories

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

defect

Tracking

()

REOPENED

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

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

Attachments

(1 file)

#[markdown(off)]
Filed by: rgurzau [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=236672219&repo=autoland

https://queue.taskcluster.net/v1/task/M7f-Aj4RRv6ll51j0Ulrfg/runs/0/artifacts/public/logs/live_backing.log

17:58:37 INFO - TEST-START | toolkit/components/thumbnails/test/browser_thumbnails_update.js
17:58:38 INFO - TEST-INFO | started process screenshot
17:58:38 INFO - TEST-INFO | screenshot: exit 0
17:58:38 INFO - Buffered messages logged at 17:58:37
17:58:38 INFO - Running subtest simpleCaptureTest
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | got expected topic -
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | data is our test URL -
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | got notification of item being created. -
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | still only 1 notification of item being created. -
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | C:\Users\task_1553793370\AppData\Local\Temp\tmp5ynm8s.mozrunner\thumbnails\31c3c75202c4a36797a81758ea8a2213.png should exist -
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | got expected topic -
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | data is our test URL -
17:58:38 INFO - Running subtest capIfStaleErrorResponseUpdateTest
17:58:38 INFO - Buffered messages logged at 17:58:38
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | we have a green thumbnail -
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | C:\Users\task_1553793370\AppData\Local\Temp\tmp5ynm8s.mozrunner\thumbnails\eae6197cdeceaf2b806a2119a1bf8ebe.png should exist -
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | modified time should be < now -
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | thumbnail is still green -
17:58:38 INFO - Running subtest capIfStaleGoodResponseUpdateTest
17:58:38 INFO - Buffered messages finished
17:58:38 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/thumbnails/test/browser_thumbnails_update.js | we have a green thumbnail - Got 0,0,0, expected 0,255,0
17:58:38 INFO - Stack trace:
17:58:38 INFO - chrome://mochikit/content/browser-test.js:test_is:1315
17:58:38 INFO - chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:captureAndCheckColor/</<:142
17:58:38 INFO - chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:retrieveImageDataForURL/<:172
17:58:38 INFO - chrome://mochikit/content/browser-test.js:run:1344
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | C:\Users\task_1553793370\AppData\Local\Temp\tmp5ynm8s.mozrunner\thumbnails\5617d2be5652fa34a756ee5e118cbc92.png should exist -
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | modified time should be >= now -
17:58:38 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | thumbnail is now red -

Status: NEW → RESOLVED
Closed: 9 months ago
Resolution: --- → INCOMPLETE
Component: Activity Streams: Newtab → New Tab Page
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

In the last 7 days, there have been 49 failures on windows10-64-qr platform, debug build type.

An example of a recent log file:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=270696964&repo=autoland&lineNumber=45466

And the relevant part of the log:
task 2019-10-10T15:36:28.084Z] 15:36:28 INFO - TEST-PASS | toolkit/components/thumbnails/test/browser_thumbnails_update.js | thumbnail is still green -
[task 2019-10-10T15:36:28.084Z] 15:36:28 INFO - Running subtest capIfStaleGoodResponseUpdateTest
[task 2019-10-10T15:36:28.084Z] 15:36:28 INFO - Buffered messages finished
[task 2019-10-10T15:36:28.084Z] 15:36:28 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/thumbnails/test/browser_thumbnails_update.js | we have a green thumbnail - Got 0,0,0, expected 0,255,0
[task 2019-10-10T15:36:28.084Z] 15:36:28 INFO - Stack trace:
[task 2019-10-10T15:36:28.084Z] 15:36:28 INFO - chrome://mochikit/content/browser-test.js:test_is:1590
[task 2019-10-10T15:36:28.084Z] 15:36:28 INFO - chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:captureAndCheckColor/</<:169
[task 2019-10-10T15:36:28.084Z] 15:36:28 INFO - chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:retrieveImageDataForURL/<:200
[task 2019-10-10T15:36:28.084Z] 15:36:28 INFO - chrome://mochikit/content/browser-test.js:run:1642

Scott, as you are the triage owner of this component, could you please take a look at this?
Thank you!

Flags: needinfo?(sdowne)
Whiteboard: [stockwell needswork:owner]

Marking as P2 so that we consider in our Nightly 72 planning.

Priority: P5 → P2
Flags: needinfo?(sdowne)

Re NI'ing Scott for this to make sure to investigate if we need to fix in this Nightly cycle.
Mardak, can you advise on urgency here? (Scott is out today for Canadian holiday) Scott and I chatted about it last week during preage, and given that it was 7 mo old, we didn't think it was urgent. But with the latest failures I'm not sure if that's true anymore. Thank you!

Flags: needinfo?(sdowne)
Flags: needinfo?(edilee)

Looks like there was some (unrelated?) change starting about 5 days ago with comment 18 showing a jump from 0.004 failures/push to 0.025. As noted in comment 24, the test may be disabled in a week if it keeps failing, so that would remove test coverage of updating thumbnails, which these failures could indicate might already be broken ?

Flags: needinfo?(edilee)

Based on comment 27 made a patch to disable the test until it is fixed. Ed, Jessilyn, any reasons to hold off on this?

Flags: needinfo?(jdavis)
Flags: needinfo?(edilee)
Keywords: leave-open
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Pushed by ccoroiu@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/a0a27f10b64c
Disable browser_thumbnails_update.js on windows qr for frequent failures. r=gbrown

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

Based on comment 27 made a patch to disable the test until it is fixed. Ed, Jessilyn, any reasons to hold off on this?

I defer the decision to Ed/Scott. Ed/Scott - what's your recommended next steps on this?

Flags: needinfo?(jdavis)

We can disable the test.

Flags: needinfo?(sdowne)

So just started to dig into this a bit.

Looks like this is the test that's causing the issue: https://searchfox.org/mozilla-central/source/toolkit/components/thumbnails/test/browser_thumbnails_update.js#123

If you look at that test comment, it says "This test is somewhat redundant - although it is using a http:// URL instead of a data: url like most others."

I wonder if that's related to this failure.

Looking at the above URL used in the test, it either returns green or red for the case we care about. https://searchfox.org/mozilla-central/source/toolkit/components/thumbnails/test/thumbnails_update.sjs

Considering it got 0,0,0 and not 0,255,0 OR 255,0,0 suggests maybe the issue is the URL is not ready in time?

I think it's this: https://searchfox.org/mozilla-central/source/toolkit/components/thumbnails/test/head.js#123

When we're calling addTab in these tests, we're not using the callback. I can reproduce it with a custom test that keep calling this function until it fails, it eventually fails. I don't now what started it.

I'm rewriting the tests to use a callback in addTab to see if that fixes it.

Seeing now that the addTab function is trying to call next as the callback and the function is being called with yield, so not sure why it's sometimes failing. Still might be an issue with addTab but not as obvious as I initially thought.

Duplicate of this bug: 1345418

With bug 1591495 fixed, I wonder if the intermittents here would have gone down?

Depends on: 1591495
Flags: needinfo?(edilee)

Tim/Mardak, can y'all help us triage this?

Flags: needinfo?(tspurway)
Flags: needinfo?(edilee)

Probably can return the priority to what it was before comment 22 now that it's been disabled on windows10-64-qr in comment 31.

Flags: needinfo?(tspurway)
Flags: needinfo?(edilee)
Priority: P2 → P5
You need to log in before you can comment on or make changes to this bug.