chore: Add LOG_ELAPSED_TIME to track global time in debug logs

AztecProtocol · Nov 20, 2024 · ca97c58 · ca97c58
1 parent a70795b
commit ca97c58
Show file tree

Hide file tree

Showing 2 changed files with 10 additions and 1 deletion.
diff --git a/yarn-project/foundation/src/config/env_var.ts b/yarn-project/foundation/src/config/env_var.ts
@@ -53,6 +53,7 @@ export type EnvVar =
   | 'L1_CHAIN_ID'
   | 'L1_PRIVATE_KEY'
   | 'L2_QUEUE_SIZE'
+  | 'LOG_ELAPSED_TIME'
   | 'LOG_JSON'
   | 'LOG_LEVEL'
   | 'MNEMONIC'

diff --git a/yarn-project/foundation/src/log/logger.ts b/yarn-project/foundation/src/log/logger.ts
@@ -20,6 +20,9 @@ function getLogLevel() {
 
 export let currentLevel = getLogLevel();
 
+const logElapsedTime = ['1', 'true'].includes(process.env.LOG_ELAPSED_TIME ?? '');
+const firstTimestamp: number = Date.now();
+
 function filterNegativePatterns(debugString: string): string {
   return debugString
     .split(',')
@@ -141,7 +144,12 @@ function logWithDebug(debug: debug.Debugger, level: LogLevel, msg: string, data?
 
   msg = data ? `${msg} ${fmtLogData(data)}` : msg;
   if (debug.enabled && LogLevels.indexOf(level) <= LogLevels.indexOf(currentLevel)) {
-    debug('[%s] %s', level.toUpperCase(), msg);
+    if (logElapsedTime) {
+      const ts = ((Date.now() - firstTimestamp) / 1000).toFixed(3);
+      debug('%ss [%s] %s', ts, level.toUpperCase(), msg);
+    } else {
+      debug('[%s] %s', level.toUpperCase(), msg);
+    }
   }
 }