# Using JavaScript Proxy to automatically time your functions *The [Proxy](https://tc39.es/ecma262/multipage/ordinary-and-exotic-objects-behaviours.html#sec-proxy-object-internal-methods-and-internal-slots) class is a way of intercepting calls to an object. This post assumes basic knowledge of the Proxy object, [there's plenty](https://duckduckgo.com/?q=javascript+proxy) of good information, so read up if this is your first Proxy encounter (I like the [MDN](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Proxy) and [javascript.info](https://javascript.info/proxy) writeups).* ## The idea Is to create a `ProxyStats` class that can time all calls to an object. I'll walk through the class creation in iterations, revisiting methods as functionality is added. ## Initial implementation [Browse the code at github (commit #05a5e66)](https://github.com/BirkAndMe/proxy-stats/tree/05a5e6698527f4ddfa1294465df5767565121fd8) ```javascript class ProxyStats { constructor() { this._timers = {}; this.stats = {}; } static watch(target) { const proxyStats = new ProxyStats(); return proxyStats.watch(target); } watch(target) { return new Proxy(target, this) } getTimeKey(target, property) { return `${target.constructor.name}.${property}`; } time(key) { this._timers[key] = Date.now(); } timeEnd(key) { const time = Date.now() - this._timers[key]; this.updateStats(key, time); console.log(key, `${time} ms (${this.stats[key].time} ms -- ${this.stats[key].count})`); } updateStats(key, time) { this.stats[key] = this.stats[key] || {time: 0, count: 0}; this.stats[key].time += time; this.stats[key].count += 1; } get(target, property, receiver) { const timeKey = 'get ' + this.getTimeKey(target, property); this.time(timeKey); const result = Reflect.get(target, property, receiver); this.timeEnd(timeKey); return result; } set(target, property, value, receiver) { const timeKey = 'set ' + this.getTimeKey(target, property); this.time(timeKey); Reflect.set(target, property, value, receiver); this.timeEnd(timeKey); return true; } } ``` The [`getTimeKey()`](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/ProxyStats.js#L16), [`time()`](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/ProxyStats.js#L20), [`timeEnd()`](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/ProxyStats.js#L24) and [`updateState()`](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/ProxyStats.js#L31) is used for timing and counting the calls to the object. Both the [static](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/ProxyStats.js#L7) and [prototype](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/ProxyStats.js#L12) `watch()` function is used for watching an object.
The static function will automatically create a new ProxyStats, while the prototype function can be used to watch several objects with the same handler instance.
Using the same ProxyStats instance to watch several objects is helpful if you want to get statistics across all objects watched. The [`get()`](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Proxy/Proxy/get)^{[spec](https://tc39.es/ecma262/multipage/ordinary-and-exotic-objects-behaviours.html#sec-proxy-object-internal-methods-and-internal-slots-get-p-receiver)} and [`set()`](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Proxy/Proxy/set)^{[spec](https://tc39.es/ecma262/multipage/ordinary-and-exotic-objects-behaviours.html#sec-proxy-object-internal-methods-and-internal-slots-set-p-v-receiver)} traps are both simple implementations. Using the [`Reflect`](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Reflect)^{[spec](https://tc39.es/ecma262/multipage/reflection.html#sec-reflect-object)} object to set or get the original value. This call is timed, and information is added to the `ProxyStats.stats` object. ### Test setup Prepare a [simple class](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/example.html#L16) to test the proxy handler. Notice the 50 ms delays added in the [`getter`](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/example.html#L19), [`setter`](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/example.html#L24) and [`function`](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/example.html#L28). ```javascript function slowFunction(min, max) { const end = Date.now() + Math.round(min + Math.random() * (max - min)); while (Date.now() < end) { } } class ExampleClass { aProperty = 'some property' get aGetter() { slowFunction(50, 50); return 'some getter'; } set aGetter($value) { slowFunction(50, 50); } aFunction() { slowFunction(50, 50); } } ``` Now [wrap the `ExampleClass`](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/example.html#L33) using the `watch()` function, and calling the different properties to see the output. ```javascript const exampleObject = ProxyStats.watch(new ExampleClass()); exampleObject.aProperty; exampleObject.aGetter; exampleObject.aGetter = ''; exampleObject.aFunction(); ``` #### Output The output here is the *console* output written in the `timeEnd()` function, it's the following format: [`KEY TIME ms (TOTAL_TIME ms -- COUNT)`](https://github.com/BirkAndMe/proxy-stats/blob/05a5e6698527f4ddfa1294465df5767565121fd8/ProxyStats.js#L28). * `KEY`: The key tells what kind of trap is used, and the object property. * `TIME`: Is the time of the current call. * `TOTAL_TIME`: Time of all calls for that specific property. * `COUNT`: The amount of times the property has been called. ```no-color get ExampleClass.aProperty 0 ms (0 ms -- 1) get ExampleClass.aGetter 50 ms (50 ms -- 1) get ExampleClass.aGetter 50 ms (100 ms -- 2) set ExampleClass.aGetter 50 ms (50 ms -- 1) get ExampleClass.aFunction 0 ms (0 ms -- 1) get ExampleClass.aFunction 0 ms (0 ms -- 2) ``` Getting a property (`get ExampleClass.aProperty`) is instant, so this seems fine at *0 ms*. Both the getter (`get ExampleClass.aGetter`) and setter (`set ExampleClass.aGetter`) takes *50 ms* as expected. But the function call (`get ExampleClass.aFunction`) is also instant, which is not correct. The reason it's instant is it only gets the property value, which is a function, it's not executing it. ## Getting function timing to work [Browse the code at github (commit #bb97f3f)](https://github.com/BirkAndMe/proxy-stats/tree/bb97f3f43b360b15dfdd396045651c3d08c297d9) To time function calls, the ProxyStats needs to wrap each function in another `Proxy` that utilizes the [`apply()`](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Proxy/Proxy/apply)^{[spec](https://tc39.es/ecma262/multipage/ordinary-and-exotic-objects-behaviours.html#sec-proxy-object-internal-methods-and-internal-slots-call-thisargument-argumentslist)} trap. This is done by [detecting functions](https://github.com/BirkAndMe/proxy-stats/blob/bb97f3f43b360b15dfdd396045651c3d08c297d9/ProxyStats.js#L54) in the `get()` trap and returning a new `Proxy`, created by the helper function [`handleFunction()`](https://github.com/BirkAndMe/proxy-stats/blob/bb97f3f43b360b15dfdd396045651c3d08c297d9/ProxyStats.js#L38): ```javascript handleFunction(target, property, receiver) { const me = this; return new Proxy(target[property], { apply(fnTarget, thisArg, args) { const timeKey = me.getTimeKey(target, property) + '()'; me.time(timeKey); const result = Reflect.apply(fnTarget, thisArg, args); me.timeEnd(timeKey); return result; } }); } get(target, property, receiver) { if (typeof target[property] === 'function') { return this.handleFunction(target, property, receiver); } const timeKey = 'get ' + this.getTimeKey(target, property); this.time(timeKey); const result = Reflect.get(target, property, receiver); this.timeEnd(timeKey); return result; } ``` It's a tiny rewrite of `get()` that returns early if the property is a function. All the functionality is in the `handleFunction()` function Note that the new `Proxy` wraps the actual function [`target[property]`](https://github.com/BirkAndMe/proxy-stats/blob/bb97f3f43b360b15dfdd396045651c3d08c297d9/ProxyStats.js#L41), and timing is simple and done the same way as with properties and getters. ## Recursive functions [Browse the code at github (commit #c652f33)](https://github.com/BirkAndMe/proxy-stats/tree/c652f33193e688cc93df11ef71a719d17c4ad915) The last issue in the POC is recursive functions. When the recursive function calls itself, it resets the timer because the key is identical. Updating the example object will give a clear view of the problem. So [a recursive function](https://github.com/BirkAndMe/proxy-stats/blob/c652f33193e688cc93df11ef71a719d17c4ad915/example.html#L32) is added to the `ExampleClass`. ```javascript aRecursiveFunction(depth) { slowFunction(50, 50); if (--depth > 0) { this.aRecursiveFunction(depth); } } ``` Calling this function with depth 2 [`exampleObject.aRecursiveFunction(2);`](https://github.com/BirkAndMe/proxy-stats/blob/c652f33193e688cc93df11ef71a719d17c4ad915/example.html#L48) will give the following output: ```no-color ExampleClass.aRecursiveFunction() 0 ms (0 ms -- 1) ExampleClass.aRecursiveFunction() 0 ms (0 ms -- 2) ExampleClass.aRecursiveFunction() 0 ms (0 ms -- 3) ``` To fix this the timer key is made unique, so it no longer resets every time a function with the same name is called. This is done in the `handleFunction()` function by adding a random string to the key: ```javascript handleFunction(target, property, receiver) { const me = this; return new Proxy(target[property], { apply(fnTarget, thisArg, args) { const timeKey = me.getTimeKey(target, property) + '() -- ' + Math.random().toString(36).substring(2); me.time(timeKey); const result = Reflect.apply(fnTarget, thisArg, args); me.timeEnd(timeKey); return result; } }); } ``` The important part here is the random string suffix [added to the `timeKey`](https://github.com/BirkAndMe/proxy-stats/blob/c652f33193e688cc93df11ef71a719d17c4ad915/ProxyStats.js#L45).
Don't get confused about the `Math.random().toString(36).substring(2)` it's just a clever way of making a random string, try running it a couple of times in the console. This trick is purely cosmetics a `Math.random()` would've done the job. This creates a problem with aggregating function calls, and makes it impossible, to sum up totals, check out the output: ```no-color ExampleClass.aFunction() -- mq55zfo3g99 50 ms (50 ms -- 1) ExampleClass.aFunction() -- hw42ikytz5m 50 ms (50 ms -- 1) ExampleClass.aRecursiveFunction() -- sirt14hqvn 50 ms (50 ms -- 1) ExampleClass.aRecursiveFunction() -- hfcibln8qjf 100 ms (100 ms -- 1) ``` To solve this the [suffix is removed](https://github.com/BirkAndMe/proxy-stats/blob/c652f33193e688cc93df11ef71a719d17c4ad915/ProxyStats.js#L27) from the key before calling `updateStats()` in the `timeEnd()`. This way the key used in the `_timers` is unique, but key used in the stats is only the function name without the unique part: ```javascript timeEnd(key) { const time = Date.now() - this._timers[key]; key = key.split(' -- ').shift(); this.updateStats(key, time); console.log(key, `${time} ms (${this.stats[key].time} ms -- ${this.stats[key].count})`); } ``` This gives a result without the unique part: ```no-color ExampleClass.aFunction() 50 ms (50 ms -- 1) ExampleClass.aFunction() 50 ms (100 ms -- 2) ExampleClass.aRecursiveFunction() 50 ms (50 ms -- 1) ExampleClass.aRecursiveFunction() 100 ms (150 ms -- 2) ``` There's still an issue with the total sum of the recursive function. - Initial call waits *50 ms*, then calls itself. - The second call waits *50 ms* before logging the time and ending the second call. - Now the initial call has been *100 ms* underway, this is logged and initial call ended. - The total sum is calculated as `second call + initial call`, which is *150 ms* even though only *100 ms* is actually used in total. At this time it's good enough for jazz, but this issue will be fixed later on. ## Future So far so good, the proof of concept seems to be working as intended (except for recursive functions). As I'll be expanding on the ProxyStats class I'll try to create relevant blog posts. The following is a list of possible topics (also functioning as notes for myself, so every bullet might not justify a blog post), in no particular order: - Fix the recursive function issue. - Documenting the class, using [JSDoc](https://jsdoc.app/). - How to use the ProxyStats class. - Testing, with simple unit tests. - Adding more features, filtering calls, smarter watcher functions. - Iterating existing functions and reviewing/rewriting code. - Performance, any obvious performance improvements.