1 /**
  2  * The Render Engine
  3  * JavaScript Profiler
  4  *
  5  * @fileoverview Profiler Object
  6  *
  7  * @author: Brett Fattori (brettf@renderengine.com)
  8  * @author: $Author: bfattori@gmail.com $
  9  * @version: $Revision: 1562 $
 10  *
 11  * Copyright (c) 2011 Brett Fattori (brettf@renderengine.com)
 12  *
 13  * Permission is hereby granted, free of charge, to any person obtaining a copy
 14  * of this software and associated documentation files (the "Software"), to deal
 15  * in the Software without restriction, including without limitation the rights
 16  * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
 17  * copies of the Software, and to permit persons to whom the Software is
 18  * furnished to do so, subject to the following conditions:
 19  *
 20  * The above copyright notice and this permission notice shall be included in
 21  * all copies or substantial portions of the Software.
 22  *
 23  * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
 24  * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
 25  * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
 26  * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
 27  * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
 28  * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
 29  * THE SOFTWARE.
 30  *
 31  */
 32 
 33 /**
 34  * @class A static JavaScript implementation of a simple profiler.
 35  * @static
 36  */
 37 R.debug.Profiler = {
 38     profileStack:[],
 39     allProfiles:{},
 40     profiles:[],
 41     running:false,
 42     engineStartTime:0,
 43     engineFrameStart:0
 44 };
 45 
 46 /**
 47  * Start the profiler.
 48  * @memberOf R.debug.Profiler
 49  */
 50 R.debug.Profiler.start = function () {
 51     R.debug.Profiler.resetProfiles();
 52     R.debug.Profiler.running = true;
 53 
 54     R.debug.Profiler.engineStartTime = R.Engine.worldTime;
 55     R.debug.Profiler.engineFrameStart = R.Engine.totalFrames;
 56 };
 57 
 58 /**
 59  * Stop the profiler, dumping whatever was being profiled.
 60  * @memberOf R.debug.Profiler
 61  */
 62 R.debug.Profiler.stop = function () {
 63     R.debug.Profiler.dump();
 64     R.debug.Profiler.running = false;
 65 };
 66 
 67 /**
 68  * Add a profile monitor to the stack of running profiles.  A good way to profile code
 69  * is to use the <tt>try/finally</tt> method so that the profile will be exited even
 70  * if the method returns from multiple points.
 71  <pre>
 72  function func() {
 73       try {
 74          Profiler.enter("func");
 75          
 76          doStuff = doStuff + 1;
 77          return doStuff;
 78       } finally {
 79          Profiler.exit();
 80       }
 81    }
 82  </pre>
 83  *
 84  * @param prof {String} The name of the profile
 85  * @memberOf R.debug.Profiler
 86  */
 87 R.debug.Profiler.enter = function (prof) {
 88     if (!R.debug.Profiler.running) {
 89         return;
 90     }
 91     var profile = R.debug.Profiler.allProfiles[prof];
 92     if (profile == null) {
 93         // Create a monitor
 94         profile = R.debug.Profiler.allProfiles[prof] = {
 95             name:prof,
 96             startMS:R.now(),
 97             execs:0,
 98             totalMS:0,
 99             instances:1,
100             pushed:false
101         };
102     } else {
103         profile.startMS = profile.instances == 0 ? R.now() : profile.startMS;
104         profile.instances++;
105     }
106     R.debug.Profiler.profileStack.push(profile);
107 };
108 
109 /**
110  * For every "enter", there needs to be a matching "exit" to
111  * tell the profiler to stop timing the contained code.  Note
112  * that "exit" doesn't take any parameters.  It is necessary that
113  * you properly balance your profile stack.  Too many "exit" calls
114  * will result in a stack underflow. Missing calls to "exit" will
115  * result in a stack overflow.
116  * @memberOf R.debug.Profiler
117  */
118 R.debug.Profiler.exit = function () {
119     if (!R.debug.Profiler.running) {
120         return;
121     }
122     if (R.debug.Profiler.profileStack.length == 0) {
123         var msg = "Profile stack underflow";
124         if (typeof console !== "undefined") {
125             console.error(msg);
126         }
127         throw(msg);
128     }
129 
130     var profile = R.debug.Profiler.profileStack.pop();
131     profile.endMS = new Date();
132     profile.execs++;
133     profile.instances--;
134     profile.totalMS += profile.instances == 0 ? (profile.endMS.getTime() - profile.startMS.getTime()) : 0;
135     if (!profile.pushed) {
136         // If we haven't remembered it, do that now
137         profile.pushed = true;
138         R.debug.Profiler.profiles.push(profile);
139     }
140 };
141 
142 /**
143  * Reset any currently running profiles and clear the stack.
144  * @memberOf R.debug.Profiler
145  */
146 R.debug.Profiler.resetProfiles = function () {
147     R.debug.Profiler.profileStack = [];
148     R.debug.Profiler.allProfiles = {};
149     R.debug.Profiler.profiles = [];
150 };
151 
152 /**
153  * Dump the profiles that are currently in the stack to a debug window.
154  * The profile stack will be cleared after the dump.
155  * @memberOf R.debug.Profiler
156  */
157 R.debug.Profiler.dump = function () {
158     if (!R.debug.Profiler.running) {
159         return;
160     }
161     if (R.debug.Profiler.profileStack.length > 0) {
162         // overflow - profiles left in stack
163         var rProfs = "";
164         for (var x in R.debug.Profiler.profileStack) {
165             rProfs += (rProfs.length > 0 ? "," : "") + x;
166         }
167         R.debug.Console.error("Profile stack overflow.  Running profiles: ", rProfs);
168     }
169 
170     var d = new Date();
171     d = d.getHours() + ":" + d.getMinutes() + ":" + d.getSeconds();
172 
173     var rev = R.debug.Profiler.profiles.reverse();
174     var totalTime = 0;
175     var out = "";
176     for (var r in rev) {
177         var avg = Math.round(rev[r].totalMS / rev[r].execs);
178         totalTime += rev[r].totalMS;
179         out += "# " + rev[r].name + " | " + (rev[r].totalMS < 1 ? "<1" : rev[r].totalMS) + " ms | " + rev[r].execs + " @ " + (avg < 1 ? "<1" : avg) + " ms\n";
180     }
181     out += "# Total Time: | " + totalTime + " ms | \n";
182 
183     R.debug.Console.warn("PROFILER RESULTS @ " + d + "\n---------------------------------------------------\n");
184     R.debug.Console.warn("   Runtime: " + (R.Engine.worldTime - R.debug.Profiler.engineStartTime) + "ms\n" +
185         "   Frames: " + (R.Engine.totalFrames - R.debug.Profiler.engineFrameStart) +
186         "\n---------------------------------------------------\n");
187 
188     R.debug.Console.info(out);
189 
190     R.debug.Profiler.resetProfiles();
191 };
192 
193 /**
194  * Wire the objects in the array with profiling
195  * @param objArray {Array} Object array
196  * @memberOf R.debug.Profiler
197  */
198 R.debug.Profiler.wireObjects = function (objArray) {
199     for (var obj in objArray) {
200 
201         for (var o in objArray[obj].prototype) {
202             try {
203                 if (typeof objArray[obj].prototype[o] == "function" &&
204                     objArray[obj].prototype.hasOwnProperty(o) && o != "constructor") {
205                     // wrap it in a function to profile it
206                     var f = objArray[obj].prototype[o];
207                     var fn = function () {
208                         try {
209                             R.debug.Profiler.enter(arguments.callee.ob + "." + arguments.callee.o + "()");
210                             return arguments.callee.f.apply(this, arguments);
211                         } finally {
212                             R.debug.Profiler.exit();
213                         }
214                     };
215                     fn.f = f;
216                     fn.o = o;
217                     fn.ob = objArray[obj].getClassName();
218 
219                     objArray[obj].prototype[o] = fn;
220                 }
221             } catch (e) {
222             }
223         }
224 
225     }
226 };
227