Source/JavaScriptCore/profiler/ProfileGenerator.cpp

   1 /*
   2  * Copyright (C) 2008, 2014 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  * 1. Redistributions of source code must retain the above copyright
   8  *    notice, this list of conditions and the following disclaimer.
   9  * 2. Redistributions in binary form must reproduce the above copyright
  10  *    notice, this list of conditions and the following disclaimer in the
  11  *    documentation and/or other materials provided with the distribution.
  12  *
  13  * THIS SOFTWARE IS PROVIDED BY APPLE INC. ``AS IS'' AND ANY
  14  * EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
  15  * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
  16  * PURPOSE ARE DISCLAIMED.  IN NO EVENT SHALL APPLE INC. OR
  17  * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL,
  18  * EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
  19  * PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR
  20  * PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY
  21  * OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
  22  * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
  23  * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
  24  */
  25
  26 #include "config.h"
  27 #include "ProfileGenerator.h"
  28
  29 #include "CallFrame.h"
  30 #include "CodeBlock.h"
  31 #include "Debugger.h"
  32 #include "JSGlobalObject.h"
  33 #include "JSStringRef.h"
  34 #include "JSFunction.h"
  35 #include "LegacyProfiler.h"
  36 #include "JSCInlines.h"
  37 #include "Profile.h"
  38 #include "StackVisitor.h"
  39 #include "Tracing.h"
  40
  41 namespace JSC {
  42
  43 PassRefPtr<ProfileGenerator> ProfileGenerator::create(ExecState* exec, const String& title, unsigned uid)
  44 {
  45     return adoptRef(new ProfileGenerator(exec, title, uid));
  46 }
  47
  48 ProfileGenerator::ProfileGenerator(ExecState* exec, const String& title, unsigned uid)
  49     : m_origin(exec ? exec->lexicalGlobalObject() : nullptr)
  50     , m_profileGroup(exec ? exec->lexicalGlobalObject()->profileGroup() : 0)
  51     , m_debuggerPausedTimestamp(NAN)
  52     , m_foundConsoleStartParent(false)
  53     , m_suspended(false)
  54 {
  55     if (Debugger* debugger = exec->lexicalGlobalObject()->debugger())
  56         m_debuggerPausedTimestamp = debugger->isPaused() ? currentTime() : NAN;
  57
  58     m_profile = Profile::create(title, uid);
  59     m_currentNode = m_rootNode = m_profile->rootNode();
  60     if (exec)
  61         addParentForConsoleStart(exec);
  62 }
  63
  64 class AddParentForConsoleStartFunctor {
  65 public:
  66     AddParentForConsoleStartFunctor(ExecState* exec, RefPtr<ProfileNode>& rootNode, RefPtr<ProfileNode>& currentNode)
  67         : m_exec(exec)
  68         , m_hasSkippedFirstFrame(false)
  69         , m_foundParent(false)
  70         , m_rootNode(rootNode)
  71         , m_currentNode(currentNode)
  72     {
  73     }
  74
  75     bool foundParent() const { return m_foundParent; }
  76
  77     StackVisitor::Status operator()(StackVisitor& visitor)
  78     {
  79         if (!m_hasSkippedFirstFrame) {
  80             m_hasSkippedFirstFrame = true;
  81             return StackVisitor::Continue;
  82         }
  83
  84         unsigned line = 0;
  85         unsigned column = 0;
  86         visitor->computeLineAndColumn(line, column);
  87         m_currentNode = ProfileNode::create(m_exec, LegacyProfiler::createCallIdentifier(m_exec, visitor->callee(), visitor->sourceURL(), line, column), m_rootNode.get());
  88         m_currentNode->appendCall(ProfileNode::Call(currentTime()));
  89         m_rootNode->spliceNode(m_currentNode.get());
  90
  91         m_foundParent = true;
  92         return StackVisitor::Done;
  93     }
  94
  95 private:
  96     ExecState* m_exec;
  97     bool m_hasSkippedFirstFrame;
  98     bool m_foundParent;
  99     RefPtr<ProfileNode>& m_rootNode;
 100     RefPtr<ProfileNode>& m_currentNode;
 101 };
 102
 103 void ProfileGenerator::addParentForConsoleStart(ExecState* exec)
 104 {
 105     AddParentForConsoleStartFunctor functor(exec, m_rootNode, m_currentNode);
 106     exec->iterate(functor);
 107
 108     m_foundConsoleStartParent = functor.foundParent();
 109 }
 110
 111 const String& ProfileGenerator::title() const
 112 {
 113     return m_profile->title();
 114 }
 115
 116 void ProfileGenerator::beginCallEntry(ProfileNode* node, double startTime)
 117 {
 118     ASSERT_ARG(node, node);
 119
 120     if (isnan(startTime))
 121         startTime = currentTime();
 122
 123     // If the debugger is paused when beginning, then don't set the start time. It
 124     // will be fixed up when the debugger unpauses or the call entry ends.
 125     if (!isnan(m_debuggerPausedTimestamp))
 126         startTime = NAN;
 127
 128     node->appendCall(ProfileNode::Call(startTime));
 129 }
 130
 131 void ProfileGenerator::endCallEntry(ProfileNode* node)
 132 {
 133     ASSERT_ARG(node, node);
 134
 135     ProfileNode::Call& last = node->lastCall();
 136
 137     // If the debugger is paused, ignore the interval that ends now.
 138     if (!isnan(m_debuggerPausedTimestamp) && !isnan(last.elapsedTime()))
 139         return;
 140
 141     // If paused and no time was accrued then the debugger was never unpaused. The call will
 142     // have no time accrued and appear to have started when the debugger was paused.
 143     if (!isnan(m_debuggerPausedTimestamp)) {
 144         last.setStartTime(m_debuggerPausedTimestamp);
 145         last.setElapsedTime(0.0);
 146         return;
 147     }
 148
 149     // Otherwise, add the interval ending now to elapsed time.
 150     double previousElapsedTime = isnan(last.elapsedTime()) ? 0.0 : last.elapsedTime();
 151     double newlyElapsedTime = currentTime() - last.startTime();
 152     last.setElapsedTime(previousElapsedTime + newlyElapsedTime);
 153 }
 154
 155 void ProfileGenerator::willExecute(ExecState* callerCallFrame, const CallIdentifier& callIdentifier)
 156 {
 157     if (JAVASCRIPTCORE_PROFILE_WILL_EXECUTE_ENABLED()) {
 158         CString name = callIdentifier.functionName().utf8();
 159         CString url = callIdentifier.url().utf8();
 160         JAVASCRIPTCORE_PROFILE_WILL_EXECUTE(m_profileGroup, const_cast<char*>(name.data()), const_cast<char*>(url.data()), callIdentifier.lineNumber(), callIdentifier.columnNumber());
 161     }
 162
 163     if (!m_origin)
 164         return;
 165
 166     if (m_suspended)
 167         return;
 168
 169     RefPtr<ProfileNode> calleeNode = nullptr;
 170
 171     // Find or create a node for the callee call frame.
 172     for (const RefPtr<ProfileNode>& child : m_currentNode->children()) {
 173         if (child->callIdentifier() == callIdentifier)
 174             calleeNode = child;
 175     }
 176
 177     if (!calleeNode) {
 178         calleeNode = ProfileNode::create(callerCallFrame, callIdentifier, m_currentNode.get());
 179         m_currentNode->addChild(calleeNode);
 180     }
 181
 182     m_currentNode = calleeNode;
 183     beginCallEntry(calleeNode.get());
 184 }
 185
 186 void ProfileGenerator::didExecute(ExecState* callerCallFrame, const CallIdentifier& callIdentifier)
 187 {
 188     if (JAVASCRIPTCORE_PROFILE_DID_EXECUTE_ENABLED()) {
 189         CString name = callIdentifier.functionName().utf8();
 190         CString url = callIdentifier.url().utf8();
 191         JAVASCRIPTCORE_PROFILE_DID_EXECUTE(m_profileGroup, const_cast<char*>(name.data()), const_cast<char*>(url.data()), callIdentifier.lineNumber(), callIdentifier.columnNumber());
 192     }
 193
 194     if (!m_origin)
 195         return;
 196
 197     if (m_suspended)
 198         return;
 199
 200     // Make a new node if the caller node has never seen this callee call frame before.
 201     // This can happen if |console.profile()| is called several frames deep in the call stack.
 202     ASSERT(m_currentNode);
 203     if (m_currentNode->callIdentifier() != callIdentifier) {
 204         RefPtr<ProfileNode> calleeNode = ProfileNode::create(callerCallFrame, callIdentifier, m_currentNode.get());
 205         beginCallEntry(calleeNode.get(), m_currentNode->lastCall().startTime());
 206         endCallEntry(calleeNode.get());
 207         m_currentNode->spliceNode(calleeNode.release());
 208         return;
 209     }
 210
 211     endCallEntry(m_currentNode.get());
 212     m_currentNode = m_currentNode->parent();
 213 }
 214
 215 void ProfileGenerator::exceptionUnwind(ExecState* handlerCallFrame, const CallIdentifier&)
 216 {
 217     // If the current node was called by the handler (==) or any
 218     // more nested function (>) the we have exited early from it.
 219     ASSERT(m_currentNode);
 220     while (m_currentNode->callerCallFrame() >= handlerCallFrame) {
 221         didExecute(m_currentNode->callerCallFrame(), m_currentNode->callIdentifier());
 222         ASSERT(m_currentNode);
 223     }
 224 }
 225
 226 void ProfileGenerator::didPause(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&)
 227 {
 228     ASSERT(isnan(m_debuggerPausedTimestamp));
 229
 230     m_debuggerPausedTimestamp = currentTime();
 231
 232     for (ProfileNode* node = m_currentNode.get(); node != m_profile->rootNode(); node = node->parent()) {
 233         ProfileNode::Call& last = node->lastCall();
 234         ASSERT(!isnan(last.startTime()));
 235
 236         double previousElapsedTime = isnan(last.elapsedTime()) ? 0.0 : last.elapsedTime();
 237         double additionalElapsedTime = m_debuggerPausedTimestamp - last.startTime();
 238         last.setStartTime(NAN);
 239         last.setElapsedTime(previousElapsedTime + additionalElapsedTime);
 240     }
 241 }
 242
 243 void ProfileGenerator::didContinue(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&)
 244 {
 245     ASSERT(!isnan(m_debuggerPausedTimestamp));
 246
 247     for (ProfileNode* node = m_currentNode.get(); node != m_profile->rootNode(); node = node->parent())
 248         node->lastCall().setStartTime(m_debuggerPausedTimestamp);
 249
 250     m_debuggerPausedTimestamp = NAN;
 251 }
 252
 253 void ProfileGenerator::stopProfiling()
 254 {
 255     for (ProfileNode* node = m_currentNode.get(); node != m_profile->rootNode(); node = node->parent())
 256         endCallEntry(node);
 257
 258     if (m_foundConsoleStartParent) {
 259         removeProfileStart();
 260         removeProfileEnd();
 261     }
 262
 263     ASSERT(m_currentNode);
 264
 265     // Set the current node to the parent, because we are in a call that
 266     // will not get didExecute call.
 267     m_currentNode = m_currentNode->parent();
 268 }
 269
 270 // The console.profile that started this ProfileGenerator will be the first child.
 271 void ProfileGenerator::removeProfileStart()
 272 {
 273     ProfileNode* currentNode = nullptr;
 274     for (ProfileNode* next = m_rootNode.get(); next; next = next->firstChild())
 275         currentNode = next;
 276
 277     if (currentNode->callIdentifier().functionName() != "profile")
 278         return;
 279
 280     currentNode->parent()->removeChild(currentNode);
 281 }
 282
 283 // The console.profileEnd that stopped this ProfileGenerator will be the last child.
 284 void ProfileGenerator::removeProfileEnd()
 285 {
 286     ProfileNode* currentNode = nullptr;
 287     for (ProfileNode* next = m_rootNode.get(); next; next = next->lastChild())
 288         currentNode = next;
 289
 290     if (currentNode->callIdentifier().functionName() != "profileEnd")
 291         return;
 292
 293     ASSERT(currentNode->callIdentifier() == (currentNode->parent()->children()[currentNode->parent()->children().size() - 1])->callIdentifier());
 294     currentNode->parent()->removeChild(currentNode);
 295 }
 296
 297 } // namespace JSC