fix: log why a device sync run failed #34

The sync adapter logged only the SyncResult counters of a run, so a
failed sync showed up in logcat as `ioErrors=1` and nothing else. The
reason was in the run's report, and JS warnings from a headless run
don't reach logcat; finding out that a run failed on "Invalid column
raw_contact_is_read_only" took reading the app's storage. The log line
now carries the report's outcome, its message (up to 300 characters)
and the number of failed items.

Checked: 55 JVM tests (`gradlew :app:testDebugUnitTest`, one new) and
the debug build.
This commit is contained in:
Linus Rath
2026-09-27 05:27:13 +02:00
parent 77fd494633
commit 417ed5a326
3 changed files with 38 additions and 1 deletions
@@ -91,7 +91,7 @@ class DeviceSyncAdapter(context: Context) :
val outcome = SyncReports.outcome(run.report, run.endReason)
SyncReports.apply(outcome, syncResult)
Log.i(TAG, "Sync ${run.runId} of $authority ended (${run.endReason}) after " +
"${SystemClock.elapsedRealtime() - startedAt} ms: $outcome")
"${SystemClock.elapsedRealtime() - startedAt} ms: ${SyncReports.summary(run.report)}; $outcome")
} catch (e: InterruptedException) {
// onSyncCanceled interrupts this thread. JS sees the run as
// cancelled at its next checkpoint (isRunCancelled).
@@ -74,6 +74,28 @@ object SyncReports {
}
}
/**
* One line for logcat: the report's outcome, its message and how many
* items failed. The reason a run failed is otherwise only in the report,
* and JS warnings from a headless run don't reach logcat.
*/
fun summary(reportJson: String?): String {
if (reportJson == null) return "no report"
val report = try {
JSONObject(reportJson)
} catch (e: JSONException) {
return "unreadable report"
}
val parts = mutableListOf("outcome=" + report.optString("outcome", "?"))
val items = report.optJSONArray("itemErrors")?.length() ?: 0
if (items > 0) parts += "itemErrors=$items"
val message = report.optString("message", "")
if (message.isNotEmpty()) parts += "message=" + message.take(MAX_LOGGED_MESSAGE)
return parts.joinToString(" ")
}
private const val MAX_LOGGED_MESSAGE = 300
fun apply(outcome: SyncOutcome, result: SyncResult) {
result.stats.numIoExceptions += outcome.ioErrors
result.stats.numAuthExceptions += outcome.authErrors
@@ -81,4 +81,19 @@ class SyncReportsTest {
fun `an outcome this build does not know is retried`() {
assertEquals(1L, SyncReports.outcome(report("somethingNew"), "reported").ioErrors)
}
@Test
fun `the log summary names the outcome, failed items and the message`() {
assertEquals("outcome=ok", SyncReports.summary(report("ok")))
assertEquals(
"outcome=internal message=Invalid column x",
SyncReports.summary(report("internal", ",\"message\":\"Invalid column x\"")),
)
val withItems = report("ok").replace("\"itemErrors\":[]", "\"itemErrors\":[{\"ref\":\"a\"},{\"ref\":\"b\"}]")
assertEquals("outcome=ok itemErrors=2", SyncReports.summary(withItems))
assertEquals("no report", SyncReports.summary(null))
assertEquals("unreadable report", SyncReports.summary("{"))
val long = SyncReports.summary(report("io", ",\"message\":\"" + "m".repeat(400) + "\""))
assertEquals("outcome=io message=".length + 300, long.length)
}
}