ENH: Add Logging to GC Marking Phase
https://bugs.webkit.org/show_bug.cgi?id=88364

Reviewed by Filip Pizlo.

Source/JavaScriptCore: 

Log GC marking to stderr or a file.  The logging in controlled
with the define ENABLE_OBJECT_MARK_LOGGING in wtf/Platform.h.
If DATA_LOG_TO_FILE in wtf/DataLog.cpp is set to 1, output is
logged to a file otherwise it is logged to stderr.

When logging is enabled, the GC is built single threaded since the
log output from the various threads isn't buffered and output in a
thread safe manner.

* heap/Heap.cpp:
(JSC::Heap::markRoots):
* heap/MarkStack.cpp:
(JSC::MarkStackThreadSharedData::resetChildren):
(JSC::MarkStackThreadSharedData::childVisitCount):
(JSC::MarkStackThreadSharedData::markingThreadMain):
(JSC::MarkStackThreadSharedData::markingThreadStartFunc):
(JSC::MarkStackThreadSharedData::MarkStackThreadSharedData):
(JSC::MarkStackThreadSharedData::reset):
* heap/MarkStack.h:
(MarkStackThreadSharedData):
(MarkStack):
(JSC::MarkStack::sharedData):
(JSC::MarkStack::resetChildCount):
(JSC::MarkStack::childCount):
(JSC::MarkStack::incrementChildCount):
* runtime/JSArray.cpp:
(JSC::JSArray::visitChildren):
* runtime/JSCell.cpp:
(JSC::JSCell::className):
* runtime/JSCell.h:
(JSCell):
(JSC::JSCell::visitChildren):
* runtime/JSString.cpp:
(JSC::JSString::visitChildren):
* runtime/JSString.h:
(JSString):
* runtime/Structure.h:
(JSC::MarkStack::internalAppend):

Source/WTF: 

* wtf/DataLog.cpp:
(WTF::dataLogString): Additional method to support GC Mark logging.
* wtf/DataLog.h:
* wtf/Platform.h: New ENABLE_OBJECT_MARK_LOGGING flag macro.


git-svn-id: http://svn.webkit.org/repository/webkit/trunk@119633 268f45cc-cd09-0410-ab3c-d52691b4dbfc
diff --git a/Source/JavaScriptCore/heap/Heap.cpp b/Source/JavaScriptCore/heap/Heap.cpp
index 27bacae..790e3aa 100644
--- a/Source/JavaScriptCore/heap/Heap.cpp
+++ b/Source/JavaScriptCore/heap/Heap.cpp
@@ -421,6 +421,10 @@
     UNUSED_PARAM(fullGC);
     ASSERT(isValidThreadState(m_globalData));
 
+#if ENABLE(OBJECT_MARK_LOGGING)
+    double gcStartTime = WTF::currentTime();
+#endif
+
     void* dummy;
     
     // We gather conservative roots before clearing mark bits because conservative
@@ -484,28 +488,33 @@
     
         {
             GCPHASE(VisitMachineRoots);
+            MARK_LOG_ROOT(visitor, "C++ Stack");
             visitor.append(machineThreadRoots);
             visitor.donateAndDrain();
         }
         {
             GCPHASE(VisitRegisterFileRoots);
+            MARK_LOG_ROOT(visitor, "Register File");
             visitor.append(registerFileRoots);
             visitor.donateAndDrain();
         }
 #if ENABLE(DFG_JIT)
         {
             GCPHASE(VisitScratchBufferRoots);
+            MARK_LOG_ROOT(visitor, "Scratch Buffers");
             visitor.append(scratchBufferRoots);
             visitor.donateAndDrain();
         }
 #endif
         {
             GCPHASE(VisitProtectedObjects);
+            MARK_LOG_ROOT(visitor, "Protected Objects");
             markProtectedObjects(heapRootVisitor);
             visitor.donateAndDrain();
         }
         {
             GCPHASE(VisitTempSortVectors);
+            MARK_LOG_ROOT(visitor, "Temp Sort Vectors");
             markTempSortVectors(heapRootVisitor);
             visitor.donateAndDrain();
         }
@@ -513,30 +522,35 @@
         {
             GCPHASE(MarkingArgumentBuffers);
             if (m_markListSet && m_markListSet->size()) {
+                MARK_LOG_ROOT(visitor, "Argument Buffers");
                 MarkedArgumentBuffer::markLists(heapRootVisitor, *m_markListSet);
                 visitor.donateAndDrain();
             }
         }
         if (m_globalData->exception) {
             GCPHASE(MarkingException);
+            MARK_LOG_ROOT(visitor, "Exceptions");
             heapRootVisitor.visit(&m_globalData->exception);
             visitor.donateAndDrain();
         }
     
         {
             GCPHASE(VisitStrongHandles);
+            MARK_LOG_ROOT(visitor, "Strong Handles");
             m_handleSet.visitStrongHandles(heapRootVisitor);
             visitor.donateAndDrain();
         }
     
         {
             GCPHASE(HandleStack);
+            MARK_LOG_ROOT(visitor, "Handle Stack");
             m_handleStack.visit(heapRootVisitor);
             visitor.donateAndDrain();
         }
     
         {
             GCPHASE(TraceCodeBlocks);
+            MARK_LOG_ROOT(visitor, "Trace Code Blocks");
             m_dfgCodeBlocks.traceMarkedCodeBlocks(visitor);
             visitor.donateAndDrain();
         }
@@ -553,6 +567,7 @@
     // the liveness of the rest of the object graph.
     {
         GCPHASE(VisitingLiveWeakHandles);
+        MARK_LOG_ROOT(visitor, "Live Weak Handles");
         while (true) {
             m_objectSpace.visitWeakSets(heapRootVisitor);
             harvestWeakReferences();
@@ -571,8 +586,19 @@
     GCCOUNTER(VisitedValueCount, visitor.visitCount());
 
     visitor.doneCopying();
+#if ENABLE(OBJECT_MARK_LOGGING)
+    size_t visitCount = visitor.visitCount();
+#if ENABLE(PARALLEL_GC)
+    visitCount += m_sharedData.childVisitCount();
+#endif
+    MARK_LOG_MESSAGE2("\nNumber of live Objects after full GC %lu, took %.6f secs\n", visitCount, WTF::currentTime() - gcStartTime);
+#endif
+
     visitor.reset();
     m_sharedData.reset();
+#if ENABLE(PARALLEL_GC)
+    m_sharedData.resetChildren();
+#endif
     m_storageSpace.doneCopying();
 
 }