Closed Bug 873455 Opened 11 years ago Closed 6 years ago

Intermittent test_bug544462.html | Image not cointained in the offline cache has loaded - got undefined, expected true

Categories

(Core :: Networking: Cache, defect, P3)

Product:
Core
Component:
Networking: Cache
Platform:
x86
Windows 7
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: RyanVM, Assigned: seth)

References

Details

(Keywords: intermittent-failure, Whiteboard: [necko-backlog])

Attachments

(1 file, 2 obsolete files)

Add assertions for imgFrame::Init failure.
3.67 KB, patch
Details | Diff | Splinter Review 
https://tbpl.mozilla.org/php/getParsedLog.php?id=23059440&tree=Mozilla-Inbound

Rev3 WINNT 6.1 mozilla-inbound debug test mochitest-3 on 2013-05-16 17:28:55 PDT for push 39b03fde453a
slave: talos-r3-w7-106

17:53:18     INFO -  22533 INFO TEST-START | /tests/dom/tests/mochitest/ajax/offline/test_bug544462.html
17:53:18     INFO -  ++DOMWINDOW == 79 (123B70D0) [serial = 1420] [outer = 0C2AD668]
17:53:18     INFO -  ++DOCSHELL 123B7ED0 == 19 [id = 400]
17:53:18     INFO -  ++DOMWINDOW == 80 (123B28A0) [serial = 1421] [outer = 00000000]
17:53:18     INFO -  ++DOMWINDOW == 81 (123B6998) [serial = 1422] [outer = 123B28A0]
17:53:18     INFO -  [Parent 1484] WARNING: NS_ENSURE_TRUE(mMutable) failed: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/netwerk/base/src/nsSimpleURI.cpp, line 265
17:53:18     INFO -  ++DOMWINDOW == 82 (123B3978) [serial = 1423] [outer = 123B28A0]
17:53:18     INFO -  [Parent 1484] WARNING: 1 sort operation has occurred for the SQL statement '0x120226a0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/storage/src/mozStoragePrivateHelpers.cpp, line 110
17:53:18     INFO -  [Parent 1484] WARNING: 1 sort operation has occurred for the SQL statement '0x120205a0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/storage/src/mozStoragePrivateHelpers.cpp, line 110
17:53:18     INFO -  [Parent 1484] WARNING: 1 sort operation has occurred for the SQL statement '0x120226a0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/storage/src/mozStoragePrivateHelpers.cpp, line 110
17:53:18     INFO -  [Parent 1484] WARNING: 1 sort operation has occurred for the SQL statement '0x120205a0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/storage/src/mozStoragePrivateHelpers.cpp, line 110
17:53:19     INFO -  [Parent 1484] WARNING: 1 sort operation has occurred for the SQL statement '0x120226a0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/storage/src/mozStoragePrivateHelpers.cpp, line 110
17:53:19     INFO -  [Parent 1484] WARNING: 1 sort operation has occurred for the SQL statement '0x120205a0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/storage/src/mozStoragePrivateHelpers.cpp, line 110
17:53:19     INFO -  [Parent 1484] WARNING: 1 sort operation has occurred for the SQL statement '0x120226a0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/storage/src/mozStoragePrivateHelpers.cpp, line 110
17:53:19     INFO -  [Parent 1484] WARNING: 1 sort operation has occurred for the SQL statement '0x120205a0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/storage/src/mozStoragePrivateHelpers.cpp, line 110
17:53:19     INFO -  [Parent 1484] WARNING: 1 sort operation has occurred for the SQL statement '0x120226a0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/storage/src/mozStoragePrivateHelpers.cpp, line 110
17:53:19     INFO -  [Parent 1484] WARNING: 1 sort operation has occurred for the SQL statement '0x120205a0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/storage/src/mozStoragePrivateHelpers.cpp, line 110
17:53:19     INFO -  [Parent 1484] WARNING: 1 sort operation has occurred for the SQL statement '0x120205a0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/storage/src/mozStoragePrivateHelpers.cpp, line 110
17:53:19     INFO -  ++DOMWINDOW == 83 (123B1C98) [serial = 1424] [outer = 123B28A0]
17:53:19     INFO -  [Parent 1484] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x8007000E: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/image/src/RasterImage.cpp, line 1260
17:53:19     INFO -  22534 INFO TEST-PASS | /tests/dom/tests/mochitest/ajax/offline/test_bug544462.html | Image from a different origin not cointained in the offline cache has loaded
17:53:19     INFO -  22535 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/ajax/offline/test_bug544462.html | Image not cointained in the offline cache has loaded - got undefined, expected true
17:53:19     INFO -  22536 INFO TEST-END | /tests/dom/tests/mochitest/ajax/offline/test_bug544462.html | finished in 1620ms
17:53:19     INFO -  [Parent 1484] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x8007000E: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/image/src/RasterImage.cpp, line 1260

This ensure failure indicates that something might be wrong with some image just being loaded (probably one of the two involved in the test)...  Worth to check from someone that knows the image code.

17:53:19     INFO -  22535 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/ajax/offline/test_bug544462.html | Image not cointained in the offline cache has loaded - got undefined, expected true

And this can have two causes:

1. race between onload->onnoupdate and image onload.  To explain:
  - onload schedules the offline cache update (this happens content sink, no in the test) that check the manifest and when discovers it has not changed since the last time fires onnoupdate where we check whether both images fined their respective onlaods
  - I don't know whether images onload happens before document.body.onload or those are background loads that may race with the update ; can someone answer that?

2. the image simply didn't load from some reason (e.g. because of the above mentioned error).
Flags: needinfo?
Seth, maybe you can help?
Flags: needinfo? → needinfo?(seth)
Joe seems like another possibly useful person to ask here.
Flags: needinfo?(joe)
(In reply to Honza Bambas (:mayhemer) from comment #1)
> This ensure failure indicates that something might be wrong with some image
> just being loaded (probably one of the two involved in the test)...  Worth
> to check from someone that knows the image code.

Specifically this indicates a failure to initialize a new frame for the image. Drilling down, this may happen because:

- The frame's size is invalid (e.g. width or height of 0).
- The frame is a paletted frame and the palette depth is not supported.
- Out of memory. (Probably not the case here.)

>   - I don't know whether images onload happens before document.body.onload

IIRC image onload does happen before document.body.onload. But this is likely irrelevant, since given the failure above the real cause is almost certainly...

> 2. the image simply didn't load from some reason

This is what appears to be happening, because of the failure initializing the frame described above. So, why might this have started happening recently? My guess is that the root cause is bug 869125, which seems to have caused another regression as well (bug 871671).
Flags: needinfo?(seth)
Depends on: 869125
Almost certainly we are managing to create the initial frame for the image while RasterImage::mSize is still zero. This bug was probably hidden before because we didn't actually use that initial frame until bug 869125 landed. Since bug 869125, we actually have to get the initial frame right!
If anyone can reproduce this, I'd be very interested in the stack for the warning at RasterImage.cpp:1260. Maybe we can change that to an assertion so we get stacks from buildbot?
Flags: needinfo?(joe)
Let's go ahead and add those assertions.
Attachment #751953 - Flags: review?(joe)
Assignee: nobody → seth
Comment on attachment 751953 [details] [diff] [review]
Add assertions for imgFrame::Init failure.

Review of attachment 751953 [details] [diff] [review]:
-----------------------------------------------------------------

loverly
Attachment #751953 - Flags: review?(joe) → review+
Whiteboard: [leave open]
Well, I guess that worked!
(In reply to Ryan VanderMeulen [:RyanVM] from comment #12)
> Well, I guess that worked!

I think symbols are broken :((

https://tbpl.mozilla.org/php/getParsedLog.php?id=23202198&tree=Mozilla-Inbound&full=1#error2
(In reply to Ryan VanderMeulen [:RyanVM][Out May 23-27] from comment #12)
> Well, I guess that worked!

It was almost *too* easy =)
What's surprising is that for the issue we're talking about in this bug, the nonzero size assertion doesn't fire, but the assertion that Init succeeded DOES fire. In other words, looking back at the possible causes of Init failing:

> - The frame's size is invalid (e.g. width or height of 0).
> - The frame is a paletted frame and the palette depth is not supported.
> - Out of memory. (Probably not the case here.)

... we have eliminated the first possibility. That's pretty surprising; I thought that'd be the most likely candidate.
Well, actually, that's not true. We've eliminated the possibility that it was caused by mSize being uninitialized when the initial frame was created. But there could be other ways that we'd get an invalid frame size. What I'm going to do here is add more fine-grained assertions.
We do also know that the image is not too big, as there are NS_WARNINGs associated with those cases.
I've pushed to try a modified patch that has more assertions.

https://tbpl.mozilla.org/?tree=Try&rev=1e66345bd60d
Argh. Not having any luck on reproducing this on try. I suggest just pushing this version to inbound.
Attachment #752568 - Flags: review?(joe)
Attachment #751953 - Attachment is obsolete: true
Comment on attachment 752568 [details] [diff] [review]
Add assertions for imgFrame::Init failure.

Review of attachment 752568 [details] [diff] [review]:
-----------------------------------------------------------------

This looks fine, but how do we avoid the assertions we failed earlier on inbound?
Attachment #752568 - Flags: review?(joe) → review+
(In reply to Joe Drew (:JOEDREW! \o/) from comment #21)
> This looks fine, but how do we avoid the assertions we failed earlier on
> inbound?

Hmm, that's a good point. We got lucky last time because the failure happened in the first push, but if it doesn't, we'd get backed out before we got any useful results. I'll just switch all the assertions over to NS_WARNINGs.
Same thing but with NS_WARNING instead of MOZ_ASSERT.
Attachment #752568 - Attachment is obsolete: true
(In reply to Seth Fowler [:seth] from comment #20)
> Argh. Not having any luck on reproducing this on try. I suggest just pushing
> this version to inbound.

The failures this is being backed out for now (https://tbpl.mozilla.org/?tree=Mozilla-Inbound&rev=11de174da4a4) were present on Try too.

Backed out:
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/de5af3547894
(In reply to Ed Morley [:edmorley UTC+1] from comment #25)
> The failures this is being backed out for now
> (https://tbpl.mozilla.org/?tree=Mozilla-Inbound&rev=11de174da4a4) were
> present on Try too.

Yes, I'm sorry I missed that. The patch tested on try above _intentionally crashed_, which made the fact that there was a bug in the patch itself less than obvious. The one I actually pushed was intended not to crash, but did anyway due to a missing "else".
Whiteboard: [leave open] → [leave open][necko-backlog]
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
Bulk change to priority: https://bugzilla.mozilla.org/show_bug.cgi?id=1399258
Priority: P3 → P1
Bulk change to priority: https://bugzilla.mozilla.org/show_bug.cgi?id=1399258
Priority: P1 → P3
leave open with no failures in 5 years- should we close this?
Flags: needinfo?(mcmanus)
comment 34
Status: NEW → RESOLVED
Closed: 6 years ago
Flags: needinfo?(mcmanus)
Resolution: --- → INCOMPLETE
Whiteboard: [leave open][necko-backlog] → [necko-backlog]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: