Ticket #1827: step_profiler.3.patch

src/profile/StepProfiler.js

@@ +1 @@
+dojo.provide("dojo.profile.StepProfiler");
+
+// summary: This is a simple profiler for measuring the time in milliseconds 
+//   between steps in a process.
+// example: 
+//   dojo.profile.StepProfiler.start("my");
+//   ... activity ...
+//   dojo.profile.StepProfiler.step("my", "mid-point");
+//   ... activity ...
+//   dojo.profile.StepProfiler.step("my", "end");
+//   dojo.profile.StepProfiler.print();
+//
+//   output via dojo.debug:
+//     StepProfiler - my.start:
+//     StepProfiler - my.mid-point: 32ms
+//     StepProfiler - my.end: 13ms
+//
+
+dojo.profile.StepProfiler = new function() {
+        var _profiles = {};
+        
+        this.step = function(profile, step, print) {
+                // summary: add a profile step. This will create a profile if the profile
+                //   name does not exist.
+                // profile: string profile name to record against
+                // step: string? name for this step. Default is step_[count] (eg. 'step_1').
+                // print: boolean? whether to print the time since the last step 
+                //   immediately. Default is false.
+                var p = _profiles[profile];
+                if (!p) {
+                        p = [];
+                        _profiles[profile] = p;
+                }
+                if (!step) {
+                        var step = "step_" + p.length;
+                }
+                p.push([step, (new Date()).valueOf()]);
+                if (print) {
+                        dojo.debug("StepProfiler - " + profile + "." + step + ": " + this._getStepTime(p, p.length-1, true));
+                }
+        }
+
+        this.start = function(profile, step, print) {
+                // summary: resets the profiler and adds an initial step. This will 
+                //   create a profile if the profile name does not exist.
+                // profile: string profile name to record against
+                // step: string? name for this step. Default is 'start'.
+                // print: boolean? whether to print the time since the last step 
+                //   immediately. Default is false.
+                this.reset(profile);
+                if (!step)
+                        var step = "start";
+                this.step(profile, step, print);
+        }
+        
+        this._getStepTime = function(profile, index, asText) {
+                // summary: return the time between two steps in a profile, in milliseconds
+                // profile: profile array a profile
+                // index: index to get the step time for
+                // asText: boolean return a string or a number
+                if (asText) {
+                        return (index > 0) ? (profile[index][1] - profile[index-1][1])+"ms" : "";
+                } else {
+                        return (index > 0) ? (profile[index][1] - profile[index-1][1]) : 0;
+                }
+        }
+        
+        this.print = function(profile) {
+                // summary: print the results for a profile using dojo.debug
+                // profile: string profile name to print
+                var p = _profiles[profile];
+                if (!p) 
+                        return;
+                
+                dojo.debug("StepProfiler - " + profile + ":");
+                for (var i=0; i<p.length; i++) {
+                        dojo.debug(" " + p[i][0] + ": " + this._getStepTime(p, i, true));
+                }
+        }
+        
+        this.toArray = function(profile) {
+                // summary: return the profile results as an array
+                // profile: string profile name to return
+                // returns: profile results in an array [[stepname,steptime_ms], [stepname,steptime_ms], ...]
+                var p = _profiles[profile];
+                if (!p)
+                        return [];
+                else {
+                        var res = [];
+                        for (var i=0; i<p.length; i++) {
+                                res.push([p[i][0], this._getStepTime(p, i, false)]);
+                        }
+                        return res;
+                } 
+        }
+        
+        this.reset = function(profile) {
+                // summary: clear the steps for a profile
+                // profile: string profile name
+                _profiles[profile] = [];
+        }
+};

tests/profile/test_StepProfiler.js

@@ +1 @@
+dojo.require("dojo.profile.StepProfiler");
+
+function profile_StepProfiler_delaybusy(time_ms) {
+        // busy-delay since setTimeout isn't available in tests, and it's 
+        // asynchronous which messes up the test logic
+        var s = (new Date()).valueOf();
+        while ((new Date()).valueOf() - s < time_ms);
+}
+
+function test_StepProfiler_profiling() {
+        dojo.profile.StepProfiler.start("test0");
+
+        profile_StepProfiler_delaybusy(100);
+        // this time also make it print "in-line"
+        dojo.profile.StepProfiler.step("test0", "step+100ms", true);
+        jum.debug("profiler should have just printed 'StepProfiler - test0.step+100ms: 100ms'");
+        
+        profile_StepProfiler_delaybusy(150);
+        dojo.profile.StepProfiler.step("test0", "step+250ms");
+        
+        profile_StepProfiler_delaybusy(50);
+        dojo.profile.StepProfiler.step("test0");
+
+        var ar = dojo.profile.StepProfiler.toArray("test0");
+        jum.assertEquals("step count", 4, ar.length);
+        jum.assertEquals("start-name", "start", ar[0][0]);
+        jum.assertEquals("start-time", 0, ar[0][1]);
+        jum.assertEquals("mid-name", "step+250ms", ar[2][0]);
+        jum.assertEquals("auto-name", "step_3", ar[3][0]);
+
+        // since JS timing is not so accurate...
+        var diff = ar[2][1] - 150;
+        var closeEnoughTime = ((diff >= 0) && (diff <= 15));
+        jum.debug("time difference was: " + diff);
+        jum.assertTrue("mid-time=" + diff, closeEnoughTime);
+        
+        jum.debug("testing StepProfiler print...");
+        dojo.profile.StepProfiler.print();
+        jum.debug("profile should have printed.");
+}
+
+function test_StepProfiler_reset() {
+        dojo.profile.StepProfiler.start("test1", "start");
+        dojo.profile.StepProfiler.step("test1", "step +0");
+
+        var ar = dojo.profile.StepProfiler.toArray("test1");
+        jum.assertEquals("initial step count", 2, ar.length);
+
+        dojo.profile.StepProfiler.reset("test1");
+        var ar = dojo.profile.StepProfiler.toArray("test1");
+        jum.assertEquals("reset step count", 0, ar.length);
+}
+