Add try catch for profiler decorator

This commit is contained in:
vakrilov
2017-05-13 13:27:13 +03:00
parent 5441e7d1fc
commit b47dafc01a
3 changed files with 100 additions and 38 deletions

View File

@ -1,6 +1,20 @@
import * as TKUnit from "../TKUnit";
import { assert, assertEqual, assertFalse, assertTrue, assertThrows } from "../TKUnit";
import * as prof from "tns-core-modules/profiling";
prof.enable();
class TestClass {
@prof.profile("__func_decorator__")
doNothing() {
//noop
}
@prof.profile("__func_decorator_error__")
throwError() {
throw new Error("This error is expected");
}
}
prof.disable();
export function setUp() {
prof.enable();
}
@ -11,56 +25,93 @@ export function tearDown() {
export function test_time_throws_if_not_enabled() {
prof.disable();
TKUnit.assertThrows(prof.time);
assertThrows(prof.time);
};
export function test_time_returns_number_if_enabled() {
TKUnit.assertEqual(typeof prof.time(), "number");
assertEqual(typeof prof.time(), "number");
};
export function test_isRunning() {
const name = "test_isRunning";
assertFalse(prof.isRunning(name), "isRunning should be false before start");
prof.start(name);
assertTrue(prof.isRunning(name), "isRunning should be true after start");
prof.pause(name);
assertFalse(prof.isRunning(name), "isRunning should be false after pause");
prof.start(name);
assertTrue(prof.isRunning(name), "isRunning should be true after second start");
prof.stop(name);
assertFalse(prof.isRunning(name), "isRunning should be false after stop");
}
export function test_start_stop() {
prof.start("__test1__");
const res = prof.stop("__test1__");
const name = "test_start_stop";
TKUnit.assertEqual(res.count, 1);
TKUnit.assert(res.totalTime <= 1);
prof.start(name);
const res = prof.stop(name);
assertEqual(res.count, 1);
assert(res.totalTime <= 1);
};
export function test_start_pause() {
export function test_start_pause_count() {
const name = "test_start_pause_count";
for (var i = 0; i < 10; i++) {
prof.start("__test2__");
prof.pause("__test2__");
prof.start(name);
prof.pause(name);
}
const res = prof.stop("__test2__");
TKUnit.assertEqual(res.count, 10);
TKUnit.assert(res.totalTime <= 1);
const res = prof.stop(name);
assertEqual(res.count, 10);
};
export function test_timer_performance() {
for (var i = 0; i < 10000; i++) {
prof.start("__test3__");
prof.pause("__test3__");
export function test_start_pause_performance() {
const count = 1000;
const name = "test_start_pause_performance";
for (var i = 0; i < count; i++) {
prof.start(name);
prof.pause(name);
}
const res = prof.stop("__test3__");
TKUnit.assertEqual(res.count, 10000);
TKUnit.assert(res.totalTime <= 30, "Total time for 1000 timer operations is too much: " + res.totalTime);
const res = prof.stop(name);
assertEqual(res.count, count);
assert(res.totalTime <= 50, `Total time for ${count} timer operations is too much: ${res.totalTime}`);
};
export function test_profile_decorator_count_counts() {
class TestClass {
@prof.profile("__func_decorator__")
f() {
//noop
export function test_profile_decorator_count() {
const test = new TestClass();
for (var i = 0; i < 10; i++) {
test.doNothing();
}
const res = prof.stop("__func_decorator__");
assertEqual(res.count, 10);
}
export function test_profile_decorator_performance() {
const count = 1000;
const test = new TestClass();
for (var i = 0; i < count; i++) {
test.doNothing();
}
for (var i = 0; i < 10; i++) {
test.f();
}
const res = prof.stop("__func_decorator__");
TKUnit.assertEqual(res.count, 10);
assertEqual(res.count, count);
assert(res.totalTime <= 50, `Total time for ${count} timer operations is too much: ${res.totalTime}`);
}
export function test_profile_decorator_handles_exceptions() {
const test = new TestClass();
assertThrows(() => test.throwError());
assertFalse(prof.isRunning("__func_decorator_error__"), "Timer should be stopped on exception.");
assertEqual(prof.stop("__func_decorator_error__").count, 1, "Timer should be called once");
}

View File

@ -48,6 +48,13 @@ export declare function pause(name: string): TimerInfo;
*/
export declare function stop(name: string): TimerInfo;
/**
* Returns true if a timer is currently running.
* @param name Name of the timer.
* @returns true is the timer is currently running.
*/
export declare function isRunning(name: string): boolean;
/**
* Method decorator factory. It will intercept the method call and start and pause a timer before and after the method call.
* Works only if profiling is enabled.

View File

@ -89,14 +89,19 @@ export function stop(name: string): TimerInfo {
return info;
}
export function isRunning(name: string): boolean {
const info = timers.get(name);
return !!(info && info.isRunning);
}
function pauseInternal(name: string): TimerInfo {
let info = timers.get(name);
const info = timers.get(name);
if (!info) {
throw new Error(`No timer started: ${name}`);
}
if (info.isRunning) {
info.lastTime = Math.round(time() - info.currentStart);
info.lastTime = time() - info.currentStart;
info.totalTime += info.lastTime;
info.count++;
info.currentStart = 0;
@ -128,12 +133,11 @@ export function profile(name?: string): MethodDecorator {
//editing the descriptor/value parameter
descriptor.value = function () {
start(name);
var result = originalMethod.apply(this, arguments);
pause(name)
return result;
try {
return originalMethod.apply(this, arguments);
} finally {
pause(name);
}
};
// return edited descriptor as opposed to overwriting the descriptor