From 006fd053ac5057bf835d1106cca9c10011ef5904 Mon Sep 17 00:00:00 2001 From: Mohamed Boudra Date: Wed, 21 Oct 2026 13:48:05 +0700 Subject: [PATCH] Record Android freezes in opt-in diagnostic builds (#7456) * feat(app): record Android stalls in opt-in diagnostic builds * refactor(app): own watchdog sinks and bounded log storage * fix(app): preserve cumulative browser profiling history --- .github/workflows/ci.yml | 8 ++ CLAUDE.md | 2 + docs/android.md | 72 ++++++++---- package.json | 9 +- packages/app/app.config.js | 6 +- packages/app/index.ts | 2 + packages/app/metro.config.cjs | 10 ++ .../paseo-native-trace/android/build.gradle | 4 + .../java/sh/paseo/trace/DiagnosticRecorder.kt | 77 +++++++++++++ .../sh/paseo/trace/DownloadsLogStorage.kt | 36 ++++++ .../java/sh/paseo/trace/HeartbeatWatchdog.kt | 38 +++++++ .../sh/paseo/trace/PaseoNativeTraceModule.kt | 14 +++ .../main/java/sh/paseo/trace/RotatingLog.kt | 61 ++++++++++ .../sh/paseo/trace/HeartbeatWatchdogTest.kt | 40 +++++++ .../java/sh/paseo/trace/RotatingLogTest.kt | 59 ++++++++++ packages/app/package.json | 13 ++- packages/app/src/performance/native-trace.ts | 49 +++++--- packages/app/src/root-app.tsx | 7 +- packages/app/src/runtime/host-runtime.ts | 17 ++- packages/app/src/utils/render-profiler.tsx | 70 ++++++------ packages/app/src/watchdog/index.ts | 35 ++++++ .../src/watchdog/internal/recorder.test.ts | 103 +++++++++++++++++ .../app/src/watchdog/internal/recorder.ts | 79 +++++++++++++ packages/client/src/daemon-client.test.ts | 101 +++++++++++------ packages/client/src/daemon-client.ts | 105 ++++++++++++++---- scripts/build-apk.mjs | 52 +++++++++ 26 files changed, 929 insertions(+), 140 deletions(-) create mode 100644 packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/DiagnosticRecorder.kt create mode 100644 packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/DownloadsLogStorage.kt create mode 100644 packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/HeartbeatWatchdog.kt create mode 100644 packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/RotatingLog.kt create mode 100644 packages/app/modules/paseo-native-trace/android/src/test/java/sh/paseo/trace/HeartbeatWatchdogTest.kt create mode 100644 packages/app/modules/paseo-native-trace/android/src/test/java/sh/paseo/trace/RotatingLogTest.kt create mode 100644 packages/app/src/watchdog/index.ts create mode 100644 packages/app/src/watchdog/internal/recorder.test.ts create mode 100644 packages/app/src/watchdog/internal/recorder.ts create mode 100644 scripts/build-apk.mjs diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 486c7333b1..e632cb4b96 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -417,6 +417,14 @@ jobs: - name: Run app unit tests run: npm run test --workspace=@getpaseo/app + - uses: actions/setup-java@v4 + with: + distribution: temurin + java-version: "21" + + - name: Run Android module tests + run: npm run test:android --workspace=@getpaseo/app + playwright-1: name: playwright (shard 1/8) needs: changes diff --git a/CLAUDE.md b/CLAUDE.md index 1fb575614d..809d6668fc 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -107,6 +107,8 @@ npm run format:check # Check formatting without writing Repo dev commands use checkout-local state by default. In this checkout, `PASEO_HOME` resolves to `.dev/paseo-home`, and `npm run cli -- ...` targets that same dev home automatically. The packaged desktop app and production-style daemon keep using `~/.paseo` on port `6767`. +When Mo requests an APK, use `npm run build:apk:arm64` for an ARM64 build: writes `artifacts/paseo-dogfood-arm64.apk` with diagnostics without starting a device; `npm run build:apk` builds all four Android architectures. + See [docs/development.md](docs/development.md) for full setup, build sync requirements, and debugging. ## Release branches diff --git a/docs/android.md b/docs/android.md index c90a27efec..9b83240c52 100644 --- a/docs/android.md +++ b/docs/android.md @@ -64,36 +64,62 @@ Gradle auto-fetches the platform/build-tools it needs once licenses are accepted From repo root: ```bash -npm run android:development # Debug build -npm run android:production # Release build -npm run android:clear # Remove generated Android project +npm run build:apk # Universal dogfood APK: 32/64-bit ARM and x86 +npm run build:apk:arm64 # Smaller dogfood APK for ARM64 phones +npm run dev:android # Build/install the debug app and start development +npm run dev:ios # Build/install the iOS development app ``` -For a production-ID release APK that local Android profiling tools can attach to: +`build:apk` writes `artifacts/paseo-dogfood-universal.apk`; `build:apk:arm64` writes +`artifacts/paseo-dogfood-arm64.apk`. Neither command launches or installs on a device. Both enable +`PASEO_WATCHDOG_BUILD=1`, the production React profiling renderer, and Android's shell-profileable +flag. These builds keep the production package ID (`sh.paseo`) and release optimizations. Use this APK for +personal dogfooding. Android system-trace spans require the separate `PASEO_PROFILE_BUILD=1` flag; +watchdog recording does not send duplicate spans to that sink by default. Normal store/release +workflows leave diagnostics disabled. + +The older `android`, `android:development`, and `ios` commands remain aliases for development. +`android:production` still builds and installs a release through Expo; use `build:apk` when you +need an artifact. `android:clear` removes the generated Android project. + +Run `npm run test:android --workspace=@getpaseo/app` to prebuild Android and run native module unit tests. The app CI job runs this command with the Android toolchain. + +### Diagnostic logs without ADB + +In a dogfood build, open Android's Files app → Downloads → **Paseo diagnostics** and share all +retained `.jsonl` files. No app screen, storage permission, or attached debugger is required. +The recorder retains eight files of about 5 MiB each across reconnects and app restarts. Rotation +replaces the oldest files, so collect them soon after reproducing a freeze. Uninstall/reinstall +can leave older Downloads files that the new installation cannot manage. + +Each file identifies its build and session. Events include application-transport frame sizes and +message/request IDs, connection transitions, parse/validation/dispatch spans, named React subtree +render timings, and foreground JS heartbeat gaps. Payloads, passwords, and message contents +are excluded; connection identifiers include host addresses. Each size has a unit: **bytes** when +already available, otherwise **UTF-16 code units** for text. These are +client transport observations, after relay decryption where applicable, not packet arrival times. + +The native recorder flags a heartbeat overdue by more than 500 ms (250 ms expected interval). +A heartbeat gap bounds the unresponsive interval; it is not an exact blocked-stack duration. +Backgrounding suspends detection. `js.stall.started` can be written while JS remains blocked; +`js.stall.recovered` records the gap when JS resumes. Recovery can appear without a start event +when JS resumes before the next native sampling tick. Process death leaves earlier files intact, +but queued/unflushed records can be lost. A missing recovery event alone does not prove a crash. + +`react.render.slow` records subtree rendering taking at least 16 ms; one-second summaries include +faster renders. Nested profiler timings overlap: don't add parent and child times. React's render +measurements do not measure native layout/paint or the complete commit phase. `recorder.dropped` +means the bounded queue overflowed; missing events in that interval must not be treated as absence +of activity. Storage failure stops recording rather than blocking the app. + +For an ordinary release APK with system trace markers only: ```bash PASEO_PROFILE_BUILD=1 npm run android:production ``` -This keeps the `sh.paseo` package id, release Hermes bundle, and release optimizations. It adds -`` and enables local Android trace markers for workspace mounts -and daemon WebSocket traffic. The markers contain message types and sizes, never payload contents, -and emit only while a system trace records the `sh.paseo` app (`perfetto -a sh.paseo ...`). - -Or from `packages/app`: - -```bash -# Debug -npx cross-env APP_VARIANT=development expo prebuild --platform android --clean --non-interactive -npx cross-env APP_VARIANT=development expo run:android --variant=debug - -# Release -npx cross-env APP_VARIANT=production expo prebuild --platform android --clean --non-interactive -npx cross-env APP_VARIANT=production expo run:android --variant=release - -# Clear generated Android project -rm -rf android -``` +Those markers emit only while a system trace records `sh.paseo` (`perfetto -a sh.paseo ...`); +they do not produce Downloads files. ## Running on an emulator against a worktree daemon diff --git a/package.json b/package.json index 67ca259ffa..54514212cf 100644 --- a/package.json +++ b/package.json @@ -41,12 +41,16 @@ "dev:server:watch": "concurrently --kill-others --names protocol,client,server --prefix-colors yellow,blue,cyan \"npm run watch:protocol\" \"npm run watch:client\" \"npm run dev:server:raw\"", "dev:server:raw": "npm run dev --workspace=@getpaseo/server", "dev:app": "cross-env PASEO_LISTEN=127.0.0.1:6768 EXPO_PORT=8081 ./scripts/dev-app.sh", + "dev:android": "npm run dev:android --workspace=@getpaseo/app", + "dev:ios": "npm run dev:ios --workspace=@getpaseo/app", "test:e2e:mobile": "./scripts/test-mobile-agent-device.sh", "test:e2e:composer-keyboard:android": "./packages/app/e2e/mobile/composer-keyboard/android.sh", "dev:website": "npm run dev --workspace=@getpaseo/website", "postinstall": "node scripts/postinstall-patches.mjs", "prepare": "lefthook install --force", "build": "npm run build --workspaces --if-present", + "build:apk": "node scripts/build-apk.mjs", + "build:apk:arm64": "node scripts/build-apk.mjs arm64", "build:highlight": "npm run build --workspace=@getpaseo/highlight", "build:highlight:clean": "npm run build:clean --workspace=@getpaseo/highlight", "build:plugin": "npm run build --workspace=@getpaseo/plugin", @@ -80,15 +84,14 @@ "acp:version-drift:check": "node scripts/check-acp-catalog-version-drift.mjs --fail-on-drift", "acp:version-drift:update": "node scripts/check-acp-catalog-version-drift.mjs --update", "start": "npm run start --workspace=@getpaseo/server", - "android": "npm run android --workspace=@getpaseo/app", + "android": "npm run dev:android", "android:development": "npm run android:development --workspace=@getpaseo/app", "android:production": "npm run android:production --workspace=@getpaseo/app", "android:release": "npm run android:production --workspace=@getpaseo/app", "android:clear": "npm run android:clear --workspace=@getpaseo/app", - "android:clean": "npm run android:clean --workspace=@getpaseo/app", "fdroid:changelogs": "node scripts/sync-fdroid-changelogs.mjs", "fdroid:changelogs:check": "node scripts/sync-fdroid-changelogs.mjs --check", - "ios": "npm run ios --workspace=@getpaseo/app", + "ios": "npm run dev:ios", "web": "npm run web --workspace=@getpaseo/app", "dev:desktop": "cross-env PASEO_LISTEN=127.0.0.1:6768 npm run dev --workspace=@getpaseo/desktop", "dev:win:desktop": "npm run dev:win --workspace=@getpaseo/desktop", diff --git a/packages/app/app.config.js b/packages/app/app.config.js index 17bc6fe636..7ddfc95029 100644 --- a/packages/app/app.config.js +++ b/packages/app/app.config.js @@ -10,6 +10,7 @@ const withAndroidScroll = require("./modules/paseo-scroll/app.plugin"); const { getNativeReleaseVersion } = require("./native-release-version"); const appVariant = process.env.APP_VARIANT ?? "production"; const isFdroidBuild = process.env.PASEO_FDROID_BUILD === "1"; +const isWatchdogBuild = process.env.PASEO_WATCHDOG_BUILD === "1"; const isProfileBuild = process.env.PASEO_PROFILE_BUILD === "1"; const buildProfile = isFdroidBuild @@ -181,7 +182,7 @@ export default { }, ], ...buildProfile.fdroidPlugins, - ...(isProfileBuild ? [withAndroidProfileable] : []), + ...(isProfileBuild || isWatchdogBuild ? [withAndroidProfileable] : []), ], experiments: { typedRoutes: true, @@ -191,6 +192,9 @@ export default { extra: { fdroidBuild: isFdroidBuild, profileBuild: isProfileBuild, + watchdogBuild: isWatchdogBuild, + diagnosticRevision: process.env.PASEO_DIAGNOSTIC_REVISION, + diagnosticBuildTime: process.env.PASEO_DIAGNOSTIC_BUILD_TIME, router: {}, eas: { projectId: "0e7f65ce-0367-46c8-a238-2b65963d235a", diff --git a/packages/app/index.ts b/packages/app/index.ts index 82d47bfe8c..d103c5cb79 100644 --- a/packages/app/index.ts +++ b/packages/app/index.ts @@ -9,6 +9,8 @@ import "@expo/metro-runtime"; // oxlint-disable-next-line import/no-unassigned-import -- Preserve Expo's entry side effects. import "expo-router/build/fast-refresh"; import { renderRootComponent } from "expo-router/build/renderRootComponent"; +import { startWatchdog } from "./src/watchdog"; import { RootApp } from "./src/root-app"; +startWatchdog(); renderRootComponent(RootApp); diff --git a/packages/app/metro.config.cjs b/packages/app/metro.config.cjs index c1fdbdef77..96a965e1f9 100644 --- a/packages/app/metro.config.cjs +++ b/packages/app/metro.config.cjs @@ -5,6 +5,7 @@ const path = require("path"); const projectRoot = __dirname; const appNodeModulesRoot = path.resolve(projectRoot, "node_modules"); const appSrcRoot = path.resolve(projectRoot, "src"); +const isWatchdogBuild = process.env.PASEO_WATCHDOG_BUILD === "1"; const isFdroidBuild = process.env.PASEO_FDROID_BUILD === "1"; const fdroidModuleOverrides = { "expo-camera": path.resolve(appSrcRoot, "fdroid/expo-camera.tsx"), @@ -16,6 +17,7 @@ const customWebPlatform = (process.env.PASEO_WEB_PLATFORM ?? "") .toLowerCase(); const config = getDefaultConfig(projectRoot); +config.cacheVersion = isWatchdogBuild ? "watchdog" : "standard"; const defaultResolveRequest = config.resolver.resolveRequest ?? resolve; // Keep app exports deterministic across dev machines and CI. Metro's Watchman @@ -75,6 +77,14 @@ function resolveWithCustomWebOverlay(context, moduleName, platform) { } config.resolver.resolveRequest = (context, moduleName, platform) => { + if ( + isWatchdogBuild && + platform === "android" && + /[/\\]Renderer[/\\]shims[/\\]/.test(context.originModulePath) && + /implementations\/(ReactFabric|ReactNativeRenderer)-prod$/.test(moduleName) + ) { + return defaultResolveRequest(context, moduleName.replace(/-prod$/, "-profiling"), platform); + } if (isFdroidBuild && platform === "android" && fdroidModuleOverrides[moduleName]) { return resolveWithCustomWebOverlay(context, fdroidModuleOverrides[moduleName], platform); } diff --git a/packages/app/modules/paseo-native-trace/android/build.gradle b/packages/app/modules/paseo-native-trace/android/build.gradle index bfd0eec72a..c0340730ff 100644 --- a/packages/app/modules/paseo-native-trace/android/build.gradle +++ b/packages/app/modules/paseo-native-trace/android/build.gradle @@ -13,3 +13,7 @@ useDefaultAndroidSdkVersions() android { namespace "sh.paseo.trace" } + +dependencies { + testImplementation "junit:junit:4.13.2" +} diff --git a/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/DiagnosticRecorder.kt b/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/DiagnosticRecorder.kt new file mode 100644 index 0000000000..512795838c --- /dev/null +++ b/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/DiagnosticRecorder.kt @@ -0,0 +1,77 @@ +package sh.paseo.trace + +import android.content.Context +import android.os.SystemClock +import android.util.Log +import org.json.JSONObject +import java.util.UUID +import java.util.concurrent.ArrayBlockingQueue +import java.util.concurrent.Executors +import java.util.concurrent.TimeUnit +import java.util.concurrent.atomic.AtomicLong + +/** All serialization and storage belongs to the worker, never the JS/UI threads. */ +internal class DiagnosticRecorder(private val context: Context, private val metadata: Map) { + private data class Event(val name: String, val data: Map, val monoMs: Long = SystemClock.elapsedRealtime(), val wallMs: Long = System.currentTimeMillis()) + private val queue = ArrayBlockingQueue(2048) + private val dropped = AtomicLong() + private val worker = Executors.newSingleThreadScheduledExecutor() + private val session = UUID.randomUUID().toString() + @Volatile private var failed = false + private val watchdog = HeartbeatWatchdog(SystemClock.elapsedRealtime(), ::record) + + private val log = RotatingLog(DownloadsLogStorage(context, session), { part -> + serialize(Event("file.start", metadata + mapOf("schema" to "1", "part" to "$part"))) + }, { error -> + failed = true + queue.clear() + Log.e("PaseoDiagnostics", "Diagnostic recording stopped: storage unavailable", error) + }) + + init { + record("session.start", metadata + mapOf("session" to session, "schema" to "1", "heartbeatMs" to "${HeartbeatTiming.intervalMs}", "stallThresholdMs" to "${HeartbeatTiming.overdueMs}")) + worker.scheduleWithFixedDelay({ drain() }, 0, HeartbeatTiming.intervalMs, TimeUnit.MILLISECONDS) + } + + fun record(name: String, data: Map) { + if (failed) return + // Limit native memory even if an instrumentation caller accidentally supplies large fields. + val bounded = data.entries.take(24).associate { it.key.take(80) to it.value.take(256) } + if (!queue.offer(Event(name.take(120), bounded))) dropped.incrementAndGet() + } + + fun heartbeat() = watchdog.heartbeat(SystemClock.elapsedRealtime()) + fun active(value: Boolean) = watchdog.active(value, SystemClock.elapsedRealtime()) + + private fun drain() { + if (failed) return + watchdog.check(SystemClock.elapsedRealtime()) + val lost = dropped.getAndSet(0) + if (lost > 0) write(Event("recorder.dropped", mapOf("count" to "$lost"))) + var remaining = 2048 + while (remaining-- > 0 && !failed) { + val event = queue.poll() ?: break + write(event) + } + log.finishBatch() + } + + private fun write(event: Event) = log.write(serialize(event)) + + private fun serialize(event: Event): ByteArray = (JSONObject().apply { + put("event", event.name) + put("session", session) + put("wallMs", event.wallMs) + put("monoMs", event.monoMs) + put("data", JSONObject(event.data)) + }.toString() + "\n").toByteArray(Charsets.UTF_8) + + fun close() { + worker.execute { + record("session.end", emptyMap()) + drain() + log.finishBatch() + } + worker.shutdown() + } +} diff --git a/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/DownloadsLogStorage.kt b/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/DownloadsLogStorage.kt new file mode 100644 index 0000000000..63608a354c --- /dev/null +++ b/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/DownloadsLogStorage.kt @@ -0,0 +1,36 @@ +package sh.paseo.trace + +import android.content.ContentUris +import android.content.ContentValues +import android.content.Context +import android.net.Uri +import android.provider.MediaStore +import java.io.OutputStream + +internal class DownloadsLogStorage(private val context: Context, private val session: String) : LogStorage { + private val resolver = context.contentResolver + private val collection = MediaStore.Downloads.EXTERNAL_CONTENT_URI + private val directory = "Download/Paseo diagnostics/" + + override fun create(part: Int): String { + val values = ContentValues().apply { + put(MediaStore.MediaColumns.DISPLAY_NAME, "paseo-diagnostics-${System.currentTimeMillis()}-${session.take(8)}-$part.jsonl") + put(MediaStore.MediaColumns.MIME_TYPE, "application/x-ndjson") + put(MediaStore.MediaColumns.RELATIVE_PATH, directory) + } + return checkNotNull(resolver.insert(collection, values)).toString() + } + + override fun append(id: String): OutputStream = + checkNotNull(resolver.openOutputStream(Uri.parse(id), "wa")).buffered(64 * 1024) + + override fun newest(): List = buildList { + resolver.query(collection, arrayOf(MediaStore.MediaColumns._ID), + "${MediaStore.MediaColumns.RELATIVE_PATH} = ? AND ${MediaStore.MediaColumns.OWNER_PACKAGE_NAME} = ?", + arrayOf(directory, context.packageName), "${MediaStore.MediaColumns._ID} DESC")?.use { cursor -> + while (cursor.moveToNext()) add(ContentUris.withAppendedId(collection, cursor.getLong(0)).toString()) + } + } + + override fun delete(id: String) { resolver.delete(Uri.parse(id), null, null) } +} diff --git a/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/HeartbeatWatchdog.kt b/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/HeartbeatWatchdog.kt new file mode 100644 index 0000000000..dcf5d1aba1 --- /dev/null +++ b/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/HeartbeatWatchdog.kt @@ -0,0 +1,38 @@ +package sh.paseo.trace + +internal object HeartbeatTiming { + const val intervalMs = 250L + const val overdueMs = 500L + const val gapMs = intervalMs + overdueMs +} + +/** Monotonic time is supplied by the owner, so suspension and recovery are deterministic. */ +internal class HeartbeatWatchdog(startMs: Long, private val emit: (String, Map) -> Unit) { + private var foreground = true + private var lastHeartbeat = startMs + private var overdue = false + + @Synchronized fun heartbeat(now: Long) { + if (foreground && now - lastHeartbeat > HeartbeatTiming.gapMs) { + emit("js.stall.recovered", mapOf("heartbeatGapMs" to "${now - lastHeartbeat}", "overdueMs" to "${now - lastHeartbeat - HeartbeatTiming.intervalMs}")) + } + lastHeartbeat = now + overdue = false + } + + @Synchronized fun active(value: Boolean, now: Long) { + if (foreground == value) return + emit("app.lifecycle", mapOf("state" to if (value) "foreground" else "background", "stallOpen" to "$overdue")) + foreground = value + lastHeartbeat = now + overdue = false + } + + @Synchronized fun check(now: Long) { + val gap = now - lastHeartbeat + if (foreground && gap > HeartbeatTiming.gapMs && !overdue) { + emit("js.stall.started", mapOf("heartbeatGapMs" to "$gap", "lastHeartbeatMonoMs" to "$lastHeartbeat")) + overdue = true + } + } +} diff --git a/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/PaseoNativeTraceModule.kt b/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/PaseoNativeTraceModule.kt index 4219993e36..5a048b30e1 100644 --- a/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/PaseoNativeTraceModule.kt +++ b/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/PaseoNativeTraceModule.kt @@ -5,9 +5,23 @@ import expo.modules.kotlin.modules.Module import expo.modules.kotlin.modules.ModuleDefinition class PaseoNativeTraceModule : Module() { + private var recorder: DiagnosticRecorder? = null + override fun definition() = ModuleDefinition { Name("PaseoNativeTrace") + Function("startRecorder") { metadata: Map -> + if (recorder == null) { + appContext.reactContext?.applicationContext?.let { recorder = DiagnosticRecorder(it, metadata) } + } + HeartbeatTiming.intervalMs + } + Function("record") { name: String, data: Map -> recorder?.record(name, data) } + Function("heartbeat") { recorder?.heartbeat() } + OnActivityEntersForeground { recorder?.active(true) } + OnActivityEntersBackground { recorder?.active(false) } + OnDestroy { recorder?.close(); recorder = null } + Function("beginSection") { name: String -> Trace.beginSection(name.take(127)) } diff --git a/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/RotatingLog.kt b/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/RotatingLog.kt new file mode 100644 index 0000000000..194b30aa8a --- /dev/null +++ b/packages/app/modules/paseo-native-trace/android/src/main/java/sh/paseo/trace/RotatingLog.kt @@ -0,0 +1,61 @@ +package sh.paseo.trace + +import java.io.OutputStream + +/** Storage supplies installation-owned files, newest first. */ +internal interface LogStorage { + fun create(part: Int): String + fun append(id: String): OutputStream + fun newest(): List + fun delete(id: String) +} + +/** Owns file identity, bounded retention and the terminal storage-failure state. */ +internal class RotatingLog( + private val storage: LogStorage, + private val header: (Int) -> ByteArray, + private val onFailure: (Exception) -> Unit, + private val maxBytes: Int = 5 * 1024 * 1024, +) { + private var current: String? = null + private var output: OutputStream? = null + private var size = 0 + private var part = 0 + var failed = false + private set + + fun write(bytes: ByteArray) = attempt { + if (current == null || size + bytes.size > maxBytes) { + finishBatch() + if (failed) return@attempt + val nextPart = part++ + current = storage.create(nextPart) + output = storage.append(checkNotNull(current)) + val first = header(nextPart) + output!!.write(first) + size = first.size + storage.newest().drop(8).forEach(storage::delete) + } + if (output == null) output = storage.append(checkNotNull(current)) + output!!.write(bytes) + size += bytes.size + } + + // Closing publishes size and modification time in Android Files. + fun finishBatch() = attempt { + output?.close() + output = null + } + + private fun attempt(action: () -> Unit) { + if (failed) return + try { + action() + } catch (error: Exception) { + failed = true + runCatching { output?.close() } + output = null + onFailure(error) + } + } +} diff --git a/packages/app/modules/paseo-native-trace/android/src/test/java/sh/paseo/trace/HeartbeatWatchdogTest.kt b/packages/app/modules/paseo-native-trace/android/src/test/java/sh/paseo/trace/HeartbeatWatchdogTest.kt new file mode 100644 index 0000000000..870c031997 --- /dev/null +++ b/packages/app/modules/paseo-native-trace/android/src/test/java/sh/paseo/trace/HeartbeatWatchdogTest.kt @@ -0,0 +1,40 @@ +package sh.paseo.trace + +import org.junit.Assert.assertEquals +import org.junit.Test + +class HeartbeatWatchdogTest { + @Test fun recordsOneStartAndRecoveryWithMeasuredGap() { + val events = mutableListOf>>() + val watchdog = HeartbeatWatchdog(0) { name, fields -> events.add(name to fields) } + watchdog.heartbeat(250) + watchdog.check(1000) + assertEquals(emptyList>>(), events) + watchdog.check(1001) + watchdog.check(2000) + watchdog.heartbeat(2250) + assertEquals(listOf( + "js.stall.started" to mapOf("heartbeatGapMs" to "751", "lastHeartbeatMonoMs" to "250"), + "js.stall.recovered" to mapOf("heartbeatGapMs" to "2000", "overdueMs" to "1750") + ), events) + } + + @Test fun backgroundAndResumeDoNotLookLikeStalls() { + val events = mutableListOf() + val watchdog = HeartbeatWatchdog(0) { name, _ -> events.add(name) } + watchdog.active(false, 100) + watchdog.check(300000) + watchdog.heartbeat(300100) + watchdog.active(true, 400000) + watchdog.heartbeat(400250) + watchdog.check(400500) + assertEquals(listOf("app.lifecycle", "app.lifecycle"), events) + } + + @Test fun recoveryIsReportedEvenIfNativeSamplingMissedTheGap() { + val events = mutableListOf() + val watchdog = HeartbeatWatchdog(0) { name, _ -> events.add(name) } + watchdog.heartbeat(900) + assertEquals(listOf("js.stall.recovered"), events) + } +} diff --git a/packages/app/modules/paseo-native-trace/android/src/test/java/sh/paseo/trace/RotatingLogTest.kt b/packages/app/modules/paseo-native-trace/android/src/test/java/sh/paseo/trace/RotatingLogTest.kt new file mode 100644 index 0000000000..ae021278a2 --- /dev/null +++ b/packages/app/modules/paseo-native-trace/android/src/test/java/sh/paseo/trace/RotatingLogTest.kt @@ -0,0 +1,59 @@ +package sh.paseo.trace + +import java.io.ByteArrayOutputStream +import java.io.IOException +import java.io.OutputStream +import org.junit.Assert.* +import org.junit.Test + +class RotatingLogTest { + private class MemoryStorage : LogStorage { + val files = linkedMapOf() + var fail = false + var opens = 0 + override fun create(part: Int): String { + val id = "part-$part" + files[id] = ByteArrayOutputStream() + return id + } + override fun append(id: String): OutputStream { + opens++ + if (fail) throw IOException("disk full") + return files.getValue(id) + } + override fun newest() = files.keys.reversed() + override fun delete(id: String) { files.remove(id) } + } + + @Test fun rotatesAtByteLimitAndKeepsEightIncludingCurrent() { + val storage = MemoryStorage() + val log = RotatingLog(storage, { "header:$it\n".toByteArray() }, { throw it }, 20) + repeat(10) { log.write("123456789012".toByteArray()); log.finishBatch() } + assertEquals((2..9).map { "part-$it" }, storage.files.keys.toList()) + for (part in 2..9) assertEquals("header:$part\n123456789012", storage.files.getValue("part-$part").toString("UTF-8")) + assertFalse(log.failed) + } + + @Test fun reopeningBatchAppendsWithoutRepeatingHeaderAndExactLimitFits() { + val storage = MemoryStorage() + val log = RotatingLog(storage, { "H".toByteArray() }, { throw it }, 5) + log.write("12".toByteArray()) + log.finishBatch() + log.write("34".toByteArray()) + assertEquals(listOf("part-0"), storage.files.keys.toList()) + assertEquals("H1234", storage.files.getValue("part-0").toString("UTF-8")) + log.write("5".toByteArray()) + assertEquals("H5", storage.files.getValue("part-1").toString("UTF-8")) + } + + @Test fun storageFailureStopsRecordingWithoutRetryStorm() { + val storage = MemoryStorage() + var failures = 0 + val log = RotatingLog(storage, { byteArrayOf() }, { failures++ }) + storage.fail = true + repeat(100) { log.write(byteArrayOf(1)); log.finishBatch() } + assertTrue(log.failed) + assertEquals(1, failures) + assertEquals(1, storage.opens) + } +} diff --git a/packages/app/package.json b/packages/app/package.json index 7f1ff46029..a2e44700e1 100644 --- a/packages/app/package.json +++ b/packages/app/package.json @@ -8,12 +8,12 @@ "start:expo": "cross-env APP_VARIANT=development expo start", "reset-project": "node ./scripts/reset-project.js", "eas-build-post-install": "npm --prefix ../.. run build:app-deps && npm run build:terminal-webview", - "android": "npm run android:development", - "android:development": "npm --prefix ../.. run build:client && cross-env APP_VARIANT=development expo prebuild --platform android --clean --non-interactive && cross-env APP_VARIANT=development expo run:android --variant=debug", + "android": "npm run dev:android", + "android:development": "npm run dev:android", "android:production": "npm --prefix ../.. run build:client && cross-env APP_VARIANT=production expo prebuild --platform android --clean --non-interactive && cross-env APP_VARIANT=production expo run:android --variant=release", "android:release": "npm run android:production", "android:clear": "node -e \"require('node:fs').rmSync('android', { recursive: true, force: true })\"", - "ios": "npm --prefix ../.. run build:client && expo run:ios", + "ios": "npm run dev:ios", "ios:release": "npm --prefix ../.. run build:client && expo run:ios --configuration Release", "web": "npm --prefix ../.. run build:client && concurrently --kill-others --names protocol,client,expo --prefix-colors yellow,blue,magenta \"npm --prefix ../.. run watch:protocol\" \"npm --prefix ../.. run watch:client\" \"npm run web:expo\"", "web:expo": "expo start --web", @@ -36,7 +36,12 @@ "profile:workspace-tabs": "node ./scripts/profile-workspace-tabs.mjs", "deploy:web": "npm run build:web && wrangler pages deploy dist --project-name paseo-app --branch main", "build:terminal-webview": "node ./scripts/build-terminal-webview-html.mjs", - "build:mermaid-runtime": "node ./src/components/markdown/fence/mermaid/build-runtime.mjs" + "build:mermaid-runtime": "node ./src/components/markdown/fence/mermaid/build-runtime.mjs", + "dev:android": "npm --prefix ../.. run build:client && cross-env APP_VARIANT=development expo prebuild --platform android --clean --non-interactive && cross-env APP_VARIANT=development expo run:android --variant=debug", + "dev:ios": "npm --prefix ../.. run build:client && cross-env APP_VARIANT=development expo run:ios", + "build:apk": "npm --prefix ../.. run build:apk", + "build:apk:arm64": "npm --prefix ../.. run build:apk:arm64", + "test:android": "expo prebuild --platform android --no-install && cd android && ./gradlew :paseo-native-trace:testReleaseUnitTest --no-daemon --max-workers=2 -Dorg.gradle.parallel=false" }, "dependencies": { "@codemirror/commands": "6.10.4", diff --git a/packages/app/src/performance/native-trace.ts b/packages/app/src/performance/native-trace.ts index b5e8e73a60..4f3cc45784 100644 --- a/packages/app/src/performance/native-trace.ts +++ b/packages/app/src/performance/native-trace.ts @@ -1,3 +1,4 @@ +import { watchdog } from "@/watchdog"; import type { DaemonClientTrace } from "@getpaseo/client/internal/daemon-client"; import { requireOptionalNativeModule } from "expo-modules-core"; import { isProfileBuild } from "@/constants/build-profile"; @@ -9,17 +10,14 @@ interface PaseoNativeTraceModule { const traceModule = requireOptionalNativeModule("PaseoNativeTrace"); -export const nativePerformanceTrace: DaemonClientTrace = { - isEnabled() { - return isProfileBuild && traceModule !== null; - }, - beginSection(name, args) { - traceModule?.beginSection(formatSectionName(name, args)); - }, - endSection() { - traceModule?.endSection(); - }, -}; +const nativeSink: DaemonClientTrace | null = + isProfileBuild && traceModule + ? { + isEnabled: () => true, + beginSection: (name, args) => traceModule.beginSection(formatSectionName(name, args)), + endSection: () => traceModule.endSection(), + } + : null; function formatSectionName(name: string, args?: Record): string { if (!args) { @@ -29,10 +27,29 @@ function formatSectionName(name: string, args?: Record): string return `${name}|${fields.join(";")}`; } +const instantSinks: ((name: string, args?: Record) => void)[] = []; +if (watchdog) instantSinks.push(watchdog.record); +if (nativeSink) + instantSinks.push((name, args) => { + nativeSink.beginSection(name, args); + nativeSink.endSection(); + }); export function traceInstant(name: string, args?: Record): void { - if (!nativePerformanceTrace.isEnabled()) { - return; - } - nativePerformanceTrace.beginSection(name, args); - nativePerformanceTrace.endSection(); + for (const write of instantSinks) write(name, args); +} + +/** Each client owns its section stack; overlapping hosts never share span identity. */ +export function createPerformanceTrace(context: Record): DaemonClientTrace { + const sinks = [watchdog?.trace(context), nativeSink].filter( + (sink): sink is DaemonClientTrace => sink != null, + ); + return { + isEnabled: () => sinks.length > 0, + beginSection(name, args) { + for (const sink of sinks) sink.beginSection(name, args); + }, + endSection() { + for (const sink of sinks) sink.endSection(); + }, + }; } diff --git a/packages/app/src/root-app.tsx b/packages/app/src/root-app.tsx index cae9b169d6..746a008d58 100644 --- a/packages/app/src/root-app.tsx +++ b/packages/app/src/root-app.tsx @@ -1,3 +1,4 @@ +import { RenderProfile } from "@/utils/render-profiler"; import { useCallback, useState, type ComponentProps } from "react"; import { ExpoRoot } from "expo-router"; import Head from "expo-router/head"; @@ -13,7 +14,11 @@ const { ctx: context } = require("expo-router/_ctx") as { }; export function RootApp() { - return ; + return ( + + + + ); } export function RootRouter({ context: routes }: Pick, "context">) { diff --git a/packages/app/src/runtime/host-runtime.ts b/packages/app/src/runtime/host-runtime.ts index 55298ce5a1..85d077ee0a 100644 --- a/packages/app/src/runtime/host-runtime.ts +++ b/packages/app/src/runtime/host-runtime.ts @@ -1,3 +1,4 @@ +import { watchdog } from "@/watchdog"; import { useSyncExternalStore, useMemo } from "react"; import AsyncStorage from "@react-native-async-storage/async-storage"; import equal from "fast-deep-equal/es6"; @@ -83,7 +84,7 @@ import { type ViewedTimelineOwnerPorts, } from "@/timeline/viewed-timeline-sync"; import { projectIconCache } from "@/projects/icon-cache"; -import { nativePerformanceTrace } from "@/performance/native-trace"; +import { createPerformanceTrace } from "@/performance/native-trace"; import { revokePushNotifications } from "@/push-notifications"; import { createAppWebSocketFactory } from "./websocket-factory"; @@ -544,7 +545,7 @@ function createDefaultDeps(): HostRuntimeControllerDeps { appVersion: resolveAppVersion() ?? undefined, runtimeGeneration, capabilities: appCapabilities, - trace: nativePerformanceTrace, + trace: createPerformanceTrace({ host: host.serverId, connection: connection.id }), providerSnapshots: "wire", ...(host.password ? { password: host.password } : {}), localCredential: () => readDesktopManagedLocalCredential(connection), @@ -604,7 +605,7 @@ function createDefaultDeps(): HostRuntimeControllerDeps { localCredential: () => readDesktopManagedLocalCredential(connection), ...(timeoutMs !== undefined ? { timeoutMs } : {}), capabilities: appCapabilities, - trace: nativePerformanceTrace, + trace: createPerformanceTrace({ host: host.serverId, connection: connection.id }), }), getClientId: () => getOrCreateClientId(), mountClientHandlers: ({ client, host }) => { @@ -1159,12 +1160,18 @@ export class HostRuntimeController { }); } - private logConnectionTransition(_input: { + private logConnectionTransition(input: { from: HostRuntimeConnectionMachineState["tag"]; to: HostRuntimeConnectionMachineState["tag"]; event: HostRuntimeConnectionMachineEvent; }): void { - // Intentionally empty - logging removed. + watchdog?.record("host.transition", { + host: this.host.serverId, + from: input.from, + to: input.to, + event: input.event.type, + epoch: String(this.connectionEpoch), + }); } private trackConnectionFirstSeen(): void { diff --git a/packages/app/src/utils/render-profiler.tsx b/packages/app/src/utils/render-profiler.tsx index cefecffde2..04a1be77df 100644 --- a/packages/app/src/utils/render-profiler.tsx +++ b/packages/app/src/utils/render-profiler.tsx @@ -1,3 +1,4 @@ +import { watchdog } from "@/watchdog"; import { Profiler, type ProfilerOnRenderCallback, type ReactNode } from "react"; export interface RenderProfileSample { @@ -28,12 +29,40 @@ function getSearchParam(name: string): string | null { return new URLSearchParams(search).get(name); } -export function isRenderProfileEnabled(): boolean { - return ( - globalThis.__PASEO_RENDER_PROFILE_ENABLED__ === true || getSearchParam("renderProfile") === "1" - ); +interface RenderSink { + isEnabled(): boolean; + render(sample: RenderProfileSample): void; + reasons(id: string, reasons: string[]): void; } +function createBrowserSink(): RenderSink { + return { + isEnabled: () => + globalThis.__PASEO_RENDER_PROFILE_ENABLED__ === true || + getSearchParam("renderProfile") === "1", + render(sample) { + globalThis.__PASEO_RENDER_PROFILE__ ??= []; + globalThis.__PASEO_RESET_RENDER_PROFILE__ ??= () => { + globalThis.__PASEO_RENDER_PROFILE__ = []; + globalThis.__PASEO_RENDER_PROFILE_REASONS__ = {}; + }; + // Browser QA compares cumulative commit counts until an explicit reset. + globalThis.__PASEO_RENDER_PROFILE__.push(sample); + }, + reasons(id, reasons) { + globalThis.__PASEO_RENDER_PROFILE_REASONS__ ??= {}; + const counts = (globalThis.__PASEO_RENDER_PROFILE_REASONS__[id] ??= {}); + for (const reason of reasons) counts[reason] = (counts[reason] ?? 0) + 1; + }, + }; +} + +// Choose the destination once. Browser QA can still enable capture at runtime. +const sink: RenderSink = watchdog + ? { isEnabled: () => true, render: watchdog.render, reasons: () => {} } + : createBrowserSink(); + +export const isRenderProfileEnabled = sink.isEnabled; const onRender: ProfilerOnRenderCallback = ( id, phase, @@ -41,30 +70,10 @@ const onRender: ProfilerOnRenderCallback = ( baseDuration, startTime, commitTime, -) => { - globalThis.__PASEO_RENDER_PROFILE__ ??= []; - globalThis.__PASEO_RENDER_PROFILE__.push({ - id, - phase, - actualDuration, - baseDuration, - startTime, - commitTime, - }); -}; +) => sink.render({ id, phase, actualDuration, baseDuration, startTime, commitTime }); export function RenderProfile({ id, children }: { id: string; children: ReactNode }) { - if (!isRenderProfileEnabled()) { - return children; - } - - globalThis.__PASEO_RENDER_PROFILE__ ??= []; - globalThis.__PASEO_RENDER_PROFILE_REASONS__ ??= {}; - globalThis.__PASEO_RESET_RENDER_PROFILE__ = () => { - globalThis.__PASEO_RENDER_PROFILE__ = []; - globalThis.__PASEO_RENDER_PROFILE_REASONS__ = {}; - }; - + if (!sink.isEnabled()) return children; return ( {children} @@ -73,12 +82,5 @@ export function RenderProfile({ id, children }: { id: string; children: ReactNod } export function recordRenderProfileReasons(id: string, reasons: string[]) { - if (!isRenderProfileEnabled() || reasons.length === 0) { - return; - } - globalThis.__PASEO_RENDER_PROFILE_REASONS__ ??= {}; - const counts = (globalThis.__PASEO_RENDER_PROFILE_REASONS__[id] ??= {}); - for (const reason of reasons) { - counts[reason] = (counts[reason] ?? 0) + 1; - } + if (sink.isEnabled()) sink.reasons(id, reasons); } diff --git a/packages/app/src/watchdog/index.ts b/packages/app/src/watchdog/index.ts new file mode 100644 index 0000000000..2a1863e54e --- /dev/null +++ b/packages/app/src/watchdog/index.ts @@ -0,0 +1,35 @@ +import { requireOptionalNativeModule } from "expo-modules-core"; +import Constants from "expo-constants"; +import { resolveAppVersion } from "@/utils/app-version"; +import { createRecorder } from "./internal/recorder"; + +interface NativeRecorder { + startRecorder(metadata: Record): number; + record(name: string, fields: Record): void; + heartbeat(): void; +} + +const native = + Constants.expoConfig?.extra?.watchdogBuild === true + ? requireOptionalNativeModule("PaseoNativeTrace") + : null; +export const watchdog = native + ? createRecorder( + (name, fields) => native.record(name, fields), + () => performance.now(), + ) + : null; +let started = false; + +export function startWatchdog(): void { + if (!native || !watchdog || started) return; + started = true; + const heartbeatMs = native.startRecorder({ + version: resolveAppVersion() ?? "unknown", + build: String(Constants.expoConfig?.extra?.diagnosticRevision ?? "unknown"), + builtAt: String(Constants.expoConfig?.extra?.diagnosticBuildTime ?? "unknown"), + reactProfiling: "true", + }); + setInterval(() => native.heartbeat(), heartbeatMs); + setInterval(() => watchdog.flushRenders(), 1000); +} diff --git a/packages/app/src/watchdog/internal/recorder.test.ts b/packages/app/src/watchdog/internal/recorder.test.ts new file mode 100644 index 0000000000..072ca2a708 --- /dev/null +++ b/packages/app/src/watchdog/internal/recorder.test.ts @@ -0,0 +1,103 @@ +import { expect, test } from "vitest"; +import { createRecorder } from "./recorder"; + +function fixture() { + const events: { name: string; fields: Record }[] = []; + let now = 0; + const recorder = createRecorder( + (name, fields) => events.push({ name, fields }), + () => now, + ); + return { + recorder, + events, + advance: (ms: number) => { + now += ms; + }, + }; +} + +test("interleaved hosts keep independent parent spans and durations", () => { + const { recorder, events, advance } = fixture(); + const a = recorder.trace({ host: "a" }); + const b = recorder.trace({ host: "b" }); + a.beginSection("frame"); + advance(5); + b.beginSection("frame"); + a.beginSection("parse"); + advance(15); + a.endSection(); + b.endSection(); + a.endSection(); + expect( + events.map(({ name, fields }) => [ + name, + fields.host, + fields.span, + fields.parent, + fields.durationMs, + ]), + ).toEqual([ + ["frame.begin", "a", "1:1", "", undefined], + ["frame.begin", "b", "2:1", "", undefined], + ["parse.begin", "a", "1:2", "1:1", undefined], + ["parse.end", "a", "1:2", undefined, "15"], + ["frame.end", "b", "2:1", undefined, "15"], + ["frame.end", "a", "1:1", undefined, "20"], + ]); +}); + +test("slow renders preserve commit identity while fast renders are summarized", () => { + const { recorder, events } = fixture(); + for (const actualDuration of [1, 2, 30]) + recorder.render({ + id: "Stream", + phase: "update", + actualDuration, + startTime: 4, + commitTime: 40, + }); + recorder.flushRenders(); + recorder.flushRenders(); + expect(events).toEqual([ + { + name: "react.render.slow", + fields: { + region: "Stream", + phase: "update", + renderMs: "30", + startMs: "4", + commitMs: "40", + jsMonoMs: "0", + }, + }, + { + name: "react.render.summary", + fields: { region: "Stream", count: "3", totalMs: "33", maxMs: "30", jsMonoMs: "0" }, + }, + ]); +}); + +test("dynamic regions are bounded and summaries reset each interval", () => { + const { recorder, events } = fixture(); + for (let i = 0; i < 10000; i++) + recorder.render({ + id: String(i), + phase: "mount", + actualDuration: 1, + startTime: 0, + commitTime: 1, + }); + recorder.flushRenders(); + expect(events.length).toBe(129); + expect(events.at(-1)?.fields).toEqual({ + region: "other", + count: "9872", + totalMs: "9872", + maxMs: "1", + jsMonoMs: "0", + }); + recorder.render({ id: "new", phase: "mount", actualDuration: 1, startTime: 0, commitTime: 1 }); + recorder.flushRenders(); + expect(events.at(-1)?.fields.region).toBe("new"); +}); diff --git a/packages/app/src/watchdog/internal/recorder.ts b/packages/app/src/watchdog/internal/recorder.ts new file mode 100644 index 0000000000..9af879abe6 --- /dev/null +++ b/packages/app/src/watchdog/internal/recorder.ts @@ -0,0 +1,79 @@ +import type { DaemonClientTrace } from "@getpaseo/client/internal/daemon-client"; + +type Fields = Record; +interface RenderSample { + id: string; + phase: string; + actualDuration: number; + startTime: number; + commitTime: number; +} + +/** Bounded render aggregation and scoped trace identity; no payloads enter this boundary. */ +export function createRecorder(write: (name: string, fields: Fields) => void, now: () => number) { + let nextClient = 0; + const renders = new Map(); + const record = (name: string, fields: Fields = {}) => + write(name, { ...fields, jsMonoMs: String(now()) }); + return { + record, + trace(context: Fields): DaemonClientTrace { + const client = String(++nextClient); + let sequence = 0; + const sections: { id: string; name: string; start: number }[] = []; + return { + isEnabled: () => true, + beginSection(name, fields) { + const id = `${client}:${++sequence}`; + record(`${name}.begin`, { + ...context, + ...fields, + client, + span: id, + parent: sections.at(-1)?.id ?? "", + }); + sections.push({ id, name, start: now() }); + }, + endSection() { + const section = sections.pop(); + if (section) + record(`${section.name}.end`, { + ...context, + client, + span: section.id, + durationMs: String(now() - section.start), + }); + }, + }; + }, + render(sample: RenderSample) { + if (sample.actualDuration >= 16) { + record("react.render.slow", { + region: sample.id, + phase: sample.phase, + renderMs: String(sample.actualDuration), + startMs: String(sample.startTime), + commitMs: String(sample.commitTime), + }); + } + // Dynamic agent/tab IDs cannot grow this map without bound. + const key = renders.has(sample.id) || renders.size < 128 ? sample.id : "other"; + const summary = renders.get(key) ?? { count: 0, totalMs: 0, maxMs: 0 }; + summary.count++; + summary.totalMs += sample.actualDuration; + summary.maxMs = Math.max(summary.maxMs, sample.actualDuration); + renders.set(key, summary); + }, + flushRenders() { + for (const [region, summary] of renders) { + record("react.render.summary", { + region, + count: String(summary.count), + totalMs: String(summary.totalMs), + maxMs: String(summary.maxMs), + }); + } + renders.clear(); + }, + }; +} diff --git a/packages/client/src/daemon-client.test.ts b/packages/client/src/daemon-client.test.ts index 7469470ad1..7f183ccfa4 100644 --- a/packages/client/src/daemon-client.test.ts +++ b/packages/client/src/daemon-client.test.ts @@ -200,38 +200,75 @@ test("traces WebSocket frames, message types, and JSON parse duration", async () mock.triggerOpen({ preserveSent: true }); await connectPromise; - expect(recorder.records).toEqual([ - { - phase: "begin", - name: "paseo.ws.message.outbound", - args: { envelopeType: "hello", messageType: "hello" }, - }, - { phase: "end" }, - { - phase: "begin", - name: "paseo.ws.frame.outbound", - args: { kind: "text", size: expect.any(String) }, - }, - { phase: "end" }, - { - phase: "begin", - name: "paseo.ws.frame.inbound", - args: { kind: "text", size: expect.any(String) }, - }, - { - phase: "begin", - name: "paseo.ws.json.parse", - args: { size: expect.any(String) }, - }, - { phase: "end" }, - { - phase: "begin", - name: "paseo.ws.message.inbound", - args: { envelopeType: "session", messageType: "status" }, - }, - { phase: "end" }, - { phase: "end" }, - ]); + const response = client.fetchAgents({ requestId: "diagnostic-request", scope: "active" }); + mock.triggerMessage( + wrapSessionMessage({ + type: "fetch_agents_response", + payload: { + requestId: "diagnostic-request", + entries: [], + pageInfo: { nextCursor: null, prevCursor: null, hasMore: false }, + }, + }), + ); + await response; + const spans = recorder.records.filter((record) => record.phase === "begin"); + expect(spans).toEqual( + expect.arrayContaining([ + expect.objectContaining({ + name: "paseo.ws.frame.inbound", + args: { + kind: "text", + size: expect.any(String), + sizeUnit: "utf16-code-units", + connectionAttempt: "1", + }, + }), + expect.objectContaining({ name: "paseo.ws.json.parse" }), + expect.objectContaining({ name: "paseo.ws.validate" }), + expect.objectContaining({ + name: "paseo.ws.message.outbound", + args: { + envelopeType: "session", + messageType: "fetch_agents_request", + requestId: "diagnostic-request", + connectionAttempt: "1", + }, + }), + expect.objectContaining({ + name: "paseo.ws.message.inbound", + args: { + envelopeType: "session", + messageType: "fetch_agents_response", + requestId: "diagnostic-request", + connectionAttempt: "1", + }, + }), + expect.objectContaining({ + name: "paseo.ws.dispatch", + args: { + messageType: "fetch_agents_response", + requestId: "diagnostic-request", + connectionAttempt: "1", + }, + }), + ]), + ); + const stack: string[] = []; + const parentage: [string, string | undefined][] = []; + for (const record of recorder.records) { + if (record.phase === "begin") { + parentage.push([record.name, stack.at(-1)]); + stack.push(record.name); + } else { + expect(stack.length).toBeGreaterThan(0); + stack.pop(); + } + } + expect(stack).toEqual([]); + expect(parentage).toContainEqual(["paseo.ws.frame.outbound", "paseo.ws.message.outbound"]); + expect(parentage).toContainEqual(["paseo.ws.dispatch", "paseo.ws.frame.inbound"]); + expect(JSON.stringify(recorder.records)).not.toContain("trace_unit_test"); }); test("does not infer browser automation capabilities from Electron runtime", async () => { diff --git a/packages/client/src/daemon-client.ts b/packages/client/src/daemon-client.ts index 30d0db6cc6..aa4624338e 100644 --- a/packages/client/src/daemon-client.ts +++ b/packages/client/src/daemon-client.ts @@ -1147,19 +1147,34 @@ function assertTransportFrameFits(frame: string | Uint8Array | ArrayBuffer): voi throw messageTooLargeError(size, MAX_WEBSOCKET_MESSAGE_BYTES); } -function describeInboundTransportFrame( - frame: unknown, - rawBytes: Uint8Array | null, -): Record { +function describeInboundTransportFrame(frame: unknown): Record { if (typeof frame === "string") { - return { kind: "text", size: String(frame.length) }; + return { kind: "text", size: String(frame.length), sizeUnit: "utf16-code-units" }; } - if (rawBytes) { - return { kind: "binary", size: String(rawBytes.byteLength) }; + if (frame instanceof ArrayBuffer || ArrayBuffer.isView(frame)) { + return { kind: "binary", size: String(frame.byteLength), sizeUnit: "bytes" }; } return { kind: "unknown", size: "0" }; } +function describeRequestIdentity(value: unknown): Record { + if (!value || typeof value !== "object") return {}; + const message = "message" in value ? value.message : value; + if (!message || typeof message !== "object") return {}; + if ("requestId" in message && typeof message.requestId === "string") + return { requestId: message.requestId }; + if ( + "payload" in message && + message.payload && + typeof message.payload === "object" && + "requestId" in message.payload && + typeof message.payload.requestId === "string" + ) { + return { requestId: message.payload.requestId }; + } + return {}; +} + function hashForLog(value: string): string { let hash = 0; for (let index = 0; index < value.length; index += 1) { @@ -1277,6 +1292,7 @@ export class DaemonClient { private connectTimeout: ReturnType | null = null; private pendingGenericTransportErrorTimeout: ReturnType | null = null; private reconnectAttempt = 0; + private traceConnectionAttempt = 0; private shouldReconnect = true; private connectPromise: Promise | null = null; private connectResolve: (() => void) | null = null; @@ -1429,6 +1445,7 @@ export class DaemonClient { headers: selected.headers, ...(selected.protocols ? { protocols: selected.protocols } : {}), }); + this.traceConnectionAttempt += 1; this.transport = transport; this.lastServerInfoMessage = null; this.authFailureReasonValue = null; @@ -1457,6 +1474,7 @@ export class DaemonClient { this.transportCleanup = [ transport.onOpen(() => { + this.traceInstant("paseo.connection.open"); if (this.pendingGenericTransportErrorTimeout) { clearTimeout(this.pendingGenericTransportErrorTimeout); this.pendingGenericTransportErrorTimeout = null; @@ -1465,6 +1483,11 @@ export class DaemonClient { void this.sendHelloMessage(); }), transport.onClose((event) => { + this.traceInstant("paseo.connection.close", { + code: String( + event && typeof event === "object" && "code" in event ? event.code : "unknown", + ), + }); this.resetConnectTimeout(); if (this.pendingGenericTransportErrorTimeout) { clearTimeout(this.pendingGenericTransportErrorTimeout); @@ -1484,6 +1507,7 @@ export class DaemonClient { }); }), transport.onError((event) => { + this.traceInstant("paseo.connection.error"); this.resetConnectTimeout(); const reason = describeTransportError(event); const isGeneric = reason === "Transport error"; @@ -1755,7 +1779,7 @@ export class DaemonClient { if (!trace?.isEnabled()) { return false; } - trace.beginSection(name, args); + trace.beginSection(name, { ...args, connectionAttempt: String(this.traceConnectionAttempt) }); return true; } @@ -1770,12 +1794,26 @@ export class DaemonClient { this.endTraceSection(isOpen); } + private beginSessionDispatchTrace(message: SessionOutboundMessage): boolean { + if (!this.config.trace?.isEnabled()) return false; + const fields = { messageType: message.type, ...describeRequestIdentity(message) }; + this.traceInstant("paseo.ws.message.inbound", { envelopeType: "session", ...fields }); + return this.beginTraceSection("paseo.ws.dispatch", fields); + } + private sendJsonMessage(envelopeType: string, messageType: string, message: unknown): void { - this.traceInstant("paseo.ws.message.outbound", { - envelopeType, - messageType, - }); - this.sendTransportFrame(JSON.stringify(message)); + const isOpen = + this.config.trace?.isEnabled() === true && + this.beginTraceSection("paseo.ws.message.outbound", { + envelopeType, + messageType, + ...describeRequestIdentity(message), + }); + try { + this.sendTransportFrame(JSON.stringify(message)); + } finally { + this.endTraceSection(isOpen); + } } private sendTransportFrame(frame: string | Uint8Array | ArrayBuffer): void { @@ -1787,6 +1825,7 @@ export class DaemonClient { const isOpen = this.beginTraceSection("paseo.ws.frame.outbound", { kind: typeof frame === "string" ? "text" : "binary", size: String(getTransportFrameSize(frame)), + sizeUnit: typeof frame === "string" ? "utf16-code-units" : "bytes", }); try { this.transport.send(frame); @@ -6394,12 +6433,13 @@ export class DaemonClient { return; } - const rawBytes = asUint8Array(rawData); const isOpen = this.beginTraceSection( "paseo.ws.frame.inbound", - describeInboundTransportFrame(rawData, rawBytes), + describeInboundTransportFrame(rawData), ); try { + // Record arrival before conversion: encoding a large text frame is JS work too. + const rawBytes = asUint8Array(rawData); if (rawBytes && this.tryHandleBinaryFrame(rawBytes)) { return; } @@ -6419,17 +6459,26 @@ export class DaemonClient { let parsedJson: unknown; const parseTraceOpen = this.beginTraceSection("paseo.ws.json.parse", { size: String(bytes), + sizeUnit: rawBytesLength === undefined ? "utf16-code-units" : "bytes", }); try { parsedJson = JSON.parse(payload); } catch { + this.traceInstant("paseo.ws.json.invalid"); return; } finally { this.endTraceSection(parseTraceOpen); } - const parsed = validateWSOutboundMessage(parsedJson); + const validationTrace = this.beginTraceSection("paseo.ws.validate"); + let parsed: ReturnType; + try { + parsed = validateWSOutboundMessage(parsedJson); + } finally { + this.endTraceSection(validationTrace); + } if (!parsed.success) { + this.traceInstant("paseo.ws.validation.failed"); const responseIdentity = extractCorrelatedResponseIdentity(parsedJson); const envelopeType = parsedJson != null && @@ -6462,6 +6511,7 @@ export class DaemonClient { } if (parsed.data.type === "hello.rejected") { + this.traceInstant("paseo.connection.rejected", { reason: parsed.data.reason }); const reasonMessage = { password_required: "Password required", incorrect_password: "Incorrect password", @@ -6473,11 +6523,12 @@ export class DaemonClient { return; } - this.traceInstant("paseo.ws.message.inbound", { - envelopeType: "session", - messageType: parsed.data.message.type, - }); - this.handleSessionMessage(parsed.data.message); + const dispatchTrace = this.beginSessionDispatchTrace(parsed.data.message); + try { + this.handleSessionMessage(parsed.data.message); + } finally { + this.endTraceSection(dispatchTrace); + } const msgType = parsed.data.message.type; this.runtimeMetrics?.recordMessage(msgType, bytes, perfNow() - startMs); if (parsed.data.message.type === "agent_stream") { @@ -6492,6 +6543,7 @@ export class DaemonClient { envelopeType: "binary", messageType: "file", opcode: String(fileFrame.opcode), + requestId: fileFrame.requestId, }); this.consecutiveLivenessFailures = 0; this.handleFileTransferFrame(fileFrame); @@ -6507,6 +6559,7 @@ export class DaemonClient { envelopeType: "binary", messageType: "terminal", opcode: String(frame.opcode), + slot: String(frame.slot), }); this.consecutiveLivenessFailures = 0; const binaryStartMs = perfNow(); @@ -6625,6 +6678,12 @@ export class DaemonClient { next.status === "disconnected" && typeof next.reason === "string" ? next.reason : null; const reason = metadata?.reason ?? reasonFromNext; const reasonCode = metadata?.reasonCode ?? toReasonCode(reason); + this.traceInstant("paseo.connection.state", { + from: previous.status, + to: next.status, + event: metadata?.event ?? "STATE_UPDATE", + reasonCode: reasonCode ?? "none", + }); this.logger.debug( { serverId: this.logServerId, @@ -6724,6 +6783,10 @@ export class DaemonClient { const baseDelay = this.config.reconnect?.baseDelayMs ?? DEFAULT_RECONNECT_BASE_DELAY_MS; const maxDelay = this.config.reconnect?.maxDelayMs ?? DEFAULT_RECONNECT_MAX_DELAY_MS; const delay = Math.min(baseDelay * 2 ** attempt, maxDelay); + this.traceInstant("paseo.connection.reconnect", { + attempt: String(attempt), + delayMs: String(delay), + }); this.reconnectAttempt = attempt + 1; this.reconnectTimeout = setTimeout(() => { this.reconnectTimeout = null; diff --git a/scripts/build-apk.mjs b/scripts/build-apk.mjs new file mode 100644 index 0000000000..964e6eacf2 --- /dev/null +++ b/scripts/build-apk.mjs @@ -0,0 +1,52 @@ +import { spawnSync, execFileSync } from "node:child_process"; +import { copyFileSync, mkdirSync, rmSync } from "node:fs"; +import { fileURLToPath } from "node:url"; +import path from "node:path"; + +const target = process.argv[2] ?? "universal"; +const architectures = { + universal: "armeabi-v7a,arm64-v8a,x86,x86_64", + arm64: "arm64-v8a", +}[target]; +if (!architectures) { + throw new Error(`Unknown APK target: ${target}. Use universal or arm64.`); +} + +const root = fileURLToPath(new URL("..", import.meta.url)); +const app = path.join(root, "packages/app"); +const env = { + ...process.env, + APP_VARIANT: "production", + PASEO_WATCHDOG_BUILD: "1", + PASEO_DIAGNOSTIC_BUILD_TIME: new Date().toISOString(), + PASEO_DIAGNOSTIC_REVISION: + execFileSync("git", ["rev-parse", "--short", "HEAD"], { cwd: root, encoding: "utf8" }).trim() + + (execFileSync("git", ["status", "--porcelain"], { cwd: root, encoding: "utf8" }).trim() + ? "-dirty" + : ""), +}; +function run(command, args, cwd) { + const result = spawnSync(command, args, { cwd, env, stdio: "inherit" }); + if (result.error) throw result.error; + if (result.status !== 0) process.exit(result.status ?? 1); +} +run("npm", ["run", "build:app-deps"], root); +run("npx", ["expo", "prebuild", "--platform", "android", "--no-install"], app); +// Gradle does not track Metro's environment flags. Always regenerate the JS artifact +// so a previous ordinary release cannot silently bypass the profiling renderer. +rmSync(path.join(app, "android/app/build/generated/assets"), { recursive: true, force: true }); +run( + "./gradlew", + [ + "assembleRelease", + "--no-daemon", + "--max-workers=2", + "-Dorg.gradle.parallel=false", + `-PreactNativeArchitectures=${architectures}`, + ], + path.join(app, "android"), +); +const destination = path.join(root, `artifacts/paseo-dogfood-${target}.apk`); +mkdirSync(path.dirname(destination), { recursive: true }); +copyFileSync(path.join(app, "android/app/build/outputs/apk/release/app-release.apk"), destination); +console.log(`\nDiagnostic release APK: ${destination}\nLogs: Downloads/Paseo diagnostics\n`);