1122744 - Intermittent browser_details.js | application crashed [@ PLDHashTable::Operate(void const *,PLDHashOperator)] (Assertion failure: aOp == PL_DHASH_LOOKUP || mRecursionLevel == 0, at pldhash.cpp:532)

Status: RESOLVED WORKSFORME

(Core :: Graphics: ImageLib, defect)

Description

[Ryan VanderMeulen [:RyanVM]]

12:33:37 INFO - Assertion failure: aOp == PL_DHASH_LOOKUP || mRecursionLevel == 0, at c:/builds/moz2_slave/fx-team-w32-d-0000000000000000/build/src/xpcom/glue/pldhash.cpp:532
12:33:37 INFO - #01: PL_DHashTableRemove(PLDHashTable *,void const *) [xpcom/glue/pldhash.cpp:660]
12:33:37 INFO - #02: mozilla::image::SurfaceCacheImpl::Remove(mozilla::image::CachedSurface *) [image/src/SurfaceCache.cpp:380]
12:33:37 INFO - #03: nsExpirationTracker<mozilla::image::CachedSurface,2>::AgeOneGeneration() [xpcom/ds/nsExpirationTracker.h:205]
12:33:37 INFO - #04: nsExpirationTracker<mozilla::image::CachedSurface,2>::TimerCallback(nsITimer *,void *) [xpcom/ds/nsExpirationTracker.h:345]
12:33:37 INFO - #05: nsTimerImpl::Fire() [xpcom/threads/nsTimerImpl.cpp:631]
12:33:37 INFO - #06: nsTimerEvent::Run() [xpcom/threads/nsTimerImpl.cpp:729]
12:33:37 INFO - #07: nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:855]
12:33:37 INFO - #08: NS_ProcessNextEvent(nsIThread *,bool) [xpcom/glue/nsThreadUtils.cpp:265]
12:33:37 INFO - #09: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:99]
12:33:37 INFO - #10: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:233]
12:33:37 INFO - #11: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:227]
12:33:37 INFO - #12: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:201]
12:33:37 INFO - #13: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:166]
12:33:37 INFO - #14: nsAppShell::Run() [widget/windows/nsAppShell.cpp:180]
12:33:37 INFO - #15: nsAppStartup::Run() [toolkit/components/startup/nsAppStartup.cpp:282]
12:33:37 INFO - #16: XREMain::XRE_mainRun() [toolkit/xre/nsAppRunner.cpp:4145]
12:33:37 INFO - #17: XREMain::XRE_main(int,char * * const,nsXREAppData const *) [toolkit/xre/nsAppRunner.cpp:4221]
12:33:37 INFO - #18: XRE_main [toolkit/xre/nsAppRunner.cpp:4441]
12:33:37 INFO - #19: do_main [browser/app/nsBrowserApp.cpp:294]
12:33:37 INFO - #20: NS_internal_main(int,char * *) [browser/app/nsBrowserApp.cpp:663]
12:33:37 INFO - #21: wmain [toolkit/xre/nsWindowsWMain.cpp:124]
12:33:37 INFO - #22: __tmainCRTStartup [f:/dd/vctools/crt/crtw32/startup/crt0.c:255]
12:33:37 INFO - #23: kernel32 + 0x53c45
12:33:37 INFO - #24: ntdll + 0x637f5
12:33:37 INFO - #25: ntdll + 0x637c8
12:33:38 INFO - TEST-INFO | Main app process: exit status 1
12:33:38 WARNING - TEST-UNEXPECTED-FAIL | ShutdownLeaks | process() called before end of test suite 

12:33:38 INFO - 638 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/browser_details.js | Error link should be hidden
12:33:38 INFO - 639 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/browser_details.js | Element should not be null, when checking visibility
12:33:38 INFO - 640 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/browser_details.js | Pending message should be hidden
12:33:38 INFO - 641 INFO Console message: No chrome package registered for chrome://foo/skin/icon.png
12:33:38 INFO - 642 INFO Console message: No chrome package registered for chrome://foo/skin/icon.png
12:33:38 INFO - 643 ERROR TEST-UNEXPECTED-FAIL | toolkit/mozapps/extensions/test/browser/browser_details.js | application terminated with exit code 1
12:33:38 INFO - runtests.py | Application ran for: 0:03:07.609000
12:33:38 INFO - zombiecheck | Reading PID log: c:\users\cltbld\appdata\local\temp\tmpn3oq6epidlog
12:33:38 INFO - ==> process 1080 launched child process 2780 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=1080.19b72ff0.2007966104 "c:\users\cltbld\appdata\local\temp\tmpd1bnzb.mozrunner\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 1080 "\\.\pipe\gecko-crash-server-pipe.1080" plugin)
12:33:48 INFO - mozcrash Saved minidump as C:\slave\test\build\blobber_upload_dir\46be3bf4-679b-4fa0-8cad-54bdaf06a8d2.dmp
12:33:48 INFO - mozcrash Saved app info as C:\slave\test\build\blobber_upload_dir\46be3bf4-679b-4fa0-8cad-54bdaf06a8d2.extra
12:33:48 WARNING - PROCESS-CRASH | toolkit/mozapps/extensions/test/browser/browser_details.js | application crashed [@ PLDHashTable::Operate(void const *,PLDHashOperator)]
12:33:48 INFO - Crash dump filename: c:\users\cltbld\appdata\local\temp\tmpd1bnzb.mozrunner\minidumps\46be3bf4-679b-4fa0-8cad-54bdaf06a8d2.dmp
12:33:48 INFO - Operating system: Windows NT
12:33:48 INFO - 6.1.7601 Service Pack 1
12:33:48 INFO - CPU: x86
12:33:48 INFO - GenuineIntel family 6 model 30 stepping 5
12:33:48 INFO - 8 CPUs
12:33:48 INFO - Crash reason: EXCEPTION_BREAKPOINT
12:33:48 INFO - Crash address: 0x5f2b24b7
12:33:48 INFO - Thread 0 (crashed)
12:33:48 INFO - 0 xul.dll!PLDHashTable::Operate(void const *,PLDHashOperator) [pldhash.cpp:2234aaa1655a : 532 + 0x29]
12:33:48 INFO - eip = 0x5f2b24b7 esp = 0x0026f0ac ebp = 0x0026f0b4 ebx = 0x0dfec800
12:33:48 INFO - esi = 0x00000214 edi = 0x00000002 eax = 0x00000000 ecx = 0x68c20ad9
12:33:48 INFO - edx = 0x002c5609 efl = 0x00000206
12:33:48 INFO - Found by: given as instruction pointer in context
12:33:48 INFO - 1 xul.dll!PL_DHashTableRemove(PLDHashTable *,void const *) [pldhash.cpp:2234aaa1655a : 659 + 0x7]
12:33:48 INFO - eip = 0x5f2b2807 esp = 0x0026f0bc ebp = 0x0026f0cc
12:33:48 INFO - Found by: call frame info
12:33:48 INFO - 2 xul.dll!nsTHashtable<nsBaseHashtableET<nsPtrHashKey<mozilla::image::Image>,nsRefPtr<mozilla::image::ImageSurfaceCache> > >::RemoveEntry(mozilla::image::Image *) [nsTHashtable.h:2234aaa1655a : 175 + 0x9]
12:33:48 INFO - eip = 0x5fb29983 esp = 0x0026f0c8 ebp = 0x0026f0cc
12:33:48 INFO - Found by: call frame info
12:33:48 INFO - 3 xul.dll!mozilla::image::SurfaceCacheImpl::Remove(mozilla::image::CachedSurface *) [SurfaceCache.cpp:2234aaa1655a : 378 + 0x8]
12:33:48 INFO - eip = 0x5fb296ab esp = 0x0026f0d4 ebp = 0x0026f0ec
12:33:48 INFO - Found by: call frame info
12:33:48 INFO - 4 xul.dll!nsExpirationTracker<mozilla::image::CachedSurface,2>::AgeOneGeneration() [nsExpirationTracker.h:2234aaa1655a : 204 + 0xc]
12:33:48 INFO - eip = 0x5fb231bb esp = 0x0026f0f4 ebp = 0x0026f114
12:33:48 INFO - Found by: call frame info
12:33:48 INFO - 5 xul.dll!nsExpirationTracker<mozilla::image::CachedSurface,2>::TimerCallback(nsITimer *,void *) [nsExpirationTracker.h:2234aaa1655a : 343 + 0x9]
12:33:48 INFO - eip = 0x5fb2aaba esp = 0x0026f11c ebp = 0x0026f120
12:33:48 INFO - Found by: call frame info
12:33:48 INFO - 6 xul.dll!nsTimerImpl::Fire() [nsTimerImpl.cpp:2234aaa1655a : 631 + 0x5]
12:33:48 INFO - eip = 0x5f286921 esp = 0x0026f128 ebp = 0x0026f1e0
12:33:48 INFO - Found by: call frame info
12:33:48 INFO - 7 xul.dll!nsTimerEvent::Run() [nsTimerImpl.cpp:2234aaa1655a : 724 + 0xd]
12:33:48 INFO - eip = 0x5f28b7f1 esp = 0x0026f1e8 ebp = 0x0026f210
12:33:48 INFO - Found by: call frame info
12:33:48 INFO - 8 xul.dll!nsThread::ProcessNextEvent(bool,bool *) [nsThread.cpp:2234aaa1655a : 855 + 0xd]
12:33:48 INFO - eip = 0x5f2897d4 esp = 0x0026f218 ebp = 0x0026f2ec
12:33:48 INFO - Found by: call frame info
12:33:48 INFO - 9 xul.dll!NS_ProcessNextEvent(nsIThread *,bool) [nsThreadUtils.cpp:2234aaa1655a : 265 + 0xc]
12:33:48 INFO - eip = 0x5f2b22ee esp = 0x0026f2f4 ebp = 0x0026f300
12:33:48 INFO - Found by: call frame info
12:33:48 INFO - 10 xul.dll!mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate *) [MessagePump.cpp:2234aaa1655a : 99 + 0x9]
12:33:48 INFO - eip = 0x5f4f8c48 esp = 0x0026f308 ebp = 0x0026f330
12:33:48 INFO - Found by: call frame info
12:33:48 INFO - 11 xul.dll!MessageLoop::RunInternal() [message_loop.cc:2234aaa1655a : 233 + 0xe]
12:33:48 INFO - eip = 0x5f4cc549 esp = 0x0026f338 ebp = 0x0026f350
12:33:48 INFO - Found by: call frame info

Comment 1

[Legacy TBPL/Treeherder Robot]

submit_timestamp: 2015-01-16T13:48:22
log: https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=1718545
repository: fx-team
who: rvandermeulen[at]mozilla[dot]com
machine: t-w732-ix-087
buildname: Windows 7 32-bit fx-team debug test mochitest-browser-chrome-3
revision: 2234aaa1655a

Assertion failure: aOp == PL_DHASH_LOOKUP || mRecursionLevel == 0, at c:/builds/moz2_slave/fx-team-w32-d-0000000000000000/build/src/xpcom/glue/pldhash.cpp:532
TEST-UNEXPECTED-FAIL | ShutdownLeaks | process() called before end of test suite
643 ERROR TEST-UNEXPECTED-FAIL | toolkit/mozapps/extensions/test/browser/browser_details.js | application terminated with exit code 1
PROCESS-CRASH | toolkit/mozapps/extensions/test/browser/browser_details.js | application crashed [@ PLDHashTable::Operate(void const *,PLDHashOperator)]
TEST-UNEXPECTED-FAIL | leakcheck | default process: missing output line for total leaks!
Return code: 1

Comment 2

[Kartikaya Gupta (email:[e-mail])]

Nathan, could this be a result of bug 1121304? I'm not sure what "mRecursionLevel" is supposed to represent here, and why it might be non-zero at that line. As far as I can tell the SurfaceCache.cpp is using the mImageCaches table "normally" and it shouldn't be blowing up like this.

Comment 3

[Nathan Froyd [:froydnj]]

(In reply to Kartikaya Gupta (email:[e-mail]) from comment #2)
> Nathan, could this be a result of bug 1121304? I'm not sure what
> "mRecursionLevel" is supposed to represent here, and why it might be
> non-zero at that line. As far as I can tell the SurfaceCache.cpp is using
> the mImageCaches table "normally" and it shouldn't be blowing up like this.

|mRecursionLevel| gets incremented (resp. decremented) whenever we start (resp. finish) "doing something" with the hash table.  We're trying to guard against the possibility that we're not, say, removing/adding elements while we're attempting to walk over all the elements, or something like that.

I agree that the stacks look like we're not doing that.  Is there any possibility that the surface caches is being touched from multiple threads here?

Comment 4

[Kartikaya Gupta (email:[e-mail])]

I'm not sure; Seth would know better. From the history it also looks like he's been touching this code a fair bit so it might be a regression from that.

Comment 5

[Seth Fowler [:seth] [:s2h]]

Oh dear.

Yep, it's accessed from multiple threads, and I forgot to add locking to some observer callbacks in bug 1116733. (I only added them to the public API.) I realized this after taking another look at the code thanks to Nathan's comment, which triggered the component of my lizard brain responsible for paranoia that somewhere in my multithreaded code, I made a mistake.

I'll have a patch up in bug 1126739 in a jiff.

Comment 6

[Andrew McCreight [:mccr8]]

Looks like the fix worked, or at least we never saw this again.