perf hooks

src/services/configuration.extension.ts

@@ -25,6 +25,8 @@ export const EVENT_CONFIGURATION_UPDATED = "event_configuration_updated";
 export const INJECTED_DEFINITIONS = Symbol.for("injected-config");
 export type ConfigManager = ReturnType<typeof Configuration>;
 
+const DECIMALS = 2;
+
 export function Configuration({
   context,
   event,
@@ -97,15 +99,15 @@ export function Configuration({
       internal.boot.application.configurationLoaders ??
       ([ConfigLoaderEnvironment, ConfigLoaderFile] as ConfigLoader[]);
 
-    const start = Date.now();
+    const start = performance.now();
 
     // * were configs disabled?
     if (is.empty(configLoaders)) {
       validateConfig();
       if (!configuration.boilerplate.IS_TEST) {
         logger.warn({ name: initialize }, `no config loaders defined`);
       }
-      return `${Date.now() - start}ms`;
+      return `${(performance.now() - start).toFixed(DECIMALS)}ms`;
     }
 
     // * load!
@@ -121,7 +123,7 @@ export function Configuration({
 
     validateConfig();
 
-    return `${Date.now() - start}ms`;
+    return `${performance.now() - start}ms`;
   }
 
   function merge(merge: Partial<PartialConfiguration>) {

src/services/lifecycle.extension.ts

@@ -15,6 +15,7 @@ type EventMapObject = {
   priority: number;
 };
 const PRE_CALLBACKS_START = 0;
+const DECIMALS = 2;
 
 export function CreateLifecycle() {
   const events = new Map<LifecycleStages, EventMapObject[]>(
@@ -44,7 +45,7 @@ export function CreateLifecycle() {
       onShutdownStart: (callback, priority) => attachEvent(callback, "ShutdownStart", priority),
     } satisfies TLifecycleBase,
     async exec(stage: LifecycleStages): Promise<string> {
-      const start = Date.now();
+      const start = performance.now();
       const list = events.get(stage);
       events.delete(stage);
       if (!is.empty(list)) {
@@ -82,7 +83,7 @@ export function CreateLifecycle() {
           async ({ callback }) => await callback(),
         );
       }
-      return `${Date.now() - start}ms`;
+      return `${(performance.now() - start).toFixed(DECIMALS)}ms`;
     },
   };
 }

src/services/logger.extension.ts

@@ -28,6 +28,7 @@ const LOG_LEVEL_PRIORITY = {
   trace: 10,
   warn: 40,
 };
+const DECIMALS = 2;
 const LOG_LEVELS = Object.keys(LOG_LEVEL_PRIORITY) as TConfigLogLevel[];
 
 let logger = {} as Record<
@@ -48,7 +49,7 @@ export async function Logger({
   internal,
   als,
 }: TServiceParams): Promise<DigitalAlchemyLogger> {
-  let lastMessage = Date.now();
+  let lastMessage = performance.now();
   let logCounter = START;
   let httpLogTarget: string;
 
@@ -158,8 +159,8 @@ export async function Logger({
         }
 
         if (loggerOptions.ms) {
-          const now = Date.now();
-          const diff = Math.floor(now - lastMessage) + `ms`;
+          const now = performance.now();
+          const diff = (now - lastMessage).toFixed(DECIMALS) + `ms`;
           lastMessage = now;
           rawData.ms = diff;
 

src/services/wiring.extension.ts

@@ -164,6 +164,7 @@ const processEvents = new Map([
   // ["unhandledRejection", (reason, promise) => {}],
 ]);
 
+const DECIMALS = 2;
 const BOILERPLATE = (internal: InternalDefinition) =>
   internal.boot.loadedModules.get("boilerplate") as GetApis<ReturnType<typeof createBoilerplate>>;
 
@@ -368,10 +369,10 @@ async function bootstrap<S extends ServiceMap, C extends OptionalModuleConfigura
     LIB_BOILERPLATE = createBoilerplate();
 
     // * Wire it
-    let start = Date.now();
+    let start = performance.now();
     await LIB_BOILERPLATE[WIRE_PROJECT](internal, wireService);
 
-    CONSTRUCT.boilerplate = `${Date.now() - start}ms`;
+    CONSTRUCT.boilerplate = `${(performance.now() - start).toFixed(DECIMALS)}ms`;
     // ~ configuration
     api.configuration?.[LOAD_PROJECT](LIB_BOILERPLATE.name, LIB_BOILERPLATE.configuration);
     const logger = api.logger.context(WIRING_CONTEXT);
@@ -409,10 +410,10 @@ async function bootstrap<S extends ServiceMap, C extends OptionalModuleConfigura
 
     const order = buildSortOrder(application, logger);
     await eachSeries(order, async i => {
-      start = Date.now();
+      start = performance.now();
       logger.info({ name: bootstrap }, `[%s] init project`, i.name);
       await i[WIRE_PROJECT](internal, wireService);
-      CONSTRUCT[i.name] = `${Date.now() - start}ms`;
+      CONSTRUCT[i.name] = `${(performance.now() - start).toFixed(DECIMALS)}ms`;
     });
 
     logger.trace({ name: bootstrap }, `library wiring complete`);
@@ -422,9 +423,9 @@ async function bootstrap<S extends ServiceMap, C extends OptionalModuleConfigura
       logger.warn({ name: bootstrap }, `bootLibrariesFirst`);
     } else {
       logger.info({ name: bootstrap }, `init application`);
-      start = Date.now();
+      start = performance.now();
       await application[WIRE_PROJECT](internal, wireService);
-      CONSTRUCT[application.name] = `${Date.now() - start}ms`;
+      CONSTRUCT[application.name] = `${(performance.now() - start).toFixed(DECIMALS)}ms`;
     }
 
     // ? Configuration values provided bootstrap take priority over module level
@@ -455,15 +456,15 @@ async function bootstrap<S extends ServiceMap, C extends OptionalModuleConfigura
       // - fastify: bindings are available but port isn't listening
 
       logger.info({ name: bootstrap }, `late init application`);
-      start = Date.now();
+      start = performance.now();
       await application[WIRE_PROJECT](internal, wireService);
-      CONSTRUCT[application.name] = `${Date.now() - start}ms`;
+      CONSTRUCT[application.name] = `${(performance.now() - start).toFixed(DECIMALS)}ms`;
     }
 
     logger.debug({ name: bootstrap }, `[Ready] running lifecycle callbacks`);
     STATS.Ready = await runReady(internal);
 
-    STATS.Total = `${Date.now() - internal.boot.startup.getTime()}ms`;
+    STATS.Total = `${performance.now() - internal.boot.startup.getTime()}ms`;
     // * App is ready!
     logger.info(
       options?.showExtraBootStats