Bug 1200832 - make Console.trace follow async parents; r=baku,bgrins
authorTom Tromey <tromey@mozilla.com>
Wed, 21 Oct 2015 08:40:00 +0200
changeset 304315 eb5224bab72b8379c63847879c00cc43030548e6
parent 304314 3a9921a0dbc780456b6c3a1de18c52f30f7ed938
child 304316 0dae594de5aca88fd1fb2788c79a8e8f3755b88c
push id1001
push userraliiev@mozilla.com
push dateMon, 18 Jan 2016 19:06:03 +0000
treeherdermozilla-release@8b89261f3ac4 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersbaku, bgrins
bugs1200832
milestone44.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 1200832 - make Console.trace follow async parents; r=baku,bgrins
browser/locales/en-US/chrome/browser/devtools/webconsole.properties
devtools/client/webconsole/console-output.js
devtools/client/webconsole/test/browser.ini
devtools/client/webconsole/test/browser_webconsole_console_trace_async.js
devtools/client/webconsole/test/test-console-trace-async.html
devtools/shared/webconsole/utils.js
dom/base/Console.cpp
dom/bindings/Exceptions.cpp
dom/webidl/Console.webidl
js/xpconnect/tests/unit/test_callFunctionWithAsyncStack.js
--- a/browser/locales/en-US/chrome/browser/devtools/webconsole.properties
+++ b/browser/locales/en-US/chrome/browser/devtools/webconsole.properties
@@ -88,16 +88,21 @@ reflow.messageWithNoLink=reflow: %Sms
 reflow.messageWithLink=reflow: %Sms\u0020
 reflow.messageLinkText=function %1$S, %2$S line %3$S
 
 # LOCALIZATION NOTE (stacktrace.anonymousFunction): this string is used to
 # display JavaScript functions that have no given name - they are said to be
 # anonymous. Test console.trace() in the webconsole.
 stacktrace.anonymousFunction=<anonymous>
 
+# LOCALIZATION NOTE (stacktrace.asyncStack): this string is used to
+# indicate that a given stack frame has an async parent.
+# %S is the "Async Cause" of the frame.
+stacktrace.asyncStack=(Async: %S)
+
 # LOCALIZATION NOTE (unknownLocation): this string is used to
 # display messages with sources that have an unknown location, eg. from
 # console.trace() calls.
 unknownLocation=<unknown>
 
 # LOCALIZATION NOTE (timerStarted): this string is used to display the result
 # of the console.time() call. Parameters: %S is the name of the timer.
 timerStarted=%S: timer started
--- a/devtools/client/webconsole/console-output.js
+++ b/devtools/client/webconsole/console-output.js
@@ -3524,18 +3524,20 @@ Widgets.Stacktrace.prototype = Heritage.
   {
     if (this.element) {
       return this;
     }
 
     let result = this.element = this.document.createElementNS(XHTML_NS, "ul");
     result.className = "stacktrace devtools-monospace";
 
-    for (let frame of this.stacktrace) {
-      result.appendChild(this._renderFrame(frame));
+    if (this.stacktrace) {
+      for (let frame of this.stacktrace) {
+        result.appendChild(this._renderFrame(frame));
+      }
     }
 
     return this;
   },
 
   /**
    * Render a frame object received from the server.
    *
@@ -3544,25 +3546,32 @@ Widgets.Stacktrace.prototype = Heritage.
    *        properties: functionName, filename and lineNumber.
    * @return DOMElement
    *         The DOM element to display for the given frame.
    */
   _renderFrame: function(frame)
   {
     let fn = this.document.createElementNS(XHTML_NS, "span");
     fn.className = "function";
+
+    let asyncCause = "";
+    if (frame.asyncCause) {
+      asyncCause =
+        l10n.getFormatStr("stacktrace.asyncStack", [frame.asyncCause]) + " ";
+    }
+
     if (frame.functionName) {
       let span = this.document.createElementNS(XHTML_NS, "span");
       span.className = "cm-variable";
-      span.textContent = frame.functionName;
+      span.textContent = asyncCause + frame.functionName;
       fn.appendChild(span);
       fn.appendChild(this.document.createTextNode("()"));
     } else {
       fn.classList.add("cm-comment");
-      fn.textContent = l10n.getStr("stacktrace.anonymousFunction");
+      fn.textContent = asyncCause + l10n.getStr("stacktrace.anonymousFunction");
     }
 
     let location = this.output.owner.createLocationNode({url: frame.filename,
                                                         line: frame.lineNumber},
                                                         "jsdebugger");
 
     // .devtools-monospace sets font-size to 80%, however .body already has
     // .devtools-monospace. If we keep it here, the location would be rendered
--- a/devtools/client/webconsole/test/browser.ini
+++ b/devtools/client/webconsole/test/browser.ini
@@ -80,16 +80,17 @@ support-files =
   test-console-output-02.html
   test-console-output-03.html
   test-console-output-04.html
   test-console-output-dom-elements.html
   test-console-output-events.html
   test-console-output-regexp.html
   test-console-column.html
   test-consoleiframes.html
+  test-console-trace-async.html
   test-certificate-messages.html
   test-data.json
   test-data.json^headers^
   test-duplicate-error.html
   test-encoding-ISO-8859-1.html
   test-error.html
   test-eval-in-stackframe.html
   test-file-location.js
@@ -306,16 +307,17 @@ skip-if = e10s # Bug 1042253 - webconsol
 [browser_webconsole_clickable_urls.js]
 skip-if = e10s # Bug 1042253 - webconsole e10s tests (Linux debug timeout)
 [browser_webconsole_closure_inspection.js]
 skip-if = e10s # Bug 1042253 - webconsole tests disabled with e10s
 [browser_webconsole_completion.js]
 [browser_webconsole_console_extras.js]
 [browser_webconsole_console_logging_api.js]
 [browser_webconsole_console_logging_workers_api.js]
+[browser_webconsole_console_trace_async.js]
 [browser_webconsole_count.js]
 [browser_webconsole_dont_navigate_on_doubleclick.js]
 [browser_webconsole_execution_scope.js]
 [browser_webconsole_for_of.js]
 [browser_webconsole_history.js]
 [browser_webconsole_hpkp_invalid-headers.js]
 [browser_webconsole_hsts_invalid-headers.js]
 skip-if = buildapp == 'mulet' || e10s # Bug 1042253 - webconsole e10s tests
new file mode 100644
--- /dev/null
+++ b/devtools/client/webconsole/test/browser_webconsole_console_trace_async.js
@@ -0,0 +1,75 @@
+/* vim:set ts=2 sw=2 sts=2 et: */
+/* 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/. */
+
+"use strict";
+
+const TEST_URI = "http://example.com/browser/devtools/client/" +
+                 "webconsole/test/test-console-trace-async.html";
+
+add_task(function* runTest() {
+  // Async stacks aren't on by default in all builds
+  yield new Promise(resolve => {
+    SpecialPowers.pushPrefEnv({"set": [
+      ["javascript.options.asyncstack", true]
+    ]}, resolve);
+  });
+
+  let {tab} = yield loadTab("data:text/html;charset=utf8,<p>hello");
+  let hud = yield openConsole(tab);
+  BrowserTestUtils.loadURI(gBrowser.selectedBrowser, TEST_URI);
+
+  let [result] = yield waitForMessages({
+    webconsole: hud,
+    messages: [{
+      name: "console.trace output",
+      consoleTrace: {
+        file: "test-console-trace-async.html",
+        fn: "inner",
+      },
+    }],
+  });
+
+  let node = [...result.matched][0];
+  ok(node, "found trace log node");
+  ok(node.textContent.includes("console.trace()"),
+     "trace log node includes console.trace()");
+  ok(node.textContent.includes("promise callback"),
+     "trace log node includes promise callback");
+  ok(node.textContent.includes("setTimeout handler"),
+     "trace log node includes setTimeout handler");
+
+  // The expected stack trace object.
+  let stacktrace = [
+    {
+      columnNumber: 3,
+      filename: TEST_URI,
+      functionName: "inner",
+      language: 2,
+      lineNumber: 9
+    },
+    {
+      asyncCause: "promise callback",
+      columnNumber: 1,
+      filename: TEST_URI,
+      functionName: "time1",
+      language: 2,
+      lineNumber: 13,
+    },
+    {
+      asyncCause: "setTimeout handler",
+      columnNumber: 1,
+      filename: TEST_URI,
+      functionName: "",
+      language: 2,
+      lineNumber: 18,
+    }
+  ];
+
+  let obj = node._messageObject;
+  ok(obj, "console.trace message object");
+  ok(obj._stacktrace, "found stacktrace object");
+  is(obj._stacktrace.toSource(), stacktrace.toSource(),
+    "stacktrace is correct");
+});
new file mode 100644
--- /dev/null
+++ b/devtools/client/webconsole/test/test-console-trace-async.html
@@ -0,0 +1,24 @@
+<!DOCTYPE html>
+<html lang="en">
+  <head><meta charset="utf-8">
+    <title>Web Console test for bug 1200832 - console.trace() async stacks</title>
+    <!-- Any copyright is dedicated to the Public Domain.
+         http://creativecommons.org/publicdomain/zero/1.0/ -->
+<script type="application/javascript">
+function inner() {
+  console.trace();
+}
+
+function time1() {
+  new Promise(function(resolve, reject) {
+    setTimeout(resolve, 10);
+  }).then(inner);
+}
+
+setTimeout(time1, 10);
+</script>
+  </head>
+  <body>
+    <p>Web Console test for bug 1200832 - console.trace() async stacks</p>
+  </body>
+</html>
--- a/devtools/shared/webconsole/utils.js
+++ b/devtools/shared/webconsole/utils.js
@@ -1984,31 +1984,31 @@ ConsoleReflowListener.prototype =
    * @param DOMHighResTimeStamp aStart
    * @param DOMHighResTimeStamp aEnd
    * @param boolean aInterruptible
    */
   sendReflow: function CRL_sendReflow(aStart, aEnd, aInterruptible)
   {
     let frame = components.stack.caller.caller;
 
-    let filename = frame.filename;
+    let filename = frame ? frame.filename : null;
 
     if (filename) {
       // Because filename could be of the form "xxx.js -> xxx.js -> xxx.js",
       // we only take the last part.
       filename = filename.split(" ").pop();
     }
 
     this.listener.onReflowActivity({
       interruptible: aInterruptible,
       start: aStart,
       end: aEnd,
       sourceURL: filename,
-      sourceLine: frame.lineNumber,
-      functionName: frame.name
+      sourceLine: frame ? frame.lineNumber : null,
+      functionName: frame ? frame.name : null
     });
   },
 
   /**
    * On uninterruptible reflow
    *
    * @param DOMHighResTimeStamp aStart
    * @param DOMHighResTimeStamp aEnd
--- a/dom/base/Console.cpp
+++ b/dom/base/Console.cpp
@@ -930,16 +930,23 @@ StackFrameToStackEntry(nsIStackFrame* aS
   rv = aStackFrame->GetColumnNumber(&columnNumber);
   NS_ENSURE_SUCCESS(rv, rv);
 
   aStackEntry.mColumnNumber = columnNumber;
 
   rv = aStackFrame->GetName(aStackEntry.mFunctionName);
   NS_ENSURE_SUCCESS(rv, rv);
 
+  nsString cause;
+  rv = aStackFrame->GetAsyncCause(cause);
+  NS_ENSURE_SUCCESS(rv, rv);
+  if (!cause.IsEmpty()) {
+    aStackEntry.mAsyncCause.Construct(cause);
+  }
+
   aStackEntry.mLanguage = aLanguage;
   return NS_OK;
 }
 
 static
 nsresult
 ReifyStack(nsIStackFrame* aStack, nsTArray<ConsoleStackEntry>& aRefiedStack)
 {
@@ -955,16 +962,20 @@ ReifyStack(nsIStackFrame* aStack, nsTArr
       rv = StackFrameToStackEntry(stack, data, language);
       NS_ENSURE_SUCCESS(rv, rv);
     }
 
     nsCOMPtr<nsIStackFrame> caller;
     rv = stack->GetCaller(getter_AddRefs(caller));
     NS_ENSURE_SUCCESS(rv, rv);
 
+    if (!caller) {
+      rv = stack->GetAsyncCaller(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
--- a/dom/bindings/Exceptions.cpp
+++ b/dom/bindings/Exceptions.cpp
@@ -672,25 +672,18 @@ NS_IMETHODIMP JSStackFrame::GetCaller(ns
   bool canCache = false, useCachedValue = false;
   GetValueIfNotCached(cx, mStack, JS::GetSavedFrameParent, mCallerInitialized,
                       &canCache, &useCachedValue, &callerObj);
 
   if (useCachedValue) {
     return StackFrame::GetCaller(aCaller);
   }
 
-  nsCOMPtr<nsIStackFrame> caller;
-  if (callerObj) {
-      caller = new JSStackFrame(callerObj);
-  } else {
-    // Do we really need this dummy frame?  If so, we should document why... I
-    // guess for symmetry with the "nothing on the stack" case, which returns
-    // a single dummy frame?
-    caller = new StackFrame();
-  }
+  nsCOMPtr<nsIStackFrame> caller =
+    callerObj ? new JSStackFrame(callerObj) : nullptr;
   caller.forget(aCaller);
 
   if (canCache) {
     mCaller = *aCaller;
     mCallerInitialized = true;
   }
 
   return NS_OK;
--- a/dom/webidl/Console.webidl
+++ b/dom/webidl/Console.webidl
@@ -76,16 +76,17 @@ dictionary ConsoleProfileEvent {
 
 // This dictionary is used to manage stack trace data.
 dictionary ConsoleStackEntry {
   DOMString filename = "";
   unsigned long lineNumber = 0;
   unsigned long columnNumber = 0;
   DOMString functionName = "";
   unsigned long language = 0;
+  DOMString? asyncCause;
 };
 
 dictionary ConsoleTimerStart {
   DOMString name = "";
   double started = 0;
 };
 
 dictionary ConsoleTimerEnd {
--- a/js/xpconnect/tests/unit/test_callFunctionWithAsyncStack.js
+++ b/js/xpconnect/tests/unit/test_callFunctionWithAsyncStack.js
@@ -12,17 +12,17 @@ function run_test() {
 
   // asyncCause may contain non-ASCII characters.
   let testAsyncCause = "Tes" + String.fromCharCode(355) + "String";
 
   Components.utils.callFunctionWithAsyncStack(function asyncCallback() {
     let stack = Components.stack;
 
     do_check_eq(stack.name, "asyncCallback");
-    do_check_eq(stack.caller.name, null);
+    do_check_eq(stack.caller, null);
     do_check_eq(stack.asyncCause, null);
 
     do_check_eq(stack.asyncCaller.name, "getAsyncStack");
     do_check_eq(stack.asyncCaller.asyncCause, testAsyncCause);
     do_check_eq(stack.asyncCaller.asyncCaller, null);
 
     do_check_eq(stack.asyncCaller.caller.name, "run_test");
     do_check_eq(stack.asyncCaller.caller.asyncCause, null);