chore: add additional logging around resource and memory useage

src/extension.ts

@@ -7,12 +7,27 @@ import { makeCoderSdk, needToken } from "./api"
 import { errToStr } from "./api-helper"
 import { Commands } from "./commands"
 import { CertificateError, getErrorDetail } from "./error"
+import { getMemoryLogger } from "./memoryLogger"
 import { Remote } from "./remote"
 import { Storage } from "./storage"
 import { toSafeHost } from "./util"
 import { WorkspaceQuery, WorkspaceProvider } from "./workspacesProvider"
 
 export async function activate(ctx: vscode.ExtensionContext): Promise<void> {
+  // Initialize the memory logger right when the extension starts.
+  const logger = getMemoryLogger()
+  await logger.initLogFile(ctx.globalStorageUri.fsPath)
+
+  // Log initial memory usage and activation
+  logger.info("CODER extension activating")
+  logger.logMemoryUsage("EXTENSION_ACTIVATE")
+
+  // Register disposal of the logger when the extension deactivates
+  ctx.subscriptions.push({ dispose: () => logger.dispose() })
+
+  // Log extension mode
+  logger.info(`Extension mode: ${extensionModeToString(ctx.extensionMode)}`)
+
   // The Remote SSH extension's proposed APIs are used to override the SSH host
   // name in VS Code itself. It's visually unappealing having a lengthy name!
   //
@@ -25,9 +40,13 @@ export async function activate(ctx: vscode.ExtensionContext): Promise<void> {
     vscode.extensions.getExtension("codeium.windsurf-remote-openssh") ||
     vscode.extensions.getExtension("ms-vscode-remote.remote-ssh")
   if (!remoteSSHExtension) {
+    logger.error("Remote SSH extension not found, cannot activate Coder extension")
     vscode.window.showErrorMessage("Remote SSH extension not found, cannot activate Coder extension")
     throw new Error("Remote SSH extension not found")
   }
+
+  logger.info(`Found Remote SSH extension: ${remoteSSHExtension.id}`)
+
   // eslint-disable-next-line @typescript-eslint/no-explicit-any
   const vscodeProposed: typeof vscode = (module as any)._load(
     "vscode",
@@ -225,4 +244,26 @@ export async function activate(ctx: vscode.ExtensionContext): Promise<void> {
       }
     }
   }
+
+  logger.info("Coder extension activation complete")
+}
+
+function extensionModeToString(mode: vscode.ExtensionMode): string {
+  switch (mode) {
+    case vscode.ExtensionMode.Development:
+      return "Development"
+    case vscode.ExtensionMode.Production:
+      return "Production"
+    case vscode.ExtensionMode.Test:
+      return "Test"
+    default:
+      return `Unknown (${mode})`
+  }
+}
+
+// Add deactivation handler to log memory usage on extension shutdown
+export function deactivate(): void {
+  const logger = getMemoryLogger()
+  logger.info("Coder extension deactivating")
+  logger.logMemoryUsage("EXTENSION_DEACTIVATE")
 }

src/inbox.ts

@@ -4,6 +4,7 @@ import { ProxyAgent } from "proxy-agent"
 import * as vscode from "vscode"
 import { WebSocket } from "ws"
 import { errToStr } from "./api-helper"
+import { getMemoryLogger } from "./memoryLogger"
 import { type Storage } from "./storage"
 
 // These are the template IDs of our notifications.
@@ -16,9 +17,16 @@ export class Inbox implements vscode.Disposable {
   readonly #storage: Storage
   #disposed = false
   #socket: WebSocket
+  #messageCount = 0
+  #workspaceId: string
 
   constructor(workspace: Workspace, httpAgent: ProxyAgent, restClient: Api, storage: Storage) {
+    const logger = getMemoryLogger()
     this.#storage = storage
+    this.#workspaceId = workspace.id
+
+    logger.trackResourceCreated("InboxWebSocket", workspace.id)
+    logger.info(`Creating inbox for workspace: ${workspace.owner_name}/${workspace.name} (${workspace.id})`)
 
     const baseUrlRaw = restClient.getAxiosInstance().defaults.baseURL
     if (!baseUrlRaw) {
@@ -37,6 +45,8 @@ export class Inbox implements vscode.Disposable {
     const socketProto = baseUrl.protocol === "https:" ? "wss:" : "ws:"
     const socketUrl = `${socketProto}//${baseUrl.host}/api/v2/notifications/inbox/watch?format=plaintext&templates=${watchTemplatesParam}&targets=${watchTargetsParam}`
 
+    logger.debug(`Connecting to inbox WebSocket at: ${socketUrl}`)
+
     const coderSessionTokenHeader = "Coder-Session-Token"
     this.#socket = new WebSocket(new URL(socketUrl), {
       followRedirects: true,
@@ -49,35 +59,72 @@ export class Inbox implements vscode.Disposable {
     })
 
     this.#socket.on("open", () => {
+      logger.info(`Inbox WebSocket connection opened for workspace: ${workspace.id}`)
       this.#storage.writeToCoderOutputChannel("Listening to Coder Inbox")
     })
 
     this.#socket.on("error", (error) => {
+      logger.error(`Inbox WebSocket error for workspace: ${workspace.id}`, error)
       this.notifyError(error)
       this.dispose()
     })
 
+    this.#socket.on("close", (code, reason) => {
+      logger.info(`Inbox WebSocket closed for workspace: ${workspace.id}, code: ${code}, reason: ${reason || "none"}`)
+      if (!this.#disposed) {
+        this.dispose()
+      }
+    })
+
     this.#socket.on("message", (data) => {
+      this.#messageCount++
+
+      // Log periodic message stats
+      if (this.#messageCount % 10 === 0) {
+        logger.info(`Inbox received ${this.#messageCount} messages for workspace: ${workspace.id}`)
+        logger.logMemoryUsage("INBOX_WEBSOCKET")
+      }
+
       try {
         const inboxMessage = JSON.parse(data.toString()) as GetInboxNotificationResponse
-
+        logger.debug(`Inbox notification received: ${inboxMessage.notification.title}`)
         vscode.window.showInformationMessage(inboxMessage.notification.title)
       } catch (error) {
+        logger.error(`Error processing inbox message for workspace: ${workspace.id}`, error)
         this.notifyError(error)
       }
     })
+
+    // Log memory stats periodically
+    const memoryInterval = setInterval(
+      () => {
+        if (!this.#disposed) {
+          logger.logMemoryUsage("INBOX_PERIODIC")
+        } else {
+          clearInterval(memoryInterval)
+        }
+      },
+      5 * 60 * 1000,
+    ) // Every 5 minutes
   }
 
   dispose() {
+    const logger = getMemoryLogger()
+
     if (!this.#disposed) {
+      logger.info(`Disposing inbox for workspace: ${this.#workspaceId} after ${this.#messageCount} messages`)
       this.#storage.writeToCoderOutputChannel("No longer listening to Coder Inbox")
       this.#socket.close()
       this.#disposed = true
+      logger.trackResourceDisposed("InboxWebSocket", this.#workspaceId)
     }
   }
 
   private notifyError(error: unknown) {
+    const logger = getMemoryLogger()
     const message = errToStr(error, "Got empty error while monitoring Coder Inbox")
+
+    logger.error(`Inbox error for workspace: ${this.#workspaceId}`, error)
     this.#storage.writeToCoderOutputChannel(message)
   }
 }

src/memoryLogger.ts

@@ -0,0 +1,221 @@
+import * as fs from "fs/promises"
+import * as os from "os"
+import * as path from "path"
+import * as vscode from "vscode"
+
+/**
+ * A class for tracking memory usage and logging resource lifecycles
+ * to help identify memory leaks in the extension.
+ */
+export class MemoryLogger {
+  private outputChannel: vscode.OutputChannel
+  private logFile: string | undefined
+  private resourceCounts = new Map<string, number>()
+  private startTime: number = Date.now()
+  private logInterval: NodeJS.Timeout | undefined
+  private disposed: boolean = false
+
+  constructor() {
+    this.outputChannel = vscode.window.createOutputChannel("Coder Memory Logging")
+    this.outputChannel.show()
+
+    // Setup periodic logging of memory usage
+    this.startPeriodicLogging()
+  }
+
+  /**
+   * Start logging memory usage periodically
+   */
+  private startPeriodicLogging(intervalMs = 60000) {
+    if (this.logInterval) {
+      clearInterval(this.logInterval)
+    }
+
+    this.logInterval = setInterval(() => {
+      if (this.disposed) {
+        return
+      }
+      this.logMemoryUsage("PERIODIC")
+      this.logResourceCounts()
+    }, intervalMs)
+  }
+
+  /**
+   * Initialize the log file for persistent logging
+   */
+  public async initLogFile(globalStoragePath: string): Promise<void> {
+    try {
+      const logDir = path.join(globalStoragePath, "logs")
+      await fs.mkdir(logDir, { recursive: true })
+
+      this.logFile = path.join(logDir, `memory-log-${new Date().toISOString().replace(/[:.]/g, "-")}.txt`)
+
+      await this.writeToLogFile("Memory logging initialized")
+      this.info("Memory logging initialized to file: " + this.logFile)
+
+      // Log initial memory state
+      this.logMemoryUsage("INIT")
+    } catch (err) {
+      this.error(`Failed to initialize log file: ${err}`)
+    }
+  }
+
+  /**
+   * Log a new resource creation
+   */
+  public trackResourceCreated(resourceType: string, id: string = ""): void {
+    const count = (this.resourceCounts.get(resourceType) || 0) + 1
+    this.resourceCounts.set(resourceType, count)
+    this.info(`RESOURCE_CREATED: ${resourceType}${id ? ":" + id : ""} (Total: ${count})`)
+  }
+
+  /**
+   * Log a resource disposal
+   */
+  public trackResourceDisposed(resourceType: string, id: string = ""): void {
+    const count = Math.max(0, (this.resourceCounts.get(resourceType) || 1) - 1)
+    if (count === 0) {
+      this.resourceCounts.delete(resourceType)
+    } else {
+      this.resourceCounts.set(resourceType, count)
+    }
+
+    this.info(`RESOURCE_DISPOSED: ${resourceType}${id ? ":" + id : ""} (Remaining: ${count})`)
+  }
+
+  /**
+   * Log error with memory usage
+   */
+  public error(message: string, error?: unknown): void {
+    const errorMsg = error ? `: ${error instanceof Error ? error.stack || error.message : String(error)}` : ""
+    const fullMessage = `[ERROR] ${message}${errorMsg}`
+
+    this.outputChannel.appendLine(fullMessage)
+    this.writeToLogFile(fullMessage)
+    this.logMemoryUsage("ERROR")
+  }
+
+  /**
+   * Log info with timestamp
+   */
+  public info(message: string): void {
+    const fullMessage = `[INFO] ${message}`
+    this.outputChannel.appendLine(fullMessage)
+    this.writeToLogFile(fullMessage)
+  }
+
+  /**
+   * Log debug info (only to file)
+   */
+  public debug(message: string): void {
+    const fullMessage = `[DEBUG] ${message}`
+    this.writeToLogFile(fullMessage)
+  }
+
+  /**
+   * Log current memory usage
+   */
+  public logMemoryUsage(context: string): void {
+    try {
+      const memoryUsage = process.memoryUsage()
+      const nodeMemoryInfo = {
+        rss: `${(memoryUsage.rss / 1024 / 1024).toFixed(2)}MB`,
+        heapTotal: `${(memoryUsage.heapTotal / 1024 / 1024).toFixed(2)}MB`,
+        heapUsed: `${(memoryUsage.heapUsed / 1024 / 1024).toFixed(2)}MB`,
+        external: `${(memoryUsage.external / 1024 / 1024).toFixed(2)}MB`,
+        uptime: formatDuration(process.uptime() * 1000),
+        totalUptime: formatDuration(Date.now() - this.startTime),
+      }
+
+      const systemMemoryInfo = {
+        totalMem: `${(os.totalmem() / 1024 / 1024 / 1024).toFixed(2)}GB`,
+        freeMem: `${(os.freemem() / 1024 / 1024 / 1024).toFixed(2)}GB`,
+        loadAvg: os
+          .loadavg()
+          .map((load) => load.toFixed(2))
+          .join(", "),
+      }
+
+      const memoryLog = `[MEMORY:${context}] Node: ${JSON.stringify(nodeMemoryInfo)} | System: ${JSON.stringify(systemMemoryInfo)}`
+      this.outputChannel.appendLine(memoryLog)
+      this.writeToLogFile(memoryLog)
+    } catch (err) {
+      this.outputChannel.appendLine(`[ERROR] Failed to log memory usage: ${err}`)
+    }
+  }
+
+  /**
+   * Log the current counts of active resources
+   */
+  private logResourceCounts(): void {
+    const counts = Array.from(this.resourceCounts.entries())
+      .map(([type, count]) => `${type}=${count}`)
+      .join(", ")
+
+    const message = `[RESOURCES] Active resources: ${counts || "none"}`
+    this.outputChannel.appendLine(message)
+    this.writeToLogFile(message)
+  }
+
+  /**
+   * Write to log file
+   */
+  private async writeToLogFile(message: string): Promise<void> {
+    if (!this.logFile) {
+      return
+    }
+
+    try {
+      const timestamp = new Date().toISOString()
+      await fs.appendFile(this.logFile, `${timestamp} ${message}\n`)
+    } catch (err) {
+      // Don't recursively call this.error to avoid potential loops
+      this.outputChannel.appendLine(`[ERROR] Failed to write to log file: ${err}`)
+    }
+  }
+
+  /**
+   * Show the log in the output channel
+   */
+  public show(): void {
+    this.outputChannel.show()
+  }
+
+  /**
+   * Dispose of the logger
+   */
+  public dispose(): void {
+    this.disposed = true
+    if (this.logInterval) {
+      clearInterval(this.logInterval)
+      this.logInterval = undefined
+    }
+    this.logMemoryUsage("DISPOSE")
+    this.outputChannel.dispose()
+  }
+}
+
+/**
+ * Format duration in milliseconds to a human-readable string
+ */
+function formatDuration(ms: number): string {
+  const seconds = Math.floor((ms / 1000) % 60)
+  const minutes = Math.floor((ms / (1000 * 60)) % 60)
+  const hours = Math.floor((ms / (1000 * 60 * 60)) % 24)
+  const days = Math.floor(ms / (1000 * 60 * 60 * 24))
+
+  return `${days}d ${hours}h ${minutes}m ${seconds}s`
+}
+
+// Singleton instance
+let instance: MemoryLogger | undefined
+
+/**
+ * Get or initialize the memory logger instance
+ */
+export function getMemoryLogger(): MemoryLogger {
+  if (!instance) {
+    instance = new MemoryLogger()
+  }
+  return instance
+}