Closed Bug 580055 Opened 11 years ago Closed 10 years ago
Log all JS function entry/exits
Split off from bug 507012. There should be a simple way to request a log of all function call entries/exits, using function tracking callback from bug 507012.
Here is a proposal. This goes through PR_LOGGING, so you use it by setting eg NSPR_LOG_MODULES=JSDiagnostics:5 NSPR_LOG_FILE=/tmp/jscalls.log This will intermix the function call reports with other JS logging, but it's easy enough to separate out. I could have a separate log module if the intermixing bothers anyone. The info logged is: - a thread identifier - the function pointer - the script filename and line number - the function name - whether JS_ON_TRACE is true while the function is being entered/exited - a boolean saying whether this is an enter or exit - timestamp Any requests for additions/modifications?
Adding mfinkle to the CC list, since I wrote this portion based on his request. The original patch also logged isInterpreted for each function call. Is that useful? I could throw that in as well.
(In reply to comment #2) > Adding mfinkle to the CC list, since I wrote this portion based on his request. > > The original patch also logged isInterpreted for each function call. Is that > useful? I could throw that in as well. I was using isInterpreted to see if code was JIT'ed or not. JS_ON_TRACE is good enough for me.
That's what I thought it must mean, but unless I confused myself, I discovered that isInterpreted means something entirely different. The details, which I don't understand, are in jsfun.h. It's something like isInterpreted means it's implemented in JS as opposed to a native function call. If isInterpreted, you can get to the defining script. But that's orthogonal to whether you're on trace or not. fwiw, watching JS_ON_TRACE while loading a gmail message is depressing. Hopefully that means that gmail functions are mostly high-level? I should see what tracevis tells me.
Updated on top of latest instrumentation. Currently requires tracemonkey branch + patches from bug 605330. This patch supersedes the one from bug 558200. Current instructions are at https://wiki.mozilla.org/Using_SlowCalls
Just some feedback. I imported this patch into my local Fennec build and tried to do some JS profiling on N900 and Android. I noticed that there is no output for XPCOM JS components. Those are handled by mozJSComponentLoader.cpp I also didn't see much of the chrome JS in the startup profiles either. The initial browser.xul onLoad handler, for example, was not in the profile.
Attachment #458442 - Attachment is obsolete: true
Briefly escaped from the hardblocker grind by updating this. Taras told me about a runtime-wide context creation callback, so I moved everything into xpconnect instead and used the callback. This now appears to be catching way more stuff, although it now sees so much stuff that it overwhelms. It's just a mass of text. But anyone interested could give it a try and see if it catches what you're interested in. I'll update the instructions on the wiki next (had to change PR_LOG sections), and upload a new processing script (slight tweaks; completely independent of this change.) Wiki - https://wiki.mozilla.org/Using_SlowCalls Processing script attached to bug 558200
Attachment #485465 - Attachment is obsolete: true
I had to un-bitrot this to use it, here's the updated patch.
Attachment #514105 - Attachment is obsolete: true
Attachment #530370 - Attachment is obsolete: true
Rebased again, but I haven't actually tested it.
I had #defines/#includes out of order so the logging was disabled in non-DEBUG builds. This patch also includes the functiontimer fix for GET_FUNCTION_PRIVATE, which doesn't really belong here.
Attachment #555900 - Attachment is obsolete: true
Steve, is it possible to get this landed, ifdef'd out? Who would need to review, etc?
Pinging again for Dietrich's question, I'd really like to see this landed. On a somewhat unrelated note, when I try to rebuild with --enable-trace-jscalls. --enable-functiontimer I get a build error: In file included from /home/ahal/hg/mozilla-central/js/src/jsalloc.cpp:40: /home/ahal/hg/mozilla-central/js/src/jscntxt.h:1153: error: ‘JSFunctionCallback’ does not name a type /home/ahal/hg/mozilla-central/js/src/jscntxt.h: In member function ‘void JSContext::doFunctionCallback(const JSFunction*, const JSScript*, int) const’: /home/ahal/hg/mozilla-central/js/src/jscntxt.h:1159: error: ‘functionCallback’ was not declared in this scope Can anyone shed some light on this?
The new profiler work likely removes the need for this, so marking WONTFIX. See bug 713227. Re-open if this is still needed.
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → WONTFIX
You need to log in before you can comment on or make changes to this bug.