In looking at performance opening new windows, I noticed a large amount of time being spent in SearchTable in jsdhash.c (3.5% of new window time when opening large numbers of windows). It's being called (through JS_DHashTableOperate) from js_AddRootRT and js_RemoveRoot, which are being called from AddRefing and Releasing XPCWrappedNative objects (which I hope we can do less, but that's another issue). These calls frequently add and remove the same object from the hashtable hundreds of times, which causes buildup of entries that are marked as removed. Each time the entry is added and removed from the hashtable, another entry marked as removed is added to the sequence of entries that must be traversed before finding a free position to add the entry or before finding the entry to remove it. In other words, the number of collisions needed to find the location for the entry increases by one each time the entry is added and removed, until the entire table gets reallocated. (I've seen this build up to as many as 260 collisions just opening a single new window.) The best solution I can think of for this is to reserve one bit of the JSDHashEntryHdr (i.e., the low or high bit of of keyHash) to mark whether an attempt to add an entry collided with the entry being marked. Then, when removing an entry, if the bit is not set, the entry can be marked free rather than removed. This would also reduce reallocations of the table.

D'oh -- gordon and I talked about this scenario, and how to solve it with a magic bit indicating that an entry has had no collisions. Then the removed entry could be recycled on add of the same key. Definite 0.9.2 work. /be

Is this a hot-button issue for 0.9.1? /be

When I tried that patch on my hyatt-branch opt build, I crashed on startup: #0 0x4070bb74 in WrappedNativeProtoMarker () from /builds/hyatt/obj/opt/dist/bin/components/libxpconnect.so #1 0x4012ff32 in JS_DHashTableEnumerate () from /builds/hyatt/obj/opt/dist/bin/libmozjs.so #2 0x4070bc25 in XPCWrappedNativeScope::MarkAllWrappedNativesAndProtos () from /builds/hyatt/obj/opt/dist/bin/components/libxpconnect.so #3 0x406fa6e7 in XPCJSRuntime::GCCallback () from /builds/hyatt/obj/opt/dist/bin/components/libxpconnect.so #4 0x40b0bc4c in DOMGCCallback () from /builds/hyatt/obj/opt/dist/bin/components/libjsdom.so #5 0x4013efcb in js_GC () from /builds/hyatt/obj/opt/dist/bin/libmozjs.so

dbaron mentioned this the other day; I'll get to it soon. /be

Please ask me anything. And test, test, test! /be

It would be good to get some testing with the new version in both js and xpcom/ds, although the current patch does work fine for me. I think you would probably get further improved performance if you added new entries on top of removed-entry sentinels by changing SearchTable from checking: if (JS_DHASH_ENTRY_IS_FREE(entry)) { to if (!JS_DHASH_ENTRY_IS_LIVE(entry)) { and then in the JS_DHASH_ADD case of JS_DHashTableOperate, preserving the collision flag when initializing the entry by, before calling initEntry, doing: if (entry->keyHash & COLLISION_FLAG) keyHash |= COLLISION_FLAG; Or is there some reason this wouldn't be safe, or would worsen performance?

I pointed out to dbaron on irc #mozilla how SearchTable must exhaustively search to the end of a double-hashed collision chain, for the given key. It can't stop at the first non-live (removed or free) entry. But it could remember the first removed entry on the chain, and return that, as dbaron proposes. Then the JS_DHashTableOperate JS_DHASH_ADD case could preserve COLLISION_FLAG from the entry returned when filling in keyHash. In the course of optimizing SearchTable in this way, I found a bug where the collision flag for newEntry (which -- see the code -- is of course independent of oldEntry->keyHash & COLLISION_FLAG) was not preserved when newEntry->keyHash was initialized. Patch coming up after some testing and metering. /be

Nearly done, I've had no time to instrument and do A-B tests, and this shouldn't hold up 0.9.4 (unless someone speaks quickly and convincingly). I'll land it as soon as 0.9.5 opens, after reporting results here. /be

Brendan Eich <brendan@meer.net> writes: >Can you re-profile after applying the latest patch in >http://bugzilla.mozilla.org/show_bug.cgi?id=81847 ? Thanks, On re-profile, JS_DHashTableOperate went from 20 with 3 direct hits to 4 with 1 direct hit. Thus the savings would be roughly 16/367 or 4.4% of the time to open 20 windows. Big win! Flat data before: Total hit count: 367 Count %Total Function Name 17 4.6 SearchTable 16 4.4 js_Mark 7 1.9 chunk_alloc 6 1.6 js_MarkGCThing ... 3 0.8 JS_DHashTableOperate Flat data after: Total hit count: 358 Count %Total Function Name 11 3.1 js_MarkGCThing 11 3.1 js_Mark 10 2.8 __pthread_alt_unlock 8 2.2 pthread_mutex_trylock 7 2.0 chunk_alloc 7 2.0 js_MarkScript 6 1.7 __libc_malloc 6 1.7 nsCOMPtr_base::~nsCOMPtr_base(void) 5 1.4 GetChar

I need some time to turn on metering and do that A-B test, but this patch looks better and better for 0.9.4, once it shakes out on the trunk. Cc'ing asa and asking dbaron for their drivers@mozilla.org opinions. /be

Upping severity, targeting at 0.9.4. /be

Comment on attachment 48181 [details] [diff] [review] same semantics as last patch, but better control flow in SearchTable (clearer and more efficient, assuming hits are more common that collisions) r=dbaron

I've been running with the new patch for a few hours (on a pre-branch build), and I've crashed two or three times. I don't think that's a good sign.

crashed where? Patch to blame how? Say more, words and backtraces and stuff good (grunt!). /be

I ran with the patch a fair bit (looking at jprofs) without problems before the branch. We the crashed related by stack backtrace to this? I'll throw this into my main build for more testing.

#3 <signal handler called> #4 0x4006fad4 in SearchTable (table=0x81b4868, key=0x43a64020, keyHash=1113587744, op=JS_DHASH_ADD) at /builds/seamonkey/mozilla/js/src/jsdhash.c:278 #5 0x4006fd67 in ChangeTable (table=0x81b4868, deltaLog2=1) at /builds/seamonkey/mozilla/js/src/jsdhash.c:375 #6 0x4006fef5 in JS_DHashTableOperate (table=0x81b4868, key=0x436f5a18, op=JS_DHASH_ADD) at /builds/seamonkey/mozilla/js/src/jsdhash.c:430 #7 0x40e5c30c in XPCWrappedNativeProtoMap::Add(XPCWrappedNativeProto*) ( this=0x81ab288, proto=0x436f5a18) at /builds/seamonkey/mozilla/js/src/xpconnect/src/xpcmaps.h:621 #8 0x40e49edf in WNProtoRemover(JSDHashTable*, JSDHashEntryHdr*, unsigned, void*) (table=0x436d9960, hdr=0x43cdef68, number=0, arg=0x81ab288) at /builds/seamonkey/mozilla/js/src/xpconnect/src/xpcwrappednativescope.cpp:620 #9 0x40070112 in JS_DHashTableEnumerate (table=0x436d9960, etor=0x40e49eb0 <WNProtoRemover(JSDHashTable*, JSDHashEntryHdr*, unsigned, void*)>, arg=0x81ab288) at /builds/seamonkey/mozilla/js/src/jsdhash.c:516 #10 0x40e5c725 in ClassInfo2WrappedNativeProtoMap::Enumerate(JSDHashOperator (*) (JSDHashTable*, JSDHashEntryHdr*, unsigned, void*), void*) (this=0x436d9950, f=0x40e49eb0 <WNProtoRemover(JSDHashTable*, JSDHashEntryHdr*, unsigned, void*)>, arg=0x81ab288) at /builds/seamonkey/mozilla/js/src/xpconnect/src/xpcmaps.h:429 #11 0x40e49f4c in XPCWrappedNativeScope::RemoveWrappedNativeProtos() ( this=0x436d9900) at /builds/seamonkey/mozilla/js/src/xpconnect/src/xpcwrappednativescope.cpp:630 #12 0x40e0ff8e in nsXPConnect::InitClasses(JSContext*, JSObject*) ( this=0x40e5c9a4, aJSContext=0x436d9630, aGlobalJSObj=0x43679218) at /builds/seamonkey/mozilla/js/src/xpconnect/src/nsXPConnect.cpp:373 ... (gdb) frame 4 #4 0x4006fad4 in SearchTable (table=0x81b4868, key=0x43a64020, keyHash=1113587744, op=JS_DHASH_ADD) at /builds/seamonkey/mozilla/js/src/jsdhash.c:278 278 if (JS_DHASH_ENTRY_IS_FREE(entry)) { (gdb) p entry $1 = (JSDHashEntryHdr *) 0x56a9ac60 (gdb) p *entry Cannot access memory at address 0x56a9ac60 (gdb) p *table $2 = {ops = 0x400e90a0, data = 0x0, hashShift = 0, sizeLog2 = 32, entrySize = 8, entryCount = 4294967293, removedCount = 0, generation = 3, entryStore = 0x43a9ab60 ""} (gdb) p *(table->ops) $4 = {allocTable = 0x4006f660 <JS_DHashAllocTable>, freeTable = 0x4006f690 <JS_DHashFreeTable>, getKey = 0x4006f720 <JS_DHashGetKeyStub>, hashKey = 0x4006f740 <JS_DHashVoidPtrKeyStub>, matchEntry = 0x4006f750 <JS_DHashMatchEntryStub>, moveEntry = 0x4006f780 <JS_DHashMoveEntryStub>, clearEntry = 0x4006f7b0 <JS_DHashClearEntryStub>, finalize = 0x4006f7e0 <JS_DHashFinalizeStub>, initEntry = 0} (gdb) p hash1 $5 = 1113587744 (gdb) p keyHash $6 = 1113587744 (gdb) frame 5 #5 0x4006fd67 in ChangeTable (table=0x81b4868, deltaLog2=1) at /builds/seamonkey/mozilla/js/src/jsdhash.c:375 375 newEntry = SearchTable(table, getKey(table, oldEntry), (gdb) p oldLog2 $7 = 31 (gdb) p newLog2 $8 = 32 (gdb) p newCapacity $9 = 1 (gdb) p oldCapacity $10 = 2147483648 (gdb) frame 6 #6 0x4006fef5 in JS_DHashTableOperate (table=0x81b4868, key=0x436f5a18, op=JS_DHASH_ADD) at /builds/seamonkey/mozilla/js/src/jsdhash.c:430 430 table->entryCount + table->removedCount == size - 1) { (gdb) p table->entryCount $11 = 4294967293 (gdb) p table->removedCount $12 = 0

4294967293 == -3

I suspect this would be fixed either by making the JS_DHASH_REMOVE case of JS_DHashtableOperate should check JS_DHASH_ENTRY_IS_LIVE rather than JS_DHASH_ENTRY_IS_BUSY or by making SearchTable only return |firstRemoved| if |op == JS_DHASH_ADD|.

I'm going to run a bit with the change in SearchTable. (I think it's better to change it there because it affects which type of entry is returned by a failed JS_DHASH_LOOKUP.) That is, I changed: return firstRemoved ? firstRemoved : entry; to return (firstRemoved && op == JS_DHASH_ADD) ? firstRemoved : entry; (It might not be a bad idea to make the change in the JS_DHASH_REMOVE case as well, though.)

Comment on attachment 48181 [details] [diff] [review] same semantics as last patch, but better control flow in SearchTable (clearer and more efficient, assuming hits are more common that collisions) Bad bad icky bad.

Here come some patches to instrument jsdhash.c and pldhash.c, and dump stacks and stats at {JS,PL}_DHashTableFinish time. I've also (based on early results from this instrumentation) fixed a glaring cycle-sink in js_LookupProperty: the cx->resolving JSDHashTable was being destroyed as soon as the outermost resolve attempt unwound. Now it lives till the context is destroyed. This sames ~26000 JSDHashTable instances. /be

Cc'ing waterson. With this awk script: /^Double hashing statistics:$/ { instats = 1; } /^ adds that made a new entry: 0/ { waste[stack[1]]++; } /^[^ ]*/ { if (!instats) stack[i++] = $0; } /^$/ { instats = 0; delete stack; i = 0; } END { for (frame in waste) { print(waste[frame], frame); } } applied to the "with the firstRemoved optimization in SearchTable" attachments above, I get these culprits of never-added-to {JS,PL}DHashTables: 1 ClassInfo2WrappedNativeProtoMap::~ClassInfo2WrappedNativeProtoMap(void)[/home/brendan/src/trunk/mozilla/dist/bin/components/libxpconnect.so +0x5D0F8] 75 nsRuleNetwork::Finish(void)[/home/brendan/src/trunk/mozilla/dist/bin/components/libgkcontent.so +0x3E57C2] 68 nsContentSupportMap::Finish(void)[/home/brendan/src/trunk/mozilla/dist/bin/components/libgkcontent.so +0x3DCB73] 32 nsTemplateMap::Finish(void)[/home/brendan/src/trunk/mozilla/dist/bin/components/libgkcontent.so +0x58FACB] Sorry I blamed XPConnect in my last comment, although the population of its JSDHashTables may be too low to justify hashing (haven't tweaked the awk script to say more -- someone humiliate me by writing a does-it-all perl script, please!). It looks like the empty PLDHashTables in content-land are more numerous by far. /be

Urgh, that was not the awk script I meant. Here it is: /^Double hashing statistics:$/ { instats = 1; } /^ adds that made a new entry: 0/ { if (match(stack[0], /DHashTableDestroy/)) { waste[stack[1]]++; } else { waste[stack[0]]++; } } /^[^ ]*/ { if (!instats) stack[i++] = $0; } /^$/ { instats = 0; delete stack; i = 0; } END { for (frame in waste) { print(waste[frame], frame); } } /be

> Sorry I blamed XPConnect in my last comment Huh? I missed that. The count of items that might go in to various xpconnect hashtables is highly variable. > ClassInfo2WrappedNativeProtoMap... XPConnect makes one of these per global object. It does not know ahead of time if there are going to be many different classes of objects in use or not. In the current world that depends mostly on the level of DOM activity in the page. I still anticipate more objects with nsIClassInfo in the future. Also, jst might not mention it, but he was looking at the time spent rooting and unrooting objects as a side effect of the caps code needing to repeatedly get at the wrapped native of JSObjects. I pointed him at this bug. He saw a significant improvement in the Quantify numbers due to the decreased malloc/free counts with today's recent patch in place.

Looking for review and super-review on the latest patch (http://bugzilla.mozilla.org/attachment.cgi?id=48527&action=view, edit your comments and checkmarks with the patch manager, use the diff -wu if you prefer it: http://bugzilla.mozilla.org/attachment.cgi?id=48528&action=edit). /be

We used to assign, now we do a logical-or? Eh? - newEntry->keyHash = oldEntry->keyHash; + newEntry->keyHash = + oldEntry->keyHash | (newEntry->keyHash & COLLISION_FLAG); Might be worth assert()-ing that |keyHash & COLLISION_FLAG == 0| upon entry into SearchTable(). The rest looks okay to me. r/sr=waterson

Comment on attachment 48528 [details] [diff] [review] diff -wu version of last patch r=dbaron on everything except the cx->resolving bits (jscntxt.c, jsobj.c), which I'd rather have someone who knows what it is review. Also, you have a bit of merging in nsTraceMalloc.c to do before you check in. :-)

waterson: SearchTable does not set keyHash to claim the entry, so ChangeTable must do so. But it failed to preserve the new entry's collision flag. Note well that the old entry's collision flag is cleared to avoid confusion. I didn't assert as you suggest because my tiny brain thought this file was small enough to keep that invariant obvious, but look what happened. Adding, patch coming up. /be

r/sr=jst for the jscntxt.c and jsobj.c changes.

Comment on attachment 49009 [details] [diff] [review] final patch, for the record Urgh, nsTraceMalloc.c's TM_ENTER_MONITOR and TM_EXIT_MONITOR are not quite right. /be

Comment on attachment 49010 [details] [diff] [review] final patch, dbaron please re-review nsTraceMalloc.c r=dbaron on the merged nsTraceMalloc.c changes (although there was one place where you didn't change |#if XP_UNIX| to |#ifdef XP_UNIX|)

Checked into trunk. Leaving open in case this is wanted on the 0.9.4 branch. /be

"Nice move, Fokker!" - _Meet The Parents_ Seems I've regressed something horribly, as bug 99442 attests. More in a bit. /be

Cc'ing cathleen and dp. The attachment 49308 [details] [diff] [review] contains all the fixes for this bug and for bug 99442, joined to the MOZILLA_0_9_4_BRANCH. If you guys can get the PDT to approve this patch for checkin, I'll gladly do the deed. You might want to wait a few days for the trunk version of these changes to prove good -- I'm pretty sure it will, after today's fiasco led to well-reviewed and doubly tested fixes. /be

In lay terms, how much perf improvement on new window will this provide ?

dp, see rjesup's before/after jprof hit counts and timing estimates in the comment dated 2001-09-04 08:49. /be

I very interested in getting this on the branch. Would one of you come to the pit at noon tomorrow to discuss? Marking nsbranch+ to get on the radar.

Pls update status of patch with "has-super-review". 5% gain is good, check it into the branch - PDT+.

Fix is on the MOZILLA_0_9_4_BRANCH. /be

Marking Verified -