Merge pull request #77 from browser-use/alex/v4-shutdown-hook-diagnostics

diag(TEMP): stderr trace through plugin shutdown + forceFlush

Author: Alezander9

packages/bcode-laminar/src/plugin.ts

@@ -82,10 +82,23 @@ export const LaminarPlugin: Plugin = ({ client }) => {
     // this hook from its top-level finally before forceFlush, so span.end()
     // here gets its export drained by the host's existing forceFlush race.
     shutdown: () => {
-      for (const [sessionId, span] of Object.entries(sessionCurrentTurnSpan)) {
-        span.end()
+      // Use console.error not client.app.log — the SDK server may already be
+      // torn down by shutdown time, and the host log is async via HTTP which
+      // doesn't honor the sync shutdown contract. v4-worker captures stderr
+      // into bcode-output-<runId>.log so this lands in the cloud artifact.
+      const sessionIds = Object.keys(sessionCurrentTurnSpan)
+      console.error(`[bcode-laminar] shutdown invoked: ending ${sessionIds.length} turn span(s)`)
+      for (const sessionId of sessionIds) {
+        const span = sessionCurrentTurnSpan[sessionId]
+        if (!span) continue
+        try {
+          span.end()
+        } catch (err) {
+          console.error(`[bcode-laminar] span.end() threw for session ${sessionId}: ${(err as Error).message}`)
+        }
         delete sessionCurrentTurnSpan[sessionId]
       }
+      console.error(`[bcode-laminar] shutdown complete`)
     },
     event: async ({ event }) => {
       switch (event.type) {

packages/opencode/src/index.ts

@@ -259,26 +259,47 @@ try {
   // before forceFlush + process.exit() below.
   try {
     const { pluginShutdownHooks } = await import("./plugin")
+    // Diagnostic via stderr: v4-worker captures into bcode-output-<runId>.log
+    // and we need to know whether this branch is even reached + how many hooks
+    // ran. Remove once V4 telemetry verification is settled.
+    process.stderr.write(`[bcode] shutdown: invoking ${pluginShutdownHooks.size} plugin shutdown hook(s)\n`)
+    let invoked = 0
     for (const hook of pluginShutdownHooks) {
       try {
         hook()
+        invoked++
       } catch (err) {
         Log.Default.error("plugin shutdown hook failed", { error: err })
+        process.stderr.write(`[bcode] shutdown: hook threw: ${(err as Error).message}\n`)
       }
     }
+    process.stderr.write(`[bcode] shutdown: invoked ${invoked}/${pluginShutdownHooks.size} hook(s) successfully\n`)
   } catch (err) {
     Log.Default.error("plugin shutdown import failed", { error: err })
+    process.stderr.write(`[bcode] shutdown: import failed: ${(err as Error).message}\n`)
   }
   // Drain any registered OTel span processors (e.g. bcode-laminar) before
   // exiting so the just-ended turn spans actually hit the wire. Bounded with
   // a 3 s race so a wedged exporter cannot hang bcode on exit. Generic to any
   // OTel-based plugin, not laminar-specific.
   const provider = trace.getTracerProvider() as { forceFlush?: () => Promise<void> }
   if (provider.forceFlush) {
+    process.stderr.write(`[bcode] shutdown: forceFlush starting\n`)
+    const start = Date.now()
     await Promise.race([
-      provider.forceFlush().catch(() => {}),
-      new Promise<void>((resolve) => setTimeout(resolve, 3000)),
+      provider.forceFlush().catch((err: Error) => {
+        process.stderr.write(`[bcode] shutdown: forceFlush rejected: ${err.message}\n`)
+      }),
+      new Promise<void>((resolve) =>
+        setTimeout(() => {
+          process.stderr.write(`[bcode] shutdown: forceFlush timed out after 3000ms\n`)
+          resolve()
+        }, 3000),
+      ),
     ])
+    process.stderr.write(`[bcode] shutdown: forceFlush done in ${Date.now() - start}ms\n`)
+  } else {
+    process.stderr.write(`[bcode] shutdown: no forceFlush on global provider\n`)
   }
   // Some subprocesses don't react properly to SIGTERM and similar signals.
   // Most notably, some docker-container-based MCP servers don't handle such signals unless