verbose logs

Author: nicktrn

apps/supervisor/src/index.ts

@@ -168,11 +168,6 @@ class ManagedSupervisor {
       });
     }
 
-    // setInterval(async () => {
-    //   const resources = await this.resourceMonitor.getNodeResources(true);
-    //   this.logger.debug("Current resources", { resources });
-    // }, 1000);
-
     this.workerSession.on("runNotification", async ({ time, run }) => {
       this.logger.log("runNotification", { time, run });
 
@@ -187,7 +182,6 @@ class ManagedSupervisor {
           runId: message.run.id,
           completedWaitpoints: message.completedWaitpoints.length,
         });
-        // TODO: Do something with them or if we don't need the data here, maybe we shouldn't even send it
       }
 
       if (!message.image) {

packages/core/src/v3/runEngineWorker/supervisor/queueConsumer.ts

@@ -55,16 +55,23 @@ export class RunQueueConsumer {
   }
 
   private async dequeue() {
-    // Incredibly verbose logging for debugging purposes
-    // this.logger.debug("dequeue()", { enabled: this.isEnabled });
+    this.logger.verbose("dequeue()", {
+      enabled: this.isEnabled,
+      intervalMs: this.intervalMs,
+      idleIntervalMs: this.idleIntervalMs,
+      maxRunCount: this.maxRunCount,
+      preDequeue: !!this.preDequeue,
+      preSkip: !!this.preSkip,
+    });
 
     if (!this.isEnabled) {
+      this.logger.warn("dequeue() - not enabled");
       return;
     }
 
     let preDequeueResult: Awaited<ReturnType<PreDequeueFn>> | undefined;
     if (this.preDequeue) {
-      // this.logger.debug("preDequeue()");
+      this.logger.verbose("preDequeue()");
 
       try {
         preDequeueResult = await this.preDequeue();
@@ -73,13 +80,15 @@ export class RunQueueConsumer {
       }
     }
 
-    // this.logger.debug("preDequeueResult", { preDequeueResult });
+    this.logger.verbose("preDequeueResult", { preDequeueResult });
 
     if (
       preDequeueResult?.skipDequeue ||
       preDequeueResult?.maxResources?.cpu === 0 ||
       preDequeueResult?.maxResources?.memory === 0
     ) {
+      this.logger.debug("skipping dequeue", { preDequeueResult });
+
       if (this.preSkip) {
         this.logger.debug("preSkip()");
 
@@ -90,7 +99,8 @@ export class RunQueueConsumer {
         }
       }
 
-      return this.scheduleNextDequeue(this.idleIntervalMs);
+      this.scheduleNextDequeue(this.idleIntervalMs);
+      return;
     }
 
     let nextIntervalMs = this.idleIntervalMs;
@@ -122,6 +132,10 @@ export class RunQueueConsumer {
   }
 
   scheduleNextDequeue(delayMs: number) {
+    if (delayMs === this.idleIntervalMs && this.idleIntervalMs !== this.intervalMs) {
+      this.logger.verbose("scheduled dequeue with idle interval", { delayMs });
+    }
+
     setTimeout(this.dequeue.bind(this), delayMs);
   }
 }

packages/core/src/v3/runEngineWorker/supervisor/session.ts

@@ -75,11 +75,9 @@ export class SupervisorSession extends EventEmitter<WorkerEvents> {
   }
 
   private async onDequeue(messages: WorkerApiDequeueResponseBody): Promise<void> {
-    // Incredibly verbose logging for debugging purposes
-    // this.logger.debug("Dequeued messages with contents", { count: messages.length, messages });
+    this.logger.verbose("Dequeued messages with contents", { count: messages.length, messages });
 
     for (const message of messages) {
-      this.logger.debug("Emitting message", { message });
       this.emit("runQueueMessage", {
         time: new Date(),
         message,

packages/core/src/v3/utils/structuredLogger.ts

@@ -15,14 +15,17 @@ export enum LogLevel {
   "warn",
   "info",
   "debug",
+  "verbose",
 }
 
 export class SimpleStructuredLogger implements StructuredLogger {
   private prettyPrint = ["1", "true"].includes(process.env.PRETTY_LOGS ?? "");
 
   constructor(
     private name: string,
-    private level: LogLevel = ["1", "true"].includes(process.env.DEBUG ?? "")
+    private level: LogLevel = ["1", "true"].includes(process.env.VERBOSE ?? "")
+      ? LogLevel.verbose
+      : ["1", "true"].includes(process.env.DEBUG ?? "")
       ? LogLevel.debug
       : LogLevel.info,
     private fields?: Record<string, unknown>
@@ -62,6 +65,12 @@ export class SimpleStructuredLogger implements StructuredLogger {
     this.#structuredLog(console.debug, message, "debug", ...args);
   }
 
+  verbose(message: string, ...args: StructuredArgs) {
+    if (this.level < LogLevel.verbose) return;
+
+    this.#structuredLog(console.debug, message, "verbose", ...args);
+  }
+
   addFields(fields: Record<string, unknown>) {
     this.fields = {
       ...this.fields,