(This also includes making a difference between "Script start/stop" en "Script annotation". E.g. we currently annotate IonMonkey compilation with the script. But for Debugger we only want the "Script start/stop" messages).

(In reply to Hannes Verschore [:h4writer] from comment #1) > [F]or Debugger we only want the "Script start/stop" messages). Do we? ISTM that having IonMonkey compilation events exposed to devtools could be very nice for perf analysis tools.

(In reply to Till Schneidereit [:till] from comment #2) > (In reply to Hannes Verschore [:h4writer] from comment #1) > > [F]or Debugger we only want the "Script start/stop" messages). > > Do we? ISTM that having IonMonkey compilation events exposed to devtools > could be very nice for perf analysis tools. *for now. Even if we expose the data, we need to be able to make a distinction between "start script" and "annotate script".

(In reply to Hannes Verschore [:h4writer] from comment #3) > *for now. Ok. > Even if we expose the data, we need to be able to make a distinction between > "start script" and "annotate script". True.

This adds the hooks needed for debugger: - startTraceLogging(); - endTraceLogging(); - drainTraceLogging(); Currently drainTraceLogging returns: [{data:""}, {data: ""}, ...]. The format still needs to get adjusted to be somewhat closer to what was requested in bug 1065722 comment 2. > var du = new Debugger(); > du.prepareTraceLogger({ > Scripts: true > }); > > du.startTraceLogging(); > > // some code > > print(JSON.stringify(du.drainTraceLogging())); e.g. now prints (with all patches): [{"data":"script /tmp/test38.js:8:10"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"Stop"},{"data":"script /tmp/test38.js:8:10"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"Stop"},{"data":"script /tmp/test38.js:8:10"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"Stop"},{"data":"script /tmp/test38.js:8:10"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"Stop"},{"data":"script /tmp/test38.js:8:10"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"Stop"},{"data":"script /tmp/test38.js:8:10"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"Stop"},{"data":"script /tmp/test38.js:8:10"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"Stop"},{"data":"script /tmp/test38.js:8:10"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"Stop"},{"data":"script /tmp/test38.js:8:10"},{"data":"script /tmp/test38.js:27:10"},{"data":"Stop"},{"data":"Stop"},{"data":"script /tmp/test38.js:41:13"},{"data":"Stop"},{"data":"script /tmp/test38.js:41:13"},{"data":"Stop"},{"data":"script /tmp/test38.js:41:13"},{"data":"Stop"},{"data":"script /tmp/test38.js:41:13"},{"data":"Stop"},{"data":"script /tmp/test38.js:41:13"},{"data":"Stop"},{"data":"script /tmp/test38.js:48:14"},{"data":"Stop"},{"data":"script /tmp/test38.js:48:14"},{"data":"Stop"},{"data":"script /tmp/test38.js:48:14"},{"data":"Stop"},{"data":"script /tmp/test38.js:41:13"},{"data":"Stop"},{"data":"script /tmp/test38.js:57:14"},{"data":"Stop"},{"data":"script /tmp/test38.js:57:14"},{"data":"Stop"},{"data":"script /tmp/test38.js:57:14"},{"data":"Stop"}]

I made the setupTraceLogger and drainTraceLogger nightly only, since these are not stable yet. I cannot guarantee the output won't change. I'm actually very confident it will still change and I don't want people rely on it yet. The first idea is to use this for tracing. The idea is to support that and keep the this api as stable as possible. Output of drainTraceLoggerTraces: > [{ > "logType": "Script", > "fileName": "/tmp/test38.js:1:0", > "lineNumber": "", > "columnNumber": "" > }, { > "logType": "Script", > "fileName": "/tmp/test38.js:8:10", > "lineNumber": "", > "columnNumber": "" > }, { > "logType": "Stop" > }, { > "logType": "Script", > "fileName": "/tmp/test38.js:8:10", > "lineNumber": "", > "columnNumber": "" > }, { > "logType": "Script", > "fileName": "/tmp/test38.js:8:10", > "lineNumber": "", > "columnNumber": "" > }, > ... In other words: we are very close. I only needs some extra patches so the fuzzers don't trip on some obvious things, before landing everything.

Comment on attachment 8505580 [details] [diff] [review] Add hooks Review of attachment 8505580 [details] [diff] [review]: ----------------------------------------------------------------- Oh I just noticed I was a bit too fast.

This is better ;) Example: > [{ > "logType": "Script", > "fileName": "/tmp/test38.js", > "lineNumber": "1", > "columnNumber": "0" > }, { > "logType": "Script", > "fileName": "/tmp/test38.js", > "lineNumber": "8", > "columnNumber": "10" > }, { > "logType": "Stop" > }, { > "logType": "Script", > "fileName": "/tmp/test38.js", > "lineNumber": "8", > "columnNumber": "10" > }, { > "logType": "Script", > "fileName": "/tmp/test38.js", > "lineNumber": "8", > "columnNumber": "10" > }, { > "logType": "Stop" > }, > ...

Comment on attachment 8505594 [details] [diff] [review] Add hooks Review of attachment 8505594 [details] [diff] [review]: ----------------------------------------------------------------- Except for TLThread::getEvents(), it seems to me that all TLThread::*debuggers* should belong to the Debugger itself (even naming of these members is a hint that it should), not to the TLThread, especially as TLThread::debuggerLostEvents() isn't used. TL shouldn't have to worry about its consumers losing events. ::: js/src/vm/Debugger.cpp @@ +3128,5 @@ > + if (!args.requireAtLeast(cx, "Debugger.startTraceLogger", 0)) > + return false; > + > + TraceLoggerThread *logger = TraceLoggerForMainThread(cx->runtime()); > + TraceLoggerEnable(logger, cx); don't forget to set a rval here and below to avoid some silly differential testing bugs. Even better, all these functions seem to return a bool, so how about just returning them in rval? @@ +3141,5 @@ > + if (!args.requireAtLeast(cx, "Debugger.endTraceLogger", 0)) > + return false; > + > + TraceLoggerThread *logger = TraceLoggerForMainThread(cx->runtime()); > + TraceLoggerDisable(logger); and here @@ +3173,5 @@ > + ContinuousSpace<EventEntry> *events = logger->getEvents(); > + > + RootedObject array(cx, NewDenseEmptyArray(cx)); > + > + uint32_t index = 0; nit: index is unused @@ +3180,5 @@ > + if (!item) > + return false; > + > + const char *eventText = logger->eventText(events->data()[i].textId); > + if (!DefineProperty(cx, item, "data", eventText, strlen(eventText))) Could you instead hoist the creation of the "data" string and reuse the String value in all DefineProperty calls? This would avoid creating the special DefineProperty variant above. Also, can you make "data" and all other string literals static constants in this file? @@ +3185,5 @@ > + return false; > + } > + > + logger->updateDebuggerLastFlushedId(); > + args.rval().setObject(*array); Don't forget to add the newly created object to the array (now i understand the unused index). @@ +3192,5 @@ > +} > +#endif > + > +bool > +Debugger::drainTraceLoggerTraces(JSContext *cx, unsigned argc, Value *vp) as stated on irc, everything TL produces are traces, so better naming would be appreciated here. @@ +3214,5 @@ > + if (textId != TraceLogger_Stop && !logger->textIdIsScriptEvent(textId)) > + continue; > + > + const char *type = (textId == TraceLogger_Stop) ? "Stop" : "Script"; > + if (!DefineProperty(cx, item, "logType", type, strlen(type))) same remark as in drainTraceLogger @@ +3217,5 @@ > + const char *type = (textId == TraceLogger_Stop) ? "Stop" : "Script"; > + if (!DefineProperty(cx, item, "logType", type, strlen(type))) > + return false; > + > + if (textId != TraceLogger_Stop) { All the things inside this if() seem pretty bound to the format output by TL. Could you make it a function there? @@ +3230,5 @@ > + > + MOZ_ASSERT(lineno && lineno != eventText); > + MOZ_ASSERT(colno && colno != eventText); > + > + // The +7 is to remove the 'script ' at the beginning of text. MOZ_ASSERT(EqualChars(eventText, "script ", 7)); @@ +3231,5 @@ > + MOZ_ASSERT(lineno && lineno != eventText); > + MOZ_ASSERT(colno && colno != eventText); > + > + // The +7 is to remove the 'script ' at the beginning of text. > + if (!DefineProperty(cx, item, "fileName", eventText + 7, size_t(lineno - eventText - 7))) Same remark as in drainTraceLogger @@ +3284,5 @@ > +#endif > + JS_FN("setupTraceLoggerForTraces", Debugger::setupTraceLoggerForTraces, 0, 0), > + JS_FN("startTraceLogger", Debugger::startTraceLogger, 0, 0), > + JS_FN("endTraceLogger", Debugger::endTraceLogger, 0, 0), > +#ifdef NIGHTLY_BUILD (see comment in Debugger.h about making them all nightly-only and grouping) ::: js/src/vm/Debugger.h @@ +375,2 @@ > static bool setupTraceLogger(JSContext *cx, unsigned argc, Value *vp); > +#endif As stated on IRC, i'd prefer all of these functions to be nightly-only, or none of them to be. Providing an incomplete API seems rather wonky. I'd like to get Nick's opinion here. (whatever happens, can you group the nightly only functions together, please?)

Addresses review comments. 1) Like discussed on IRC the DefineProperty helper function is still there. There was some confusing as to which char is getting copied. Though it resulted in using JSIDs for the function. 2) I don't agree on the fact that we should make them all or none nightly only. IIRC we should try to not use "ifdef NIGHTLY_BUILD". And the setupTraceLoggerScriptCalls, drainTraceLoggerScriptCalls, startTraceLogger and endTraceLogger are all stable. Now setupTraceLogger/drainTraceLogger is for curious hearts and to give an idea what we can log, but is an unstable API. Humans will be able to read the logs without problem, but creating scripts depending on the exact output it provides won't work. That is the reason I want it behind NIGHTLY_BUILD. So it gives the devtools something to play with and to push for a more stable API. (So it will possibly increase the adoption of tracelogger). But is mostly playground for now. That's the message I want to send with NIGHTLY_BUILD. Good to toy with. Currently don't depend on it. If you don't agree with it, I would rather remove these two functions than the alternatives (make all tracelogger function nightly only or make these two function non-nightly).

Comment on attachment 8509489 [details] [diff] [review] Add hooks Review of attachment 8509489 [details] [diff] [review]: ----------------------------------------------------------------- Sorry, API design is hard. I'd just remove the nightly only functions at this point, but that's your call. Also, I'd like to see a last updated version before holy r+. ::: js/src/vm/Debugger.cpp @@ +356,5 @@ > sources(cx), > objects(cx), > + environments(cx), > + traceLoggerLastDrainedId(0), > + traceLoggerLastDrainedIteration(0) So this is used by both drainTraceLogger and drainTraceLoggerScriptCalls, which is likely to confuse users if they interleave calls to these functions. That sounds like another argument for not keeping the drainTraceLogger nightly only functions, but if you want to keep them, would it make sense to use another pair of uint32? @@ +3039,5 @@ > args.rval().setObject(*global); > return dbg->wrapDebuggeeValue(cx, args.rval()); > } > > +#ifdef NIGHTLY_BUILD can you group the two #ifdef NIGHTLY_BUILD together here as well, please? @@ +3044,2 @@ > bool > Debugger::setupTraceLogger(JSContext *cx, unsigned argc, Value *vp) How come setupTraceLogger isn't a part of this patch anymore? @@ +3110,5 @@ > } > +#endif > + > +bool > +Debugger::setupTraceLoggerScriptCalls(JSContext *cx, unsigned argc, Value *vp) Sorry about naming craziness here, but this doesn't give the possibility to setup with an object. Could it be enableTraceLoggerScriptCalls instead? @@ +3118,5 @@ > + return false; > + > + TraceLogEnableTextId(cx, TraceLogger_Scripts); > + > + args.rval().setBoolean(true); rather than returning true here, can you either return undefined by symmetry with other functions or return the bool value returned by TraceLogEnableTextId? @@ +3164,5 @@ > + RootedValue str(cx, StringValue(text)); > + if (!JS_DefinePropertyById(cx, obj, id, str, JSPROP_ENUMERATE)) > + return false; > + > + return true; how about simply return JS_DefinePropertyById(cx, obj, id, str, JSPROP_ENUMERATE); ? @@ +3198,5 @@ > + if (!DefineProperty(cx, item, dataId, eventText, strlen(eventText))) > + return false; > + > + RootedValue obj(cx, ObjectValue(*item)); > + if (!JS_DefineElement(cx, array, index, obj, 0)) if you don't use JSPROP_ENUMERATE here, will the element be available in |for in/of| loops? (same question below in the ScriptCalls variant) @@ +3232,5 @@ > + 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")); maybe worth it to put it in common names as well? ::: js/src/vm/Debugger.h @@ +268,5 @@ > > /* The map from debuggee Envs to Debugger.Environment instances. */ > ObjectWeakMap environments; > > + /* TODO */ remove this or complete ::: js/src/vm/TraceLogging.h @@ +102,5 @@ > bool enable(); > bool enable(JSContext *cx); > bool disable(); > > + ContinuousSpace<EventEntry> *getEvents() { unused @@ +109,5 @@ > + > + // Given the previous iteration and lastEntryId, return an array of > + // events. At the same time update the iteration and lastEntry and gives > + // back how many events there are and if there were any lost events. > + EventEntry *getEvents(uint32_t *lastIteration, uint32_t *lastEntryId, Considering what it does now, getEvents seems too blur. What about getEventsFrom? @@ +113,5 @@ > + EventEntry *getEvents(uint32_t *lastIteration, uint32_t *lastEntryId, > + size_t *num, bool *lostEvents) > + { > + EventEntry *start; > + *lostEvents = this->lostEvents(*lastIteration, *lastEntryId); This could be made in the debugger itself, as lostEvents(...) is public and its two arguments come from the outside. That would have the benefit to remove one arg to this function call and split responsibilities. I would also think that once again, this is not TL's responsability to think about users losing events. The work made by getEvents(...) should be internalized by the Debugger. If you decide to reuse getEvents(), and use it along with iteration(), all this work could be done in the Debugger itself. Not blocking review on this, as i can see the advantage that this could be reused by TLGraph in the future. @@ +117,5 @@ > + *lostEvents = this->lostEvents(*lastIteration, *lastEntryId); > + if (iteration_ == *lastIteration) { > + MOZ_ASSERT(events.lastEntryId() >= *lastEntryId); > + *num = events.lastEntryId() - *lastEntryId; > + start = events.data() + (*lastEntryId + 1); i'd just remove the parenthesis here around the + @@ +134,5 @@ > + 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); > + > + uint32_t iteration() { unused @@ +146,5 @@ > + return false; > + } > + > + // When proceeded to the next iteration, but lastEntryId points to > + // the maximum capacity. There are no logs that are lost. Please make it a single sentence (otherwise the first one has no main section).

(In reply to Benjamin Bouvier [:bbouvier] from comment #11) > Comment on attachment 8509489 [details] [diff] [review] > Add hooks > > Review of attachment 8509489 [details] [diff] [review]: > ----------------------------------------------------------------- > > Sorry, API design is hard. I'd just remove the nightly only functions at > this point, but that's your call. Also, I'd like to see a last updated > version before holy r+. > > ::: js/src/vm/Debugger.cpp > @@ +356,5 @@ > > sources(cx), > > objects(cx), > > + environments(cx), > > + traceLoggerLastDrainedId(0), > > + traceLoggerLastDrainedIteration(0) > > So this is used by both drainTraceLogger and drainTraceLoggerScriptCalls, > which is likely to confuse users if they interleave calls to these > functions. That sounds like another argument for not keeping the > drainTraceLogger nightly only functions, but if you want to keep them, would > it make sense to use another pair of uint32? Good point. > > @@ +3039,5 @@ > > args.rval().setObject(*global); > > return dbg->wrapDebuggeeValue(cx, args.rval()); > > } > > > > +#ifdef NIGHTLY_BUILD > > can you group the two #ifdef NIGHTLY_BUILD together here as well, please? > > @@ +3044,2 @@ > > bool > > Debugger::setupTraceLogger(JSContext *cx, unsigned argc, Value *vp) > > How come setupTraceLogger isn't a part of this patch anymore? Never was. Bug 1072906 contains that patch ;) > @@ +3110,5 @@ > > } > > +#endif > > + > > +bool > > +Debugger::setupTraceLoggerScriptCalls(JSContext *cx, unsigned argc, Value *vp) > > Sorry about naming craziness here, but this doesn't give the possibility to > setup with an object. Could it be enableTraceLoggerScriptCalls instead? I prefer not. This means "setup Tracelogger". No need for an object. EnableTraceLoggerScriptCalls would cause too much confusion with StartTraceLogger. People would think the TraceLogger would be already recording after doing EnableXXX. So I think setupXXX is still the best option. > > @@ +3118,5 @@ > > + return false; > > + > > + TraceLogEnableTextId(cx, TraceLogger_Scripts); > > + > > + args.rval().setBoolean(true); > > rather than returning true here, can you either return undefined by symmetry > with other functions or return the bool value returned by > TraceLogEnableTextId? TraceLogEnableTextId doesn't return a bool. So since it didn't fail it returns true to indicate setting up was successful. (In symmetry with plain setupTraceLogger which return false upon fail). > @@ +3232,5 @@ > > + 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")); > > maybe worth it to put it in common names as well? Found it a bit too specific to TL. So I didn't add it, currently. The fact you are also hesitant also made me not change it. > @@ +109,5 @@ > > + > > + // Given the previous iteration and lastEntryId, return an array of > > + // events. At the same time update the iteration and lastEntry and gives > > + // back how many events there are and if there were any lost events. > > + EventEntry *getEvents(uint32_t *lastIteration, uint32_t *lastEntryId, > > Considering what it does now, getEvents seems too blur. What about > getEventsFrom? I went for getEventsStartingAt

Comment on attachment 8509598 [details] [diff] [review] Add hooks Review of attachment 8509598 [details] [diff] [review]: ----------------------------------------------------------------- Nice, thanks! ::: js/src/vm/CommonPropertyNames.h @@ +44,5 @@ > macro(count, count, "count") \ > macro(currency, currency, "currency") \ > macro(currencyDisplay, currencyDisplay, "currencyDisplay") \ > macro(std_iterator, std_iterator, "@@iterator") \ > + macro(data, data, "data") \ Same argument applies to data, then, as it's the first use... ::: js/src/vm/TraceLogging.h @@ +127,5 @@ > + 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); > + > + uint32_t iteration() { still unused

Hi, sorry had to back this out in https://treeherder.mozilla.org/ui/#/jobs?repo=mozilla-central&revision=b9fd2074d588 since with the landings of this changesets we had permafailures in ggc tests like https://treeherder.mozilla.org/ui/logviewer.html#?job_id=661496&repo=mozilla-central