From 6fce03c816ea47e7e6190b051cc2823192dabf31 Mon Sep 17 00:00:00 2001 From: Eduardo Speroni Date: Wed, 11 Nov 2026 19:16:17 -0300 Subject: [PATCH 1/4] ci: keep crash diagnostics when the test app dies or hangs When the test app died, the harness printed only logcat filtered to the app's pid, which drops crash_dump's backtrace, ActivityManager's death and ANR lines and low-memory kills, and nothing was uploaded. On death, an ErrorReportActivity or a timeout it now writes the unfiltered logcat, the crash buffer, the app's process exit records, thread stacks if the app is still alive, and this run's tombstones to test-app/dist/crash-diagnostics/, prints a summary, and CI uploads the folder as an artifact on failure. --- .github/workflows/pull_request.yml | 7 + .../tools/try_to_find_test_result_file.js | 131 +++++++++++++++--- 2 files changed, 118 insertions(+), 20 deletions(-) diff --git a/.github/workflows/pull_request.yml b/.github/workflows/pull_request.yml index 8bcd1fee7..59c6da0e1 100644 --- a/.github/workflows/pull_request.yml +++ b/.github/workflows/pull_request.yml @@ -182,6 +182,13 @@ jobs: with: name: android-unit-test-results path: test-app/dist/android_unit_test_results.xml + - name: Upload crash diagnostics + if: ${{ failure() }} + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 + with: + name: android-crash-diagnostics + path: test-app/dist/crash-diagnostics/ + if-no-files-found: ignore - name: Test report summary if: ${{ !cancelled() }} # annotate_only keeps this usable from fork PRs: it reports via workflow diff --git a/test-app/tools/try_to_find_test_result_file.js b/test-app/tools/try_to_find_test_result_file.js index 447628304..add55783d 100644 --- a/test-app/tools/try_to_find_test_result_file.js +++ b/test-app/tools/try_to_find_test_result_file.js @@ -1,4 +1,6 @@ const { exec } = require("child_process"); +const fs = require("fs"); +const path = require("path"); const appId = "com.tns.testapplication"; const runOnDeviceOrEmulator = process.argv.slice(2).join(" ") || "-e"; @@ -15,6 +17,8 @@ const adbCallTimeoutMs = 30 * 1000; const adbExecOptions = { timeout: adbCallTimeoutMs, maxBuffer: 64 * 1024 * 1024 }; const scriptStartTime = new Date(); const logcatCutoffTime = new Date(scriptStartTime.getTime() - 60 * 1000); // 1 minute before start +// Uploaded by CI as an artifact when the run fails. +const diagnosticsDir = path.join(__dirname, "..", "dist", "crash-diagnostics"); let timedOut = false; // TODO: check why gradle doesn't show error logs @@ -75,29 +79,116 @@ function filterLogcatFromCutoff(logcatOutput) { return lines.slice(startIndex).join("\n"); } -async function readAndFilterLogcat() { - // if we have a PID, filter by it - if (appPID !== -1) { - return new Promise((resolve) => { - exec(`${adbPrefix} logcat -d --pid=${appPID}`, adbExecOptions, (error, stdout) => { - resolve(filterLogcatFromCutoff(stdout || "")); - }); - }); - } - // otherwise, do a general logcat read +function adbOutput(args) { return new Promise((resolve) => { - console.log('Reading full logcat since app PID is unknown'); - exec(`${adbPrefix} logcat -d`, adbExecOptions, (error, stdout) => { - resolve(filterLogcatFromCutoff(stdout || "")); + exec(`${adbPrefix} ${args}`, adbExecOptions, (error, stdout, stderr) => { + resolve({ error, stdout: stdout || "", stderr: stderr || "" }); }); }); } -async function exitWithLogcatDump() { - console.log("Dumping logcat for debugging:"); +function writeDiagnostic(name, contents) { + try { + fs.mkdirSync(diagnosticsDir, { recursive: true }); + fs.writeFileSync(path.join(diagnosticsDir, name), contents); + } catch (err) { + console.log(`Could not write ${name}: ${err.message}`); + } +} + +function lastLines(text, count) { + const lines = text.split("\n"); + return lines.slice(Math.max(0, lines.length - count)).join("\n"); +} + +// The newest ApplicationExitInfo record: its reason (native crash, crash, ANR, +// low memory, signaled...) is the one thing that tells a crash from a kill. +function latestExitRecord(exitInfo) { + const start = exitInfo.indexOf("ApplicationExitInfo #0:"); + if (start === -1) return ""; + const next = exitInfo.indexOf("ApplicationExitInfo #1:", start); + return exitInfo.slice(start, next === -1 ? undefined : next).trim(); +} + +async function isAppAlive() { + const { stdout } = await adbOutput( + `shell "pidof ${appId} 2>/dev/null || ps | grep ${appId}"` + ); + return Number.isFinite(parseAppPid(stdout)); +} + +async function collectDiagnostics() { + const sections = []; + + // Unfiltered by pid on purpose: crash_dump's backtrace (tag DEBUG), the + // ActivityManager death/ANR lines and lmkd kills are logged by other pids. + const fullLogcat = filterLogcatFromCutoff( + (await adbOutput("logcat -d -v threadtime -b main,system,crash")).stdout + ); + writeDiagnostic("logcat.txt", fullLogcat); + + if (appPID !== -1) { + const appLogcat = filterLogcatFromCutoff( + (await adbOutput(`logcat -d -v threadtime --pid=${appPID}`)).stdout + ); + writeDiagnostic("logcat-app.txt", appLogcat); + sections.push(["Last app logcat lines", lastLines(appLogcat, 150)]); + } + + const crashBuffer = filterLogcatFromCutoff( + (await adbOutput("logcat -d -v threadtime -b crash")).stdout + ); + writeDiagnostic("logcat-crash.txt", crashBuffer); + sections.push(["Crash buffer", lastLines(crashBuffer, 200)]); + + const exitInfo = (await adbOutput(`shell dumpsys activity exit-info ${appId}`)).stdout; + writeDiagnostic("exit-info.txt", exitInfo); + sections.push(["Latest process exit", latestExitRecord(exitInfo)]); + + // Tombstones and other processes' stacks need root, which emulator images + // without Google Play grant. Restarting adbd breaks every other adb client + // of the device, so only CI, which owns its emulator, asks for it. + if (process.env.CI) { + await adbOutput("root"); + await adbOutput("wait-for-device"); + } + + if (appPID !== -1 && (await isAppAlive())) { + const stacks = await adbOutput(`shell debuggerd -b ${appPID}`); + writeDiagnostic("stacks.txt", stacks.stdout + stacks.stderr); + sections.push(["App is still alive; thread stacks written to stacks.txt", ""]); + } + + const cutoffSeconds = Math.floor(logcatCutoffTime.getTime() / 1000); + const { stdout: tombstoneList } = await adbOutput( + `shell "stat -c '%Y %n' /data/tombstones/tombstone_* 2>/dev/null"` + ); + const tombstones = tombstoneList + .split("\n") + .map((line) => line.trim().split(" ")) + .filter(([mtime, file]) => file && !file.endsWith(".pb") && parseInt(mtime, 10) >= cutoffSeconds) + .map(([, file]) => file); + for (const file of tombstones) { + const { stdout } = await adbOutput(`exec-out cat ${file}`); + writeDiagnostic(path.basename(file) + ".txt", stdout); + } + sections.push([ + "Tombstones from this run", + tombstones.length ? tombstones.join("\n") : "(none, or not readable without root)", + ]); + + for (const [title, body] of sections) { + console.log(`----- ${title} -----`); + if (body) console.log(body); + } + console.log(`Full diagnostics written to ${diagnosticsDir}`); +} + +async function exitWithDiagnostics() { try { - const logcat = await readAndFilterLogcat(); - console.log(logcat); + await collectDiagnostics(); + } catch (err) { + console.log(`Collecting diagnostics failed: ${err && err.message}`); } finally { process.exit(1); } @@ -132,7 +223,7 @@ async function ensureProcessAlive() { return; } console.error(`${appId} process died or never started!`); - await exitWithLogcatDump(); + await exitWithDiagnostics(); } consecutiveLivenessMisses = 0; @@ -149,7 +240,7 @@ async function checkForErrorActivity() { if (!error) { console.error("App has crashed - ErrorReportActivity is displaying!"); - await exitWithLogcatDump(); + await exitWithDiagnostics(); } } @@ -181,7 +272,7 @@ async function pollForResults() { if (timedOut) { console.error("Tests results file not found within timeout window."); - await exitWithLogcatDump(); + await exitWithDiagnostics(); } setTimeout(pollForResults, pollIntervalMs); From 2ea2655268372e557a73f426b653e6c9976dddc5 Mon Sep 17 00:00:00 2001 From: Eduardo Speroni Date: Wed, 11 Nov 2026 19:22:44 -0300 Subject: [PATCH 2/4] ci: take the logcat cutoff from the device clock and dump stacks of the live pid Logcat stamps are device-local time, so a cutoff from the host clock drops every line when the device's time zone is behind the host's. Logcat's UTC format modifier needs API 24, and the harness still supports API 21-23. --- .../tools/try_to_find_test_result_file.js | 26 ++++++++++++++----- 1 file changed, 20 insertions(+), 6 deletions(-) diff --git a/test-app/tools/try_to_find_test_result_file.js b/test-app/tools/try_to_find_test_result_file.js index add55783d..a1ea5c649 100644 --- a/test-app/tools/try_to_find_test_result_file.js +++ b/test-app/tools/try_to_find_test_result_file.js @@ -16,7 +16,10 @@ const adbCallTimeoutMs = 30 * 1000; // dump can both exceed that. const adbExecOptions = { timeout: adbCallTimeoutMs, maxBuffer: 64 * 1024 * 1024 }; const scriptStartTime = new Date(); -const logcatCutoffTime = new Date(scriptStartTime.getTime() - 60 * 1000); // 1 minute before start +const cutoffMarginMs = 60 * 1000; +// Logcat stamps are device-local wall-clock time, so main() replaces this with +// the device's clock when it can read it; the host clock is only a fallback. +let logcatCutoffTime = new Date(scriptStartTime.getTime() - cutoffMarginMs); // Uploaded by CI as an artifact when the run fails. const diagnosticsDir = path.join(__dirname, "..", "dist", "crash-diagnostics"); @@ -110,11 +113,11 @@ function latestExitRecord(exitInfo) { return exitInfo.slice(start, next === -1 ? undefined : next).trim(); } -async function isAppAlive() { +async function currentAppPid() { const { stdout } = await adbOutput( `shell "pidof ${appId} 2>/dev/null || ps | grep ${appId}"` ); - return Number.isFinite(parseAppPid(stdout)); + return parseAppPid(stdout); } async function collectDiagnostics() { @@ -153,13 +156,15 @@ async function collectDiagnostics() { await adbOutput("wait-for-device"); } - if (appPID !== -1 && (await isAppAlive())) { - const stacks = await adbOutput(`shell debuggerd -b ${appPID}`); + const livePid = await currentAppPid(); + if (Number.isFinite(livePid)) { + const stacks = await adbOutput(`shell debuggerd -b ${livePid}`); writeDiagnostic("stacks.txt", stacks.stdout + stacks.stderr); sections.push(["App is still alive; thread stacks written to stacks.txt", ""]); } - const cutoffSeconds = Math.floor(logcatCutoffTime.getTime() / 1000); + // stat's mtime is epoch seconds, independent of the device's time zone. + const cutoffSeconds = Math.floor((scriptStartTime.getTime() - cutoffMarginMs) / 1000); const { stdout: tombstoneList } = await adbOutput( `shell "stat -c '%Y %n' /data/tombstones/tombstone_* 2>/dev/null"` ); @@ -282,7 +287,16 @@ function delay(ms) { return new Promise((resolve) => setTimeout(resolve, ms)); } +async function useDeviceClockForLogcatCutoff() { + const { stdout } = await adbOutput(`shell "date '+%m-%d %H:%M:%S.000'"`); + const deviceNow = parseLogcatTimestamp(stdout); + if (deviceNow) { + logcatCutoffTime = new Date(deviceNow.getTime() - cutoffMarginMs); + } +} + async function main() { + await useDeviceClockForLogcatCutoff(); setTimeout(() => { timedOut = true; }, processTimeoutMs); From a9609cf8819513ecd316ea84177cceb17d236d51 Mon Sep 17 00:00:00 2001 From: Eduardo Speroni Date: Wed, 11 Nov 2026 19:24:21 -0300 Subject: [PATCH 3/4] ci: leave logcat unfiltered when the device clock can't be read --- test-app/tools/try_to_find_test_result_file.js | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/test-app/tools/try_to_find_test_result_file.js b/test-app/tools/try_to_find_test_result_file.js index a1ea5c649..4022df3a7 100644 --- a/test-app/tools/try_to_find_test_result_file.js +++ b/test-app/tools/try_to_find_test_result_file.js @@ -17,9 +17,10 @@ const adbCallTimeoutMs = 30 * 1000; const adbExecOptions = { timeout: adbCallTimeoutMs, maxBuffer: 64 * 1024 * 1024 }; const scriptStartTime = new Date(); const cutoffMarginMs = 60 * 1000; -// Logcat stamps are device-local wall-clock time, so main() replaces this with -// the device's clock when it can read it; the host clock is only a fallback. -let logcatCutoffTime = new Date(scriptStartTime.getTime() - cutoffMarginMs); +// Logcat stamps are device-local wall-clock time, so the cutoff comes from the +// device's clock. Until main() reads it (or if it can't), logcat stays +// unfiltered: a host-clock cutoff could drop the whole run when zones differ. +let logcatCutoffTime = null; // Uploaded by CI as an artifact when the run fails. const diagnosticsDir = path.join(__dirname, "..", "dist", "crash-diagnostics"); @@ -69,6 +70,7 @@ function parseLogcatTimestamp(line) { } function filterLogcatFromCutoff(logcatOutput) { + if (!logcatCutoffTime) return logcatOutput; const lines = logcatOutput.split("\n"); // Find the first line that is at or after the cutoff time From 5b50e2e817e2a60b3fa0d94bb2bdbaed780c7a6f Mon Sep 17 00:00:00 2001 From: Eduardo Speroni Date: Wed, 11 Nov 2026 19:29:52 -0300 Subject: [PATCH 4/4] ci: make crash diagnostics hold up on old images and local reruns Use repeated -b and filter the app's lines out of the full logcat (comma-listed buffers and --pid need API 24), skip an exit record from before this run, clear the folder before writing, keep adb's error text when a capture is empty, and only claim thread stacks when debuggerd produced them. --- .../tools/try_to_find_test_result_file.js | 50 +++++++++++++++---- 1 file changed, 41 insertions(+), 9 deletions(-) diff --git a/test-app/tools/try_to_find_test_result_file.js b/test-app/tools/try_to_find_test_result_file.js index 4022df3a7..2b98fa4f2 100644 --- a/test-app/tools/try_to_find_test_result_file.js +++ b/test-app/tools/try_to_find_test_result_file.js @@ -101,6 +101,12 @@ function writeDiagnostic(name, contents) { } } +// An empty capture keeps adb's own error, so an empty artifact says why. +function adbText({ error, stdout, stderr }) { + if (stdout.trim()) return stdout; + return stderr || (error ? String(error.message) : ""); +} + function lastLines(text, count) { const lines = text.split("\n"); return lines.slice(Math.max(0, lines.length - count)).join("\n"); @@ -108,11 +114,31 @@ function lastLines(text, count) { // The newest ApplicationExitInfo record: its reason (native crash, crash, ANR, // low memory, signaled...) is the one thing that tells a crash from a kill. +// Records survive reinstalls, so one from before this run is not reported. function latestExitRecord(exitInfo) { const start = exitInfo.indexOf("ApplicationExitInfo #0:"); if (start === -1) return ""; const next = exitInfo.indexOf("ApplicationExitInfo #1:", start); - return exitInfo.slice(start, next === -1 ? undefined : next).trim(); + const record = exitInfo.slice(start, next === -1 ? undefined : next).trim(); + const stamp = /timestamp=(\d{4})-(\d{2})-(\d{2}) (\d{2}):(\d{2}):(\d{2})\.(\d{3})/.exec(record); + if (stamp && logcatCutoffTime) { + const [, y, mo, d, h, mi, sec, ms] = stamp.map((v) => parseInt(v, 10)); + if (new Date(y, mo - 1, d, h, mi, sec, ms) < logcatCutoffTime) { + return "(no exit recorded during this run)"; + } + } + return record; +} + +// threadtime lines: "MM-DD HH:mm:ss.mmm PID TID L TAG: message" +function linesOfPid(logcat, pid) { + return logcat + .split("\n") + .filter((line) => { + const match = /^\d{2}-\d{2}\s+\S+\s+(\d+)\s/.exec(line); + return match && parseInt(match[1], 10) === pid; + }) + .join("\n"); } async function currentAppPid() { @@ -124,29 +150,29 @@ async function currentAppPid() { async function collectDiagnostics() { const sections = []; + fs.rmSync(diagnosticsDir, { recursive: true, force: true }); // Unfiltered by pid on purpose: crash_dump's backtrace (tag DEBUG), the // ActivityManager death/ANR lines and lmkd kills are logged by other pids. + // Repeated -b, not a comma list, and no --pid: both need API 24. const fullLogcat = filterLogcatFromCutoff( - (await adbOutput("logcat -d -v threadtime -b main,system,crash")).stdout + adbText(await adbOutput("logcat -d -v threadtime -b main -b system -b crash")) ); writeDiagnostic("logcat.txt", fullLogcat); if (appPID !== -1) { - const appLogcat = filterLogcatFromCutoff( - (await adbOutput(`logcat -d -v threadtime --pid=${appPID}`)).stdout - ); + const appLogcat = linesOfPid(fullLogcat, appPID); writeDiagnostic("logcat-app.txt", appLogcat); sections.push(["Last app logcat lines", lastLines(appLogcat, 150)]); } const crashBuffer = filterLogcatFromCutoff( - (await adbOutput("logcat -d -v threadtime -b crash")).stdout + adbText(await adbOutput("logcat -d -v threadtime -b crash")) ); writeDiagnostic("logcat-crash.txt", crashBuffer); sections.push(["Crash buffer", lastLines(crashBuffer, 200)]); - const exitInfo = (await adbOutput(`shell dumpsys activity exit-info ${appId}`)).stdout; + const exitInfo = adbText(await adbOutput(`shell dumpsys activity exit-info ${appId}`)); writeDiagnostic("exit-info.txt", exitInfo); sections.push(["Latest process exit", latestExitRecord(exitInfo)]); @@ -161,8 +187,14 @@ async function collectDiagnostics() { const livePid = await currentAppPid(); if (Number.isFinite(livePid)) { const stacks = await adbOutput(`shell debuggerd -b ${livePid}`); - writeDiagnostic("stacks.txt", stacks.stdout + stacks.stderr); - sections.push(["App is still alive; thread stacks written to stacks.txt", ""]); + writeDiagnostic("stacks.txt", adbText(stacks)); + const captured = !stacks.error && stacks.stdout.trim(); + sections.push([ + captured + ? "App is still alive; thread stacks written to stacks.txt" + : "App is still alive; debuggerd failed, see stacks.txt", + "", + ]); } // stat's mtime is epoch seconds, independent of the device's time zone.