✨ Add time logging

elastic · Nov 12, 2024 · 8fb54a2 · 8fb54a2
1 parent d6b8f9b
commit 8fb54a2
Showing 1 changed file with 37 additions and 5 deletions.
diff --git a/x-pack/test/functional/page_objects/log_wrapper.ts b/x-pack/test/functional/page_objects/log_wrapper.ts
@@ -7,6 +7,10 @@
 
 import { ToolingLog } from '@kbn/tooling-log';
 
+function isPromise<T>(value: unknown): value is Promise<T> {
+  return value instanceof Promise;
+}
+
 /**
  * Wraps the specified object instance with debug log statements of all method calls.
  *
@@ -19,17 +23,45 @@ export function logWrapper<T extends Record<string, Function>>(
   log: ToolingLog,
   instance: T
 ): T {
+  const logger = prepareLogger(log, prefix);
   return Object.keys(instance).reduce((acc, prop) => {
     const baseFn = acc[prop];
     (acc as Record<string, Function>)[prop] = (...args: unknown[]) => {
-      logMethodCall(log, prefix, prop, args);
-      return baseFn.apply(instance, args);
+      logger.start(prop, args);
+      const result = baseFn.apply(instance, args);
+      if (isPromise(result)) {
+        result.then(logger.end, logger.end);
+      } else {
+        logger.end();
+      }
+      return result;
     };
     return acc;
   }, instance);
 }
 
-function logMethodCall(log: ToolingLog, prefix: string, prop: string, args: unknown[]) {
-  const argsStr = args.map((arg) => (typeof arg === 'string' ? `'${arg}'` : arg)).join(', ');
-  log.debug(`${prefix}.${prop}(${argsStr})`);
+function prepareLogger(log: ToolingLog, prefix: string) {
+  let now = Date.now();
+  let currentContext = '';
+
+  return {
+    start: (prop: string, args: unknown[]) => {
+      if (prop === '') {
+        return;
+      }
+      currentContext = `${prop}(${args
+        .map((arg) => (typeof arg === 'string' ? `'${arg}'` : JSON.stringify(arg)))
+        .join(', ')})`;
+      log.debug(`${prefix}.${currentContext}`);
+      now = Date.now();
+    },
+    end: () => {
+      if (currentContext === '') {
+        return;
+      }
+      log.debug(`${prefix}.${currentContext} - (Took ${Date.now() - now} ms)`);
+      now = Date.now();
+      currentContext = '';
+    },
+  };
 }