From 0fff306c6fa19cb871c4b3e723d9f6144f0c128c Mon Sep 17 00:00:00 2001 From: ShelbyZ Date: Sun, 22 Sep 2019 08:10:32 -0700 Subject: [PATCH 1/3] feat: add estimated execution time to function run - use process.hrtime.bigint() to track start/stop - debug log estimated execution time in milliseconds Not sure if requiring debug() is the correct way to report this information. We could also consider displaying a warning/error message if the estimated duration execeeds the defined limit. Another approach to capturing timing would be to use perf_hooks to setup an observer and add measurements. The observer could process the measurements (logging) and disconnect. --- src/runtime/route.ts | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/src/runtime/route.ts b/src/runtime/route.ts index acbfe702..5fb6ca2e 100644 --- a/src/runtime/route.ts +++ b/src/runtime/route.ts @@ -133,21 +133,35 @@ export function functionToRoute( debug('Event for %s: %o', req.path, event); const context = constructContext(config); debug('Context for %s: %p', req.path, context); + let run_timings: { + start: bigint; + end: bigint; + } = { + start: BigInt(0), + end: BigInt(0), + }; const callback: ServerlessCallback = function callback( err, responseObject? ) { + run_timings.end = process.hrtime.bigint(); debug('Function execution %s finished', req.path); if (err) { handleError(err, req, res, functionFilePath); return; } handleSuccess(responseObject, res); + debug( + `(Estimated) Total Execution Time: ${Number( + run_timings.end - run_timings.start + ) / 1e6}ms` + ); }; debug('Calling function for %s', req.path); try { + run_timings.start = process.hrtime.bigint(); fn(context, event, callback); } catch (err) { callback(err); From f7e4a299eae9335b7fac0a5d5823605a911f9913 Mon Sep 17 00:00:00 2001 From: ShelbyZ Date: Tue, 24 Sep 2019 22:33:01 -0700 Subject: [PATCH 2/3] feat: add estimated execution time to function run - fix trying to use process.hrtime.bigint() on nodeJS 6.x --- src/runtime/route.ts | 19 ++++++++++--------- 1 file changed, 10 insertions(+), 9 deletions(-) diff --git a/src/runtime/route.ts b/src/runtime/route.ts index 5fb6ca2e..42c3a2ae 100644 --- a/src/runtime/route.ts +++ b/src/runtime/route.ts @@ -134,18 +134,18 @@ export function functionToRoute( const context = constructContext(config); debug('Context for %s: %p', req.path, context); let run_timings: { - start: bigint; - end: bigint; + start: [number, number]; + end: [number, number]; } = { - start: BigInt(0), - end: BigInt(0), + start: [0, 0], + end: [0, 0], }; const callback: ServerlessCallback = function callback( err, responseObject? ) { - run_timings.end = process.hrtime.bigint(); + run_timings.end = process.hrtime(); debug('Function execution %s finished', req.path); if (err) { handleError(err, req, res, functionFilePath); @@ -153,15 +153,16 @@ export function functionToRoute( } handleSuccess(responseObject, res); debug( - `(Estimated) Total Execution Time: ${Number( - run_timings.end - run_timings.start - ) / 1e6}ms` + `(Estimated) Total Execution Time: ${(run_timings.end[0] * 1e9 + + run_timings.end[1] - + (run_timings.start[0] * 1e9 + run_timings.start[1])) / + 1e6}ms` ); }; debug('Calling function for %s', req.path); try { - run_timings.start = process.hrtime.bigint(); + run_timings.start = process.hrtime(); fn(context, event, callback); } catch (err) { callback(err); From 4c5a29ed5fd853fddf6768583e568ac9be2443e4 Mon Sep 17 00:00:00 2001 From: ShelbyZ Date: Wed, 25 Sep 2019 11:06:59 -0700 Subject: [PATCH 3/3] feat: add estimated execution time to function run - moving debug statement before error handling/return --- src/runtime/route.ts | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/src/runtime/route.ts b/src/runtime/route.ts index 42c3a2ae..5b5ac050 100644 --- a/src/runtime/route.ts +++ b/src/runtime/route.ts @@ -147,17 +147,17 @@ export function functionToRoute( ) { run_timings.end = process.hrtime(); debug('Function execution %s finished', req.path); - if (err) { - handleError(err, req, res, functionFilePath); - return; - } - handleSuccess(responseObject, res); debug( `(Estimated) Total Execution Time: ${(run_timings.end[0] * 1e9 + run_timings.end[1] - (run_timings.start[0] * 1e9 + run_timings.start[1])) / 1e6}ms` ); + if (err) { + handleError(err, req, res, functionFilePath); + return; + } + handleSuccess(responseObject, res); }; debug('Calling function for %s', req.path);