Bug 1160307 - capture async stack frames on Javascript timeline markers. r=fitzgen, r=smaug r=Paolo

This commit is contained in:
Tom Tromey 2015-11-05 11:31:00 +01:00
parent c35fa2fa77
commit 358f546a3b
16 changed files with 199 additions and 22 deletions

View File

@ -13885,7 +13885,9 @@ void
nsDocShell::NotifyJSRunToCompletionStart(const char* aReason,
const char16_t* aFunctionName,
const char16_t* aFilename,
const uint32_t aLineNumber)
const uint32_t aLineNumber,
JS::Handle<JS::Value> aAsyncStack,
JS::Handle<JS::Value> aAsyncCause)
{
// If first start, mark interval start.
if (mJSRunToCompletionDepth == 0) {
@ -13893,7 +13895,8 @@ nsDocShell::NotifyJSRunToCompletionStart(const char* aReason,
if (timelines && timelines->HasConsumer(this)) {
timelines->AddMarkerForDocShell(this, Move(
MakeUnique<JavascriptTimelineMarker>(
aReason, aFunctionName, aFilename, aLineNumber, MarkerTracingType::START)));
aReason, aFunctionName, aFilename, aLineNumber, MarkerTracingType::START,
aAsyncStack, aAsyncCause)));
}
}

View File

@ -43,7 +43,7 @@ interface nsITabParent;
typedef unsigned long nsLoadFlags;
[scriptable, builtinclass, uuid(539bce70-8261-462f-bbd0-40ee90b7d636)]
[scriptable, builtinclass, uuid(9f2babc4-4c2a-4cf7-929f-a1efc325b0df)]
interface nsIDocShell : nsIDocShellTreeItem
{
/**
@ -1048,7 +1048,9 @@ interface nsIDocShell : nsIDocShellTreeItem
[noscript,notxpcom,nostdcall] void notifyJSRunToCompletionStart(in string aReason,
in wstring functionName,
in wstring fileName,
in unsigned long lineNumber);
in unsigned long lineNumber,
in jsval asyncStack,
in jsval asyncCause);
[noscript,notxpcom,nostdcall] void notifyJSRunToCompletionStop();
/**

View File

@ -21,13 +21,21 @@ public:
const char16_t* aFunctionName,
const char16_t* aFileName,
uint32_t aLineNumber,
MarkerTracingType aTracingType)
MarkerTracingType aTracingType,
JS::Handle<JS::Value> aAsyncStack,
JS::Handle<JS::Value> aAsyncCause)
: TimelineMarker("Javascript", aTracingType, MarkerStackRequest::NO_STACK)
, mCause(NS_ConvertUTF8toUTF16(aReason))
, mFunctionName(aFunctionName)
, mFileName(aFileName)
, mLineNumber(aLineNumber)
{}
{
JSContext* ctx = nsContentUtils::GetCurrentJSContext();
if (ctx) {
mAsyncStack.init(ctx, aAsyncStack);
mAsyncCause.init(ctx, aAsyncCause);
}
}
virtual void AddDetails(JSContext* aCx, dom::ProfileTimelineMarker& aMarker) override
{
@ -41,6 +49,18 @@ public:
stackFrame.mSource.Construct(mFileName);
stackFrame.mFunctionDisplayName.Construct(mFunctionName);
if (mAsyncStack.isObject() && !mAsyncStack.isNullOrUndefined() &&
mAsyncCause.isString()) {
JS::Rooted<JSObject*> asyncStack(aCx, mAsyncStack.toObjectOrNull());
JS::Rooted<JSString*> asyncCause(aCx, mAsyncCause.toString());
JS::Rooted<JSObject*> parentFrame(aCx);
if (!JS::CopyAsyncStack(aCx, asyncStack, asyncCause, &parentFrame, 0)) {
JS_ClearPendingException(aCx);
} else {
stackFrame.mAsyncParent = parentFrame;
}
}
JS::Rooted<JS::Value> newStack(aCx);
if (ToJSValue(aCx, stackFrame, &newStack)) {
if (newStack.isObject()) {
@ -57,6 +77,8 @@ private:
nsString mFunctionName;
nsString mFileName;
uint32_t mLineNumber;
JS::PersistentRooted<JS::Value> mAsyncStack;
JS::PersistentRooted<JS::Value> mAsyncCause;
};
} // namespace mozilla

View File

@ -31,4 +31,50 @@ var TESTS = [{
}
}];
if (Services.prefs.getBoolPref("javascript.options.asyncstack")) {
TESTS.push({
desc: "Async stack trace on Javascript marker",
searchFor: (markers) => {
return markers.some(m => (m.name == "Javascript" &&
m.causeName == "promise callback"));
},
setup: function(docShell) {
content.dispatchEvent(new content.Event("promisetest"));
},
check: function(markers) {
markers = markers.filter(m => (m.name == "Javascript" &&
m.causeName == "promise callback"));
ok(markers.length > 0, "Found a Javascript marker");
let frame = markers[0].stack;
ok(frame.asyncParent !== null, "Parent frame has async parent");
is(frame.asyncParent.asyncCause, "promise callback",
"Async parent has correct cause");
is(frame.asyncParent.functionDisplayName, "do_promise",
"Async parent has correct function name");
}
}, {
desc: "Async stack trace on Javascript marker with script",
searchFor: (markers) => {
return markers.some(m => (m.name == "Javascript" &&
m.causeName == "promise callback"));
},
setup: function(docShell) {
content.dispatchEvent(new content.Event("promisescript"));
},
check: function(markers) {
markers = markers.filter(m => (m.name == "Javascript" &&
m.causeName == "promise callback"));
ok(markers.length > 0, "Found a Javascript marker");
let frame = markers[0].stack;
ok(frame.asyncParent !== null, "Parent frame has async parent");
is(frame.asyncParent.asyncCause, "promise callback",
"Async parent has correct cause");
is(frame.asyncParent.functionDisplayName, "do_promise_script",
"Async parent has correct function name");
}
});
}
timelineContentTest(TESTS);

View File

@ -21,6 +21,33 @@
}
window.addEventListener("dog", do_xhr, true);
function do_promise() {
new Promise(function(resolve, reject) {
console.time("Bob");
window.setTimeout(function() {
resolve(23);
}, 10);
}).then(function (val) {
console.timeEnd("Bob");
});
}
window.addEventListener("promisetest", do_promise, true);
var globalResolver;
function do_promise_script() {
new Promise(function(resolve, reject) {
console.time("Bob");
globalResolver = resolve;
window.setTimeout("globalResolver(23);", 10);
}).then(function (val) {
console.timeEnd("Bob");
});
}
window.addEventListener("promisescript", do_promise_script, true);
</script>
</body>

View File

@ -564,7 +564,8 @@ AutoEntryScript::DocshellEntryMonitor::DocshellEntryMonitor(JSContext* aCx,
void
AutoEntryScript::DocshellEntryMonitor::Entry(JSContext* aCx, JSFunction* aFunction,
JSScript* aScript)
JSScript* aScript, JS::Handle<JS::Value> aAsyncStack,
JS::Handle<JSString*> aAsyncCause)
{
JS::Rooted<JSFunction*> rootedFunction(aCx);
if (aFunction) {
@ -609,10 +610,13 @@ AutoEntryScript::DocshellEntryMonitor::Entry(JSContext* aCx, JSFunction* aFuncti
const char16_t* functionNameChars = functionName.isTwoByte() ?
functionName.twoByteChars() : nullptr;
JS::Rooted<JS::Value> asyncCauseValue(aCx, aAsyncCause ? StringValue(aAsyncCause) :
JS::NullValue());
docShellForJSRunToCompletion->NotifyJSRunToCompletionStart(mReason,
functionNameChars,
filename.BeginReading(),
lineNumber);
lineNumber, aAsyncStack,
asyncCauseValue);
}
}

View File

@ -349,20 +349,26 @@ private:
public:
DocshellEntryMonitor(JSContext* aCx, const char* aReason);
void Entry(JSContext* aCx, JSFunction* aFunction) override
void Entry(JSContext* aCx, JSFunction* aFunction,
JS::Handle<JS::Value> aAsyncStack,
JS::Handle<JSString*> aAsyncCause) override
{
Entry(aCx, aFunction, nullptr);
Entry(aCx, aFunction, nullptr, aAsyncStack, aAsyncCause);
}
void Entry(JSContext* aCx, JSScript* aScript) override
void Entry(JSContext* aCx, JSScript* aScript,
JS::Handle<JS::Value> aAsyncStack,
JS::Handle<JSString*> aAsyncCause) override
{
Entry(aCx, nullptr, aScript);
Entry(aCx, nullptr, aScript, aAsyncStack, aAsyncCause);
}
void Exit(JSContext* aCx) override;
private:
void Entry(JSContext* aCx, JSFunction* aFunction, JSScript* aScript);
void Entry(JSContext* aCx, JSFunction* aFunction, JSScript* aScript,
JS::Handle<JS::Value> aAsyncStack,
JS::Handle<JSString*> aAsyncCause);
const char* mReason;
};

View File

@ -15,7 +15,7 @@ dictionary ProfileTimelineStackFrame {
DOMString functionDisplayName;
object? parent = null;
object? asyncParent = null;
object? asyncCause = null;
DOMString asyncCause;
};
dictionary ProfileTimelineLayerRect {

View File

@ -359,12 +359,16 @@ class MOZ_STACK_CLASS AutoEntryMonitor {
// We have begun executing |function|. Note that |function| may not be the
// actual closure we are running, but only the canonical function object to
// which the script refers.
virtual void Entry(JSContext* cx, JSFunction* function) = 0;
virtual void Entry(JSContext* cx, JSFunction* function,
HandleValue asyncStack,
HandleString asyncCause) = 0;
// Execution has begun at the entry point of |script|, which is not a
// function body. (This is probably being executed by 'eval' or some
// JSAPI equivalent.)
virtual void Entry(JSContext* cx, JSScript* script) = 0;
virtual void Entry(JSContext* cx, JSScript* script,
HandleValue asyncStack,
HandleString asyncCause) = 0;
// Execution of the function or script has ended.
virtual void Exit(JSContext* cx) { }

View File

@ -89,6 +89,7 @@
#include "vm/Interpreter-inl.h"
#include "vm/NativeObject-inl.h"
#include "vm/SavedStacks-inl.h"
#include "vm/String-inl.h"
using namespace js;
@ -6198,6 +6199,22 @@ JS::CaptureCurrentStack(JSContext* cx, JS::MutableHandleObject stackp, unsigned
return true;
}
JS_PUBLIC_API(bool)
JS::CopyAsyncStack(JSContext* cx, JS::HandleObject asyncStack,
JS::HandleString asyncCause, JS::MutableHandleObject stackp,
unsigned maxFrameCount)
{
js::AssertObjectIsSavedFrameOrWrapper(cx, asyncStack);
JSCompartment* compartment = cx->compartment();
MOZ_ASSERT(compartment);
Rooted<SavedFrame*> frame(cx);
if (!compartment->savedStacks().copyAsyncStack(cx, asyncStack, asyncCause,
&frame, maxFrameCount))
return false;
stackp.set(frame.get());
return true;
}
JS_PUBLIC_API(Zone*)
JS::GetObjectZone(JSObject* obj)
{

View File

@ -5486,6 +5486,25 @@ SetOutOfMemoryCallback(JSRuntime* rt, OutOfMemoryCallback cb, void* data);
extern JS_PUBLIC_API(bool)
CaptureCurrentStack(JSContext* cx, MutableHandleObject stackp, unsigned maxFrameCount = 0);
/*
* This is a utility function for preparing an async stack to be used
* by some other object. This may be used when you need to treat a
* given stack trace as an async parent. If you just need to capture
* the current stack, async parents and all, use CaptureCurrentStack
* instead.
*
* Here |asyncStack| is the async stack to prepare. It is copied into
* |cx|'s current compartment, and the newest frame is given
* |asyncCause| as its asynchronous cause. If |maxFrameCount| is
* non-zero, capture at most the youngest |maxFrameCount| frames. The
* new stack object is written to |stackp|. Returns true on success,
* or sets an exception and returns |false| on error.
*/
extern JS_PUBLIC_API(bool)
CopyAsyncStack(JSContext* cx, HandleObject asyncStack,
HandleString asyncCause, MutableHandleObject stackp,
unsigned maxFrameCount);
/*
* Accessors for working with SavedFrame JSObjects
*

View File

@ -4416,7 +4416,8 @@ class ShellAutoEntryMonitor : JS::dbg::AutoEntryMonitor {
MOZ_ASSERT(!enteredWithoutExit);
}
void Entry(JSContext* cx, JSFunction* function) override {
void Entry(JSContext* cx, JSFunction* function, JS::HandleValue asyncStack,
JS::HandleString asyncCause) override {
MOZ_ASSERT(!enteredWithoutExit);
enteredWithoutExit = true;
@ -4430,7 +4431,8 @@ class ShellAutoEntryMonitor : JS::dbg::AutoEntryMonitor {
oom = !log.append(make_string_copy("anonymous"));
}
void Entry(JSContext* cx, JSScript* script) override {
void Entry(JSContext* cx, JSScript* script, JS::HandleValue asyncStack,
JS::HandleString asyncCause) override {
MOZ_ASSERT(!enteredWithoutExit);
enteredWithoutExit = true;

View File

@ -1017,6 +1017,21 @@ SavedStacks::saveCurrentStack(JSContext* cx, MutableHandleSavedFrame frame, unsi
return insertFrames(cx, iter, frame, maxFrameCount);
}
bool
SavedStacks::copyAsyncStack(JSContext* cx, HandleObject asyncStack, HandleString asyncCause,
MutableHandleSavedFrame adoptedStack, unsigned maxFrameCount)
{
MOZ_ASSERT(initialized());
assertSameCompartment(cx, this);
RootedObject asyncStackObj(cx, CheckedUnwrap(asyncStack));
MOZ_ASSERT(asyncStackObj);
MOZ_ASSERT(js::SavedFrame::isSavedFrameAndNotProto(*asyncStackObj));
RootedSavedFrame frame(cx, &asyncStackObj->as<js::SavedFrame>());
return adoptAsyncStack(cx, frame, asyncCause, adoptedStack, maxFrameCount);
}
void
SavedStacks::sweep(JSRuntime* rt)
{

View File

@ -164,6 +164,8 @@ class SavedStacks {
bool init();
bool initialized() const { return frames.initialized(); }
bool saveCurrentStack(JSContext* cx, MutableHandleSavedFrame frame, unsigned maxFrameCount = 0);
bool copyAsyncStack(JSContext* cx, HandleObject asyncStack, HandleString asyncCause,
MutableHandleSavedFrame adoptedStack, unsigned maxFrameCount = 0);
void sweep(JSRuntime* rt);
void trace(JSTracer* trc);
uint32_t count();

View File

@ -971,10 +971,14 @@ InterpreterActivation::InterpreterActivation(RunState& state, JSContext* cx,
MOZ_ASSERT_IF(entryFrame_->isEvalFrame(), state.script()->isActiveEval());
if (entryMonitor_) {
RootedValue stack(cx_);
stack.setObjectOrNull(asyncStack_.get());
if (!cx_->compartment()->wrap(cx_, &stack))
stack.setUndefined();
if (entryFrame->isFunctionFrame())
entryMonitor_->Entry(cx_, entryFrame->fun());
entryMonitor_->Entry(cx_, entryFrame->fun(), stack, asyncCause_);
else
entryMonitor_->Entry(cx_, entryFrame->script());
entryMonitor_->Entry(cx_, entryFrame->script(), stack, asyncCause_);
}
}

View File

@ -1498,10 +1498,14 @@ jit::JitActivation::JitActivation(JSContext* cx, CalleeToken entryPoint, bool ac
if (entryMonitor_) {
MOZ_ASSERT(entryPoint);
RootedValue stack(cx_);
stack.setObjectOrNull(asyncStack_.get());
if (!cx_->compartment()->wrap(cx_, &stack))
stack.setUndefined();
if (CalleeTokenIsFunction(entryPoint))
entryMonitor_->Entry(cx_, CalleeTokenToFunction(entryPoint));
entryMonitor_->Entry(cx_, CalleeTokenToFunction(entryPoint), stack, asyncCause_);
else
entryMonitor_->Entry(cx_, CalleeTokenToScript(entryPoint));
entryMonitor_->Entry(cx_, CalleeTokenToScript(entryPoint), stack, asyncCause_);
}
}