Bug 1072910 - TraceLogger: Create hooks for the debugger, r=bbouvier
authorHannes Verschore <hv1989@gmail.com>
Thu, 20 Nov 2014 17:44:02 +0100
changeset 247500 bad0e92bd0265f354a67a4e6d8724937346854df
parent 247499 dd75dcb78dc7e79c1e444afd75d76ef1e627b15c
child 247501 092b29ea64e08b6e9229173cae11343e63cbd52e
push id4489
push userraliiev@mozilla.com
push dateMon, 23 Feb 2015 15:17:55 +0000
treeherdermozilla-beta@fd7c3dc24146 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersbbouvier
bugs1072910
milestone37.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 1072910 - TraceLogger: Create hooks for the debugger, r=bbouvier
js/src/vm/Debugger.cpp
js/src/vm/Debugger.h
js/src/vm/TraceLogging.cpp
js/src/vm/TraceLogging.h
--- a/js/src/vm/Debugger.cpp
+++ b/js/src/vm/Debugger.cpp
@@ -362,17 +362,23 @@ Debugger::Debugger(JSContext *cx, Native
     trackingAllocationSites(false),
     allocationSamplingProbability(1.0),
     allocationsLogLength(0),
     maxAllocationsLogLength(DEFAULT_MAX_ALLOCATIONS_LOG_LENGTH),
     frames(cx->runtime()),
     scripts(cx),
     sources(cx),
     objects(cx),
-    environments(cx)
+    environments(cx),
+#ifdef NIGHTLY_BUILD
+    traceLoggerLastDrainedId(0),
+    traceLoggerLastDrainedIteration(0),
+#endif
+    traceLoggerScriptedCallsLastDrainedId(0),
+    traceLoggerScriptedCallsLastDrainedIteration(0)
 {
     assertSameCompartment(cx, dbg);
 
     cx->runtime()->debuggerList.insertBack(this);
     JS_INIT_CLIST(&breakpoints);
     JS_INIT_CLIST(&onNewGlobalObjectWatchersLink);
 }
 
@@ -3752,16 +3758,28 @@ Debugger::makeGlobalObjectReference(JSCo
     Rooted<GlobalObject *> global(cx, dbg->unwrapDebuggeeArgument(cx, args[0]));
     if (!global)
         return false;
 
     args.rval().setObject(*global);
     return dbg->wrapDebuggeeValue(cx, args.rval());
 }
 
+static bool
+DefineProperty(JSContext *cx, HandleObject obj, HandleId id, const char *value, size_t n)
+{
+    JSString *text = JS_NewStringCopyN(cx, value, n);
+    if (!text)
+        return false;
+
+    RootedValue str(cx, StringValue(text));
+    return JS_DefinePropertyById(cx, obj, id, str, JSPROP_ENUMERATE);
+}
+
+#ifdef NIGHTLY_BUILD
 bool
 Debugger::setupTraceLogger(JSContext *cx, unsigned argc, Value *vp)
 {
     THIS_DEBUGGER(cx, argc, vp, "setupTraceLogger", args, dbg);
     if (!args.requireAtLeast(cx, "Debugger.setupTraceLogger", 1))
         return false;
 
     RootedObject obj(cx, ToObject(cx, args[0]));
@@ -3820,16 +3838,179 @@ Debugger::setupTraceLogger(JSContext *cx
         else
             TraceLogDisableTextId(cx, textIds[i]);
     }
 
     args.rval().setBoolean(true);
     return true;
 }
 
+bool
+Debugger::drainTraceLogger(JSContext *cx, unsigned argc, Value *vp)
+{
+    THIS_DEBUGGER(cx, argc, vp, "drainTraceLogger", args, dbg);
+    if (!args.requireAtLeast(cx, "Debugger.drainTraceLogger", 0))
+        return false;
+
+    size_t num;
+    TraceLoggerThread *logger = TraceLoggerForMainThread(cx->runtime());
+    bool lostEvents = logger->lostEvents(dbg->traceLoggerLastDrainedIteration,
+                                         dbg->traceLoggerLastDrainedId);
+    EventEntry *events = logger->getEventsStartingAt(&dbg->traceLoggerLastDrainedIteration,
+                                                     &dbg->traceLoggerLastDrainedId,
+                                                     &num);
+
+    RootedObject array(cx, NewDenseEmptyArray(cx));
+    JSAtom *dataAtom = Atomize(cx, "data", strlen("data"));
+    if (!dataAtom)
+        return false;
+    RootedId dataId(cx, AtomToId(dataAtom));
+
+    /* Add all events to the array. */
+    uint32_t index = 0;
+    for (EventEntry *eventItem = events; eventItem < events + num; eventItem++, index++) {
+        RootedObject item(cx, NewObjectWithGivenProto(cx, &PlainObject::class_, nullptr, cx->global()));
+        if (!item)
+            return false;
+
+        const char *eventText = logger->eventText(eventItem->textId);
+        if (!DefineProperty(cx, item, dataId, eventText, strlen(eventText)))
+            return false;
+
+        RootedValue obj(cx, ObjectValue(*item));
+        if (!JS_DefineElement(cx, array, index, obj, JSPROP_ENUMERATE))
+            return false;
+    }
+
+    /* Add "lostEvents" indicating if there are events that were lost. */
+    RootedValue lost(cx, BooleanValue(lostEvents));
+    if (!JS_DefineProperty(cx, array, "lostEvents", lost, JSPROP_ENUMERATE))
+        return false;
+
+    args.rval().setObject(*array);
+
+    return true;
+}
+#endif
+
+bool
+Debugger::setupTraceLoggerScriptCalls(JSContext *cx, unsigned argc, Value *vp)
+{
+    THIS_DEBUGGER(cx, argc, vp, "setupTraceLoggerScriptCalls", args, dbg);
+    if (!args.requireAtLeast(cx, "Debugger.setupTraceLoggerScriptCalls", 0))
+        return false;
+
+    TraceLogEnableTextId(cx, TraceLogger_Scripts);
+
+    args.rval().setBoolean(true);
+
+    return true;
+}
+
+bool
+Debugger::startTraceLogger(JSContext *cx, unsigned argc, Value *vp)
+{
+    THIS_DEBUGGER(cx, argc, vp, "startTraceLogger", args, dbg);
+    if (!args.requireAtLeast(cx, "Debugger.startTraceLogger", 0))
+        return false;
+
+    TraceLoggerThread *logger = TraceLoggerForMainThread(cx->runtime());
+    TraceLoggerEnable(logger, cx);
+
+    args.rval().setUndefined();
+
+    return true;
+}
+
+bool
+Debugger::endTraceLogger(JSContext *cx, unsigned argc, Value *vp)
+{
+    THIS_DEBUGGER(cx, argc, vp, "endTraceLogger", args, dbg);
+    if (!args.requireAtLeast(cx, "Debugger.endTraceLogger", 0))
+        return false;
+
+    TraceLoggerThread *logger = TraceLoggerForMainThread(cx->runtime());
+    TraceLoggerDisable(logger);
+
+    args.rval().setUndefined();
+
+    return true;
+}
+
+bool
+Debugger::drainTraceLoggerScriptCalls(JSContext *cx, unsigned argc, Value *vp)
+{
+    THIS_DEBUGGER(cx, argc, vp, "drainTraceLoggerScriptCalls", args, dbg);
+    if (!args.requireAtLeast(cx, "Debugger.drainTraceLoggerScriptCalls", 0))
+        return false;
+
+    size_t num;
+    TraceLoggerThread *logger = TraceLoggerForMainThread(cx->runtime());
+    bool lostEvents = logger->lostEvents(dbg->traceLoggerScriptedCallsLastDrainedIteration,
+                                         dbg->traceLoggerScriptedCallsLastDrainedId);
+    EventEntry *events = logger->getEventsStartingAt(
+                                         &dbg->traceLoggerScriptedCallsLastDrainedIteration,
+                                         &dbg->traceLoggerScriptedCallsLastDrainedId,
+                                         &num);
+
+    RootedObject array(cx, NewDenseEmptyArray(cx));
+    RootedId fileNameId(cx, AtomToId(cx->names().fileName));
+    RootedId lineNumberId(cx, AtomToId(cx->names().lineNumber));
+    RootedId columnNumberId(cx, AtomToId(cx->names().columnNumber));
+    JSAtom *logTypeAtom = Atomize(cx, "logType", strlen("logType"));
+    if (!logTypeAtom)
+        return false;
+    RootedId logTypeId(cx, AtomToId(logTypeAtom));
+
+    /* Add all events to the array. */
+    uint32_t index = 0;
+    for (EventEntry *eventItem = events; eventItem < events + num; eventItem++) {
+        RootedObject item(cx, NewObjectWithGivenProto(cx, &PlainObject::class_, nullptr, cx->global()));
+        if (!item)
+            return false;
+
+        uint32_t textId = eventItem->textId;
+        if (textId != TraceLogger_Stop && !logger->textIdIsScriptEvent(textId))
+            continue;
+
+        const char *type = (textId == TraceLogger_Stop) ? "Stop" : "Script";
+        if (!DefineProperty(cx, item, logTypeId, type, strlen(type)))
+            return false;
+
+        if (textId != TraceLogger_Stop) {
+            const char *filename, *lineno, *colno;
+            size_t filename_len, lineno_len, colno_len;
+            logger->extractScriptDetails(textId, &filename, &filename_len, &lineno, &lineno_len,
+                                         &colno, &colno_len);
+
+            if (!DefineProperty(cx, item, fileNameId, filename, filename_len))
+                return false;
+            if (!DefineProperty(cx, item, lineNumberId, lineno, lineno_len))
+                return false;
+            if (!DefineProperty(cx, item, columnNumberId, colno, colno_len))
+                return false;
+        }
+
+        RootedValue obj(cx, ObjectValue(*item));
+        if (!JS_DefineElement(cx, array, index, obj, JSPROP_ENUMERATE))
+            return false;
+
+        index++;
+    }
+
+    /* Add "lostEvents" indicating if there are events that were lost. */
+    RootedValue lost(cx, BooleanValue(lostEvents));
+    if (!JS_DefineProperty(cx, array, "lostEvents", lost, JSPROP_ENUMERATE))
+        return false;
+
+    args.rval().setObject(*array);
+
+    return true;
+}
+
 const JSPropertySpec Debugger::properties[] = {
     JS_PSGS("enabled", Debugger::getEnabled, Debugger::setEnabled, 0),
     JS_PSGS("onDebuggerStatement", Debugger::getOnDebuggerStatement,
             Debugger::setOnDebuggerStatement, 0),
     JS_PSGS("onExceptionUnwind", Debugger::getOnExceptionUnwind,
             Debugger::setOnExceptionUnwind, 0),
     JS_PSGS("onNewScript", Debugger::getOnNewScript, Debugger::setOnNewScript, 0),
     JS_PSGS("onNewPromise", Debugger::getOnNewPromise, Debugger::setOnNewPromise, 0),
@@ -3849,17 +4030,24 @@ const JSFunctionSpec Debugger::methods[]
     JS_FN("hasDebuggee", Debugger::hasDebuggee, 1, 0),
     JS_FN("getDebuggees", Debugger::getDebuggees, 0, 0),
     JS_FN("getNewestFrame", Debugger::getNewestFrame, 0, 0),
     JS_FN("clearAllBreakpoints", Debugger::clearAllBreakpoints, 0, 0),
     JS_FN("findScripts", Debugger::findScripts, 1, 0),
     JS_FN("findObjects", Debugger::findObjects, 1, 0),
     JS_FN("findAllGlobals", Debugger::findAllGlobals, 0, 0),
     JS_FN("makeGlobalObjectReference", Debugger::makeGlobalObjectReference, 1, 0),
+    JS_FN("setupTraceLoggerScriptCalls", Debugger::setupTraceLoggerScriptCalls, 0, 0),
+    JS_FN("drainTraceLoggerScriptCalls", Debugger::drainTraceLoggerScriptCalls, 0, 0),
+    JS_FN("startTraceLogger", Debugger::startTraceLogger, 0, 0),
+    JS_FN("endTraceLogger", Debugger::endTraceLogger, 0, 0),
+#ifdef NIGHTLY_BUILD
     JS_FN("setupTraceLogger", Debugger::setupTraceLogger, 1, 0),
+    JS_FN("drainTraceLogger", Debugger::drainTraceLogger, 0, 0),
+#endif
     JS_FS_END
 };
 
 
 /*** Debugger.Script *****************************************************************************/
 
 static inline JSScript *
 GetScriptReferent(JSObject *obj)
--- a/js/src/vm/Debugger.h
+++ b/js/src/vm/Debugger.h
@@ -302,16 +302,27 @@ class Debugger : private mozilla::Linked
 
     /* The map from debuggee objects to their Debugger.Object instances. */
     typedef DebuggerWeakMap<JSObject*> ObjectWeakMap;
     ObjectWeakMap objects;
 
     /* The map from debuggee Envs to Debugger.Environment instances. */
     ObjectWeakMap environments;
 
+    /*
+     * Keep track of tracelogger last drained identifiers to know if there are
+     * lost events.
+     */
+#ifdef NIGHTLY_BUILD
+    uint32_t traceLoggerLastDrainedId;
+    uint32_t traceLoggerLastDrainedIteration;
+#endif
+    uint32_t traceLoggerScriptedCallsLastDrainedId;
+    uint32_t traceLoggerScriptedCallsLastDrainedIteration;
+
     class FrameRange;
     class ScriptQuery;
     class ObjectQuery;
 
     bool addDebuggeeGlobal(JSContext *cx, Handle<GlobalObject*> obj);
     void removeDebuggeeGlobal(FreeOp *fop, GlobalObject *global, GlobalObjectSet::Enum *debugEnum);
 
     /*
@@ -400,17 +411,24 @@ class Debugger : private mozilla::Linked
     static bool hasDebuggee(JSContext *cx, unsigned argc, Value *vp);
     static bool getDebuggees(JSContext *cx, unsigned argc, Value *vp);
     static bool getNewestFrame(JSContext *cx, unsigned argc, Value *vp);
     static bool clearAllBreakpoints(JSContext *cx, unsigned argc, Value *vp);
     static bool findScripts(JSContext *cx, unsigned argc, Value *vp);
     static bool findObjects(JSContext *cx, unsigned argc, Value *vp);
     static bool findAllGlobals(JSContext *cx, unsigned argc, Value *vp);
     static bool makeGlobalObjectReference(JSContext *cx, unsigned argc, Value *vp);
+    static bool setupTraceLoggerScriptCalls(JSContext *cx, unsigned argc, Value *vp);
+    static bool drainTraceLoggerScriptCalls(JSContext *cx, unsigned argc, Value *vp);
+    static bool startTraceLogger(JSContext *cx, unsigned argc, Value *vp);
+    static bool endTraceLogger(JSContext *cx, unsigned argc, Value *vp);
+#ifdef NIGHTLY_BUILD
     static bool setupTraceLogger(JSContext *cx, unsigned argc, Value *vp);
+    static bool drainTraceLogger(JSContext *cx, unsigned argc, Value *vp);
+#endif
     static bool construct(JSContext *cx, unsigned argc, Value *vp);
     static const JSPropertySpec properties[];
     static const JSFunctionSpec methods[];
 
     static bool getNewestAbstractFramePtr(JSContext *cx);
     static bool updateExecutionObservabilityOfFrames(JSContext *cx, const ExecutionObservableSet &obs,
                                                      IsObserving observing);
     static bool updateExecutionObservabilityOfScripts(JSContext *cx, const ExecutionObservableSet &obs,
--- a/js/src/vm/TraceLogging.cpp
+++ b/js/src/vm/TraceLogging.cpp
@@ -92,16 +92,17 @@ class AutoTraceLoggerThreadStateLock
   private:
     MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER
 };
 
 TraceLoggerThread::TraceLoggerThread()
   : enabled(0),
     failed(false),
     graph(),
+    iteration_(0),
     top(nullptr)
 { }
 
 bool
 TraceLoggerThread::init()
 {
     if (!pointerMap.init())
         return false;
@@ -247,22 +248,68 @@ TraceLoggerThread::disable()
 
     logTimestamp(TraceLogger_Disable);
     enabled = 0;
 
     return true;
 }
 
 const char *
-TraceLoggerThread::eventText(uint32_t id) {
+TraceLoggerThread::eventText(uint32_t id)
+{
     if (id < TraceLogger_Last)
         return TLTextIdString(static_cast<TraceLoggerTextId>(id));
     return extraTextId[id - TraceLogger_Last];
 }
 
+bool
+TraceLoggerThread::textIdIsScriptEvent(uint32_t id)
+{
+    if (id < TraceLogger_Last)
+        return false;
+
+    // Currently this works by checking if text begins with "script".
+    const char *str = eventText(id);
+    return EqualChars(str, "script", 6);
+}
+
+void
+TraceLoggerThread::extractScriptDetails(uint32_t textId, const char **filename, size_t *filename_len,
+                                        const char **lineno, size_t *lineno_len, const char **colno,
+                                        size_t *colno_len)
+{
+    MOZ_ASSERT(textIdIsScriptEvent(textId));
+
+    const char *script = eventText(textId);
+
+    // Get the start of filename (remove 'script ' at the start).
+    MOZ_ASSERT(EqualChars(script, "script ", 7));
+    *filename = script + 7;
+
+    // Get the start of lineno and colno.
+    *lineno = script;
+    *colno = script;
+    const char *next = script - 1;
+    while ((next = strchr(next + 1, ':'))) {
+        *lineno = *colno;
+        *colno = next;
+    }
+
+    MOZ_ASSERT(*lineno && *lineno != script);
+    MOZ_ASSERT(*colno && *colno != script);
+
+    // Remove the ':' at the front.
+    *lineno = *lineno + 1;
+    *colno = *colno + 1;
+
+    *filename_len = *lineno - *filename - 1;
+    *lineno_len = *colno - *lineno - 1;
+    *colno_len = strlen(*colno);
+}
+
 uint32_t
 TraceLoggerThread::createTextId(const char *text)
 {
     assertNoQuotes(text);
 
     PointerHashMap::AddPtr p = pointerMap.lookupForAdd((const void *)text);
     if (p)
         return p->value();
@@ -377,16 +424,17 @@ TraceLoggerThread::logTimestamp(uint32_t
         return;
 
     if (!events.ensureSpaceBeforeAdd()) {
         uint64_t start = rdtsc() - traceLoggers.startupTime;
 
         if (graph.get())
             graph->log(events);
 
+        iteration_++;
         events.clear();
 
         // Log the time it took to flush the events as being from the
         // Tracelogger.
         if (graph.get()) {
             MOZ_ASSERT(events.capacity() > 2);
             EventEntry &entryStart = events.pushUninitialized();
             entryStart.time = start;
--- a/js/src/vm/TraceLogging.h
+++ b/js/src/vm/TraceLogging.h
@@ -80,31 +80,76 @@ class TraceLoggerThread
 
     mozilla::UniquePtr<TraceLoggerGraph> graph;
 
     PointerHashMap pointerMap;
     Vector<char *, 0, js::SystemAllocPolicy> extraTextId;
 
     ContinuousSpace<EventEntry> events;
 
+    // Every time the events get flushed, this count is increased by one.
+    // This together with events.lastEntryId(), gives an unique position.
+    uint32_t iteration_;
+
   public:
     AutoTraceLog *top;
 
     TraceLoggerThread();
     bool init();
     ~TraceLoggerThread();
 
     bool init(uint32_t loggerId);
     void initGraph();
 
     bool enable();
     bool enable(JSContext *cx);
     bool disable();
 
+    // Given the previous iteration and lastEntryId, return an array of events
+    // (there could be lost events). At the same time update the iteration and
+    // lastEntry and gives back how many events there are.
+    EventEntry *getEventsStartingAt(uint32_t *lastIteration, uint32_t *lastEntryId, size_t *num) {
+        EventEntry *start;
+        if (iteration_ == *lastIteration) {
+            MOZ_ASSERT(events.lastEntryId() >= *lastEntryId);
+            *num = events.lastEntryId() - *lastEntryId;
+            start = events.data() + *lastEntryId + 1;
+        } else {
+            *num = events.lastEntryId() + 1;
+            start = events.data();
+        }
+
+        *lastIteration = iteration_;
+        *lastEntryId = events.lastEntryId();
+        return start;
+    }
+
+    // Extract the details filename, lineNumber and columnNumber out of a event
+    // containing script information.
+    void extractScriptDetails(uint32_t textId, const char **filename, size_t *filename_len,
+                              const char **lineno, size_t *lineno_len, const char **colno,
+                              size_t *colno_len);
+
+    bool lostEvents(uint32_t lastIteration, uint32_t lastEntryId) {
+        // If still logging in the same iteration, there are no lost events.
+        if (lastIteration == iteration_) {
+            MOZ_ASSERT(lastEntryId <= events.lastEntryId());
+            return false;
+        }
+
+        // When proceeded to the next iteration and lastEntryId points to
+        // the maximum capacity there are no logs that are lost.
+        if (lastIteration + 1 == iteration_ && lastEntryId == events.capacity())
+            return false;
+
+        return true;
+    }
+
     const char *eventText(uint32_t id);
+    bool textIdIsScriptEvent(uint32_t id);
 
     // The createTextId functions map a unique input to a logger ID.
     // This can be used to give start and stop events. Calls to these functions should be
     // limited if possible, because of the overhead.
     // Note: it is not allowed to use them in logTimestamp.
     uint32_t createTextId(const char *text);
     uint32_t createTextId(JSScript *script);
     uint32_t createTextId(const JS::ReadOnlyCompileOptions &script);