From 98bc82f0438ab75b33aea1b107989d3b3db90ac8 Mon Sep 17 00:00:00 2001 From: Mohamed Boudra Date: Tue, 20 Oct 2026 04:32:18 +0200 Subject: [PATCH] refactor(app): own watchdog sinks and bounded log storage --- .github/workflows/ci.yml | 8 ++ CLAUDE.md | 4 +- docs/android.md | 14 ++- packages/app/app.config.js | 4 +- packages/app/index.ts | 4 +- packages/app/metro.config.cjs | 5 +- .../java/sh/paseo/trace/DiagnosticRecorder.kt | 106 +++++------------- .../sh/paseo/trace/DownloadsLogStorage.kt | 36 ++++++ .../java/sh/paseo/trace/HeartbeatWatchdog.kt | 12 +- .../sh/paseo/trace/PaseoNativeTraceModule.kt | 1 + .../main/java/sh/paseo/trace/RotatingLog.kt | 61 ++++++++++ .../java/sh/paseo/trace/RotatingLogTest.kt | 59 ++++++++++ packages/app/package.json | 3 +- packages/app/src/performance/native-trace.ts | 47 ++++---- packages/app/src/runtime/host-runtime.ts | 4 +- packages/app/src/utils/render-profiler.tsx | 80 ++++++------- .../src/{diagnostics => watchdog}/index.ts | 14 +-- .../internal/recorder.test.ts | 0 .../internal/recorder.ts | 0 packages/client/src/daemon-client.test.ts | 17 ++- packages/client/src/daemon-client.ts | 29 ++--- 21 files changed, 318 insertions(+), 190 deletions(-) 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/RotatingLog.kt create mode 100644 packages/app/modules/paseo-native-trace/android/src/test/java/sh/paseo/trace/RotatingLogTest.kt rename packages/app/src/{diagnostics => watchdog}/index.ts (73%) rename packages/app/src/{diagnostics => watchdog}/internal/recorder.test.ts (100%) rename packages/app/src/{diagnostics => watchdog}/internal/recorder.ts (100%) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 7c2a397170..bc94e1c3d5 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 8a5814912d..88255b1f67 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -90,8 +90,6 @@ Do not: - Hedge with "generally", "typically", or "you may want to" when the answer is "do this". - Clear your throat: "It's worth noting that", "In order to", "This section covers". -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. - ## Quick start ```bash @@ -108,6 +106,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 4920f8a728..9b83240c52 100644 --- a/docs/android.md +++ b/docs/android.md @@ -73,13 +73,17 @@ npm run dev:ios # Build/install the iOS development app `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. It keeps the production package ID (`sh.paseo`) and release optimizations. Use this APK for -personal dogfooding. Normal store/release workflows leave diagnostics disabled. +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 @@ -91,13 +95,15 @@ 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 +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. Process death leaves earlier files intact, +`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 diff --git a/packages/app/app.config.js b/packages/app/app.config.js index 6b3d5edd62..fefd0ad95f 100644 --- a/packages/app/app.config.js +++ b/packages/app/app.config.js @@ -11,7 +11,7 @@ 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 = isWatchdogBuild || process.env.PASEO_PROFILE_BUILD === "1"; +const isProfileBuild = process.env.PASEO_PROFILE_BUILD === "1"; const buildProfile = isFdroidBuild ? { @@ -181,7 +181,7 @@ export default { }, ], ...buildProfile.fdroidPlugins, - ...(isProfileBuild ? [withAndroidProfileable] : []), + ...(isProfileBuild || isWatchdogBuild ? [withAndroidProfileable] : []), ], experiments: { typedRoutes: true, diff --git a/packages/app/index.ts b/packages/app/index.ts index 16553c6886..d103c5cb79 100644 --- a/packages/app/index.ts +++ b/packages/app/index.ts @@ -9,8 +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 { startDiagnostics } from "./src/diagnostics"; +import { startWatchdog } from "./src/watchdog"; import { RootApp } from "./src/root-app"; -startDiagnostics(); +startWatchdog(); renderRootComponent(RootApp); diff --git a/packages/app/metro.config.cjs b/packages/app/metro.config.cjs index 412364221b..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,7 +17,7 @@ const customWebPlatform = (process.env.PASEO_WEB_PLATFORM ?? "") .toLowerCase(); const config = getDefaultConfig(projectRoot); -config.cacheVersion = process.env.PASEO_WATCHDOG_BUILD === "1" ? "watchdog" : "standard"; +config.cacheVersion = isWatchdogBuild ? "watchdog" : "standard"; const defaultResolveRequest = config.resolver.resolveRequest ?? resolve; // Keep app exports deterministic across dev machines and CI. Metro's Watchman @@ -77,7 +78,7 @@ function resolveWithCustomWebOverlay(context, moduleName, platform) { config.resolver.resolveRequest = (context, moduleName, platform) => { if ( - process.env.PASEO_WATCHDOG_BUILD === "1" && + isWatchdogBuild && platform === "android" && /[/\\]Renderer[/\\]shims[/\\]/.test(context.originModulePath) && /implementations\/(ReactFabric|ReactNativeRenderer)-prod$/.test(moduleName) 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 index 1561f8f1cd..512795838c 100644 --- 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 @@ -1,12 +1,9 @@ package sh.paseo.trace -import android.content.ContentValues import android.content.Context import android.os.SystemClock -import android.provider.MediaStore import android.util.Log import org.json.JSONObject -import java.io.OutputStream import java.util.UUID import java.util.concurrent.ArrayBlockingQueue import java.util.concurrent.Executors @@ -20,16 +17,20 @@ internal class DiagnosticRecorder(private val context: Context, private val meta private val dropped = AtomicLong() private val worker = Executors.newSingleThreadScheduledExecutor() private val session = UUID.randomUUID().toString() - private var output: OutputStream? = null - private var currentUri: android.net.Uri? = null - private var size = 0 - private var part = 0 @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 "250", "stallThresholdMs" to "500")) - worker.scheduleWithFixedDelay({ drain() }, 0, 250, TimeUnit.MILLISECONDS) + 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) { @@ -44,85 +45,32 @@ internal class DiagnosticRecorder(private val context: Context, private val meta private fun drain() { if (failed) return - try { - watchdog.check(SystemClock.elapsedRealtime()) - val lost = dropped.getAndSet(0) - if (lost > 0) write(Event("recorder.dropped", mapOf("count" to "$lost"))) - // A traffic flood must not prevent watchdog checks or flushing. - var remaining = 2048 - while (remaining-- > 0) { - val event = queue.poll() ?: break - write(event) - } - // Closing each batch publishes size/modified time to MediaStore. Keeping a - // descriptor open makes the current file appear as 0 B in Android Files. - output?.close() - output = null - } catch (error: Exception) { - // Storage failure must never crash the app or create a retry storm. - failed = true - queue.clear() - runCatching { output?.close() } - output = null - Log.e("PaseoDiagnostics", "Diagnostic recording stopped: storage unavailable", error) + 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) { - val bytes = (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) - if (currentUri == null || size + bytes.size > 5 * 1024 * 1024) rotate() - if (output == null) { - output = checkNotNull(context.contentResolver.openOutputStream(checkNotNull(currentUri), "wa")).buffered(64 * 1024) - } - output!!.write(bytes) - size += bytes.size - } + private fun write(event: Event) = log.write(serialize(event)) - private fun rotate() { - output?.close() - output = null - val resolver = context.contentResolver - val collection = MediaStore.Downloads.EXTERNAL_CONTENT_URI - 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, "Download/Paseo diagnostics/") - } - val uri = checkNotNull(resolver.insert(collection, values)) - currentUri = uri - output = checkNotNull(resolver.openOutputStream(uri, "w")).buffered(64 * 1024) - val header = (JSONObject().apply { - put("event", "file.start") - put("session", session) - put("wallMs", System.currentTimeMillis()) - put("monoMs", SystemClock.elapsedRealtime()) - put("data", JSONObject(metadata + mapOf("schema" to "1", "part" to "$part"))) - }.toString() + "\n").toByteArray(Charsets.UTF_8) - output!!.write(header) - size = header.size - // Only prune files created by this installation, never arbitrary user downloads. - resolver.query(collection, arrayOf(MediaStore.MediaColumns._ID), - "${MediaStore.MediaColumns.RELATIVE_PATH} = ? AND ${MediaStore.MediaColumns.OWNER_PACKAGE_NAME} = ?", - arrayOf("Download/Paseo diagnostics/", context.packageName), "${MediaStore.MediaColumns._ID} DESC")?.use { cursor -> - var count = 0 - while (cursor.moveToNext()) { - if (++count > 8) resolver.delete(android.content.ContentUris.withAppendedId(collection, cursor.getLong(0)), null, null) - } - } - } + 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() - runCatching { output?.close() } - output = null + 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 index 11034c50e4..dcf5d1aba1 100644 --- 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 @@ -1,5 +1,11 @@ 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 @@ -7,8 +13,8 @@ internal class HeartbeatWatchdog(startMs: Long, private val emit: (String, Map 750) { - emit("js.stall.recovered", mapOf("heartbeatGapMs" to "${now - lastHeartbeat}", "overdueMs" to "${now - lastHeartbeat - 250}")) + 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 @@ -24,7 +30,7 @@ internal class HeartbeatWatchdog(startMs: Long, private val emit: (String, Map 750 && !overdue) { + 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 59921b5f20..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 @@ -14,6 +14,7 @@ class PaseoNativeTraceModule : Module() { 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() } 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/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 c8eae37f58..791cb5d50b 100644 --- a/packages/app/package.json +++ b/packages/app/package.json @@ -40,7 +40,8 @@ "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" + "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 8161527136..4f3cc45784 100644 --- a/packages/app/src/performance/native-trace.ts +++ b/packages/app/src/performance/native-trace.ts @@ -1,4 +1,4 @@ -import { diagnostics } from "@/diagnostics"; +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"; @@ -10,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) { @@ -30,27 +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 { - diagnostics?.record(name, args); - 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 recorder = diagnostics?.trace(context); + const sinks = [watchdog?.trace(context), nativeSink].filter( + (sink): sink is DaemonClientTrace => sink != null, + ); return { - isEnabled: () => recorder !== undefined || nativePerformanceTrace.isEnabled(), + isEnabled: () => sinks.length > 0, beginSection(name, args) { - recorder?.beginSection(name, args); - if (nativePerformanceTrace.isEnabled()) nativePerformanceTrace.beginSection(name, args); + for (const sink of sinks) sink.beginSection(name, args); }, endSection() { - recorder?.endSection(); - if (nativePerformanceTrace.isEnabled()) nativePerformanceTrace.endSection(); + for (const sink of sinks) sink.endSection(); }, }; } diff --git a/packages/app/src/runtime/host-runtime.ts b/packages/app/src/runtime/host-runtime.ts index 63d22db40d..85d077ee0a 100644 --- a/packages/app/src/runtime/host-runtime.ts +++ b/packages/app/src/runtime/host-runtime.ts @@ -1,4 +1,4 @@ -import { diagnostics } from "@/diagnostics"; +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"; @@ -1165,7 +1165,7 @@ export class HostRuntimeController { to: HostRuntimeConnectionMachineState["tag"]; event: HostRuntimeConnectionMachineEvent; }): void { - diagnostics?.record("host.transition", { + watchdog?.record("host.transition", { host: this.host.serverId, from: input.from, to: input.to, diff --git a/packages/app/src/utils/render-profiler.tsx b/packages/app/src/utils/render-profiler.tsx index 4a93e7d78c..6615d3410f 100644 --- a/packages/app/src/utils/render-profiler.tsx +++ b/packages/app/src/utils/render-profiler.tsx @@ -1,4 +1,4 @@ -import { diagnostics } from "@/diagnostics"; +import { watchdog } from "@/watchdog"; import { Profiler, type ProfilerOnRenderCallback, type ReactNode } from "react"; export interface RenderProfileSample { @@ -29,14 +29,41 @@ function getSearchParam(name: string): string | null { return new URLSearchParams(search).get(name); } -export function isRenderProfileEnabled(): boolean { - return ( - diagnostics !== null || - 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__ = {}; + }; + if (globalThis.__PASEO_RENDER_PROFILE__.length >= 2000) + globalThis.__PASEO_RENDER_PROFILE__.shift(); + 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, @@ -44,36 +71,10 @@ const onRender: ProfilerOnRenderCallback = ( baseDuration, startTime, commitTime, -) => { - if (diagnostics) { - diagnostics.render({ id, phase, actualDuration, startTime, commitTime }); - return; - } - globalThis.__PASEO_RENDER_PROFILE__ ??= []; - if (globalThis.__PASEO_RENDER_PROFILE__.length >= 2000) - globalThis.__PASEO_RENDER_PROFILE__.shift(); - 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} @@ -82,12 +83,5 @@ export function RenderProfile({ id, children }: { id: string; children: ReactNod } export function recordRenderProfileReasons(id: string, reasons: string[]) { - if (diagnostics || !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/diagnostics/index.ts b/packages/app/src/watchdog/index.ts similarity index 73% rename from packages/app/src/diagnostics/index.ts rename to packages/app/src/watchdog/index.ts index 5adf614bc8..2a1863e54e 100644 --- a/packages/app/src/diagnostics/index.ts +++ b/packages/app/src/watchdog/index.ts @@ -4,7 +4,7 @@ import { resolveAppVersion } from "@/utils/app-version"; import { createRecorder } from "./internal/recorder"; interface NativeRecorder { - startRecorder(metadata: Record): void; + startRecorder(metadata: Record): number; record(name: string, fields: Record): void; heartbeat(): void; } @@ -13,7 +13,7 @@ const native = Constants.expoConfig?.extra?.watchdogBuild === true ? requireOptionalNativeModule("PaseoNativeTrace") : null; -export const diagnostics = native +export const watchdog = native ? createRecorder( (name, fields) => native.record(name, fields), () => performance.now(), @@ -21,15 +21,15 @@ export const diagnostics = native : null; let started = false; -export function startDiagnostics(): void { - if (!native || !diagnostics || started) return; +export function startWatchdog(): void { + if (!native || !watchdog || started) return; started = true; - native.startRecorder({ + 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(), 250); - setInterval(() => diagnostics.flushRenders(), 1000); + setInterval(() => native.heartbeat(), heartbeatMs); + setInterval(() => watchdog.flushRenders(), 1000); } diff --git a/packages/app/src/diagnostics/internal/recorder.test.ts b/packages/app/src/watchdog/internal/recorder.test.ts similarity index 100% rename from packages/app/src/diagnostics/internal/recorder.test.ts rename to packages/app/src/watchdog/internal/recorder.test.ts diff --git a/packages/app/src/diagnostics/internal/recorder.ts b/packages/app/src/watchdog/internal/recorder.ts similarity index 100% rename from packages/app/src/diagnostics/internal/recorder.ts rename to packages/app/src/watchdog/internal/recorder.ts diff --git a/packages/client/src/daemon-client.test.ts b/packages/client/src/daemon-client.test.ts index 1f49a74eea..7f183ccfa4 100644 --- a/packages/client/src/daemon-client.test.ts +++ b/packages/client/src/daemon-client.test.ts @@ -254,13 +254,20 @@ test("traces WebSocket frames, message types, and JSON parse duration", async () }), ]), ); - // Every started span must close, including nested send/dispatch work. - let depth = 0; + const stack: string[] = []; + const parentage: [string, string | undefined][] = []; for (const record of recorder.records) { - depth += record.phase === "begin" ? 1 : -1; - expect(depth).toBeGreaterThanOrEqual(0); + if (record.phase === "begin") { + parentage.push([record.name, stack.at(-1)]); + stack.push(record.name); + } else { + expect(stack.length).toBeGreaterThan(0); + stack.pop(); + } } - expect(depth).toBe(0); + 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"); }); diff --git a/packages/client/src/daemon-client.ts b/packages/client/src/daemon-client.ts index 4f20ae559d..4b2ea38859 100644 --- a/packages/client/src/daemon-client.ts +++ b/packages/client/src/daemon-client.ts @@ -1794,12 +1794,21 @@ 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 { - const isOpen = this.beginTraceSection("paseo.ws.message.outbound", { - envelopeType, - messageType, - ...describeRequestIdentity(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 { @@ -6512,15 +6521,7 @@ export class DaemonClient { return; } - this.traceInstant("paseo.ws.message.inbound", { - envelopeType: "session", - messageType: parsed.data.message.type, - ...describeRequestIdentity(parsed.data.message), - }); - const dispatchTrace = this.beginTraceSection("paseo.ws.dispatch", { - messageType: parsed.data.message.type, - ...describeRequestIdentity(parsed.data.message), - }); + const dispatchTrace = this.beginSessionDispatchTrace(parsed.data.message); try { this.handleSessionMessage(parsed.data.message); } finally {