Closed Bug 1008254 Opened 10 years ago Closed 10 years ago

Intermittent B2G PROCESS-CRASH | Shutdown | application crashed [@ mozilla::LinkedList<thread_info>::~LinkedList] (with Assertion failure: isEmpty(), at LinkedList.h:305)

Categories

(Firefox OS Graveyard :: General, defect)

ARM
Gonk (Firefox OS)
defect
Not set
critical

Tracking

(firefox31 unaffected, firefox32 fixed, firefox33 fixed, firefox-esr24 unaffected, b2g-v1.4 unaffected, b2g-v2.0 fixed, b2g-v2.1 fixed)

RESOLVED FIXED
2.0 S5 (4july)
Tracking Status
firefox31 --- unaffected
firefox32 --- fixed
firefox33 --- fixed
firefox-esr24 --- unaffected
b2g-v1.4 --- unaffected
b2g-v2.0 --- fixed
b2g-v2.1 --- fixed

People

(Reporter: emorley, Assigned: bjacob)

References

Details

(Keywords: crash, intermittent-failure)

Attachments

(1 file, 1 obsolete file)

Broken out from bug 965677.

First occurrence (in this form at least) seems to be:

RyanVM
https://tbpl.mozilla.org/php/getParsedLog.php?id=37697490&tree=Mozilla-Inbound
b2g_emulator_vm mozilla-inbound debug test mochitest-debug-9 on 2014-04-12 10:41:33
revision: ba77af4dbd10
slave: tst-linux64-spot-655

B2GRunner TEST-UNEXPECTED-FAIL | Shutdown | application timed out after 450.0 seconds with no output
PROCESS-CRASH | Shutdown | application crashed [@ mozilla::LinkedList<thread_info>::~LinkedList]
Return code: 247
04-12 18:17:33.553   776   776 F MOZ_Assert: Assertion failure: isEmpty(), at ../../dist/include/mozilla/LinkedList.h:305
04-12 18:25:20.484   769   769 I Gecko   : [Child 769] ###!!! ABORT: ActorDestroy by IPC channel failure at CompositorChild: file ../../../gecko/gfx/layers/ipc/CompositorChild.cpp, line 134
04-12 18:25:20.534   769   769 E Gecko   : mozalloc_abort: [Child 769] ###!!! ABORT: ActorDestroy by IPC channel failure at CompositorChild: file ../../../gecko/gfx/layers/ipc/CompositorChild.cpp, line 134
04-12 18:25:20.534   769   769 F libc    : Fatal signal 11 (SIGSEGV) at 0x00000000 (code=1)
This usually indicates the B2G process has crashed

==

Newer occurrence:
https://tbpl.mozilla.org/php/getParsedLog.php?id=39356504&tree=Mozilla-Inbound
{
06:00:04     INFO -  [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:00:05     INFO -  [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:00:05     INFO -  [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:00:05     INFO -  [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:00:05     INFO -  [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:00:05     INFO -  [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:00:05     INFO -  [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:00:05     INFO -  [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:00:05     INFO -  nsStringStats
06:00:05     INFO -   => mAllocCount:          11085
06:00:05     INFO -   => mReallocCount:          425
06:00:05     INFO -   => mFreeCount:            9602  --  LEAKED 1483 !!!
06:00:05     INFO -   => mShareCount:          13649
06:00:05     INFO -   => mAdoptCount:            933
06:00:05     INFO -   => mAdoptFreeCount:        933
06:00:05     INFO -   => Process ID: 830, Thread ID: 1074467976
06:00:06     INFO -  [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:00:06     INFO -  [Parent 671] WARNING: Failed to remove shutdown observer!: file ../../../gecko/dom/bluetooth/bluez/BluetoothOppManager.cpp, line 207
06:00:06     INFO -  [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:00:06     INFO -  [Parent 671] WARNING: Failed to remove shutdown observer!: file ../../../gecko/dom/bluetooth/bluez/BluetoothA2dpManager.cpp, line 79
06:00:06     INFO -  [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:00:06     INFO -  [Parent 671] WARNING: Failed to remove shutdown observer!: file ../../../gecko/dom/bluetooth/BluetoothHidManager.cpp, line 77
06:00:06     INFO -  [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:00:06     INFO -  [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:00:06     INFO -  [Parent 671] WARNING: Failed to remove observers!: file ../../../gecko/dom/bluetooth/bluez/BluetoothHfpManager.cpp, line 474
06:00:06     INFO -  [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:00:06     INFO -  [Parent 671] WARNING: NS_ENSURE_TRUE(obs) failed: file ../../../../gecko/dom/system/gonk/AudioManager.cpp, line 446
06:00:12     INFO -  [Parent 671] WARNING: unable to Flush() dirty datasource during XPCOM shutdown: file ../../../../gecko/rdf/base/src/nsRDFXMLDataSource.cpp, line 747
06:00:22     INFO -  [Parent 671] WARNING: Leaking the RDF Service.: file ../../../gecko/rdf/build/nsRDFModule.cpp, line 165
06:00:22     INFO -  Assertion failed at ../../../../../gecko/gfx/cairo/cairo/src/cairo-ft-font.c:444: unscaled->face == NULL
06:00:22     INFO -  WARNING: YOU ARE LEAKING THE WORLD (at least one JSRuntime and everything alive inside it, that is) AT JS_ShutDown TIME.  FIX THIS!
06:00:22     INFO -  [Parent 671] ###!!! ASSERTION: Component Manager being held past XPCOM shutdown.: 'cnt == 0', file ../../../gecko/xpcom/build/nsXPComInit.cpp, line 937
06:00:22     INFO -  [Parent 671] WARNING: '!compMgr', file ../../../gecko/xpcom/glue/nsComponentManagerUtils.cpp, line 59
06:07:52     INFO -  B2GRunner TEST-UNEXPECTED-FAIL | Shutdown | application timed out after 450.0 seconds with no output
06:07:52     INFO -  B2GRunner INFO | checking for crashes in '/data/local/tests/profile/minidumps'
06:08:16  WARNING -  PROCESS-CRASH | Shutdown | application crashed [@ mozilla::LinkedList<thread_info>::~LinkedList]
06:08:16     INFO -  Crash dump filename: /tmp/tmpGmjTdd/7855005c-dd40-e058-79a5bec2-69ee66c6.dmp
06:08:16     INFO -  Operating system: Android
06:08:16     INFO -                    0.0.0 Linux 2.6.29-00302-g586075d #31 Mon Feb 24 10:28:23 PST 2014 armv7l Android/full/generic:4.0.4.0.4.0.4/OPENMASTER/eng.cltbld.20140509.065604:eng/test-keys
06:08:16     INFO -  CPU: arm
06:08:16     INFO -       0 CPUs
06:08:16     INFO -  Crash reason:  SIGSEGV
06:08:16     INFO -  Crash address: 0x0
06:08:16     INFO -  Thread 0 (crashed)
06:08:16     INFO -   0  libmozglue.so!mozilla::LinkedList<thread_info>::~LinkedList [LinkedList.h : 305 + 0x4]
06:08:16     INFO -       r4 = 0x4005d0b8    r5 = 0x400d2000    r6 = 0x400d2060    r7 = 0x00000006
06:08:16     INFO -       r8 = 0x00001000    r9 = 0x00000000   r10 = 0x4005d0b8    fp = 0x0000000c
06:08:16     INFO -       sp = 0xbec568c8    lr = 0x4002650f    pc = 0x40026512
06:08:16     INFO -      Found by: given as instruction pointer in context
06:08:16     INFO -   1  libc.so!__cxa_finalize [atexit.c : 158 + 0x5]
06:08:16     INFO -       r4 = 0x400a555c    r5 = 0x400d2000    r6 = 0x400d2060    r7 = 0x00000006
06:08:16     INFO -       r8 = 0x00001000    r9 = 0x00000000   r10 = 0x4005d0b8    fp = 0x0000000c
06:08:16     INFO -       sp = 0xbec568d8    pc = 0x40080c05
06:08:16     INFO -      Found by: call frame info
06:08:16     INFO -   2  libc.so!exit [exit.c : 57 + 0x7]
06:08:16     INFO -       r4 = 0x00000000    r5 = 0xbec56934    r6 = 0x00000009    r7 = 0xbec5695c
06:08:16     INFO -       r8 = 0x00000000    r9 = 0x00000000   r10 = 0x00000000    fp = 0x00000000
06:08:16     INFO -       sp = 0xbec56918    pc = 0x40080fa1
06:08:16     INFO -      Found by: call frame info
}

Logcat:
{
06:09:27     INFO -  05-09 13:00:00.946   830   830 I GonkMemoryPressure: Observed XPCOM shutdown.
06:09:27     INFO -  05-09 13:00:04.495   830   830 I Gecko   : [Child 830] WARNING: Leaking the RDF Service.: file ../../../gecko/rdf/build/nsRDFModule.cpp, line 165
06:09:27     INFO -  05-09 13:00:04.505   830   830 I Gecko   : [Child 830] WARNING: Fonts still alive while shutting down gfxFontCache: 'mFonts.Count() == 0', file ../../../gecko/gfx/thebes/gfxFont.cpp, line 1705
06:09:27     INFO -  05-09 13:00:04.575   830   830 I Gecko   : [Child 830] ###!!! ASSERTION: Component Manager being held past XPCOM shutdown.: 'cnt == 0', file ../../../gecko/xpcom/build/nsXPComInit.cpp, line 937
06:09:27     INFO -  05-09 13:00:04.575   830   830 I Gecko   : [Child 830] WARNING: '!compMgr', file ../../../gecko/xpcom/glue/nsComponentManagerUtils.cpp, line 59
06:09:27     INFO -  05-09 13:00:04.639   830   830 I Gecko   : [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:09:27     INFO -  05-09 13:00:04.648   830   830 I Gecko   : [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:09:27     INFO -  05-09 13:00:04.648   830   830 I Gecko   : [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:09:27     INFO -  05-09 13:00:04.655   830   830 I Gecko   : [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:09:27     INFO -  05-09 13:00:04.655   830   830 I Gecko   : [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:09:27     INFO -  05-09 13:00:04.665   830   830 I Gecko   : [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:09:27     INFO -  05-09 13:00:04.665   830   830 I Gecko   : [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:09:27     INFO -  05-09 13:00:04.675   830   830 I Gecko   : [Child 830] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 143
06:09:27     INFO -  05-09 13:00:04.715   830   830 F MOZ_Assert: Assertion failure: isEmpty(), at ../../dist/include/mozilla/LinkedList.h:305
06:09:27     INFO -  05-09 13:00:05.875   671   671 I Gecko   : [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:09:27     INFO -  05-09 13:00:05.875   671   671 I Gecko   : [Parent 671] WARNING: Failed to remove shutdown observer!: file ../../../gecko/dom/bluetooth/bluez/BluetoothOppManager.cpp, line 207
06:09:27     INFO -  05-09 13:00:05.885   671   671 I Gecko   : [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:09:27     INFO -  05-09 13:00:05.885   671   671 I Gecko   : [Parent 671] WARNING: Failed to remove shutdown observer!: file ../../../gecko/dom/bluetooth/bluez/BluetoothA2dpManager.cpp, line 79
06:09:27     INFO -  05-09 13:00:05.896   671   671 I Gecko   : [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:09:27     INFO -  05-09 13:00:05.896   671   671 I Gecko   : [Parent 671] WARNING: Failed to remove shutdown observer!: file ../../../gecko/dom/bluetooth/BluetoothHidManager.cpp, line 77
06:09:27     INFO -  05-09 13:00:05.905   671   671 I Gecko   : [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:09:27     INFO -  05-09 13:00:05.926   671   671 I Gecko   : [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:09:27     INFO -  05-09 13:00:05.926   671   671 I Gecko   : [Parent 671] WARNING: Failed to remove observers!: file ../../../gecko/dom/bluetooth/bluez/BluetoothHfpManager.cpp, line 474
06:09:27     INFO -  05-09 13:00:05.935   671   671 I Gecko   : [Parent 671] ###!!! ASSERTION: Using observer service after XPCOM shutdown!: 'Error', file ../../../gecko/xpcom/ds/nsObserverService.cpp, line 260
06:09:27     INFO -  05-09 13:00:05.965   671   671 I Gecko   : [Parent 671] WARNING: NS_ENSURE_TRUE(obs) failed: file ../../../../gecko/dom/system/gonk/AudioManager.cpp, line 446
06:09:27     INFO -  05-09 13:00:11.876   671   671 I Gecko   : --DOMWINDOW == 3 (0x475289a0) [pid = 671] [serial = 5] [outer = 0x47527aa0] [url = app://test-container.gaiamobile.org/index.html]
06:09:27     INFO -  05-09 13:00:11.886   671   671 I Gecko   : [Parent 671] WARNING: unable to Flush() dirty datasource during XPCOM shutdown: file ../../../../gecko/rdf/base/src/nsRDFXMLDataSource.cpp, line 747
06:09:27     INFO -  05-09 13:00:11.906   671   671 I Gecko   : --DOMWINDOW == 2 (0x47527aa0) [pid = 671] [serial = 3] [outer = 0x0] [url = app://test-container.gaiamobile.org/index.html]
06:09:27     INFO -  05-09 13:00:21.996   671   671 I Gecko   : [Parent 671] WARNING: Leaking the RDF Service.: file ../../../gecko/rdf/build/nsRDFModule.cpp, line 165
06:09:27     INFO -  05-09 13:00:22.095   671   671 I Gecko   : [Parent 671] ###!!! ASSERTION: Component Manager being held past XPCOM shutdown.: 'cnt == 0', file ../../../gecko/xpcom/build/nsXPComInit.cpp, line 937
06:09:27     INFO -  05-09 13:00:22.095   671   671 I Gecko   : [Parent 671] WARNING: '!compMgr', file ../../../gecko/xpcom/glue/nsComponentManagerUtils.cpp, line 59
06:09:27     INFO -  05-09 13:07:52.275   784   784 I Gecko   : [Child 784] ###!!! ABORT: ActorDestroy by IPC channel failure at CompositorChild: file ../../../gecko/gfx/layers/ipc/CompositorChild.cpp, line 169
06:09:27     INFO -  05-09 13:07:52.295   804   804 I Gecko   : [Child 804] ###!!! ABORT: ActorDestroy by IPC channel failure at CompositorChild: file ../../../gecko/gfx/layers/ipc/CompositorChild.cpp, line 169
06:09:27     INFO -  05-09 13:07:52.305   822   822 I Gecko   : [Child 822] ###!!! ABORT: ActorDestroy by IPC channel failure at CompositorChild: file ../../../gecko/gfx/layers/ipc/CompositorChild.cpp, line 169
06:09:27     INFO -  05-09 13:07:52.315   822   822 E Gecko   : mozalloc_abort: [Child 822] ###!!! ABORT: ActorDestroy by IPC channel failure at CompositorChild: file ../../../gecko/gfx/layers/ipc/CompositorChild.cpp, line 169
06:09:27     INFO -  05-09 13:07:52.315   822   822 F MOZ_CRASH: Hit MOZ_CRASH() at ../../../gecko/memory/mozalloc/mozalloc_abort.cpp:30
06:09:27     INFO -  05-09 13:07:52.325    33    33 I ServiceManager: service 'media.resource_manager' died
06:09:27     INFO -  05-09 13:07:52.325    33    33 I ServiceManager: service 'permission' died
06:09:27    ERROR -  05-09 13:07:52.336   822   822 F libc    : Fatal signal 11 (SIGSEGV) at 0x00000000 (code=1)
06:09:27    ERROR -  This usually indicates the B2G process has crashed
06:09:27     INFO -  05-09 13:07:52.355   804   804 E Gecko   : mozalloc_abort: [Child 804] ###!!! ABORT: ActorDestroy by IPC channel failure at CompositorChild: file ../../../gecko/gfx/layers/ipc/CompositorChild.cpp, line 169
06:09:27     INFO -  05-09 13:07:52.355   804   804 F MOZ_CRASH: Hit MOZ_CRASH() at ../../../gecko/memory/mozalloc/mozalloc_abort.cpp:30
06:09:27    ERROR -  05-09 13:07:52.355   804   804 F libc    : Fatal signal 11 (SIGSEGV) at 0x00000000 (code=1)
06:09:27    ERROR -  This usually indicates the B2G process has crashed
06:09:27     INFO -  05-09 13:07:52.365   784   784 E Gecko   : mozalloc_abort: [Child 784] ###!!! ABORT: ActorDestroy by IPC channel failure at CompositorChild: file ../../../gecko/gfx/layers/ipc/CompositorChild.cpp, line 169
06:09:27     INFO -  05-09 13:07:52.365   784   784 F MOZ_CRASH: Hit MOZ_CRASH() at ../../../gecko/memory/mozalloc/mozalloc_abort.cpp:30
06:09:27    ERROR -  05-09 13:07:52.365   784   784 F libc    : Fatal signal 11 (SIGSEGV) at 0x00000000 (code=1)
06:09:27    ERROR -  This usually indicates the B2G process has crashed
}
Be still my heart, a frequent, unowned B2G shutdown crash. I hear bjacob loves these!
Flags: needinfo?(bjacob)
The problem is that CompositorChild::ActorDestroy posts a RunnableMethod to the main thread to call Release() there, thinking that this is enough to ensure that the CompositorChild is destroyed on the main thread, but it's not, because the RunnableMethod itself holds a strong reference to its closure object --- the CompositorChild! --- so the destructions only occurs when the RunnableMethod itself is torn down, which happens later... and back on the IO thread!

This should be fixed as part of The Big Patch Queue that I'll hopefully be landing this week.
Flags: needinfo?(bjacob)
Sorry, CompositorChild::ActorDestroy only posts a runnable to the current thread, I got that wrong in comment 320. Anyway, I have a patch that automatically defers the last release to the main thread, and that should fix this, and it does seem to work on this try push:

https://tbpl.mozilla.org/?tree=Try&rev=ef203ea5b300
Depends on: 924622
(In reply to Benoit Jacob [:bjacob] from comment #321)
> https://tbpl.mozilla.org/?tree=Try&rev=ef203ea5b300

M9 retriggers on that run aren't looking promising :(
Sorry, this is actually a totally different crash from what I had been looking at. Looking now.
Ah, so, this LinkedList<thread_info_t> is actually a Nuwa thing:

http://dxr.mozilla.org/mozilla-central/source/mozglue/build/Nuwa.cpp#202

and was added in Bug 771765, in http://hg.mozilla.org/mozilla-central/rev/eeda15041dec

@tlee, do you have ideas about what is causing this intermittent crash?
Flags: needinfo?(tlee)
Here are two try pushes to help us understand what is going on here.

https://tbpl.mozilla.org/?tree=Try&rev=bbe84d15bed8
has my gfx/layers/ipc shutdown debugging patch --- lots of logging. If this bug has anything to do with gfx/layers/ipc, then this should tell us about that. But I'm not convinced of that and the "CompositorChild" assertions in the log seem like a red herring: CompositorChild just so happens that it asserts on ActorDestroy, making child processes complain after the parent died.

https://tbpl.mozilla.org/?tree=Try&rev=138a0b120d25
has custom logging to understand the present bug. Since this assertion is asserting that Nuwa's list of thread_info objects should be empty on exit, this patch is then dumping its contents, so we can see what thread is left there. In a nutshell, this bug is going to have anything to do with gfx/layers/ipc if, and only if the thread that's left is the Compositor thread.
The latter try push failed to build; new try:
https://tbpl.mozilla.org/?tree=Try&rev=21c7a5e553ae
(In reply to Ed Morley [:edmorley UTC+0] from comment #0)
> Android/full/generic:4.0.4.0.4.0.4/OPENMASTER/eng.cltbld.20140509.065604:eng/
> test-keys
> 06:08:16     INFO -  CPU: arm
> 06:08:16     INFO -       0 CPUs
> 06:08:16     INFO -  Crash reason:  SIGSEGV
> 06:08:16     INFO -  Crash address: 0x0
> 06:08:16     INFO -  Thread 0 (crashed)
> 06:08:16     INFO -   0 
> libmozglue.so!mozilla::LinkedList<thread_info>::~LinkedList [LinkedList.h :
> 305 + 0x4]
> 06:08:16     INFO -       r4 = 0x4005d0b8    r5 = 0x400d2000    r6 =
> 0x400d2060    r7 = 0x00000006
> 06:08:16     INFO -       r8 = 0x00001000    r9 = 0x00000000   r10 =
> 0x4005d0b8    fp = 0x0000000c
> 06:08:16     INFO -       sp = 0xbec568c8    lr = 0x4002650f    pc =
> 0x40026512
> 06:08:16     INFO -      Found by: given as instruction pointer in context
> 06:08:16     INFO -   1  libc.so!__cxa_finalize [atexit.c : 158 + 0x5]
> 06:08:16     INFO -       r4 = 0x400a555c    r5 = 0x400d2000    r6 =
> 0x400d2060    r7 = 0x00000006
> 06:08:16     INFO -       r8 = 0x00001000    r9 = 0x00000000   r10 =
> 0x4005d0b8    fp = 0x0000000c
> 06:08:16     INFO -       sp = 0xbec568d8    pc = 0x40080c05
> 06:08:16     INFO -      Found by: call frame info
> 06:08:16     INFO -   2  libc.so!exit [exit.c : 57 + 0x7]
> 06:08:16     INFO -       r4 = 0x00000000    r5 = 0xbec56934    r6 =
> 0x00000009    r7 = 0xbec5695c
> 06:08:16     INFO -       r8 = 0x00000000    r9 = 0x00000000   r10 =
> 0x00000000    fp = 0x00000000
> 06:08:16     INFO -       sp = 0xbec56918    pc = 0x40080fa1
> 06:08:16     INFO -      Found by: call frame info
> }

Apparently, this is a fault alarm.  Since it is called in atexit.c; the finalizer of the process, it means the process is in closing.
Flags: needinfo?(tlee) → needinfo?(pwang)
Nuwa is not enabled by default in debug build. It looks like tests which run Nuwa do not tear down properly.
New try pushes:

https://tbpl.mozilla.org/?tree=Try&rev=ba6b2632ba27
to debug any gfx/layers/ipc issue

https://tbpl.mozilla.org/?tree=Try&rev=0182e780d658
to understand what is still in the Nuwa sAllThreadsList on exit.
All right, the latter try push tells us that there is a whole bunch of thread_infos left in this Nuwa global linked list at exit time:

07-01 17:47:05.180   831   831 I Gecko   : [Child 831] WARNING: Leaking the RDF Service.: file ../../../gecko/rdf/build/nsRDFModule.cpp, line 165
07-01 17:47:05.180   831   831 I Gecko   : [Child 831] WARNING: Fonts still alive while shutting down gfxFontCache: 'mFonts.Count() == 0', file ../../../gecko/gfx/thebes/gfxFont.cpp, line 1891
07-01 17:47:05.220   831   831 I Gecko   : [Child 831] ###!!! ASSERTION: Component Manager being held past XPCOM shutdown.: 'cnt == 0', file ../../../gecko/xpcom/build/nsXPComInit.cpp, line 959
07-01 17:47:05.220   831   831 I Gecko   : [Child 831] WARNING: '!compMgr', file /builds/slave/b2g_try_emu-d_dep-000000000000/build/gecko/xpcom/glue/nsComponentManagerUtils.cpp, line 62
07-01 17:47:05.274   831   831 I Gecko   : [Child 831] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 144
07-01 17:47:05.274   831   831 I Gecko   : [Child 831] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 144
07-01 17:47:05.280   831   831 I Gecko   : [Child 831] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 144
07-01 17:47:05.280   831   831 I Gecko   : [Child 831] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 144
07-01 17:47:05.280   831   831 I Gecko   : [Child 831] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 144
07-01 17:47:05.290   831   831 I Gecko   : [Child 831] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 144
07-01 17:47:05.290   831   831 I Gecko   : [Child 831] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 144
07-01 17:47:05.300   831   831 I Gecko   : [Child 831] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file ../../../gecko/xpcom/base/nsTraceRefcnt.cpp, line 144
07-01 17:47:05.330   831   831 W BJACOB  : Nuwa sAllThreads outstanding threads:
07-01 17:47:05.330   831   831 W BJACOB  : name=Chrome_ChildThr origNativeThreadID=822 recreatedNativeThreadID=832
07-01 17:47:05.330   831   831 W BJACOB  : name=Analysis Helper origNativeThreadID=823 recreatedNativeThreadID=833
07-01 17:47:05.330   831   831 W BJACOB  : name=Analysis Helper origNativeThreadID=824 recreatedNativeThreadID=835
07-01 17:47:05.330   831   831 W BJACOB  : name=Socket Thread origNativeThreadID=825 recreatedNativeThreadID=836
07-01 17:47:05.330   831   831 W BJACOB  : name=MemoryPressure origNativeThreadID=827 recreatedNativeThreadID=837
07-01 17:47:05.340   831   831 W BJACOB  : name=Timer origNativeThreadID=828 recreatedNativeThreadID=838
07-01 17:47:05.340   831   831 W BJACOB  : name=ImageBridgeChil origNativeThreadID=829 recreatedNativeThreadID=839
07-01 17:47:05.340   831   831 W BJACOB  : name=BufferMgrChild origNativeThreadID=830 recreatedNativeThreadID=840
07-01 17:47:05.340   831   831 W BJACOB  : total: 8 outstanding threads.
07-01 17:47:05.340   831   831 W BJACOB  : note: sThreadCount=8, sThreadFreezeCount=8
07-01 17:47:05.340   831   831 F MOZ_Assert: Assertion failure: isEmpty(), at ../../dist/include/mozilla/LinkedList.h:305
Attached patch Allow non-empty sAllThreads list on exit (obsolete) (deleted) — Splinter Review
Thinker, Patrick, does this patch sound reasonable? Note the code comment explaining what we are doing there. I think I would agree that ideally we should be able to shut down all threads before we hit global destructors. But as comment 395 shows, we are still far away from this point: 8 different threads, from very different parts of gecko, were remaining at this point, on that try run. As we need to fix this intermittent (near permanent) orange in short order, I was thinking that this patch would be an acceptable compromise?
Attachment #8448997 - Flags: review?(tlee)
Attachment #8448997 - Flags: review?(pwang)
This try push shows that this is an effective way of removing this intermittent failure:
https://tbpl.mozilla.org/?tree=Try&rev=bb54ab51331f
Comment on attachment 8448997 [details] [diff] [review]
Allow non-empty sAllThreads list on exit

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

Adding khuey for review based on hg log. We want this to land ASAP as it's near-perma-orange.
Attachment #8448997 - Flags: review?(khuey)
Comment on attachment 8448997 [details] [diff] [review]
Allow non-empty sAllThreads list on exit

r=me if you file bugs on all the threads that are still alive.
Attachment #8448997 - Flags: review?(khuey) → review+
Logging code is just big enough to require a review.
Attachment #8449634 - Flags: review?(khuey)
Filed bug 1033577 to track the effort toward re-enabling that assertion. Will file individual bugs for each thread, blocking bug 1033577.
Attachment #8448997 - Attachment is obsolete: true
Attachment #8448997 - Flags: review?(tlee)
Attachment #8448997 - Flags: review?(pwang)
Flags: needinfo?(pwang)
https://hg.mozilla.org/mozilla-central/rev/7cf9ff845a1e
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Please request Aurora approval on this patch when you get a chance.
Flags: needinfo?(bjacob)
Target Milestone: --- → 2.0 S5 (4july)
Comment on attachment 8449634 [details] [diff] [review]
Allow non-empty sAllThreads list on exit, and report it on logcat

Approval Request Comment
[Feature/regressing bug #]: don't know
[User impact if declined]: none for real users: only affects debug builds. There, it's a shutdown crash only. The big deal is for tree sherriffs, it's a very frequent orange.
[Describe test coverage new/current, TBPL]: This was discovered by test failures on tbpl, it's near perma orange without the patch, and solid green with the patch. Visible on b2g emulator debug mochitest-9.
[Risks and why]: Very low risk: Simple change, clearing a list before we destroy it.
[String/UUID change made/needed]: none
Attachment #8449634 - Flags: approval-mozilla-aurora?
Flags: needinfo?(bjacob)
Comment on attachment 8449634 [details] [diff] [review]
Allow non-empty sAllThreads list on exit, and report it on logcat

Fix a boring issue which makes sheriff sad. Approving!
Attachment #8449634 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: