934442 - GenerationalGC: mochitest test_cpows.xul assertion failure

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

[Jon Coppeard (:jonco) (PTO until 5th Jan)]

In GGC browser builds on linux.

Full log: https://tbpl.mozilla.org/php/getParsedLog.php?id=29983709&tree=Try&full=1#error2

10:36:32     INFO -  Assertion failure: table, at ../../dist/include/js/HashTable.h:1081
10:36:34     INFO -  1210 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/content/base/test/chrome/test_document_register.xul | This test left crash dumps behind, but we weren't expecting it to!

11:11:57  WARNING -  PROCESS-CRASH | Main app process exited normally | application crashed [@ js::detail::HashTable<js::HashMapEntry<JSObject*, unsigned long long>, js::HashMap<JSObject*, unsigned long long, js::PointerHasher<JSObject*, 3u>, js::SystemAllocPolicy>::MapHashPolicy, js::SystemAllocPolicy>::lookup(JSObject* const&, unsigned int, unsigned int) const]
11:11:57     INFO -  Crash dump filename: /tmp/tmpFd11LR/minidumps/6e236769-f4df-c8a5-2b8fe032-1797e033.dmp
11:11:57     INFO -  Operating system: Linux
11:11:57     INFO -                    0.0.0 Linux 3.2.0-23-generic-pae #36-Ubuntu SMP Tue Apr 10 22:19:09 UTC 2012 i686
11:11:57     INFO -  CPU: x86
11:11:57     INFO -       GenuineIntel family 6 model 45 stepping 7
11:11:57     INFO -       1 CPU
11:11:57     INFO -  Crash reason:  SIGSEGV
11:11:57     INFO -  Crash address: 0x0
11:11:57     INFO -  Thread 0 (crashed)
11:11:57     INFO -   0  libxul.so!js::detail::HashTable<js::HashMapEntry<JSObject*, unsigned long long>, js::HashMap<JSObject*, unsigned long long, js::PointerHasher<JSObject*, 3u>, js::SystemAllocPolicy>::MapHashPolicy, js::SystemAllocPolicy>::lookup(JSObject* const&, unsigned int, unsigned int) const [HashTable.h:64651a1a79ca : 1079 + 0x19]
11:11:57     INFO -      eip = 0xb4542236   esp = 0xbf9205a0   ebp = 0xbf9205d8   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x096f1080   edi = 0xbf92063c   eax = 0x00000000   ecx = 0xb30b98ac
11:11:57     INFO -      edx = 0x00000000   efl = 0x00210286
11:11:57     INFO -      Found by: given as instruction pointer in context
11:11:57     INFO -   1  libxul.so!js::detail::HashTable<js::HashMapEntry<JSObject*, unsigned long long>, js::HashMap<JSObject*, unsigned long long, js::PointerHasher<JSObject*, 3u>, js::SystemAllocPolicy>::MapHashPolicy, js::SystemAllocPolicy>::lookup(JSObject* const&) const [HashTable.h:64651a1a79ca : 1395 + 0x9]
11:11:57     INFO -      eip = 0xb45423ca   esp = 0xbf9205e0   ebp = 0xbf920608   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0xbf9205f8   edi = 0xbf92063c
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -   2  libxul.so!mozilla::jsipc::ObjectIdCache::keyMarkCallback(JSTracer*, void*, void*) [HashTable.h:64651a1a79ca : 92 + 0xe]
11:11:57     INFO -      eip = 0xb45439d1   esp = 0xbf920610   ebp = 0xbf920658   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x096f1080   edi = 0xbf920638
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -   3  libxul.so!js::gc::StoreBuffer::CallbackRef::mark(JSTracer*) [StoreBuffer.h:64651a1a79ca : 340 + 0x16]
11:11:57     INFO -      eip = 0xb510d8d0   esp = 0xbf920660   ebp = 0xbf920678   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x096d18a8   edi = 0x096d1248
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -   4  libxul.so!js::gc::StoreBuffer::GenericBuffer::mark(JSTracer*) [StoreBuffer.cpp:64651a1a79ca : 184 + 0x10]
11:11:57     INFO -      eip = 0xb50905f8   esp = 0xbf920680   ebp = 0xbf9206b8   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x096d18a8   edi = 0x096d1248
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -   5  libxul.so!js::Nursery::collect(JSRuntime*, JS::gcreason::Reason) [Nursery.cpp:64651a1a79ca : 597 + 0x4]
11:11:57     INFO -      eip = 0xb55fad2c   esp = 0xbf9206c0   ebp = 0xbf920758   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0xbf9206fc   edi = 0x09500d58
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -   6  libxul.so!js::MinorGC(JSRuntime*, JS::gcreason::Reason) [jsgc.cpp:64651a1a79ca : 4799 + 0x18]
11:11:57     INFO -      eip = 0xb51251eb   esp = 0xbf920760   ebp = 0xbf920788   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x09501810   edi = 0xbf920778
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -   7  libxul.so!Collect [jsgc.cpp:64651a1a79ca : 4651 + 0xb]
11:11:57     INFO -      eip = 0xb513eddf   esp = 0xbf920790   ebp = 0xbf920848   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x09414fb0   edi = 0x09500d58
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -   8  libxul.so!js::GC(JSRuntime*, js::JSGCInvocationKind, JS::gcreason::Reason) [jsgc.cpp:64651a1a79ca : 4723 + 0x22]
11:11:57     INFO -      eip = 0xb513f4db   esp = 0xbf920850   ebp = 0xbf920868   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x09414fb0   edi = 0x00000033
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -   9  libxul.so!JS::GCForReason(JSRuntime*, JS::gcreason::Reason) [jsfriendapi.cpp:64651a1a79ca : 192 + 0x17]
11:11:57     INFO -      eip = 0xb510f27e   esp = 0xbf920870   ebp = 0xbf920888   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x09414fb0   edi = 0x00000033
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -  10  libxul.so!mozilla::CycleCollectedJSRuntime::Collect(unsigned int) const [CycleCollectedJSRuntime.cpp:64651a1a79ca : 942 + 0xa]
11:11:57     INFO -      eip = 0xb4a2ca81   esp = 0xbf920890   ebp = 0xbf9208b8   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x09414fb0   edi = 0x00000033
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -  11  libxul.so!nsCycleCollector::BeginCollection(ccType, nsICycleCollectorListener*) [nsCycleCollector.cpp:64651a1a79ca : 2755 + 0xf]
11:11:57     INFO -      eip = 0xb4a3499f   esp = 0xbf9208c0   ebp = 0xbf920978   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x093f9cf0   edi = 0x00000000
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -  12  libxul.so!nsCycleCollector::Collect(ccType, nsTArray<PtrInfo*>*, nsCycleCollectorResults*, nsICycleCollectorListener*) [nsCycleCollector.cpp:64651a1a79ca : 2687 + 0xe]
11:11:57     INFO -      eip = 0xb4a34af0   esp = 0xbf920980   ebp = 0xbf9209a8   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x093f9cf0   edi = 0xb5c0d190
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -  13  libxul.so!nsCycleCollector::ShutdownCollect() [nsCycleCollector.cpp:64651a1a79ca : 2667 + 0x17]
11:11:57     INFO -      eip = 0xb4a34c7c   esp = 0xbf9209b0   ebp = 0xbf924878   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x00000000   edi = 0xb5c0d190
11:11:57     INFO -      Found by: call frame info
11:11:57     INFO -  14  libxul.so!nsCycleCollector_shutdown() [nsCycleCollector.cpp:64651a1a79ca : 3170 + 0x7]
11:11:57     INFO -      eip = 0xb4a34d45   esp = 0xbf924880   ebp = 0xbf9248b8   ebx = 0xb719d8e8
11:11:57     INFO -      esi = 0x093fdd58   edi = 0xbf9248dc
11:11:57     INFO -      Found by: call frame info

Comment 1

[Jon Coppeard (:jonco) (PTO until 5th Jan)]

Looks like this is actually a problem in test_cpows.xul, and it's the child processes dying.

Comment 2

[Jon Coppeard (:jonco) (PTO until 5th Jan)]

The child process is crashing because post-barriers are accessing an ObjectIdCache that has already been freed.

A simple fix for this would be to trigger a minor GC in the destructor, but I'm not sure we were planning on exposing this functionality.  An alternative might be to offer some way to remove callback postbarriers, the same as as we do for relocatable values, but this would complicate the store buffer.

The ObjectIdCache is part of a JavaScriptChild which should be gettiing freed from ContentChild::DeallocPJavaScriptChild(), but I can't see where that is ever called.

Comment 3

[Jon Coppeard (:jonco) (PTO until 5th Jan)]

Yet another possibility would be to add a callback that fires when a minor GC has taken place, and delay freeing the memory until that happens.  None of these seem like particularly great options.

Terrence do you have an opinion on which way to go?

Comment 4

[Terrence Cole [:terrence]]

No, I really don't have a great feel for what the best api is. Here are my thoughts so far.

* Triggering a minor GC would be easy for both sides to implement, but is gross and will probably bite us with horrible performance. Lets not do this.

* Making generic buffer entries removable would be really annoying for us and the generic buffer is already quite slow as is. I'd prefer not to do this.

* A callback to free would be easy for us to implement and is similar to how the major GC works; however, it would require a sizable amount of work on the other side. I don't like this, but it is the best that has been suggested. 

* Another option would be to add a layer of indirection. Perhaps the generic buffer entry could track what tracks this cache and only mark if it is still live? I guess it is the JavaScriptChild itself which is dead already? If so, JavaScriptChild::makeId is still probably too low. How far up would we need to go?

Comment 5

[Jon Coppeard (:jonco) (PTO until 5th Jan)]

Attachment: bug934442-cpows-crash

It turns out there is already a way to queue an object for finalization that happens at the end of the next GC.  The simplest fix for this is probably to use that to free the hashtable then, since we're guaranteed to have done a minor GC by then.

Comment 6

[Terrence Cole [:terrence]]

Comment on attachment 830947 [details] [diff] [review]
bug934442-cpows-crash

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

Neat! r=me

Comment 7

[Jon Coppeard (:jonco) (PTO until 5th Jan)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/3f40322844ed

Comment 8

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/3f40322844ed