Closed Bug 549533 Opened 15 years ago Closed 13 years ago

improve cycle collector performance

Categories

(Core :: XPCOM, defect)

Product:
Core
Component:
XPCOM
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED

People

(Reporter: gal, Unassigned)

References

Details

No description provided.
In a browser with a single gmail window open I see a cycle collection every 5 seconds or so. It usually takes about 60ms (this is a 2GHz x86 laptop, fennec devices must get completely hammered by this). js_IsAboutToBeFinalized seems to be an obvious **** we should fix right away. # Report 1 - Session 6 - Time Profile of Everything <CycleCollection> SharkProfileViewer # Generated from the visible portion of the outline view - 12.8%, js_GC, libmozjs.dylib - 7.6%, js_SweepScopeProperties, libmozjs.dylib - 6.3%, js_IsAboutToBeFinalized, libmozjs.dylib - 5.8%, PL_DHashTableOperate, XUL - 5.4%, JS_DHashTableEnumerate, libmozjs.dylib - 4.2%, js_CallGCMarker, libmozjs.dylib - 4.2%, WrappedNativeMarker(JSDHashTable*, JSDHashEntryHdr*, unsigned int, void*), XUL - 3.3%, nsXPConnect::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 2.8%, nsDeque::Push(void*), XUL - 2.8%, GraphWalker<ScanBlackVisitor>::DoWalk(nsDeque&), XUL - 2.8%, WrappedNativeSuspecter(JSDHashTable*, JSDHashEntryHdr*, unsigned int, void*), XUL - 2.6%, GCGraphBuilder::NoteXPCOMChild(nsISupports*), XUL - 2.6%, js_TraceObject, libmozjs.dylib - 2.0%, GCGraphBuilder::NoteScriptChild(unsigned int, void*), XUL - 1.8%, JSFreePointerListTask::run(), libmozjs.dylib - 1.5%, nsDeque::PopFront(), XUL - 1.5%, PL_DHashTableFinish, XUL - 1.3%, js_atom_sweeper(JSDHashTable*, JSDHashEntryHdr*, unsigned int, void*), libmozjs.dylib - 1.3%, WrappedNativeJSGCThingTracer(JSDHashTable*, JSDHashEntryHdr*, unsigned int, void*), XUL - 1.1%, nsGenericElement::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 1.1%, JS_TraceChildren, libmozjs.dylib - 1.1%, js_TraceScript, libmozjs.dylib - 1.0%, JSScopeProperty::trace(JSTracer*), libmozjs.dylib - 1.0%, WrappedNativeTearoffSweeper(JSDHashTable*, JSDHashEntryHdr*, unsigned int, void*), XUL - 0.9%, PL_DHashTableInit, XUL + 0.8%, PtrToNodeMatchEntry(PLDHashTable*, PLDHashEntryHdr const*, void const*), XUL | + 0.8%, PL_DHashTableOperate, XUL | | + 0.4%, GCGraphBuilder::NoteScriptChild(unsigned int, void*), XUL | | | + 0.2%, js_CallGCMarker, libmozjs.dylib | | | | + 0.2%, js_TraceObject, libmozjs.dylib | | | | | + 0.2%, nsXPConnect::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL | | | | | | + 0.2%, nsCycleCollector::BeginCollection(), XUL | | | | | | | + 0.2%, XPCCycleCollectGCCallback(JSContext*, JSGCStatus), XUL | | | | | | | | + 0.2%, js_GC, libmozjs.dylib | | | | | | | | | + 0.2%, nsXPConnect::Collect(), XUL | | | | | | | | | | + 0.2%, nsCycleCollector::Collect(unsigned int), XUL | | | | | | | | | | | + 0.2%, nsJSContext::MaybeCC(int), XUL | | | | | | | | | | | | + 0.2%, nsXMLHttpRequest::RequestCompleted(), XUL | | | | | | | | | | | | | + 0.2%, nsXMLHttpRequest::OnStopRequest(nsIRequest*, nsISupports*, unsigned int), XUL | | | | | | | | | | | | | | + 0.2%, nsHttpChannel::OnStopRequest(nsIRequest*, nsISupports*, unsigned int), XUL | | | | | | | | | | | | | | | + 0.2%, nsInputStreamPump::OnStateStop(), XUL | | | | | | | | | | | | | | | | + 0.2%, nsInputStreamPump::OnInputStreamReady(nsIAsyncInputStream*), XUL | | | | | | | | | | | | | | | | | + 0.2%, nsInputStreamReadyEvent::Run(), XUL | | | | | | | | | | | | | | | | | | + 0.2%, nsThread::ProcessNextEvent(int, int*), XUL | | | | | | | | | | | | | | | | | | | + 0.2%, NS_ProcessPendingEvents_P(nsIThread*, unsigned int), XUL | | | | | | | | | | | | | | | | | | | | + 0.2%, nsBaseAppShell::NativeEventCallback(), XUL | | | | | | | | | | | | | | | | | | | | | + 0.2%, nsAppShell::ProcessGeckoEvents(void*), XUL | | | | | | | | | | | | | | | | | | | | | | + 0.2%, nsAppShell::Run(), XUL | | | | | | | | | | | | | | | | | | | | | | | + 0.2%, nsAppStartup::Run(), XUL | | | | | | | | | | | | | | | | | | | | | | | | + 0.2%, XRE_main, XUL | | | | | | | | | | | | | | | | | | | | | | | | | 0.2%, main, firefox-bin | | | - 0.2%, nsGenericElement::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL | | - 0.3%, GCGraphBuilder::NoteXPCOMChild(nsISupports*), XUL | | - 0.1%, nsPurpleBuffer::SelectPointers(GCGraphBuilder&), XUL - 0.8%, NS_TableDrivenQI(void*, QITableEntry const*, nsID const&, void**), XUL - 0.8%, js_GetGCThingTraceKind, libmozjs.dylib - 0.8%, PR_Lock, libnspr4.dylib - 0.7%, nsJSEventListener::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 0.6%, nsCycleCollector::BeginCollection(), XUL - 0.6%, GCGraphBuilder::NoteXPCOMRoot(nsISupports*), XUL - 0.5%, NS_CycleCollectorSuspect2_P, XUL - 0.5%, nsGenericElement::AddRef(), XUL - 0.5%, fun_trace(JSTracer*, JSObject*), libmozjs.dylib - 0.5%, nsJSEventListener::cycleCollection::Trace(void*, void (*)(unsigned int, void*, void*), void*), XUL - 0.5%, nsDeque::~nsDeque(), XUL - 0.5%, WrappedNativeProtoMarker(JSDHashTable*, JSDHashEntryHdr*, unsigned int, void*), XUL - 0.5%, NoteJSChild(JSTracer*, void*, unsigned int), XUL - 0.5%, GraphWalker<scanVisitor>::DoWalk(nsDeque&), XUL - 0.4%, PL_DHashTableEnumerate, XUL - 0.4%, nsPurpleBuffer::SelectPointers(GCGraphBuilder&), XUL - 0.4%, nsXBLProtoImpl::Trace(void (*)(unsigned int, void*, void*), void*) const, XUL - 0.4%, NativeInterfaceGC(JSDHashTable*, JSDHashEntryHdr*, unsigned int, void*), XUL - 0.3%, nsAttrAndChildArray::AttrCount() const, XUL - 0.3%, nsXULPrototypeNode::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 0.3%, PL_DHashVoidPtrKeyStub, XUL - 0.3%, nsGenericElement::cycleCollection::Trace(void*, void (*)(unsigned int, void*, void*), void*), XUL - 0.3%, nsDeque::GrowCapacity(), XUL - 0.3%, XPCWrappedNative::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 0.3%, JS_CallTracer, libmozjs.dylib - 0.3%, XPCWrappedNativeScope::MarkAllWrappedNativesAndProtos(), XUL - 0.3%, PL_DHashClearEntryStub, XUL - 0.2%, JS_DHashTableOperate, libmozjs.dylib - 0.2%, js_script_filename_sweeper(JSHashEntry*, int, void*), libmozjs.dylib - 0.2%, nsDocument::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 0.2%, nsGenericElement::Release(), XUL - 0.2%, nsGenericDOMDataNode::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 0.2%, GCGraphBuilder::NoteNativeChild(void*, nsCycleCollectionParticipant*), XUL - 0.2%, nsXBLInsertionPoint::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 0.2%, PR_EnterMonitor, libnspr4.dylib - 0.2%, nsJSContext::QueryInterface(nsID const&, void**), XUL - 0.2%, nsNodeInfo::AddRef(), XUL - 0.2%, nsNodeInfo::QueryInterface(nsID const&, void**), XUL - 0.2%, XPCJSRuntime::TraceXPConnectRoots(JSTracer*, int), XUL - 0.2%, xpc_TraceForValidWrapper(JSTracer*, XPCWrappedNative*), XUL - 0.2%, XPCWrappedNative::GetWrappedNativeOfJSObject(JSContext*, JSObject*, JSObject*, JSObject**, XPCWrappedNativeTearOff**), XUL - 0.2%, nsCycleCollector::RootWhite(), XUL - 0.2%, PR_Unlock, libnspr4.dylib - 0.2%, nsXPCWrappedJS::AddRef(), XUL - 0.1%, nsScriptObjectTracer::TraverseScriptObjects(void*, nsCycleCollectionTraversalCallback&), XUL - 0.1%, nsXBLProtoImplProperty::Trace(void (*)(unsigned int, void*, void*), void*) const, XUL - 0.1%, XPCWrappedNative::TraceOtherWrapper(JSTracer*), XUL - 0.1%, nsCycleCollector_finishCollection(), XUL - 0.1%, _PR_UNIX_GetInterval, libnspr4.dylib - 0.1%, NativeInterfaceSweeper(JSDHashTable*, JSDHashEntryHdr*, unsigned int, void*), XUL - 0.1%, nsBaseCommandController::QueryInterface(nsID const&, void**), XUL - 0.1%, nsSmallVoidArray::Count() const, XUL - 0.1%, array_trace(JSTracer*, JSObject*), libmozjs.dylib - 0.1%, InMemoryDataSource::Internal::Release(), XUL - 0.1%, nsXBLPrototypeBinding::Traverse(nsCycleCollectionTraversalCallback&) const, XUL - 0.1%, nsBindingManager::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 0.1%, nsXBLDocumentInfo::AddRef(), XUL - 0.1%, nsTHashtable<nsBaseHashtableET<nsISupportsHashKey, nsRefPtr<nsXBLBinding> > >::s_HashKey(PLDHashTable*, void const*), XUL - 0.1%, nsEventListenerManager::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 0.1%, js_FinishTitle, libmozjs.dylib - 0.1%, JS_IsAboutToBeFinalized, libmozjs.dylib - 0.1%, XPCVariant::Release(), XUL - 0.1%, nsGlobalChromeWindow::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 0.1%, nsXBLProtoImplMethod::Trace(void (*)(unsigned int, void*, void*), void*) const, XUL - 0.1%, nsCOMPtr_base::begin_assignment(), XUL - 0.1%, nsXMLElement::QueryInterface(nsID const&, void**), XUL - 0.1%, nsXPathEvaluator::AggregatedQueryInterface(nsID const&, void**), XUL - 0.1%, nsDocument::cycleCollection::Trace(void*, void (*)(unsigned int, void*, void*), void*), XUL - 0.1%, nsHashtable::Enumerate(int (*)(nsHashKey*, void*, void*), void*), XUL - 0.1%, JSScope::destroy(JSContext*), libmozjs.dylib - 0.1%, nsGenericDOMDataNode::AddRef(), XUL - 0.1%, nsXULPrototypeNode::cycleCollection::Trace(void*, void (*)(unsigned int, void*, void*), void*), XUL - 0.1%, WrappedJSDyingJSObjectFinder(JSDHashTable*, JSDHashEntryHdr*, unsigned int, void*), XUL - 0.1%, TraceJSObject(unsigned int, void*, void*), XUL - 0.1%, nsJSContext::Release(), XUL - 0.1%, XPCWrappedNativeScope::SuspectAllWrappers(XPCJSRuntime*, JSContext*, nsCycleCollectionTraversalCallback&), XUL - 0.1%, nsXPCWrappedJS::cycleCollection::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 0.1%, XPCJSRuntime::GCCallback(JSContext*, JSGCStatus), XUL - 0.1%, nsCycleCollector::ScanRoots(), XUL - 0.1%, XPCWrappedNative::Release(), XUL - 0.1%, nsXPCWrappedJS::TraceJS(JSTracer*), XUL - 0.1%, NoteJSHolder(JSDHashTable*, JSDHashEntryHdr*, unsigned int, void*), XUL - 0.1%, nsXBLDocumentInfo::cycleCollection::Trace(void*, void (*)(unsigned int, void*, void*), void*), XUL - 0.1%, XPCTraceableVariant::TraceJS(JSTracer*), XUL - 0.1%, JSContextParticipant::Traverse(void*, nsCycleCollectionTraversalCallback&), XUL - 0.1%, GCGraphBuilder::NoteRoot(unsigned int, void*, nsCycleCollectionParticipant*), XUL - 0.1%, XPCWrappedNativeScope::TraceJS(JSTracer*, XPCJSRuntime*), XUL - 0.1%, nsXPCWrappedJS::QueryInterface(nsID const&, void**), XUL - 0.1%, nsXPConnect::GetRuntimeInstance(), XUL
gmail open, idle: #0 nsCycleCollector::BeginCollection (this=0x103859e00) at ../../../xpcom/base/nsCycleCollector.cpp:2581 #1 0x00000001000216e9 in XPCCycleCollectGCCallback (cx=0x103267a00, status=JSGC_MARK_END) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:392 #2 0x000000010242bc12 in js_GC (cx=<value temporarily unavailable, due to optimizations>, gckind=GC_NORMAL) at ../../../js/src/jsgc.cpp:3169 #3 0x000000010001e886 in nsXPConnect::Collect (this=0x102c11e50) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:479 #4 0x0000000100b7cfb4 in nsCycleCollector::Collect (this=0x103859e00, aTryCollections=1) at ../../../xpcom/base/nsCycleCollector.cpp:2522 #5 0x00000001005d02f3 in nsJSContext::CC () at /Users/gal/workspace/tracemonkey-repository/dom/base/nsJSEnvironment.cpp:3549 #6 0x00000001005d02f3 in nsJSContext::IntervalCC () at /Users/gal/workspace/tracemonkey-repository/dom/base/nsJSEnvironment.cpp:3637 #0 nsCycleCollector::BeginCollection (this=0x103859e00) at ../../../xpcom/base/nsCycleCollector.cpp:2581 #1 0x00000001000216e9 in XPCCycleCollectGCCallback (cx=0x103267a00, status=JSGC_MARK_END) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:392 #2 0x000000010242bc12 in js_GC (cx=<value temporarily unavailable, due to optimizations>, gckind=GC_NORMAL) at ../../../js/src/jsgc.cpp:3169 #3 0x000000010001e886 in nsXPConnect::Collect (this=0x102c11e50) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:479 #4 0x0000000100b7cfb4 in nsCycleCollector::Collect (this=0x103859e00, aTryCollections=1) at ../../../xpcom/base/nsCycleCollector.cpp:2522 #5 0x00000001005d02f3 in nsJSContext::CC () at /Users/gal/workspace/tracemonkey-repository/dom/base/nsJSEnvironment.cpp:3549 #6 0x00000001005d02f3 in nsJSContext::IntervalCC () at /Users/gal/workspace/tracemonkey-repository/dom/base/nsJSEnvironment.cpp:3637 #7 0x00000001005d02f3 in nsUserActivityObserver::Observe (this=0x11bc62c60, aSubject=<value temporarily unavailable, due to optimizations>, aTopic=0x100db0d68 "user-interaction-inactive", aData=<value temporarily unavailable, due to optimizations>) at ../../../dom/base/nsJSEnvironment.cpp:268
The patch in bug 497789 should help js_SweepScopeProperties (renamed to js::SweepScopeProperties) not loom so large. /be
Switching to cnn.com and then gmail.com: #0 nsCycleCollector::BeginCollection (this=0x103859e00) at ../../../xpcom/base/nsCycleCollector.cpp:2581 #1 0x00000001000216e9 in XPCCycleCollectGCCallback (cx=0x103267a00, status=JSGC_MARK_END) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:392 #2 0x000000010242bc12 in js_GC (cx=<value temporarily unavailable, due to optimizations>, gckind=GC_NORMAL) at ../../../js/src/jsgc.cpp:3169 #3 0x000000010001e886 in nsXPConnect::Collect (this=0x102c11e50) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:479 #4 0x0000000100b7cfb4 in nsCycleCollector::Collect (this=0x103859e00, aTryCollections=1) at ../../../xpcom/base/nsCycleCollector.cpp:2522 #5 0x00000001005d01bc in nsJSContext::MaybeCC (aHigherProbability=1) at ../../../dom/base/nsJSEnvironment.cpp:3549 #6 0x00000001005d056e in GCTimerFired (aTimer=<value temporarily unavailable, due to optimizations>, aClosure=<value temporarily unavailable, due to optimizations>) at ../../../dom/base/nsJSEnvironment.cpp:3625 #7 0x0000000100b738ba in nsTimerImpl::Fire (this=0x11ac549e0) at ../../../xpcom/threads/nsTimerImpl.cpp:427 #8 0x0000000100b73968 in nsTimerEvent::Run (this=<value temporarily unavailable, due to optimizations>) at ../../../xpcom/threads/nsTimerImpl.cpp:519 #9 0x0000000100b701b3 in nsThread::ProcessNextEvent (this=0x102c01580, mayWait=0, result=0x7fff5fbfd0ec) at ../../../xpcom/threads/nsThread.cpp:527 #10 0x0000000100b31f7e in NS_ProcessPendingEvents_P (thread=0x102c01580, timeout=20) at nsThreadUtils.cpp:200 #11 0x0000000100ae4a06 in nsBaseAppShell::NativeEventCallback (this=0x102c0a600) at ../../../../widget/src/xpwidgets/nsBaseAppShell.cpp:125 #12 0x0000000100ab3cc7 in nsAppShell::ProcessGeckoEvents (aInfo=<value temporarily unavailable, due to optimizations>) at ../../../../widget/src/cocoa/nsAppShell.mm:510
XML Requests can still trigger GCs it seems: (gdb) bt #0 nsCycleCollector::BeginCollection (this=0x103859e00) at ../../../xpcom/base/nsCycleCollector.cpp:2581 #1 0x00000001000216e9 in XPCCycleCollectGCCallback (cx=0x103267a00, status=JSGC_MARK_END) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:392 #2 0x000000010242bc12 in js_GC (cx=<value temporarily unavailable, due to optimizations>, gckind=GC_NORMAL) at ../../../js/src/jsgc.cpp:3169 #3 0x000000010001e886 in nsXPConnect::Collect (this=0x102c11e50) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:479 #4 0x0000000100b7cfb4 in nsCycleCollector::Collect (this=0x103859e00, aTryCollections=1) at ../../../xpcom/base/nsCycleCollector.cpp:2522 #5 0x00000001005d01bc in nsJSContext::MaybeCC (aHigherProbability=0) at ../../../dom/base/nsJSEnvironment.cpp:3549 #6 0x0000000100479371 in ~nsString [inlined] () at ../../../../content/base/src/nsXMLHttpRequest.cpp:2163 #7 0x0000000100479371 in ~nsDependentString [inlined] () at /Users/gal/workspace/tracemonkey-repository/opt-build/dist/include/nsTDependentString.h:53 #8 0x0000000100479371 in nsXMLHttpRequest::RequestCompleted (this=0x1254f11a0) at ../../../../content/base/src/nsXMLHttpRequest.cpp:2164 #9 0x0000000100479622 in nsXMLHttpRequest::OnStopRequest (this=0x1254f11a0, request=0x1254f3558, ctxt=<value temporarily unavailable, due to optimizations>, status=0) at ../../../../content/base/src/nsXMLHttpRequest.cpp:2106 #10 0x0000000100150816 in nsCOMPtr<nsIStreamListener>::operator= () at /Users/gal/workspace/tracemonkey-repository/opt-build/dist/include/nsCOMPtr.h:5283 #11 0x0000000100150816 in nsHttpChannel::OnStopRequest (this=0x1254f3510, request=0x0, ctxt=<value temporarily unavailable, due to optimizations>, status=0) at ../../../../../netwerk/protocol/http/src/nsHttpChannel.cpp:5284 #12 0x00000001000c98b7 in nsCOMPtr<nsIStreamListener>::operator= () at /Users/gal/workspace/tracemonkey-repository/opt-build/dist/include/nsCOMPtr.h:576 #13 0x00000001000c98b7 in nsInputStreamPump::OnStateStop (this=0x1254f4890) at ../../../../netwerk/base/src/nsInputStreamPump.cpp:577 #14 0x00000001000c9f98 in nsInputStreamPump::OnInputStreamReady (this=0x1254f4890, stream=<value temporarily unavailable, due to optimizations>) at ../../../../netwerk/base/src/nsInputStreamPump.cpp:401 #15 0x0000000100b536c4 in nsCOMPtr<nsIInputStreamCallback>::operator= () at /Users/gal/workspace/tracemonkey-repository/opt-build/dist/include/nsCOMPtr.h:112 #16 0x0000000100b536c4 in nsInputStreamReadyEvent::Run (this=0x1254f4630) at ../../../xpcom/io/nsStreamUtils.cpp:113 #17 0x0000000100b701b3 in nsThread::ProcessNextEvent (this=0x102c01580, mayWait=0, result=0x7fff5fbfd0ec) at ../../../xpcom/threads/nsThread.cpp:527 #18 0x0000000100b31f7e in NS_ProcessPendingEvents_P (thread=0x102c01580, timeout=20) at nsThreadUtils.cpp:200 #19 0x0000000100ae4a06 in nsBaseAppShell::NativeEventCallback (this=0x102c0a600) at ../../../../widget/src/xpwidgets/nsBaseAppShell.cpp:125 #20 0x0000000100ab3cc7 in nsAppShell::ProcessGeckoEvents (aInfo=<value temporarily unavailable, due to optimizations>) at ../../../../widget/src/cocoa/nsAppShell.mm:510 #21 0x00007fff82eb6271 in __CFRunLoopDoSources0 () #22 0x00007fff82eb4469 in __CFRunLoopRun () #23 0x00007fff82eb3c2f in CFRunLoopRunSpecific () #24 0x00007fff8478aa4e in RunCurrentEventLoopInMode () #25 0x00007fff8478a853 in ReceiveNextEventCommon () #26 0x00007fff8478a70c in BlockUntilNextEventMatchingListInMode () #27 0x00007fff87f871f2 in _DPSNextEvent () #28 0x00007fff87f86b41 in -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] () #29 0x00007fff87f4c747 in -[NSApplication run] () #30 0x0000000100ab35bb in nsAppShell::Run (this=<value temporarily unavailable, due to optimizations>) at ../../../../widget/src/cocoa/nsAppShell.mm:863 #31 0x0000000100944a64 in nsAppStartup::Run (this=0x102c41f90) at ../../../../../toolkit/components/startup/src/nsAppStartup.cpp:183 #32 0x0000000100011004 in XRE_main (argc=<value temporarily unavailable, due to optimizations>, argv=<value temporarily unavailable, due to optimizations>, aAppData=<value temporarily unavailable, due to optimizations>) at ../../../toolkit/xre/nsAppRunner.cpp:3489 #33 0x0000000100001a3e in main (argc=1, argv=0x7fff5fbfeb80) at ../../../browser/app/nsBrowserApp.cpp:158 (gdb) up #1 0x00000001000216e9 in XPCCycleCollectGCCallback (cx=0x103267a00, status=JSGC_MARK_END) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:392 392 gInCollection = nsCycleCollector_beginCollection(); (gdb) #2 0x000000010242bc12 in js_GC (cx=<value temporarily unavailable, due to optimizations>, gckind=GC_NORMAL) at ../../../js/src/jsgc.cpp:3169 3169 (void) rt->gcCallback(cx, JSGC_MARK_END); (gdb) #3 0x000000010001e886 in nsXPConnect::Collect (this=0x102c11e50) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:479 479 JS_GC(cx); (gdb) up #4 0x0000000100b7cfb4 in nsCycleCollector::Collect (this=0x103859e00, aTryCollections=1) at ../../../xpcom/base/nsCycleCollector.cpp:2522 2522 (mRuntimes[nsIProgrammingLanguage::JAVASCRIPT])->Collect(); (gdb) up #5 0x00000001005d01bc in nsJSContext::MaybeCC (aHigherProbability=0) at ../../../dom/base/nsJSEnvironment.cpp:3549 3549 sCollectedObjectsCounts = nsCycleCollector_collect(); (gdb) up #6 0x0000000100479371 in ~nsString [inlined] () at ../../../../content/base/src/nsXMLHttpRequest.cpp:2163 2163 nsJSContext::MaybeCC(PR_FALSE); (gdb) up #7 0x0000000100479371 in ~nsDependentString [inlined] () at /Users/gal/workspace/tracemonkey-repository/opt-build/dist/include/nsTDependentString.h:53 2163 nsJSContext::MaybeCC(PR_FALSE); (gdb) up #8 0x0000000100479371 in nsXMLHttpRequest::RequestCompleted (this=0x1254f11a0) at ../../../../content/base/src/nsXMLHttpRequest.cpp:2164 2163 nsJSContext::MaybeCC(PR_FALSE); (gdb) list 2159 // We're a multipart request, so we're not done. Reset to opened. 2160 ChangeState(XML_HTTP_REQUEST_OPENED); 2161 } 2162 2163 nsJSContext::MaybeCC(PR_FALSE); 2164 return rv; 2165 }
Right after (one second or so) I got another one: (gdb) bt #0 nsCycleCollector::BeginCollection (this=0x103859e00) at ../../../xpcom/base/nsCycleCollector.cpp:2581 #1 0x00000001000216e9 in XPCCycleCollectGCCallback (cx=0x103267a00, status=JSGC_MARK_END) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:392 #2 0x000000010242bc12 in js_GC (cx=<value temporarily unavailable, due to optimizations>, gckind=GC_NORMAL) at ../../../js/src/jsgc.cpp:3169 #3 0x000000010001e886 in nsXPConnect::Collect (this=0x102c11e50) at ../../../../../js/src/xpconnect/src/nsXPConnect.cpp:479 #4 0x0000000100b7cfb4 in nsCycleCollector::Collect (this=0x103859e00, aTryCollections=1) at ../../../xpcom/base/nsCycleCollector.cpp:2522 #5 0x00000001005d01bc in nsJSContext::MaybeCC (aHigherProbability=0) at ../../../dom/base/nsJSEnvironment.cpp:3549 #6 0x0000000100479371 in ~nsString [inlined] () at ../../../../content/base/src/nsXMLHttpRequest.cpp:2163 #7 0x0000000100479371 in ~nsDependentString [inlined] () at /Users/gal/workspace/tracemonkey-repository/opt-build/dist/include/nsTDependentString.h:53 #8 0x0000000100479371 in nsXMLHttpRequest::RequestCompleted (this=0x1252a4b80) at ../../../../content/base/src/nsXMLHttpRequest.cpp:2164 #9 0x0000000100479622 in nsXMLHttpRequest::OnStopRequest (this=0x1252a4b80, request=0x116487448, ctxt=<value temporarily unavailable, due to optimizations>, status=0) at ../.. This definitely needs more measuring. I am in gmail, reloading gmail by entering gmail.com into the url bar again.
So... why are we ending up with collection every 5 seconds here, exactly? We call MaybeCC with aHigherProbability = false. Then what?
In particular, how is sDelayedCCollectCount ending up > NS_MAX_DELAYED_CCOLLECT? How many XHRs are in flight here, exactly?
And IntervalCC() is supposed to be a no-op unless 10s have passed since the last CC, for that matter.
Depends on: 549538
Depends on: 549540
Depends on: 549541
Depends on: 549544
The 10s value might hold if you are counting absolute time and not process time since I stopped in gdb. Still, this heuristics seems poor. An idling browser should accumulate so much trash that we need to CC every 10s. Does anyone understand the actual heuristics. We seem to trigger CCs from all over the place, independently. If I stop the browser in gdb and then restart, I sometimes see 2 CCs in sequence with different call stacks.
Ah, yes. PR_Now is wall-clock time, for sure. > Still, this heuristics seems poor. Well, the heuristic is that if more than 10s have passed _and_ a whole bunch of other stuff is true then cc. See the code in nsJSContext::MaybeCC. > Does anyone understand the actual heuristics. Smaug. ;)
I'd like to have better heuristics :) The current ones have evolved slowly to handle different cases, like not regressing tp, not CC too much with gmail (but that was gmail perhaps a year or two ago), CC enough if there is lots of possible garbage (this is a case which may happen with XHR for example - or with any dhtml), try to postpone CC if user is active... I wonder if we could split cycle collector's traverse and unlink phases so that pause would happen more often but would be smaller. (In reply to comment #10) > We seem to trigger CCs from all over the > place, independently. I don't understand this one. Generally there are 3 ways to trigger CC: page load, XHR load, and user activity notifier. - The first one is there because there used to be GC at that time. Also, changing how CC is called at that time causes tp regressions easily. - XHR load is there since it usually creates new documents that may lead to garbage. This is a case we should probably remove. It was added there before there was a way to check suspected object count, IIRC. - User activity; better to at least try to CC when user might not notice it. (Hoping that CC doesn't take too much time when watching videos)
Eventually it would be better if cycle collector could itself notice that there is lots of possible garbage and call collect() when needed.
This hasn't been touched in a year and a half, so I'm going to close it. See bug 698919 for further ideas on improving CC performance.
Status: NEW → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
Blocks: 698919
No longer blocks: 698919
Blocks: 698919
You need to log in before you can comment on or make changes to this bug.