Open Bug 886080 Opened 11 years ago Updated 2 years ago

Intermittent dynamic-feImage-01.svg | assertion count 1 is more than expected 0 assertions from ASSERTION: Double UnblockOnload!?: 'mCurrentRequestFlags & REQUEST_BLOCKS_ONLOAD'

Categories

(Core :: Graphics: ImageLib, defect, P3)

Product:
Core
Component:
Graphics: ImageLib
Platform:
x86
Linux
Type:
defect

Tracking

()

People

(Reporter: philor, Unassigned)

References

Details

(Keywords: assertion, intermittent-failure, Whiteboard: [leave open])

Attachments

(1 file)

Patch
874 bytes, patch
joe
: review+
Details | Diff | Splinter Review 
https://tbpl.mozilla.org/php/getParsedLog.php?id=24478447&tree=Mozilla-Inbound
Ubuntu VM 12.04 mozilla-inbound debug test reftest on 2013-06-22 15:09:11 PDT for push 1ea803d6be37
slave: tst-linux32-ec2-071

16:31:10     INFO -  ###!!! ASSERTION: Double UnblockOnload!?: 'mCurrentRequestFlags & REQUEST_BLOCKS_ONLOAD', file ../../../../content/base/src/nsImageLoadingContent.cpp, line 641
16:31:10     INFO -  nsImageLoadingContent::UnblockOnload(imgIRequest*) [content/base/src/nsImageLoadingContent.cpp:640]
16:31:10     INFO -  imgRequestProxy::UnblockOnload() [image/src/imgRequestProxy.cpp:873]
16:31:10     INFO -  imgStatusTracker::SyncNotifyDifference(imgStatusTracker::StatusDiff) [image/src/imgStatusTracker.cpp:591]
16:31:10     INFO -  mozilla::image::RasterImage::FinishedSomeDecoding(mozilla::image::RasterImage::eShutdownIntent, mozilla::image::RasterImage::DecodeRequest*) [image/src/RasterImage.cpp:3102]
16:31:10     INFO -  mozilla::image::RasterImage::RequestDecodeCore(mozilla::image::RasterImage::RequestDecodeType) [image/src/RasterImage.cpp:2393]
16:31:10     INFO -  mozilla::image::RasterImage::StartDecoding() [image/src/RasterImage.cpp:2323]
16:31:10     INFO -  mozilla::dom::SVGFEImageElement::Notify(imgIRequest*, int, nsIntRect const*) [content/svg/content/src/SVGFEImageElement.cpp:299]
16:31:10     INFO -  imgRequestProxy::OnStartContainer() [image/src/imgRequestProxy.cpp:714]
16:31:10     INFO -  imgStatusTracker::SyncNotifyState(nsTObserverArray<imgRequestProxy*>&, bool, unsigned int, nsIntRect&, bool) [image/src/imgStatusTracker.cpp:486]
16:31:10     INFO -  imgStatusTracker::SyncNotify(imgRequestProxy*) [obj-firefox/dist/include/nsTObserverArray.h:356]
16:31:10     INFO -  imgRequestNotifyRunnable::Run() [image/src/imgStatusTracker.cpp:366]
16:31:10     INFO -  nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:626]
16:31:10     INFO -  NS_ProcessNextEvent(nsIThread*, bool) [obj-firefox/xpcom/build/nsThreadUtils.cpp:238]
16:31:10     INFO -  mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:83]
16:31:10     INFO -  MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:219]
16:31:10     INFO -  MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:506]
16:31:10     INFO -  nsBaseAppShell::Run() [widget/xpwidgets/nsBaseAppShell.cpp:165]
16:31:10     INFO -  nsAppStartup::Run() [toolkit/components/startup/nsAppStartup.cpp:270]
16:31:10     INFO -  XREMain::XRE_mainRun() [toolkit/xre/nsAppRunner.cpp:3857]
16:31:10     INFO -  XREMain::XRE_main(int, char**, nsXREAppData const*) [toolkit/xre/nsAppRunner.cpp:3924]
16:31:10     INFO -  XRE_main [toolkit/xre/nsAppRunner.cpp:4127]
16:31:10     INFO -  do_main [browser/app/nsBrowserApp.cpp:272]
16:31:10     INFO -  main [browser/app/nsBrowserApp.cpp:634]
16:31:10     INFO -  REFTEST TEST-PASS | file:///builds/slave/test/build/tests/reftest/tests/layout/reftests/svg/dynamic-feImage-01.svg | image comparison (==)
16:31:10     INFO -  REFTEST INFO | Loading a blank page
16:31:10     INFO -  ++DOMWINDOW == 72 (0xbd5aaa8) [serial = 22356] [outer = 0xa229868]
16:31:10     INFO -  REFTEST TEST-UNEXPECTED-FAIL | file:///builds/slave/test/build/tests/reftest/tests/layout/reftests/svg/dynamic-feImage-01.svg | assertion count 1 is more than expected 0 assertions
Any ideas what might be going on here, jwatt?
Flags: needinfo?(jwatt)
I'm going to look at this.
Assignee: nobody → khuey
I caught this in the record and replay machine.  I'm on PTO the rest of this week so I may not investigate it immediately.
Alright I understand the problem.  Now to figure out what the fix is.
Flags: needinfo?(jwatt)
(In reply to Kyle Huey [:khuey] (khuey@mozilla.com) from comment #47)
> I caught this in the record and replay machine.  I'm on PTO the rest of this
> week so I may not investigate it immediately.

Ah great - thank you :-)
Attached patch Patch — — Splinter Review 
This is a bandaid more than anything else, but I think it's what we want for now.  It effectively reverts part of Bug 792199.
Attachment #773934 - Flags: review?(joe)
Comment on attachment 773934 [details] [diff] [review]
Patch

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

This, as is, is totally safe, but I can't comment on the SVG code's requirements.
Attachment #773934 - Flags: review?(joe) → review+
Comment on attachment 773934 [details] [diff] [review]
Patch

Unfortunately it's not 100% non-notifying:

NS_IMETHODIMP
RasterImage::RequestDecode()
{
  return RequestDecodeCore(SYNCHRONOUS_NOTIFY);
}

I think we're going to create a third entry point, something that calls RequestDecodeCore(ASYNCHRONOUS), perhaps called AsyncRequestDecode or some such.
Attachment #773934 - Flags: review+ → review-
I don't have time to work on anything more complicated :-/
Assignee: khuey → nobody
Component: SVG → ImageLib
Kyle, could you post what you found (ie the relevant stack it sounds like) so someone else can pick this up?
Flags: needinfo?(khuey)
(In reply to Joe Drew (:JOEDREW! \o/) from comment #83)
> This, as is, is totally safe, but I can't comment on the SVG code's
> requirements.

It looks fine to me.
(In reply to Timothy Nikkel (:tn) from comment #89)
> Kyle, could you post what you found (ie the relevant stack it sounds like)
> so someone else can pick this up?

The problem is that we are dispatching notifications, the observer calls back into imagelib and does something that causes us to try to dispatch more notifications, and we end up dispatching them out of order.  The actual stack is:

 	xul.dll!NS_DebugBreak(unsigned int aSeverity=1, const char * aStr=0x684e4b3c, const char * aExpr=0x684e4df4, const char * aFile=0x684e4db0, int aLine=641)  Line 293	C++
 	xul.dll!nsImageLoadingContent::UnblockOnload(imgIRequest * aRequest=0x0ae3df00)  Line 641 + 0x26 bytes	C++
 	xul.dll!imgRequestProxy::UnblockOnload()  Line 875	C++
 	xul.dll!imgStatusTracker::SendUnblockOnload(imgRequestProxy * aProxy=0x0ae3df00)  Line 1030	C++
 	xul.dll!imgStatusTracker::SyncNotifyDifference(imgStatusTracker::StatusDiff diff={...})  Line 593	C++
 	xul.dll!mozilla::image::RasterImage::FinishedSomeDecoding(mozilla::image::RasterImage::eShutdownIntent aIntent=eShutdownIntent_Done, mozilla::image::RasterImage::DecodeRequest * aRequest=0x00000000)  Line 3104	C++
 	xul.dll!mozilla::image::RasterImage::RequestDecodeCore(mozilla::image::RasterImage::RequestDecodeType aDecodeType=SYNCHRONOUS_NOTIFY)  Line 2393 + 0xc bytes	C++
 	xul.dll!mozilla::image::RasterImage::StartDecoding()  Line 2324	C++
>	xul.dll!mozilla::dom::SVGFEImageElement::Notify(imgIRequest * aRequest=0x0ae3df00, int aType=1, const nsIntRect * aData=0x00000000)  Line 300	C++
 	xul.dll!imgRequestProxy::OnStartContainer()  Line 714	C++
 	xul.dll!imgStatusTracker::SyncNotifyState(nsTObserverArray<imgRequestProxy *> & proxies={...}, bool hasImage=true, unsigned int state=119, nsIntRect & dirtyRect={...}, bool hadLastPart=true)  Line 486 + 0x53 bytes	C++
 	xul.dll!imgStatusTracker::SyncNotify(imgRequestProxy * proxy=0x0ae3df00)  Line 628 + 0x40 bytes	C++
 	xul.dll!imgRequestNotifyRunnable::Run()  Line 369	C++
 	xul.dll!nsThread::ProcessNextEvent(bool mayWait=false, bool * result=0x0036f37f)  Line 626 + 0x19 bytes	C++
Flags: needinfo?(khuey)
Kyle and I also talked about this, and it's not clear whether this patch will fix the problem. It might make it less frequent, so I gave him verbal-r+ to land the patch as-is, leaving this bug open to collect failures that will definitely still occur (and find out how frequently they occur), but absent us doing one of:

1) Adding AsyncRequestDecode, which does absolutely no notification, and is used from places that do not want reentrant notifications, or
2) Changing imagelib to never do reentrant notification, which is absolutely possible, but when I tried it broke things

we can't fix this bug absolutely.

Only 2) will fix this *class* of bug, but it's got a lot of knock-on effects that someone will need to deal with.
Attachment #773934 - Flags: review- → review+
Whiteboard: [leave open]
Marked random-if on Linux for too many intermittent failures:
https://hg.mozilla.org/integration/mozilla-inbound/rev/aa1a5a6159c0
Whiteboard: [leave open] → [marked random-if on Linux][leave open]
Let's see if skip-if works better.
https://hg.mozilla.org/integration/mozilla-inbound/rev/e4dfd9facfbd
Whiteboard: [marked random-if on Linux][leave open] → [marked skip-if on Linux][leave open]
Blocks: 1053878
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: