Fix replay audio timing reliability

.github/workflows/server-test.yaml

@@ -51,6 +51,9 @@ jobs:
           git diff --exit-code -- lib/events/category_gen.go
         working-directory: server
 
+      - name: Install recording regression dependencies
+        run: sudo apt-get update && sudo apt-get install -y ffmpeg
+
       - name: Run server unit tests
         run: make test-unit
         working-directory: server
@@ -133,3 +136,13 @@ jobs:
         env:
           E2E_CHROMIUM_HEADFUL_IMAGE: onkernel/chromium-headful:${{ steps.vars.outputs.short_sha }}
           E2E_CHROMIUM_HEADLESS_IMAGE: onkernel/chromium-headless:${{ steps.vars.outputs.short_sha }}
+          RECORDING_AUDIO_OUTPUT_PATH: ${{ runner.temp }}/replay-audio/recording.mp4
+
+      - name: Upload replay audio diagnostics
+        if: always()
+        uses: actions/upload-artifact@v4
+        with:
+          name: replay-audio-${{ github.run_id }}-${{ github.run_attempt }}
+          path: ${{ runner.temp }}/replay-audio/
+          retention-days: 14
+          if-no-files-found: warn

server/Makefile

@@ -46,7 +46,7 @@ test-e2e:
 	@echo ""
 	@echo "=== Running e2e tests (this may take a few minutes) ==="
 	@echo ""
-	go test -v -race -timeout 120m ./e2e/
+	go test -v -race -count=1 -timeout 120m ./e2e/
 
 clean:
 	@rm -rf $(BIN_DIR)

server/e2e/e2e_recording_audio_test.go

@@ -41,6 +41,14 @@ func TestReplayRecordingIncludesAudioTrack(t *testing.T) {
 	require.NoError(t, c.WaitReady(ctx), "api not ready")
 	require.NoError(t, c.WaitDevTools(ctx), "devtools not ready")
 
+	// WIDTH/HEIGHT configure Xvfb, not headful Xorg. Apply the intended size
+	// through the API instead of recording the dummy display's 4K default.
+	initialWidth, initialHeight, err := getXRootResolution(ctx, c)
+	require.NoError(t, err)
+	t.Logf("[replay-audio] initial display=%dx%d", initialWidth, initialHeight)
+	patchDisplayExpectingOK(t, ctx, c, 1280, 720, 60)
+	waitForXRootResolution(t, ctx, c, 1280, 720, 15*time.Second)
+
 	// Verify the browser sees a real sound card over pure CDP/websocket. Chromium
 	// excludes PulseAudio monitor sources from enumerateDevices(), so the
 	// recorder's capture sink alone is invisible as an input. The standalone
@@ -151,6 +159,10 @@ func TestReplayRecordingZombocomArchiveAudio(t *testing.T) {
 func recordReplayAudio(t *testing.T, ctx context.Context, c *TestContainer, playwrightCode string, outputPath string, minPeakLevel float64) {
 	t.Helper()
 
+	if outputPath != "" {
+		defer captureReplayAudioDiagnostics(t, c, outputPath)
+	}
+
 	client, err := c.APIClient()
 	require.NoError(t, err, "failed to create API client")
 
@@ -160,6 +172,7 @@ func recordReplayAudio(t *testing.T, ctx context.Context, c *TestContainer, play
 	maxDuration := 120
 	maxFileSize := 100
 	recordAudio := true
+	startTime := time.Now()
 	startResp, err := client.StartRecordingWithResponse(ctx, instanceoapi.StartRecordingJSONRequestBody{
 		MaxDurationInSeconds: &maxDuration,
 		MaxFileSizeInMB:      &maxFileSize,
@@ -168,6 +181,7 @@ func recordReplayAudio(t *testing.T, ctx context.Context, c *TestContainer, play
 	require.NoError(t, err, "POST /recording/start failed")
 	require.Equal(t, http.StatusCreated, startResp.StatusCode(), "unexpected start status: %s body=%s", startResp.Status(), string(startResp.Body))
 
+	t.Logf("[replay-audio] recording start took %s", time.Since(startTime))
 	stopped := false
 	defer func() {
 		if !stopped {
@@ -176,17 +190,21 @@ func recordReplayAudio(t *testing.T, ctx context.Context, c *TestContainer, play
 		}
 	}()
 
+	playwrightStart := time.Now()
 	runResp, err := client.ExecutePlaywrightCodeWithResponse(ctx, instanceoapi.ExecutePlaywrightCodeJSONRequestBody{
 		Code: playwrightCode,
 	})
+	t.Logf("[replay-audio] playwright took %s", time.Since(playwrightStart))
 	require.NoError(t, err, "playwright request failed")
 	require.Equal(t, http.StatusOK, runResp.StatusCode(), "unexpected playwright status: %s body=%s", runResp.Status(), string(runResp.Body))
 	require.NotNil(t, runResp.JSON200, "expected playwright JSON response")
 	if !runResp.JSON200.Success {
 		t.Fatalf("playwright execution failed: error=%s stderr=%s result=%#v", stringValue(runResp.JSON200.Error), stringValue(runResp.JSON200.Stderr), runResp.JSON200.Result)
 	}
 
+	stopTime := time.Now()
 	stopResp, err := client.StopRecordingWithResponse(ctx, instanceoapi.StopRecordingJSONRequestBody{})
+	t.Logf("[replay-audio] recording stop took %s; elapsed %s", time.Since(stopTime), time.Since(startTime))
 	stopped = true
 	require.NoError(t, err, "POST /recording/stop failed")
 	require.Equal(t, http.StatusOK, stopResp.StatusCode(), "unexpected stop status: %s body=%s", stopResp.Status(), string(stopResp.Body))
@@ -205,6 +223,7 @@ func recordReplayAudio(t *testing.T, ctx context.Context, c *TestContainer, play
 	require.True(t, mp4HasAudioTrack(downloadResp.Body), "downloaded recording does not contain an audio track")
 	require.Greater(t, mp4AudioPeakLevel(t, ctx, c, recordingPath), minPeakLevel, "downloaded recording audio track is silent")
 	formatDuration, audioDuration := mp4Durations(t, ctx, c, recordingPath)
+	t.Logf("[replay-audio] format_duration=%.6f audio_duration=%.6f gap=%.6f", formatDuration, audioDuration, formatDuration-audioDuration)
 	require.GreaterOrEqual(t, audioDuration, formatDuration-2, "downloaded recording audio track ends before the recording does")
 }
 

server/e2e/recording_audio_diagnostics_test.go

@@ -0,0 +1,48 @@
+package e2e
+
+import (
+	"context"
+	"net/http"
+	"os"
+	"path/filepath"
+	"testing"
+	"time"
+)
+
+// Capture only the isolated audio fixture's services, never environment variables
+// or browser storage. Run before the test container is removed, including on failure.
+func captureReplayAudioDiagnostics(t *testing.T, c *TestContainer, outputPath string) {
+	t.Helper()
+	ctx, cancel := context.WithTimeout(context.Background(), 20*time.Second)
+	defer cancel()
+	if err := os.MkdirAll(filepath.Dir(outputPath), 0o755); err != nil {
+		t.Logf("audio diagnostics: %v", err)
+		return
+	}
+	// A failed Playwright request still leaves a useful recording after cleanup.
+	if _, err := os.Stat(outputPath); os.IsNotExist(err) {
+		client, err := c.APIClient()
+		if err == nil {
+			response, err := client.DownloadRecordingWithResponse(ctx, nil)
+			if err == nil && response.StatusCode() == http.StatusOK {
+				if err := os.WriteFile(outputPath, response.Body, 0o644); err != nil {
+					t.Logf("audio diagnostics recording: %v", err)
+				}
+			}
+		}
+	}
+	commands := map[string][]string{
+		"probe.json":   {"ffprobe", "-v", "error", "-show_format", "-show_streams", "-show_packets", "-of", "json", "/recordings/default.mp4"},
+		"services.log": {"sh", "-c", "for f in /var/log/supervisord/kernel-images-api /var/log/supervisord/pulseaudio /var/log/supervisord.log; do echo ==== $f; cat $f; done"},
+		"pulse.log":    {"sh", "-c", "PULSE_SERVER=unix:/tmp/pulse/native pactl list sinks; PULSE_SERVER=unix:/tmp/pulse/native pactl list source-outputs"},
+	}
+	for suffix, command := range commands {
+		code, out, err := c.Exec(ctx, command)
+		if err != nil || code != 0 {
+			t.Logf("audio diagnostics %s: exit=%d err=%v", suffix, code, err)
+		}
+		if err := os.WriteFile(outputPath+"."+suffix, []byte(out), 0o644); err != nil {
+			t.Logf("audio diagnostics: %v", err)
+		}
+	}
+}

server/lib/recorder/audio_integration_test.go

@@ -0,0 +1,102 @@
+package recorder
+
+import (
+	"encoding/json"
+	"os/exec"
+	"path/filepath"
+	"runtime"
+	"strconv"
+	"testing"
+
+	"github.com/stretchr/testify/require"
+)
+
+func TestFFmpegAudioPreservesInputStartOffset(t *testing.T) {
+	if runtime.GOOS != "linux" {
+		t.Skip("separate PulseAudio input is Linux-only")
+	}
+	for _, binary := range []string{"ffmpeg", "ffprobe"} {
+		if _, err := exec.LookPath(binary); err != nil {
+			t.Skipf("%s required: %v", binary, err)
+		}
+	}
+	dir := t.TempDir()
+	path := filepath.Join(dir, "audio.mp4")
+	params := defaultParams(dir)
+	audio := true
+	params.RecordAudio = &audio
+	args, err := ffmpegArgs(params, path)
+	require.NoError(t, err)
+
+	// Model live devices opened three seconds apart on the same clock. Both
+	// finish at timestamp 16, so their final output packets must still coincide.
+	// Replace only capture devices; retain the production sync/encode/mux flags.
+	fixtureArgs := make([]string, 0, len(args))
+	for i := 0; i < len(args); i++ {
+		switch {
+		case args[i] == "-framerate":
+			i++
+		case args[i] == "-f" && (args[i+1] == "x11grab" || args[i+1] == "pulse"):
+			fixtureArgs = append(fixtureArgs, "-f", "lavfi")
+			i++
+		case args[i] == "-i":
+			input := "testsrc2=size=320x240:rate=10:duration=6,setpts=PTS+10/TB"
+			if args[i+1] == "KernelOutput.monitor" {
+				input = "sine=frequency=440:sample_rate=48000:duration=3,asetpts=PTS+13/TB"
+			}
+			fixtureArgs = append(fixtureArgs, "-i", input)
+			i++
+		default:
+			fixtureArgs = append(fixtureArgs, args[i])
+		}
+	}
+	out, err := exec.CommandContext(t.Context(), "ffmpeg", fixtureArgs...).CombinedOutput()
+	require.NoError(t, err, "%s", out)
+	for _, name := range []string{"fragmented", "finalized"} {
+		t.Run(name, func(t *testing.T) {
+			if name == "finalized" {
+				finalized := filepath.Join(dir, "finalized.mp4")
+				out, err := exec.CommandContext(t.Context(), "ffmpeg", remuxArgs(path, finalized, "")...).CombinedOutput()
+				require.NoError(t, err, "%s", out)
+				path = finalized
+			}
+			out, err := exec.CommandContext(t.Context(), "ffprobe", "-v", "error", "-show_packets", "-of", "json", path).Output()
+			require.NoError(t, err)
+			var probe struct {
+				Packets []struct {
+					CodecType string `json:"codec_type"`
+					PTS       string `json:"pts_time"`
+					Duration  string `json:"duration_time"`
+				} `json:"packets"`
+			}
+			require.NoError(t, json.Unmarshal(out, &probe))
+			var videoEnd, audioEnd float64
+			audioPTS := make([]float64, 0)
+			for _, p := range probe.Packets {
+				pts, err := strconv.ParseFloat(p.PTS, 64)
+				require.NoError(t, err)
+				var duration float64
+				if p.Duration != "" {
+					duration, err = strconv.ParseFloat(p.Duration, 64)
+					require.NoError(t, err)
+				}
+				if p.CodecType == "video" {
+					videoEnd = pts + duration
+				} else if p.CodecType == "audio" {
+					audioEnd = pts + duration
+					audioPTS = append(audioPTS, pts)
+				}
+			}
+			t.Logf("video_end=%.6f audio_end=%.6f", videoEnd, audioEnd)
+			require.InDelta(t, videoEnd, audioEnd, 0.1, "independently zeroing input timestamps moves audio three seconds early")
+			// empty_moov starts the first packet at zero. Subsequent packets must
+			// preserve the device offset, without padding the gap with silent samples.
+			require.Greater(t, len(audioPTS), 1)
+			require.InDelta(t, 3, audioPTS[1], 0.03)
+			pcm, err := exec.CommandContext(t.Context(), "ffmpeg", "-v", "error", "-i", path,
+				"-map", "0:a:0", "-f", "s16le", "-ac", "2", "-ar", "48000", "-").Output()
+			require.NoError(t, err)
+			require.InDelta(t, 3, float64(len(pcm))/(48000*2*2), 0.05, "sync must not add silent samples")
+		})
+	}
+}

server/lib/recorder/ffmpeg.go

@@ -748,10 +748,8 @@ func ffmpegArgs(params FFmpegRecordingParams, outputPath string) ([]string, erro
 		"-pix_fmt", "yuv420p", // Web-standard pixel format
 	}...)
 
-	// Timestamp handling for reliable playback. Single-input video-only capture
-	// overwrites x11grab's timestamps with wall-clock time for stable playback.
-	// With audio we must not: it would stamp the separate video and audio inputs
-	// independently and desync them, so we keep their input PTS instead.
+	// Keep the legacy timestamp options for video-only capture. Audio capture
+	// synchronizes the two device clocks with -isync on the PulseAudio input.
 	if !recordAudio {
 		args = append(args, "-use_wallclock_as_timestamps", "1")
 	}
@@ -783,6 +781,10 @@ func ffmpegArgs(params FFmpegRecordingParams, outputPath string) ([]string, erro
 func audioInputArgs(params FFmpegRecordingParams) []string {
 	return []string{
 		"-thread_queue_size", "512",
+		// Both devices use wall-clock timestamps, but open at different times.
+		// Without -isync, ffmpeg subtracts each input's start independently,
+		// shifting the later-opened audio earlier by the device startup gap.
+		"-isync", "0",
 		"-f", "pulse",
 		"-i", params.audioSource(),
 	}

server/runtime/playwright-daemon.test.ts

@@ -0,0 +1,71 @@
+import assert from 'node:assert/strict';
+import { spawn } from 'node:child_process';
+import { once } from 'node:events';
+import { existsSync } from 'node:fs';
+import { mkdtemp, rm, writeFile } from 'node:fs/promises';
+import { createConnection } from 'node:net';
+import { tmpdir } from 'node:os';
+import { join } from 'node:path';
+import { setTimeout } from 'node:timers/promises';
+import { pathToFileURL } from 'node:url';
+import test from 'node:test';
+
+test('socket readiness does not wait for cold browser-engine imports', { timeout: 10000 }, async t => {
+  const dir = await mkdtemp(join(tmpdir(), 'playwright-startup-'));
+  const socketPath = join(dir, 'daemon.sock');
+  const started = join(dir, 'import-started');
+  const release = join(dir, 'release-import');
+  const loader = join(dir, 'loader.mjs');
+  // Hold package evaluation until released, rather than depending on CPU load
+  // or the speed of installed Playwright packages to reproduce cold startup.
+  const engine = `
+    import { existsSync, writeFileSync } from 'node:fs';
+    import { setTimeout } from 'node:timers/promises';
+    writeFileSync(${JSON.stringify(started)}, '');
+    while (!existsSync(${JSON.stringify(release)})) await setTimeout(20);
+    export const chromium = { connectOverCDP: async () => ({
+      on() {}, isConnected() { return true; }, async close() {}
+    }) };
+    export const transform = async code => ({ code });
+    export const Browser = null, CDPSession = null, Page = null;
+  `;
+  await writeFile(loader, `
+    export async function resolve(specifier, context, nextResolve) {
+      if (['playwright-core', 'patchright', 'esbuild'].includes(specifier)) {
+        return { url: 'data:text/javascript,' + encodeURIComponent(${JSON.stringify(engine)}), shortCircuit: true };
+      }
+      if (['./page-target-id-cache', './webmcp'].includes(specifier)) specifier += '.ts';
+      return nextResolve(specifier, context);
+    }
+  `);
+  const child = spawn(process.execPath, [
+    '--experimental-loader', pathToFileURL(loader).href,
+    new URL('./playwright-daemon.ts', import.meta.url).pathname,
+  ], { env: { ...process.env, PLAYWRIGHT_DAEMON_SOCKET: socketPath }, stdio: ['ignore', 'ignore', 'pipe'] });
+  let stderr = '';
+  child.stderr.on('data', chunk => { stderr += chunk; });
+  const exited = once(child, 'exit');
+  t.after(async () => {
+    child.kill('SIGKILL');
+    await exited;
+    await rm(dir, { recursive: true, force: true });
+  });
+  const deadline = performance.now() + 4000;
+  while ((!existsSync(started) || !existsSync(socketPath)) && performance.now() < deadline && child.exitCode === null) {
+    await setTimeout(20);
+  }
+  assert.ok(existsSync(started), `engine import was not exercised: ${stderr}`);
+  assert.ok(existsSync(socketPath), `socket blocked by engine initialization: ${stderr}`);
+  const socket = createConnection(socketPath);
+  try {
+    await once(socket, 'connect');
+  } finally {
+    socket.destroy();
+  }
+  await writeFile(release, '');
+  const connectedDeadline = performance.now() + 2000;
+  while (!stderr.includes('CDP connection established') && performance.now() < connectedDeadline) {
+    await setTimeout(20);
+  }
+  assert.match(stderr, /CDP connection established/);
+});

server/runtime/playwright-daemon.ts

@@ -11,9 +11,7 @@
 
 import { createServer, Socket } from 'net';
 import { unlinkSync, existsSync } from 'fs';
-import { transform } from 'esbuild';
-import { chromium as chromiumPW, Browser, CDPSession, Page } from 'playwright-core';
-import { chromium as chromiumPR } from 'patchright';
+import type { Browser, CDPSession, Page } from 'playwright-core';
 
 import { PageTargetIdCache } from './page-target-id-cache';
 import { createWebMCPClient } from './webmcp';
@@ -71,6 +69,7 @@ async function transformCode(code: string): Promise<string> {
   // Wrap in async function so top-level await/return are valid for esbuild
   const wrapped = `async function __userCode__() {\n${code}\n}`;
 
+  const { transform } = await import('esbuild');
   const result = await transform(wrapped, {
     loader: 'ts',
     target: 'es2022',
@@ -117,7 +116,11 @@ async function ensureBrowserConnection(): Promise<Browser> {
 
   connecting = true;
   try {
-    const chromium = USE_PATCHRIGHT ? chromiumPR : chromiumPW;
+    // Load the engine after socket binding, outside the API's short
+    // socket-ready deadline. Only initialize the selected engine.
+    const { chromium } = USE_PATCHRIGHT
+      ? await import('patchright')
+      : await import('playwright-core');
 
     if (browser) {
       try {