Bug 995295. Make console.trace() faster when the console is closed by avoiding reification of the stack until someone actually asks for it. r=baku
☠☠ backed out by c3cbf4cac7fe ☠ ☠
authorBoris Zbarsky <bzbarsky@mit.edu>
Tue, 15 Apr 2014 22:58:44 -0400
changeset 197241 af250d9dee47448af2793658296da623db840328
parent 197240 f0057045ace5c3b83ed65d38399e298641d7bd31
child 197242 17f84a2187f2492639a7fdc0a2274bc854775821
push id3624
push userasasaki@mozilla.com
push dateMon, 09 Jun 2014 21:49:01 +0000
treeherdermozilla-beta@b1a5da15899a [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersbaku
bugs995295
milestone31.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 995295. Make console.trace() faster when the console is closed by avoiding reification of the stack until someone actually asks for it. r=baku
dom/base/Console.cpp
dom/webidl/Console.webidl
--- a/dom/base/Console.cpp
+++ b/dom/base/Console.cpp
@@ -2,25 +2,28 @@
 /* This Source Code Form is subject to the terms of the Mozilla Public
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include "mozilla/dom/Console.h"
 #include "mozilla/dom/ConsoleBinding.h"
 
 #include "mozilla/dom/Exceptions.h"
+#include "mozilla/dom/ToJSValue.h"
+#include "mozilla/Maybe.h"
 #include "nsCycleCollectionParticipant.h"
 #include "nsDocument.h"
 #include "nsDOMNavigationTiming.h"
 #include "nsGlobalWindow.h"
 #include "nsJSUtils.h"
 #include "nsPerformance.h"
 #include "WorkerPrivate.h"
 #include "WorkerRunnable.h"
 #include "xpcprivate.h"
+#include "nsContentUtils.h"
 
 #include "nsIConsoleAPIStorage.h"
 #include "nsIDOMWindowUtils.h"
 #include "nsIInterfaceRequestorUtils.h"
 #include "nsILoadContext.h"
 #include "nsIServiceManager.h"
 #include "nsISupportsPrimitives.h"
 #include "nsIWebNavigation.h"
@@ -166,17 +169,26 @@ public:
 
   Console::MethodName mMethodName;
   bool mPrivate;
   int64_t mTimeStamp;
   DOMHighResTimeStamp mMonotonicTimer;
 
   nsString mMethodString;
   nsTArray<JS::Heap<JS::Value>> mArguments;
-  Sequence<ConsoleStackEntry> mStack;
+
+  // Stack management is complicated, because we want to do it as
+  // lazily as possible.  Therefore, we have the following behavior:
+  // 1)  mTopStackFrame is initialized whenever we have any JS on the stack
+  // 2)  mReifiedStack is initialized if we're created in a worker.
+  // 3)  mStack is set (possibly to null if there is no JS on the stack) if
+  //     we're created on main thread.
+  Maybe<ConsoleStackEntry> mTopStackFrame;
+  Maybe<nsTArray<ConsoleStackEntry>> mReifiedStack;
+  nsCOMPtr<nsIStackFrame> mStack;
 };
 
 // This class is used to clear any exception at the end of this method.
 class ClearException
 {
 public:
   ClearException(JSContext* aCx)
     : mCx(aCx)
@@ -729,16 +741,68 @@ Console::Assert(JSContext* aCx, bool aCo
 METHOD(Count, "count")
 
 void
 Console::__noSuchMethod__()
 {
   // Nothing to do.
 }
 
+static
+nsresult
+StackFrameToStackEntry(nsIStackFrame* aStackFrame,
+                       ConsoleStackEntry& aStackEntry,
+                       uint32_t aLanguage)
+{
+  MOZ_ASSERT(aStackFrame);
+
+  nsresult rv = aStackFrame->GetFilename(aStackEntry.mFilename);
+  NS_ENSURE_SUCCESS(rv, rv);
+
+  int32_t lineNumber;
+  rv = aStackFrame->GetLineNumber(&lineNumber);
+  NS_ENSURE_SUCCESS(rv, rv);
+
+  aStackEntry.mLineNumber = lineNumber;
+
+  rv = aStackFrame->GetName(aStackEntry.mFunctionName);
+  NS_ENSURE_SUCCESS(rv, rv);
+
+  aStackEntry.mLanguage = aLanguage;
+  return NS_OK;
+}
+
+static
+nsresult
+ReifyStack(nsIStackFrame* aStack, nsTArray<ConsoleStackEntry>& aRefiedStack)
+{
+  nsCOMPtr<nsIStackFrame> stack(aStack);
+
+  while (stack) {
+    uint32_t language;
+    nsresult rv = stack->GetLanguage(&language);
+    NS_ENSURE_SUCCESS(rv, rv);
+
+    if (language == nsIProgrammingLanguage::JAVASCRIPT ||
+        language == nsIProgrammingLanguage::JAVASCRIPT2) {
+      ConsoleStackEntry& data = *aRefiedStack.AppendElement();
+      nsresult rv = StackFrameToStackEntry(stack, data, language);
+      NS_ENSURE_SUCCESS(rv, rv);
+    }
+
+    nsCOMPtr<nsIStackFrame> caller;
+    rv = stack->GetCaller(getter_AddRefs(caller));
+    NS_ENSURE_SUCCESS(rv, rv);
+
+    stack.swap(caller);
+  }
+
+  return NS_OK;
+}
+
 // Queue a call to a console method. See the CALL_DELAY constant.
 void
 Console::Method(JSContext* aCx, MethodName aMethodName,
                 const nsAString& aMethodString,
                 const Sequence<JS::Value>& aData)
 {
   // This RAII class removes the last element of the mQueuedCalls if something
   // goes wrong.
@@ -793,64 +857,62 @@ Console::Method(JSContext* aCx, MethodNa
                       DEFAULT_MAX_STACKTRACE_DEPTH : 1;
   nsCOMPtr<nsIStackFrame> stack = CreateStack(aCx, maxDepth);
 
   if (!stack) {
     Throw(aCx, NS_ERROR_FAILURE);
     return;
   }
 
-  // nsIStackFrame is not thread-safe so we take what we need and we store in
-  // an array of ConsoleStackEntry objects.
+  // Walk up to the first JS stack frame and save it if we find it.
   do {
     uint32_t language;
     nsresult rv = stack->GetLanguage(&language);
     if (NS_FAILED(rv)) {
       Throw(aCx, rv);
       return;
     }
 
     if (language == nsIProgrammingLanguage::JAVASCRIPT ||
         language == nsIProgrammingLanguage::JAVASCRIPT2) {
-      ConsoleStackEntry& data = *callData->mStack.AppendElement();
-
-      rv = stack->GetFilename(data.mFilename);
+      callData->mTopStackFrame.construct();
+      nsresult rv = StackFrameToStackEntry(stack,
+                                           callData->mTopStackFrame.ref(),
+                                           language);
       if (NS_FAILED(rv)) {
         Throw(aCx, rv);
         return;
       }
 
-      int32_t lineNumber;
-      rv = stack->GetLineNumber(&lineNumber);
-      if (NS_FAILED(rv)) {
-        Throw(aCx, rv);
-        return;
-      }
-
-      data.mLineNumber = lineNumber;
-
-      rv = stack->GetName(data.mFunctionName);
-      if (NS_FAILED(rv)) {
-        Throw(aCx, rv);
-        return;
-      }
-
-      data.mLanguage = language;
+      break;
     }
 
     nsCOMPtr<nsIStackFrame> caller;
     rv = stack->GetCaller(getter_AddRefs(caller));
     if (NS_FAILED(rv)) {
       Throw(aCx, rv);
       return;
     }
 
     stack.swap(caller);
   } while (stack);
 
+  if (NS_IsMainThread()) {
+    callData->mStack = stack;
+  } else {
+    // nsIStackFrame is not threadsafe, so we need to snapshot it now,
+    // before we post our runnable to the main thread.
+    callData->mReifiedStack.construct();
+    nsresult rv = ReifyStack(stack, callData->mReifiedStack.ref());
+    if (NS_FAILED(rv)) {
+      Throw(aCx, rv);
+      return;
+    }
+  }
+
   // Monotonic timer for 'time' and 'timeEnd'
   if ((aMethodName == MethodTime || aMethodName == MethodTimeEnd) && mWindow) {
     nsGlobalWindow *win = static_cast<nsGlobalWindow*>(mWindow.get());
     MOZ_ASSERT(win);
 
     ErrorResult rv;
     nsRefPtr<nsPerformance> performance = win->GetPerformance(rv);
     if (rv.Failed()) {
@@ -914,24 +976,70 @@ Console::Notify(nsITimer *timer)
   if (mQueuedCalls.isEmpty() && mTimer) {
     mTimer->Cancel();
     mTimer = nullptr;
   }
 
   return NS_OK;
 }
 
+// We store information to lazily compute the stack in the reserved slots of
+// LazyStackGetter.  The first slot always stores a JS object: it's either the
+// JS wrapper of the nsIStackFrame or the actual reified stack representation.
+// The second slot is a PrivateValue() holding an nsIStackFrame* when we haven't
+// reified the stack yet, or an UndefinedValue() otherwise.
+enum {
+  SLOT_STACKOBJ,
+  SLOT_RAW_STACK
+};
+
+bool
+LazyStackGetter(JSContext* aCx, unsigned aArgc, JS::Value* aVp)
+{
+  JS::CallArgs args = CallArgsFromVp(aArgc, aVp);
+  JS::Rooted<JSObject*> callee(aCx, &args.callee());
+
+  JS::Value v = js::GetFunctionNativeReserved(&args.callee(), SLOT_RAW_STACK);
+  if (v.isUndefined()) {
+    // Already reified.
+    args.rval().set(js::GetFunctionNativeReserved(callee, SLOT_STACKOBJ));
+    return true;
+  }
+
+  nsIStackFrame* stack = reinterpret_cast<nsIStackFrame*>(v.toPrivate());
+  nsTArray<ConsoleStackEntry> reifiedStack;
+  nsresult rv = ReifyStack(stack, reifiedStack);
+  if (NS_FAILED(rv)) {
+    Throw(aCx, rv);
+    return false;
+  }
+
+  JS::Rooted<JS::Value> stackVal(aCx);
+  if (!ToJSValue(aCx, reifiedStack, &stackVal)) {
+    return false;
+  }
+
+  MOZ_ASSERT(stackVal.isObject());
+
+  js::SetFunctionNativeReserved(callee, SLOT_STACKOBJ, stackVal);
+  js::SetFunctionNativeReserved(callee, SLOT_RAW_STACK, JS::UndefinedValue());
+
+  args.rval().set(stackVal);
+  return true;
+}
+
 void
 Console::ProcessCallData(ConsoleCallData* aData)
 {
   MOZ_ASSERT(aData);
+  MOZ_ASSERT(NS_IsMainThread());
 
   ConsoleStackEntry frame;
-  if (!aData->mStack.IsEmpty()) {
-    frame = aData->mStack[0];
+  if (!aData->mTopStackFrame.empty()) {
+    frame = aData->mTopStackFrame.ref();
   }
 
   AutoSafeJSContext cx;
   ClearException ce(cx);
   RootedDictionary<ConsoleEvent> event(cx);
 
   JSAutoCompartment ac(cx, aData->mGlobal);
 
@@ -967,24 +1075,19 @@ Console::ProcessCallData(ConsoleCallData
                        event.mStyles.Value());
       break;
 
     default:
       event.mArguments.Construct();
       ArgumentsToValueList(aData->mArguments, event.mArguments.Value());
   }
 
-  if (ShouldIncludeStackrace(aData->mMethodName)) {
-    event.mStacktrace.Construct();
-    event.mStacktrace.Value().SwapElements(aData->mStack);
-  }
-
-  else if (aData->mMethodName == MethodGroup ||
-           aData->mMethodName == MethodGroupCollapsed ||
-           aData->mMethodName == MethodGroupEnd) {
+  if (aData->mMethodName == MethodGroup ||
+      aData->mMethodName == MethodGroupCollapsed ||
+      aData->mMethodName == MethodGroupEnd) {
     ComposeGroupName(cx, aData->mArguments, event.mGroupName);
   }
 
   else if (aData->mMethodName == MethodTime && !aData->mArguments.IsEmpty()) {
     event.mTimer = StartTimer(cx, aData->mArguments[0], aData->mMonotonicTimer);
   }
 
   else if (aData->mMethodName == MethodTimeEnd && !aData->mArguments.IsEmpty()) {
@@ -1004,16 +1107,60 @@ Console::ProcessCallData(ConsoleCallData
   JS::Rooted<JSObject*> eventObj(cx, &eventValue.toObject());
   MOZ_ASSERT(eventObj);
 
   if (!JS_DefineProperty(cx, eventObj, "wrappedJSObject", eventValue,
                          nullptr, nullptr, JSPROP_ENUMERATE)) {
     return;
   }
 
+  if (ShouldIncludeStackrace(aData->mMethodName)) {
+    // Now define the "stacktrace" property on eventObj.  There are two cases
+    // here.  Either we came from a worker and have a reified stack, or we want
+    // to define a getter that will lazily reify the stack.
+    if (!aData->mReifiedStack.empty()) {
+      JS::Rooted<JS::Value> stacktrace(cx);
+      if (!ToJSValue(cx, aData->mReifiedStack.ref(), &stacktrace) ||
+          !JS_DefineProperty(cx, eventObj, "stacktrace", stacktrace,
+                             nullptr, nullptr, JSPROP_ENUMERATE)) {
+        return;
+      }
+    } else {
+      JSFunction* fun = js::NewFunctionWithReserved(cx, LazyStackGetter, 0, 0,
+                                                    eventObj, "stacktrace");
+      if (!fun) {
+        return;
+      }
+
+      JS::Rooted<JSObject*> funObj(cx, JS_GetFunctionObject(fun));
+
+      // We want to store our stack in the function and have it stay alive.  But
+      // we also need sane access to the C++ nsIStackFrame.  So store both a JS
+      // wrapper and the raw pointer: the former will keep the latter alive.
+      JS::Rooted<JS::Value> stackVal(cx);
+      nsresult rv = nsContentUtils::WrapNative(cx, aData->mStack,
+                                               &stackVal);
+      if (NS_FAILED(rv)) {
+        return;
+      }
+
+      js::SetFunctionNativeReserved(funObj, SLOT_STACKOBJ, stackVal);
+      js::SetFunctionNativeReserved(funObj, SLOT_RAW_STACK,
+                                    JS::PrivateValue(aData->mStack.get()));
+
+      if (!JS_DefineProperty(cx, eventObj, "stacktrace", JS::UndefinedValue(),
+                             JS_DATA_TO_FUNC_PTR(JSPropertyOp, funObj.get()),
+                             nullptr,
+                             JSPROP_ENUMERATE | JSPROP_SHARED | JSPROP_GETTER |
+                             JSPROP_SETTER)) {
+        return;
+      }
+    }
+  }
+
   if (!mStorage) {
     mStorage = do_GetService("@mozilla.org/consoleAPI-storage;1");
   }
 
   if (!mStorage) {
     NS_WARNING("Failed to get the ConsoleAPIStorage service.");
     return;
   }
--- a/dom/webidl/Console.webidl
+++ b/dom/webidl/Console.webidl
@@ -42,17 +42,22 @@ dictionary ConsoleEvent {
   DOMString functionName = "";
   double timeStamp = 0;
   sequence<any> arguments;
 
   // This array will only hold strings or null elements.
   sequence<any> styles;
 
   boolean private = false;
-  sequence<ConsoleStackEntry> stacktrace;
+  // stacktrace is handled via a getter in some cases so we can construct it
+  // lazily.  Note that we're not making this whole thing an interface because
+  // consumers expect to see own properties on it, which would mean making the
+  // props unforgeable, which means lots of JSFunction allocations.  Maybe we
+  // should fix those consumers, of course....
+  // sequence<ConsoleStackEntry> stacktrace;
   DOMString groupName = "";
   any timer = null;
   any counter = null;
 };
 
 // Event for profile operations
 dictionary ConsoleProfileEvent {
   DOMString action = "";