MozillaWiki

Javascript Profiling: Difference between revisions

Page Discussion

Javascript Profiling (view source)

Revision as of 19:58, 19 September 2012

2,488 bytes added ,  19 September 2012
Note that this API plan has been set aside.
No edit summary
(Note that this API plan has been set aside.)
 
(9 intermediate revisions by one other user not shown)
Line 1: Line 1:
Note: the API described here has been set aside; it will not become part of the Mozilla platform. We're going to use the [https://developer.mozilla.org/en-US/docs/Performance/Profiling_with_the_Built-in_Profiler SPS profiler] as our profiling back end.
= Profiling API =
= Profiling API =


Line 4: Line 6:


As an idea of what should be possible to build on top of this API, see [http://unity3d.com/support/documentation/Manual/Profiler.html Unity's profiler],
As an idea of what should be possible to build on top of this API, see [http://unity3d.com/support/documentation/Manual/Profiler.html Unity's profiler],
The profiling API is centered around profiling particular "contexts" of information. These "contexts" represent a set of scripts which are to be profiled, and will be referred to as from the root object, or "the global." This concept is similar to the [[Debugger]] API. When profiling a script, the scripts being profiled are contained to the specified global.


== The Profiler object ==
== The Profiler object ==


There will be a global <tt>Profiler</tt> object available to instantiate to begin profiling other objects. The <tt>Profiler</tt> object has the following methods:
There will be a global <tt>Profiler</tt> object available to instantiate to begin profiling the runtime in which the profiler was created in. The <tt>Profiler</tt> object has the following methods:


<dl>
<dl>
Line 15: Line 15:
<dd>The constructor takes no arguments
<dd>The constructor takes no arguments


<dt>startProfiling(obj, [sample_rate, [max_samples]])
<dt>start([sample_rate, [max_samples]])
<dd>Ensures that profiling has started on the specified object's runtime. The sample rate and max samples are optional parameters which can tune how the profile is collected.
<dd>Begins profiling. All arguments are optional. The sample rate is the time between samples of the call stack specified in microseconds (defaults to 1000 = 1ms). The sample rate is mostly a guideline as the platform being run might not guarantee the granularity of timing. Samples will not happen more frequently than the specified rate, but may occur more infrequently.
 
The sample rate is the time between samples of the call stack specified in microseconds (defaults to 1000 = 1ms). The sample rate is mostly a guideline as the platform being run might not guarantee the granularity of timing. Samples will not happen more frequently than the specified rate, but may occur more infrequently.


A maximum number of samples can be specified as well, but the default is unlimited (0). If the maximum number of samples is reached, then the sample storage is treated as a ring buffer, discarding the oldest samples.
A maximum number of samples can be specified as well, but the default is unlimited (0). If the maximum number of samples is reached, then the sample storage is treated as a ring buffer, discarding the oldest samples.


If some other Profiler object is profiling the specified runtime, then an error is thrown if the sample rate or maximum sample count is different. Eventually a call to stopProfiling() must be paired with this call to cease data collection.
If some other Profiler object is profiling the runtime, then the other profiler is forcibly stopped. Eventually a call to stop() must be paired with this call to cease data collection.
<dt>isProfiling(obj)
<dt>isProfiling()
<dd>Returns whether profiling is turned on for the specified runtime
<dd>Returns whether profiling is active for this Profiler instance
<dt>frame()
<dt>frame()
<dd>Fetch the current object instance representing the current stack trace of invocation for the invoking context's global. Properties can be added to this object and will be persisted across invocations of this method so long as each invocation has the same backtrace. If the invoking context's global is not being profiled by the <tt>Profiler</tt> instance, then an error is thrown
<dd>Fetches an object to represent the current stack trace to be later returned via results(). This object can have any properties attached to it and will persist across different invocations of frame() so long as the same backtrace is present each time. All information specified here will later be available via results() with the full backtrace listed. By default this returns an empty object with no properties. If the profiler is not active or has been forcibly stopped, then an error is thrown.
<dt>info(obj)
<dt>results()
<dd>Returns all profile information for the specified object's runtime. The data returned is all that is collected between the last invocation of clearInfo() and all the profile data.
<dd>Returns all profile information gathered. The data returned is all that is collected between the last invocation of reset() and all the sample data.
<dt>clearInfo(obj)
<dt>samples()
<dd>Removes all custom frame() information stored for the specified object's runtime. Also clears all profiling samples collected so far.
<dd>Returns all profiling samples gathered. The data returned is all that is collected between the last invocation of reset() and now. If profiling is turned on, it is disabled for the duration of this function.
<dt>stopProfiling(obj)
<dt>reset()
<dd>Ceases profiling on the specified runtime. This must only be called if a pairing call to startProfiling(obj) has been made.
<dd>Resets all information that is stored. This includes samples and also frame() information.
<dt>stop()
<dd>Ceases profiling on the runtime. If this profiler is not active or has been forcibly stopped, an error is thrown.


</dl>
</dl>


=== The return of <tt>.info()</tt> ===
=== The return of <tt>.results()</tt> ===


The return value is an object which is a hash containing all the information. The hash can loosely be viewed as a trie. Here's some example code:
The return value is an object which is a hash containing all the information. The hash can loosely be viewed as a trie. Here's some example code:
Line 61: Line 61:
  }                                       
  }                                       
                                          
                                          
  p.startProfiling(p);                   
  p.start();                   
  foo(4000000);                           
  foo(4000000);                           
  bar(200);                               
  bar(200);                               
  p.stopProfiling(p);                  
  p.stop();
                                          
                                          
  print(JSON.stringify(p.info(p)))       
  print(JSON.stringify(p.results()))       


And the following hash would be printed:
And the following hash would be printed:


  {                                                                   
  {                                                                   
   ticks: 624,                                                       
   samples: 624,                                                     
  gcSamples: 1,                                                     
  micros: 12421,                                                       
   children: [                                                       
   children: [                                                       
     {                                                               
     {                                                               
       function: { file: 'input.js', line: 1 },                       
       function: { file: 'input.js', line: 1, name: '<top level>' },                       
       site: { file: 'input.js', line: 25 },                         
       site: { file: 'input.js', line: 25 },                         
       ticks: 624,                                                   
       samples: 624,                                                   
       children: [                                                   
       children: [                                                   
         {                                                           
         {                                                           
           function: { file: 'input.js', line: 1, name: 'foo' },     
           function: { file: 'input.js', line: 1, name: 'foo' },     
           site: { file: 'input.js', line: 7 },                       
           site: { file: 'input.js', line: 7 },                       
           ticks: 195,                                               
           samples: 195,                                               
           self: 195                                                 
           selfCount: 195                                                 
         }, {                                                         
         }, {                                                         
           function: { file: 'input.js', line: 1, name: 'foo' },     
           function: { file: 'input.js', line: 1, name: 'foo' },     
           site: { file: 'input.js', line: 11 },                     
           site: { file: 'input.js', line: 11 },                     
           ticks: 429,                                               
           samples: 429,                                               
           self: 429                                                 
           selfCount: 429                                                 
         }                                                           
         }                                                           
       ]                                                             
       ]                                                             
     }, {                                                             
     }, {                                                             
       function: { file: 'input.js', line: 1},                       
       function: { file: 'input.js', line: 1 },                       
       site: { file: 'input.js', line: 26},                           
       site: { file: 'input.js', line: 26 },                           
       children: [                                                   
       children: [                                                   
         {                                                           
         {                                                           
Line 112: Line 114:
=== Profiled Statistics ===
=== Profiled Statistics ===


Some internal events are profiled when profiling is turned on, and they are kept track of in the following fields of the corresponding <tt>Profiler.Frame</tt> instance.
At the root level of the results is the following information:
 
<dl>
<dt>samples
<dd>The total number of samples that were taken while the profiler was running.
<dt>gcSamples
<dd>This is the total number of samples which were taken where GC activity was happening, but no other JS code was running.
<dt>micros
<dd>This is the number of microseconds for which the profiler was running. If the results were generated when the profiler was stopped, then this is the amount of time between the start/stop. If the profiler is still running, then this is the amount of time from the start of the profiler to when the results() method was called.
</dl>
 
Each child then has the following profile statistics:


<dl>
<dl>
<dt>ticks
<dt>function
<dd>This is an integer value of the number of ticks while this function's frame was on the stack. This is useful when counting total time spent in a function. It should be true that: <tt>ticks = self + children.sum('ticks')</tt>
<dd>This is the function in which the sample was taken. It contains information about the function's name/file/line definition
<dt>self
<dt>site
<dd>This is an integer value like "ticks," but instead only counts the time spent in the function itself. When a sample is taken and a function is currently running (it's the top of the stack), it's self count is increased.
<dd>This is the actual site of execution at which the sample was taken. For example if function a calls function b and a sample were then taken, the site of b would be the line at which the sample was taken inside b, and the site of a would be the line of the function call to b.
<dt>gc
<dt>data
<dd>This integer represents the number of times that garbage collection was invoked at the site
<dd>If the frame() method was invoked, then this represents the corresponding data which was attached to the frame information.
<dt>compile
<dt>samples
<dd>This integer represents the number of times a function was compiled when invoked from this site.
<dd>This is an integer value of the number of ticks while this function's frame was on the stack. This is useful when counting total time spent in a function. It should be true that: <tt>samples = selfCount + children.sum('samples')</tt>
<dt>selfCount
<dd>This is an integer value like "samples," but instead only counts the time spent in the function itself. When a sample is taken and a function is currently running (it's the top of the stack), it's selfCount is increased.
</dl>
</dl>


Other statistics can be easily added from either JS or C++.
 
=== The return of <tt>.samples()</tt> ===
 
The samples() method of a Profiler returns a list of sample objects which describe a sample taken at a particular time. Each object has the following structure:
{                                                   
    micros: 100,                                     
    weight: 2,                                       
    stack: [                                         
        {                                           
            function: { line: 20, file: '...' },     
            site: { line: 30, file: '...' }         
        },                                           
        ...                                         
    ]                                               
}                                                   
 
Each sample's field are as follows:
<dl>
<dt>micros
<dd>This is the time at which the sample was taken (in microseconds).
<dt>weight
<dd>Due to the way sampling is currently implemented, time spent in native C++ functions prevent samples from being taken. For this reason, the time is attributed to the next sample. Hence this weight indicates how many samples were deferred to this stack trace.
<dt>stack
<dd>This will be a non-empty array with the stack trace at the time of the sample. The first function is the top of the stack and each subsequent function called the previous function. The 'function' field describes where the function was defined, and the 'site' field describes where the function is currently executing.
</dl>


== Use Cases ==
== Use Cases ==
Line 133: Line 172:
=== Test Cases ===
=== Test Cases ===


The test suite would initially create a <tt>Profiler</tt> object and then start/stop profiling the current page on each call to <tt>startProfiling</tt>/<tt>stopProfiling</tt> and the information returned from <tt>info</tt> would be what is displayed. Between each test, the <tt>clearInfo</tt> method would be used to prevent pollution between runs.
The test suite would initially create a <tt>Profiler</tt> object and then start/stop profiling the current page on each call to <tt>start</tt>/<tt>stop</tt> and the information returned from <tt>results</tt> would be what is displayed. Between each test, the <tt>reset</tt> method would be used to prevent pollution between runs.


=== Extension ===
=== Extension ===


Opened on a page and creates its own <tt>Profiler</tt> object. It then profiles the current page via <tt>startProfiling</tt> (probably a button to be hit). Some time later <tt>info</tt> is used to get information about the run of profiling (again probably a button being hit) and then all of the information is sorted through and displayed in some fancy fashion.
Opened on a page and creates its own <tt>Profiler</tt> object. It then profiles the current page via <tt>start</tt> (probably a button to be hit). Some time later <tt>results</tt> is used to get information about the run of profiling (again probably a button being hit) and then all of the information is sorted through and displayed in some fancy fashion.


The page being profiled is unaware that it's being profiled, and there's nothing that it needs to do to help it along.
The page being profiled is unaware that it's being profiled, and there's nothing that it needs to do to help it along.
Jimb
Confirmed users
497

edits

Retrieved from "https://wiki.mozilla.org/Special:MobileDiff/446844...472070"