profiler/ProfileNode.cpp

   1 /*
   2  * Copyright (C) 2008 Apple Inc. All rights reserved.
   3  *
   4  * Redistribution and use in source and binary forms, with or without
   5  * modification, are permitted provided that the following conditions
   6  * are met:
   7  *
   8  * 1.  Redistributions of source code must retain the above copyright
   9  *     notice, this list of conditions and the following disclaimer.
  10  * 2.  Redistributions in binary form must reproduce the above copyright
  11  *     notice, this list of conditions and the following disclaimer in the
  12  *     documentation and/or other materials provided with the distribution.
  13  * 3.  Neither the name of Apple Computer, Inc. ("Apple") nor the names of
  14  *     its contributors may be used to endorse or promote products derived
  15  *     from this software without specific prior written permission.
  16  *
  17  * THIS SOFTWARE IS PROVIDED BY APPLE AND ITS CONTRIBUTORS "AS IS" AND ANY
  18  * EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
  19  * WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
  20  * DISCLAIMED. IN NO EVENT SHALL APPLE OR ITS CONTRIBUTORS BE LIABLE FOR ANY
  21  * DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES
  22  * (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;
  23  * LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
  24  * ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
  25  * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF
  26  * THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
  27  */
  28
  29 #include "config.h"
  30 #include "ProfileNode.h"
  31
  32 #include "Profiler.h"
  33 #include <stdio.h>
  34 #include <wtf/DateMath.h>
  35 #include <wtf/DataLog.h>
  36 #include <wtf/text/StringHash.h>
  37
  38 #if OS(WINDOWS)
  39 #include <windows.h>
  40 #endif
  41
  42 using namespace WTF;
  43
  44 namespace JSC {
  45
  46 static double getCount()
  47 {
  48 #if OS(WINDOWS)
  49     static LARGE_INTEGER frequency;
  50     if (!frequency.QuadPart)
  51         QueryPerformanceFrequency(&frequency);
  52     LARGE_INTEGER counter;
  53     QueryPerformanceCounter(&counter);
  54     return static_cast<double>(counter.QuadPart) / frequency.QuadPart;
  55 #else
  56     return currentTimeMS();
  57 #endif
  58 }
  59
  60 ProfileNode::ProfileNode(ExecState* callerCallFrame, const CallIdentifier& callIdentifier, ProfileNode* headNode, ProfileNode* parentNode)
  61     : m_callerCallFrame(callerCallFrame)
  62     , m_callIdentifier(callIdentifier)
  63     , m_head(headNode)
  64     , m_parent(parentNode)
  65     , m_nextSibling(0)
  66     , m_startTime(0.0)
  67     , m_actualTotalTime(0.0)
  68     , m_visibleTotalTime(0.0)
  69     , m_actualSelfTime(0.0)
  70     , m_visibleSelfTime(0.0)
  71     , m_numberOfCalls(0)
  72     , m_visible(true)
  73 {
  74     startTimer();
  75 }
  76
  77 ProfileNode::ProfileNode(ExecState* callerCallFrame, ProfileNode* headNode, ProfileNode* nodeToCopy)
  78     : m_callerCallFrame(callerCallFrame)
  79     , m_callIdentifier(nodeToCopy->callIdentifier())
  80     , m_head(headNode)
  81     , m_parent(nodeToCopy->parent())
  82     , m_nextSibling(0)
  83     , m_startTime(0.0)
  84     , m_actualTotalTime(nodeToCopy->actualTotalTime())
  85     , m_visibleTotalTime(nodeToCopy->totalTime())
  86     , m_actualSelfTime(nodeToCopy->actualSelfTime())
  87     , m_visibleSelfTime(nodeToCopy->selfTime())
  88     , m_numberOfCalls(nodeToCopy->numberOfCalls())
  89     , m_visible(nodeToCopy->visible())
  90 {
  91 }
  92
  93 ProfileNode* ProfileNode::willExecute(ExecState* callerCallFrame, const CallIdentifier& callIdentifier)
  94 {
  95     for (StackIterator currentChild = m_children.begin(); currentChild != m_children.end(); ++currentChild) {
  96         if ((*currentChild)->callIdentifier() == callIdentifier) {
  97             (*currentChild)->startTimer();
  98             return (*currentChild).get();
  99         }
 100     }
 101
 102     RefPtr<ProfileNode> newChild = ProfileNode::create(callerCallFrame, callIdentifier, m_head ? m_head : this, this); // If this ProfileNode has no head it is the head.
 103     if (m_children.size())
 104         m_children.last()->setNextSibling(newChild.get());
 105     m_children.append(newChild.release());
 106     return m_children.last().get();
 107 }
 108
 109 ProfileNode* ProfileNode::didExecute()
 110 {
 111     endAndRecordCall();
 112     return m_parent;
 113 }
 114
 115 void ProfileNode::addChild(PassRefPtr<ProfileNode> prpChild)
 116 {
 117     RefPtr<ProfileNode> child = prpChild;
 118     child->setParent(this);
 119     if (m_children.size())
 120         m_children.last()->setNextSibling(child.get());
 121     m_children.append(child.release());
 122 }
 123
 124 ProfileNode* ProfileNode::findChild(ProfileNode* node) const
 125 {
 126     if (!node)
 127         return 0;
 128
 129     for (size_t i = 0; i < m_children.size(); ++i) {
 130         if (*node == m_children[i].get())
 131             return m_children[i].get();
 132     }
 133
 134     return 0;
 135 }
 136
 137 void ProfileNode::removeChild(ProfileNode* node)
 138 {
 139     if (!node)
 140         return;
 141
 142     for (size_t i = 0; i < m_children.size(); ++i) {
 143         if (*node == m_children[i].get()) {
 144             m_children.remove(i);
 145             break;
 146         }
 147     }
 148
 149     resetChildrensSiblings();
 150 }
 151
 152 void ProfileNode::insertNode(PassRefPtr<ProfileNode> prpNode)
 153 {
 154     RefPtr<ProfileNode> node = prpNode;
 155
 156     for (unsigned i = 0; i < m_children.size(); ++i)
 157         node->addChild(m_children[i].release());
 158
 159     m_children.clear();
 160     m_children.append(node.release());
 161 }
 162
 163 void ProfileNode::stopProfiling()
 164 {
 165     if (m_startTime)
 166         endAndRecordCall();
 167
 168     m_visibleTotalTime = m_actualTotalTime;
 169
 170     ASSERT(m_actualSelfTime == 0.0 && m_startTime == 0.0);
 171
 172     // Because we iterate in post order all of our children have been stopped before us.
 173     for (unsigned i = 0; i < m_children.size(); ++i)
 174         m_actualSelfTime += m_children[i]->totalTime();
 175
 176     ASSERT(m_actualSelfTime <= m_actualTotalTime);
 177     m_actualSelfTime = m_actualTotalTime - m_actualSelfTime;
 178     m_visibleSelfTime = m_actualSelfTime;
 179 }
 180
 181 ProfileNode* ProfileNode::traverseNextNodePostOrder() const
 182 {
 183     ProfileNode* next = m_nextSibling;
 184     if (!next)
 185         return m_parent;
 186     while (ProfileNode* firstChild = next->firstChild())
 187         next = firstChild;
 188     return next;
 189 }
 190
 191 ProfileNode* ProfileNode::traverseNextNodePreOrder(bool processChildren) const
 192 {
 193     if (processChildren && m_children.size())
 194         return m_children[0].get();
 195
 196     if (m_nextSibling)
 197         return m_nextSibling;
 198
 199     ProfileNode* nextParent = m_parent;
 200     if (!nextParent)
 201         return 0;
 202
 203     ProfileNode* next;
 204     for (next = m_parent->nextSibling(); !next; next = nextParent->nextSibling()) {
 205         nextParent = nextParent->parent();
 206         if (!nextParent)
 207             return 0;
 208     }
 209
 210     return next;
 211 }
 212
 213 void ProfileNode::setTreeVisible(ProfileNode* node, bool visible)
 214 {
 215     ProfileNode* nodeParent = node->parent();
 216     ProfileNode* nodeSibling = node->nextSibling();
 217     node->setParent(0);
 218     node->setNextSibling(0);
 219
 220     for (ProfileNode* currentNode = node; currentNode; currentNode = currentNode->traverseNextNodePreOrder())
 221         currentNode->setVisible(visible);
 222
 223     node->setParent(nodeParent);
 224     node->setNextSibling(nodeSibling);
 225 }
 226
 227 void ProfileNode::calculateVisibleTotalTime()
 228 {
 229     double sumOfVisibleChildrensTime = 0.0;
 230
 231     for (unsigned i = 0; i < m_children.size(); ++i) {
 232         if (m_children[i]->visible())
 233             sumOfVisibleChildrensTime += m_children[i]->totalTime();
 234     }
 235
 236     m_visibleTotalTime = m_visibleSelfTime + sumOfVisibleChildrensTime;
 237 }
 238
 239 bool ProfileNode::focus(const CallIdentifier& callIdentifier)
 240 {
 241     if (!m_visible)
 242         return false;
 243
 244     if (m_callIdentifier != callIdentifier) {
 245         m_visible = false;
 246         return true;
 247     }
 248
 249     for (ProfileNode* currentParent = m_parent; currentParent; currentParent = currentParent->parent())
 250         currentParent->setVisible(true);
 251
 252     return false;
 253 }
 254
 255 void ProfileNode::exclude(const CallIdentifier& callIdentifier)
 256 {
 257     if (m_visible && m_callIdentifier == callIdentifier) {
 258         setTreeVisible(this, false);
 259
 260         m_parent->setVisibleSelfTime(m_parent->selfTime() + m_visibleTotalTime);
 261     }
 262 }
 263
 264 void ProfileNode::restore()
 265 {
 266     m_visibleTotalTime = m_actualTotalTime;
 267     m_visibleSelfTime = m_actualSelfTime;
 268     m_visible = true;
 269 }
 270
 271 void ProfileNode::endAndRecordCall()
 272 {
 273     m_actualTotalTime += m_startTime ? getCount() - m_startTime : 0.0;
 274     m_startTime = 0.0;
 275
 276     ++m_numberOfCalls;
 277 }
 278
 279 void ProfileNode::startTimer()
 280 {
 281     if (!m_startTime)
 282         m_startTime = getCount();
 283 }
 284
 285 void ProfileNode::resetChildrensSiblings()
 286 {
 287     unsigned size = m_children.size();
 288     for (unsigned i = 0; i < size; ++i)
 289         m_children[i]->setNextSibling(i + 1 == size ? 0 : m_children[i + 1].get());
 290 }
 291
 292 #ifndef NDEBUG
 293 void ProfileNode::debugPrintData(int indentLevel) const
 294 {
 295     // Print function names
 296     for (int i = 0; i < indentLevel; ++i)
 297         dataLog("  ");
 298
 299     dataLog("Function Name %s %d SelfTime %.3fms/%.3f%% TotalTime %.3fms/%.3f%% VSelf %.3fms VTotal %.3fms Visible %s Next Sibling %s\n",
 300         functionName().utf8().data(),
 301         m_numberOfCalls, m_actualSelfTime, selfPercent(), m_actualTotalTime, totalPercent(),
 302         m_visibleSelfTime, m_visibleTotalTime,
 303         (m_visible ? "True" : "False"),
 304         m_nextSibling ? m_nextSibling->functionName().utf8().data() : "");
 305
 306     ++indentLevel;
 307
 308     // Print children's names and information
 309     for (StackIterator currentChild = m_children.begin(); currentChild != m_children.end(); ++currentChild)
 310         (*currentChild)->debugPrintData(indentLevel);
 311 }
 312
 313 // print the profiled data in a format that matches the tool sample's output.
 314 double ProfileNode::debugPrintDataSampleStyle(int indentLevel, FunctionCallHashCount& countedFunctions) const
 315 {
 316     dataLog("    ");
 317
 318     // Print function names
 319     const char* name = functionName().utf8().data();
 320     double sampleCount = m_actualTotalTime * 1000;
 321     if (indentLevel) {
 322         for (int i = 0; i < indentLevel; ++i)
 323             dataLog("  ");
 324
 325          countedFunctions.add(functionName().impl());
 326
 327         dataLog("%.0f %s\n", sampleCount ? sampleCount : 1, name);
 328     } else
 329         dataLog("%s\n", name);
 330
 331     ++indentLevel;
 332
 333     // Print children's names and information
 334     double sumOfChildrensCount = 0.0;
 335     for (StackIterator currentChild = m_children.begin(); currentChild != m_children.end(); ++currentChild)
 336         sumOfChildrensCount += (*currentChild)->debugPrintDataSampleStyle(indentLevel, countedFunctions);
 337
 338     sumOfChildrensCount *= 1000;    //
 339     // Print remainder of samples to match sample's output
 340     if (sumOfChildrensCount < sampleCount) {
 341         dataLog("    ");
 342         while (indentLevel--)
 343             dataLog("  ");
 344
 345         dataLog("%.0f %s\n", sampleCount - sumOfChildrensCount, functionName().utf8().data());
 346     }
 347
 348     return m_actualTotalTime;
 349 }
 350 #endif
 351
 352 } // namespace JSC