Motivation: ---------- Rev 4: changes to probe creation and added section on javascript probes Date: 09 March 2007 Rev 3: updates after initial feedback Date: 21 Feb 2007 The main goal for this Dynamic Tracing Framework for Mozilla is to provide a common interface for adding instrumentation points or probes to Mozilla so its behavior can be easily observed by developers and administrators even in production systems. This framework will allow Mozilla to use the appropriate monitoring/tracing facility provided by each OS. OpenSolaris, FreeBSD and MacOS will use DTrace and other OSes can use their own respective tool. What is DTrace? -------------- DTrace is a comprehensive dynamic tracing framework supported in OpenSolaris, FreeBSD and MacOS. It allows developers and administrators to examine the behavior of user programs and the operating system on live production systems. DTrace allows you to probe not just a specific application or portion of the OS, but to combine queries so you can see how parts of your application are interacting with other parts of the system such as the kernel, platform libraries and the XServer. Traditionally this type of system wide, cross application debugging has been very difficult to do particularly in a multitasking asynchronous desktop environment. A few examples of the type of questions DTrace can answer out of the box when being used to examine your applications performance: * What files is my application opening, how long is this I/O taking, what is the size distribution of reads on this file, what errors are occurring. * Show me where a particular time consuming function is being called in my application and display all the consolidated stack traces for this function call. * Trace across a specific application function call, and show the library, system and kernel calls being made by this function and the time taken to make them to help identify performance bottlenecks. User Defined Probes -------------------- "DTrace provides a facility for user application developers to define customized probes in application code to augment the capabilities of the pid provider (traces instructions in a process). These static probes impose little to no overhead when disabled and are dynamically enabled like all other DTrace probes. You can use static probes to describe application semantics to users of DTrace without exposing or requiring implementation knowledge of your applications." Statically Defined Tracing for User Applications: http://docs.sun.com/app/docs/doc/817-6223/6mlkidlms?a=view We plan to provide an infrastructure to make it easy to add such user define probes to the Mozilla code base, that users/developers can then enable at run time to observe and measure the application performance. The probes will be designed to impose no overhead when they are disabled. You can get some of this information already using debug builds of the browser, but by placing probes in the code base they can be enabled dynamically at run time to fetch this type of debug information from normal browser builds. Some possible areas we could add probes to monitor are: * loadURLStart/loadURLEnd * dataStreamStart/dataStreamEnd * parseHTMLStart/parseHTMLEnd * domConstructionStart/domConstructionEnd * rendertreeConstructionStart/rendertreeConstructionEnd * layout-start/layout-end: monitor phases of layout * JavaScript probes: func calls, object creation/ destruction and script execution The hope is that folks who really know the Mozilla code base will point us in the write direction or add the probes themselves. Just got pointed at a few docs on irc.mozilla.org#developers by biesi (Christian Biesinger) that look very promising [apparently a bit out of date but overview still ok]. Seems that asking a simple question like "How long does it take to load a page?" is really a very tricky question :) Hopefully the probes we and others will add should finally allow us to nail this down. Document Loading: From Load Start to Finding a Handler (Boris Zbarsky) http://www.mozilla.org/docs/docshell/uri-load-start.html The Life Of An HTML HTTP Request (Alexander Larsson) http://www.mozilla.org/docs/url_load.html To start things off, prompted by a suggestion from Robert O'Callahan, we are providing a patch to add probes to the new Layout engine to monitor layout reflow, frame construction and paint. We've kept the infrastructure patch and the probe patch separate. I'm sure people will cry in horror at our mods to the build system so please feel free to correct us. Background ------------ There are a number of docs on Dtrace, and here's a quick start doc and a complete reference guide. http://www.sun.com/software/solaris/howtoguides/dtracehowto.jsp http://docs.sun.com/app/docs/doc/817-6223 OpenSolaris DTrace Community page http://www.opensolaris.org/os/community/dtrace Open source apps that provide user level probes (bottom of page) http://uadmin.blogspot.com/2006/05/what-is-dtrace.html Proposed Solution: ------------------- We think this solution is reasonably simple and non-intrusive. We will have dtrace disabled by default, you will turn it on when building on a platform that supports it by passing an enable-dtrace option to configure: $ ./configure --enable-dtrace 1. Define dtrace probes in a top level mozilla-trace.d probe file. They have the following format: provider trace_mozilla { probe layout__start(int*, int); : } Generate a probe macros header file, mozilla-trace.h.in, from the probe file. This is processed by configure to generate the mozilla-trace.h header, it needs to change the _DTRACE_VERSON macro to INCLUDE_MOZILLA_DTRACE. The mozilla-trace.h makes it easy to use the probes in any C++ file, just by including the probe macro header. The generated macro probes in mozilla-trace.h have the following format: TRACE_MOZILLA_([arg0, arg1, ...argN]) PROBE_NAME = Probe name such as layout__start, layout__end, etc arg1..argN = Any args to pass to the probe such as presentation context, layout phase etc. Example usage: TRACE_MOZILLA_LAYOUT_START((int *)GetPresContext(), eLayoutPhase_Reflow); The generated mozilla-trace.h.in file should be checked into cvs. If a developer wants to add new probes they can modify the mozilla-trace.d and run configure with enable-dtrace to generate an updated mozilla-trace.h.in and mozilla-trace.h file on a system that supports dtrace. Then they just check in the mozilla-trace.h.in which is available on all platforms for the autobuild bot. 2. Map macros to functions appropriate for each OS. For OS's that don't have suitable tracing facility, just map the macros to nothing - doing this will not have any affect on performance or existing behavior. The generated probe macros can be safely inserted into C++ code and will compile to noops if DTrace is not present on the system. Sample of mozilla-trace.h: #if INCLUDE_MOZILLA_DTRACE #define TRACE_MOZILLA_LAYOUT_START(arg0, arg1) \ __dtrace_mozilla___layout__start(arg0, arg1) extern void __dtrace_mozilla___layout__end(int *, int);; : #else #define TRACE_MOZILLA_LAYOUT_START(arg0, arg1) : #endif 3. Add any file(s) to support the particular OS tracing facility For Dtrace: mozilla/configure.in Add a rule to configure.in so if the --enable-dtrace option has been passed and dtrace is detected on the system [by the presence of sys/std.h], it uses dtrace to create a mozilla-trace.h.in and mozilla-trace.h header from the probe file mozilla-trace.d, which contains probe macros for all of the dtrace mozilla probes. mozilla/config/rules.mk Any C++ file that contains probes will contain undefined probe functions when compiled. It needs to be processed by dtrace to create a dtrace-probe object file that can be linked with this object to manage these dependencies. Add a rule to create the dtrace-probe object file for any object code that contains probes. Add this dtrace probe object file to the list of objects required when creating any archive and library that contains the object files with probes. mozilla/config/autoconf.mk.in Add support for HAVE_DTRACE define to be used in the configure and makefiles. mozilla/mozilla-trace.d Add any probes that are to be used in the C++ files of Mozilla. Add comments to describe the arguments that each of the probes take, as only their types are specified in the probes. 4. Update the Makefiles as necessary for each OS For DTrace: mozilla/config/Makefile.in Add the mozilla-trace.h to the list of HEADERS available to all C++ files during compilation. mozilla//Makefile.in mozilla///Makefile.in For each subcomponent that contains probes update it's Makefile with the dtrace object probe target that will be used by the included rules.mk when building the component. Do the same for any nested subcomponents. Include this just before the rules.mk is included in the Makefile.in For example: mozilla/layer/Makefile.in and mozilla/layout/base/Makefile.in ifdef HAVE_DTRACE DTRACE_PROBE_OBJ = $(LIBRARY_NAME)-dtrace.$(OBJ_SUFFIX) endif include $(topsrcdir)/config/rules.mk How to add probes: ----------------- To add a probe, include the mozilla-trace.h header at the top of the file and just add any of the probe macros to the appropriate location in the code. As the header is always available there is no need to put any #ifdef's around the macros, they are compiled out on platforms with no dtrace support or if --enable-dtrace has not been passed to configure when building. #include "mozilla-trace.h" void foobar ( ... ) TRACE_MOZILLA_LAYOUT_START((int *)GetPresContext(), eLayoutPhase_FrameC); As mentioned above, with a few hints from Robert, we have added probes to the new layout engine, at the same location as the AUTO_LAYOUT_PHASE_ENTRY_POINT macro and where the objects later go out of scope. Hopefully this will to help others delve into the new layout engine, measure its performance and help identify any issues that might need tweaking. No doubt others will have plenty of ideas as to where we could add other probes. As we have only limited knowledge of the Mozilla code base we are hoping that others more knowledgeable in the area will help us to identify some new interesting probes. We've suggested some high level probes above but would need help in identifying where to put them in the code :) If there are enough probes embedded in Mozilla, it will be very easy to observe it's behavior on non debug builds, which would be very cool. To list out the probes that have been added, just run firefox built with the probes and type: $ dtrace -P 'trace_mozilla*' -l ID PROVIDER MODULE FUNCTION NAME 54 trace_mozilla1815 libgklayout.so trace_layout_exit layout-end 55 trace_mozilla1815 libgklayout.so trace_layout_enter layout-start : Issue: ------- With this approach in C++ there can be a problem as pointed out by David Baron, if you are using pairs of matching entry and exit probes. You need to put in exit probes at all exit points in a function block to which you have added an entry probe. This can be error prone if there are multiple exit points and the code block is long. So a workaround is to declare a struct with a constructor and destructor into which you put the probes and you just declare an instance of this struct where you would have put the entry probe. When this struct goes out of scope it's destructor is called and the exit probe fires. There is no need to add a separate exit probe explicitly in the code. This does mean you pay the cost of declaring an extra struct in the calling code, but this should be neglible as the stuct has no expensive initialisation code, it just stores the construction parameters. We made these changes for the layout probes. This change means that the Function reported for these probes would now be the constructor and destructor of the struct, so we wrapped them in more meaningful extern C trace function names [refer to the Mozilla Dynamic Tracing Framework + layout probes patch: nsPresContext.h, nsPresContext.cpp]. You can use these probe construction techniques if you wish for your own probes or if you simply want an entry probe and are happy to have the enclosing C++ function as the probes Function name then just follow the standard approach outlined above. If you wish to demangle any of the printed C++ function names, just run the output through c++filt. How to use probes: ------------------- For DTrace, probes can be enabled using a D script. When the probes are not enabled, there is little or no performance hit. Here are a few examples, one prints out the counts of the phases as the script is running and the other the times of the phases. Note: with the above mentioned changes to the layout probes, the scripts have been changed as the Function name now just referes to the wrapper trace extern function not the C++ function. This can be obtained if required by using the dtrace ustack() function. layout_count.d ------------------ This script is counting the number of times each layout phase is triggered for a given presentation context. #!/usr/sbin/dtrace -s #pragma D option quiet enum eLayoutPhases { EPaint, EReflow, EFrameC}; BEGIN { phaseStr[EPaint] = "paint"; phaseStr[EReflow] = "reflow"; phaseStr[EFrameC] = "frameCon"; } trace_mozilla$target:::layout-start { @[arg0, phaseStr[arg1], probefunc] = count(); } dtrace:::END { printf("%10s %10s %8s %-30s \n", "Pres Ctx", "Phase", "Count", "Function"); printa("%10d [ %8s ] %5@d %-30s \n", @); } $ dtrace -qs layout_count.d -p `pgrep firefox-bin` Pres Ctx Phase Count Function 149475272 [ paint ] 1 trace_layout_enter 157302440 [ reflow ] 1 trace_layout_enter 157302440 [ paint ] 4 trace_layout_enter 149475272 [ reflow ] 7 trace_layout_enter 149475272 [ frameCon ] 15 trace_layout_enter 140235064 [ reflow ] 23 trace_layout_enter 140235064 [ frameCon ] 26 trace_layout_enter 140235064 [ paint ] 47 trace_layout_enter layout_time.d --------------- This script is measuring the time spent in different layout phases for a given presentation context. #!/usr/sbin/dtrace -s #pragma D option quiet enum eLayoutPhases { EPaint, EReflow, EFrameC}; dtrace:::BEGIN { phaseStr[EPaint] = "paint"; phaseStr[EReflow] = "reflow"; phaseStr[EFrameC] = "frameCon"; } trace_mozilla$target:::layout-start { self->ts[arg0, arg1] = timestamp; } trace_mozilla$target:::layout-end /self->ts[arg0, arg1]/ { @phase_time[arg0, phaseStr[arg1]] = sum((timestamp - self->ts[arg0, arg1])/1000); self->ts[arg0, arg1] = 0; } dtrace:::END { printf("%10s %10s %8s\n", "Pres Ctx", "Phase", "Time(usec)"); printa("%10d [ %8s ] %5@d\n", @phase_time); } $ dtrace -qs layout_time.d -p `pgrep firefox-bin` Pres Ctx Phase Time(usec) 157782656 [ frameCon ] 848 161117304 [ paint ] 900 140235064 [ frameCon ] 1221 157782656 [ reflow ] 4047 140235064 [ reflow ] 10379 159964560 [ frameCon ] 10649 157782656 [ paint ] 23764 159964560 [ paint ] 32233 140235064 [ paint ] 152911 159964560 [ reflow ] 184040 Javascript Probes ================== We have now included a separate javascript probes patch for Brendan Gregg's mozilla javascript probes, that can be applied on top of the Mozilla Dynamic Tracing Framework + layout probes patch. All of the probes listed in Brendan's Blog on JavaScript and DTrace will work: Brendan's Javascript Blog:http://blogs.sun.com/brendan/entry/dtrace_meets_javascript Demo of the probes in action: http://frsun.downloads.edgesuite.net/sun/07C00953/index.html But we have changed the namespace to be in sync with the other mozilla probes, so you will need to change the probe names in the script appriopriately, for example: Change: javascript*:::function-entry to trace_mozilla*:::js_function-entry To list the available javascript probes once the patch is applied and mozilla rebuilt with --enable-dtrace, just type: $ dtrace -n 'trace_mozilla*:::js*' -l ID PROVIDER MODULE FUNCTION NAME 35 trace_mozilla1815 libmozjs.so jsdtrace_execute_done js_execute-done 36 trace_mozilla1815 libmozjs.so js_Execute js_execute-done 37 trace_mozilla1815 libmozjs.so jsdtrace_execute_start js_execute-start 38 trace_mozilla1815 libmozjs.so js_Execute js_execute-start 39 trace_mozilla1815 libmozjs.so jsdtrace_function_entry js_function-entry 40 trace_mozilla1815 libmozjs.so js_Interpret js_function-entry 41 trace_mozilla1815 libmozjs.so jsdtrace_function_return js_function-return 42 trace_mozilla1815 libmozjs.so js_Interpret js_function-return 43 trace_mozilla1815 libmozjs.so jsdtrace_object_create js_object-create 44 trace_mozilla1815 libmozjs.so js_NewObject js_object-create 45 trace_mozilla1815 libmozjs.so js_CloneBlockObject js_object-create 46 trace_mozilla1815 libmozjs.so jsdtrace_object_create_done js_object-create-done 47 trace_mozilla1815 libmozjs.so js_NewObject js_object-create-done 48 trace_mozilla1815 libmozjs.so js_CloneBlockObject js_object-create-done 49 trace_mozilla1815 libmozjs.so jsdtrace_object_create_start js_object-create-start 50 trace_mozilla1815 libmozjs.so js_NewObject js_object-create-start 51 trace_mozilla1815 libmozjs.so js_CloneBlockObject js_object-create-start 52 trace_mozilla1815 libmozjs.so jsdtrace_object_finalize js_object-finalize 53 trace_mozilla1815 libmozjs.so js_FinalizeObject js_object-finalize js_funcalls.d -------------------- This script counts all of the javascript function calls that are being executed by firefox and gives the originating file for the javascript code, listed under FUNC and FILE respectively. You could use a predicate to exclude javascript being used by the browser's chrome UI if you wished, but this simple script just counts all of the function calls. #pragma D option quiet dtrace:::BEGIN { printf("Tracing... Hit Ctrl-C to end.\n"); } trace_mozilla*:::js_function-entry { @funcs[basename(copyinstr(arg0)), copyinstr(arg2)] = count(); } dtrace:::END { printf(" %-32s %-36s %8s\n", "FILE", "FUNC", "CALLS"); printa(" %-32s %-36s %@8d\n", @funcs); } ^C FILE FUNC CALLS autocomplete.xml createEvent 1 autocomplete.xml dispatchEvent 1 bookmarks.js GetSources 1 bookmarks.js IsContainer 1 : : : browser.xml QueryInterface 130 nsSessionStore.js QueryInterface 987 nsSessionStore.js getNext 988 nsSessionStore.js hasMoreElements 990 Prototype ---------- We have a prototype working and have logged a bugzilla bug #370906 with the patches attached. I've also attached a longer script using these probes to the bug which gives a detailed breakdown on the Layout Phases timings, when nested phases occur and any unbalanced phases. I've now added a spearate patch providing Brendan Gregg's javascript probes. This is a proposal, so comments, suggestions, feedbacks are certainly welcome. Regards, John, Padraig and Alfred John Rice Padraig O'Briain Alfred Peng