fix(session): watchdog respects per-session TTL and suppress test noise (#64) (#64)

Watchdog used global TIMEOUT (5 min) to kill all sessions, ignoring
per-session timeout query param. Pydoll creates 1-hour persistent
sessions that got killed every ~6 minutes, causing scrape failures.

- Store timeout query param in session.ttl (was hardcoded to 0)
- Watchdog uses per-session TTL when set, falls back to global default
- Upgrade KILLING log from info→warn for production visibility
- Capture pydoll subprocess stderr (only surface on failure)
- Suppress debug logger in unit tests via env override

Author: DivMode

docs/SESSION_LEAK_POSTMORTEM.md

@@ -115,6 +115,51 @@ If you see memory climbing again:
    ```
    Safe — active sessions reference dirs by handle, not path.
 
+## Part 2: Watchdog vs Per-Session Timeout (2026-03-06)
+
+### Summary
+
+After deploying the `destroySession` fix (Part 1), the watchdog correctly cleaned up sessions. But sessions were STILL going stale — the watchdog fired every 60s, killing ~2 sessions aged 367-420s. The `destroySession` fix treated the symptom (orphaned data dirs); this fix addresses the root cause (why sessions go stale in the first place).
+
+### Root Cause
+
+The watchdog used global `TIMEOUT` env var (300s = 5 min) instead of per-session `ttl`.
+
+Pydoll's AhrefsSessionManager creates persistent Chrome sessions with `timeout=3600000` (1 hour) via the WebSocket query param. The limiter (queue library) correctly used this as the job timeout. But the watchdog ignored it entirely and used `TIMEOUT + 60s` = 360s as the kill threshold.
+
+**The math:**
+- Watchdog threshold: `TIMEOUT + 60s` = 360s
+- Watchdog poll interval: 60s
+- Expected stale age: 360-420s (threshold + poll variance)
+- Observed stale ages: 367-420s — exact match
+
+### The Cascade
+
+```
+t=0:     Pydoll connects with timeout=3600000 (1 hour)
+t=0-5m:  Session alive, scrapes running normally
+t=6m:    Watchdog kills session (360s threshold + poll variance)
+t=6m:    Pydoll's WebSocket closes → "browser_session_closed"
+t=6m:    Any in-flight scrape fails → "Turnstile timeout" / "workflow failed"
+t=6m+:   Pydoll recreates session (AhrefsSessionManager._ensure_session)
+t=12m:   Watchdog kills again...
+```
+
+### Fix
+
+1. **Store per-session timeout**: `session.ttl = timeout` query param (was hardcoded to `0`)
+2. **Watchdog respects TTL**: `maxAge = s.ttl > 0 ? s.ttl + 60_000 : defaultMaxAgeMs`
+3. **Upgraded log levels**: `KILLING browser session` → `warn` (was `info`, invisible in prod)
+
+Sessions with no explicit timeout (`ttl=0`) still use the global `TIMEOUT + 60s` default (unchanged behavior). Persistent sessions (e.g., Ahrefs `ttl=3600000`) now have watchdog threshold of 3,660s (1 hour + 60s buffer).
+
+### Corrected Causal Chain
+
+The Part 1 postmortem incorrectly attributed scrape failures to "10+ GB working set starving Chrome for memory." The VM has 50 GB RAM and the container has no memory limit. The real cause of scrape failures was the watchdog killing persistent sessions every ~6 minutes:
+
+1. Orphaned data dirs → memory growth (real, but not the cause of scrape failures)
+2. Watchdog killing persistent sessions → scrape failures (the actual root cause)
+
 ## Effect v4 Lesson Learned
 
 `Effect.promise` treats rejections as DEFECTS (unrecoverable). `Effect.ignore` only catches typed ERRORS.

src/browsers/browser-launcher.ts

@@ -144,8 +144,9 @@ export class BrowserLauncher {
       return this.handlePageConnection(req);
     }
 
-    // Parse launch options
+    // Parse launch options and per-session timeout
     const launchOptions = this.parseLaunchOptions(req, router);
+    const timeout = req.parsed.searchParams.get('timeout');
 
     // Determine user data directory
     const manualUserDataDir = this.getManualUserDataDir(launchOptions);
@@ -196,7 +197,7 @@ export class BrowserLauncher {
       routePath: router.path,
       startedOn: Date.now(),
       trackingId,
-      ttl: 0,
+      ttl: timeout ? +timeout : 0,
       userDataDir,
     };
 

src/session/cf/cf-sites.integration.test.ts

@@ -432,17 +432,27 @@ describe.concurrent('CF Solver Multi-Site', () => {
 
 const PYDOLL_DIR = '/Users/peter/Developer/catchseo/packages/pydoll-scraper';
 
-/** Run a command with proxy env var and return stdout. */
+/** Run a command with proxy env var and return stdout. Stderr is captured and only surfaced on failure. */
 function runWithProxy(args: string[], timeoutMs: number): string {
   const proxy = process.env.LOCAL_MOBILE_PROXY;
   if (!proxy) throw new Error('LOCAL_MOBILE_PROXY required for pydoll tests');
-  return execFileSync('uv', ['run', 'pydoll', ...args], {
-    cwd: PYDOLL_DIR,
-    env: { ...process.env, LOCAL_MOBILE_PROXY: proxy },
-    encoding: 'utf-8',
-    timeout: timeoutMs,
-    maxBuffer: 10 * 1024 * 1024,
-  });
+  try {
+    return execFileSync('uv', ['run', 'pydoll', ...args], {
+      cwd: PYDOLL_DIR,
+      env: { ...process.env, LOCAL_MOBILE_PROXY: proxy },
+      encoding: 'utf-8',
+      timeout: timeoutMs,
+      stdio: ['ignore', 'pipe', 'pipe'],
+      maxBuffer: 10 * 1024 * 1024,
+    });
+  } catch (err: unknown) {
+    const execErr = err as { stderr?: string; stdout?: string; message?: string };
+    const stderr = execErr.stderr || '';
+    const stdout = execErr.stdout || '';
+    throw new Error(
+      `pydoll ${args[0]} failed:\n${stderr}\n\nstdout:\n${stdout}`,
+    );
+  }
 }
 
 describe('Pydoll Pipeline', () => {

src/session/session-lifecycle-manager.ts

@@ -184,7 +184,7 @@ export class SessionLifecycleManager {
     }
 
     if (!keepOpen) {
-      this.log.info(`KILLING browser session ${session.id}: numbConnected=${connected} keepUntil=${keepUntil} force=${force}`);
+      this.log.warn(`KILLING browser session ${session.id}: numbConnected=${connected} keepUntil=${keepUntil} force=${force}`);
       await Effect.runPromise(this.destroySession(browser, session));
     }
 
@@ -277,20 +277,24 @@ export class SessionLifecycleManager {
    * Uses destroySession — the same cleanup pipeline as normal close.
    * Impossible to diverge from the close() path.
    */
-  startWatchdog(maxSessionAgeMs: number): void {
+  startWatchdog(defaultMaxAgeMs: number): void {
     const lifecycle = this;
     this.watchdogFiber = Effect.runFork(
       Effect.fn('watchdog.tick')(function*() {
         const now = Date.now();
         const stale = lifecycle.registry.toArray()
-          .filter(([, s]) => now - s.startedOn > maxSessionAgeMs);
+          .filter(([, s]) => {
+            // Use per-session TTL if set, otherwise fall back to global default
+            const maxAge = s.ttl > 0 ? s.ttl + 60_000 : defaultMaxAgeMs;
+            return now - s.startedOn > maxAge;
+          });
 
         if (stale.length > 0) {
           lifecycle.log.warn(`Watchdog: ${stale.length} stale session(s)`);
           yield* Effect.all(
             stale.map(([browser, session]) => {
               lifecycle.log.warn(
-                `Watchdog: force-closing ${session.id} (age=${Math.round((now - session.startedOn) / 1000)}s)`,
+                `Watchdog: force-closing ${session.id} (age=${Math.round((now - session.startedOn) / 1000)}s, ttl=${session.ttl}ms, numbConnected=${session.numbConnected})`,
               );
               return lifecycle.destroySession(browser, session).pipe(
                 Effect.timeout('20 seconds'),

src/session/session-lifecycle.test.ts

@@ -218,6 +218,80 @@ describe('SessionLifecycleManager', () => {
   });
 });
 
+describe('watchdog per-session TTL', () => {
+  let registry: SessionRegistry;
+  let lifecycle: SessionLifecycleManager;
+
+  beforeEach(() => {
+    registry = new SessionRegistry();
+    lifecycle = new SessionLifecycleManager(registry);
+  });
+
+  it('watchdog respects per-session TTL over global default', async () => {
+    const browser = makeBrowser('b1');
+    // Session with ttl=3600000 (1 hour), 400s old — past global default but within TTL
+    const session = makeSession('s1', {
+      ttl: 3_600_000,
+      startedOn: Date.now() - 400_000,
+    });
+    registry.register(browser, session);
+
+    // Global default would kill at 360s, but session TTL is 1 hour + 60s buffer
+    lifecycle.startWatchdog(360_000);
+
+    // Wait for one watchdog tick (60s schedule, but first tick fires immediately)
+    await new Promise((r) => setTimeout(r, 1_500));
+
+    // Session should still be alive (ttl=1h, only 400s old)
+    expect(registry.size()).toBe(1);
+
+    // Cleanup
+    lifecycle.clearTimers();
+    await lifecycle.shutdown();
+  });
+
+  it('watchdog kills session with no TTL using global default', async () => {
+    const browser = makeBrowser('b1');
+    // Session with ttl=0 (no per-session TTL), 400s old — past global 360s default
+    const session = makeSession('s1', {
+      ttl: 0,
+      startedOn: Date.now() - 400_000,
+    });
+    registry.register(browser, session);
+
+    lifecycle.startWatchdog(360_000);
+
+    // Wait for one watchdog tick
+    await new Promise((r) => setTimeout(r, 1_500));
+
+    // Session should be killed (no per-session TTL, 400s > 360s global default)
+    expect(registry.size()).toBe(0);
+
+    lifecycle.clearTimers();
+  });
+
+  it('watchdog kills session that exceeds its own TTL', async () => {
+    const browser = makeBrowser('b1');
+    // Session with ttl=300000 (5 min), but 400s old (past ttl + 60s buffer = 360s)
+    const session = makeSession('s1', {
+      ttl: 300_000,
+      startedOn: Date.now() - 400_000,
+    });
+    registry.register(browser, session);
+
+    // Global default is much larger, but per-session TTL should take priority
+    lifecycle.startWatchdog(7_200_000);
+
+    // Wait for one watchdog tick
+    await new Promise((r) => setTimeout(r, 1_500));
+
+    // Session should be killed (400s > ttl 300s + 60s buffer = 360s)
+    expect(registry.size()).toBe(0);
+
+    lifecycle.clearTimers();
+  });
+});
+
 effectDescribe('acquireSession', () => {
   effectIt.effect('registers on acquire, removes on scope close', () =>
     Effect.gen(function*() {

vitest.config.ts

@@ -15,6 +15,7 @@ export default defineConfig({
           include: ['src/**/*.test.ts'],
           exclude: ['src/**/*.integration.test.ts'],
           globals: false,
+          env: { DEBUG: '' },
           fakeTimers: {
             toFake: undefined,
           },