An app's own log: a devlog contract, and a Runtime tab for an APK component

Android forbids one app reading another's logcat, so an APK this server
delivers has had no way to say what it did to somebody holding the phone
and nothing else. It can now expose its own bounded log through a
ContentProvider at `<applicationId>.devlog`, guarded by a permission
declared here; README.md's "An app's own log" is the whole contract, and
any project this server delivers can implement it.

The phone reads that provider while the Runtime tab is open and forwards
what is new into the component's runtime log on this machine, so the tab
renders from the same store a service's does and the history outlives the
phone. `LogKind::Runtime` stays one kind with two sources rather than
growing a third, and this server parses nothing -- what arrives is one
line of text each, appended, exactly as a service's stdout is.

The log button is now unconditional, like the gear beside it: with the
tab able to say which of several reasons there is nothing to read, its
absence was the one thing that could not say anything at all.

Supersedes ai-app posting its ring to ai-server over the tunnel, which
put a phone's lines under the wrong component and only ever worked for
that one project.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
This commit is contained in:
irisandClaude Fable 5.1 committed 2026-09-07 16:43:42 -04:00
1 parent 3727c7c67b
commit 013d7116d7
11 files changed
+772 -44

No files matched your search

+38 -16
View File
@@ -574,22 +574,44 @@ mutable at runtime from the phone.
process marked its own errors -- and sequences with no meaning on a process marked its own errors -- and sequences with no meaning on a
phone are consumed rather than printed, so a cursor movement cannot phone are consumed rather than printed, so a cursor movement cannot
arrive looking like a corrupted log. arrive looking like a corrupted log.
- **A runtime log can carry a *phone app's* own lines, and nothing here - **An APK's runtime log comes from the phone, through a contract any
had to change for it.** ai-app (`~/repos/ai-app-2`, the `rustify` managed app can implement.** A `Server` runs here and its script says
branch) has a phone this project delivers APKs to whose owner has no where it writes; an `Apk` runs on the phone, where Android forbids one
`adb`; Android forbids one app reading another's `logcat`, so the app app reading another's `logcat` -- so the app keeps a bounded copy of its
keeps a bounded in-memory copy of its own log and posts it to own log and exposes it through a `ContentProvider` at
`ai-server` over the tunnel it is already enrolled against. `<applicationId>.devlog`, guarded by `dev.updater.permission.READ_DEVLOG`
`ai-server` re-emits each line into its own `tracing` output, which is (declared here, `protectionLevel="normal"`). README.md has the whole
this server's `Managed` service redirecting stdout to contract; what matters here is the shape of it.
`$XDG_DATA_HOME/dev-updater/services/<key>-<component>/<same>.log` -- **One kind, two sources**: `LogKind::Runtime` stays one tab and one
so the lines arrive in the *server* component's Runtime tab, tagged route, and `AppEntry::component_logs` picks the source from the
`ai_server::client_log` and carrying the app's own clock. Worth knowing component's variant. That is deliberately not a third kind -- the reader
before adding a device-log store here: this route was chosen over one is asking the same question either way, and a `hasDevLog` beside
(a new authenticated write endpoint on the TLS surface, a per-app log `hasRuntimeLogs` would have been the same axis said twice.
store, `hasRuntimeLogs` for an APK component, and a second enrollment The phone forwards rather than rendering the provider directly, into
for that app) precisely because the existing runtime log already `POST /apps/{key}/components/{name}/runtime-log`, so the history
reaches the reader. Their reasoning is in ai-app's outlives the phone and both kinds render from one store. **This server
parses nothing**: what arrives is one line of text each, formatted on
the phone, appended by `logs::append_devlog` -- the same posture it
takes towards a service's stdout, and what keeps every managed app's log
format out of here. Refused for a `Server`, because a file with two
writers is two versions of what a service printed. The store is
`$XDG_DATA_HOME/dev-updater/devlogs/<key>-<component>.log` with one
rotation at 4 MiB (`.1`, the same two generations a build log has, and
the only bound available -- a phone forwards a stream with no run
boundary to rotate on).
**`normal` rather than `signature` is a real trade and is written down
in three places** (the manifest, README.md, and ai-app's
`docs/DECISIONS.md` 2026-09-07): the two apps are signed with different
locally generated keys, so a signature permission would be held by
nothing, and what `normal` costs is that any app requesting it by name
can read another's dev log on that phone.
**What this replaced**: ai-app's app used to post its ring to
`ai-server` over the tunnel, which re-emitted it into its own `tracing`
output and so into the *server* component's runtime log. Nothing here
had to change for that, which was its whole appeal -- but it put a
phone's lines under a different component, needed the app to be enrolled
against a server with a baked-in token, and only ever worked for that
one project. It is deleted; their reasoning is in ai-app's
`docs/DECISIONS.md`, 2026-09-07. `docs/DECISIONS.md`, 2026-09-07.
- **A project's row has three buttons -- Pull, Update, Remove -- and the - **A project's row has three buttons -- Pull, Update, Remove -- and the
first two are the same act at two lengths.** Pull takes the commits and first two are the same act at two lengths.** Pull takes the commits and
+67
View File
@@ -534,6 +534,73 @@ an override anyway. It stays this server's business rather than the build
script's because it is a property of *this* hop to a phone: a project script's because it is a property of *this* hop to a phone: a project
built without dev-updater has no reason to strip. built without dev-updater has no reason to strip.
## An app's own log
A `Server` component's runtime log is what its service script reports. An
`Apk` runs on the phone instead, where Android forbids one app reading
another's `logcat` — so an app delivered here has no way to say what it
did to somebody holding the phone and nothing else. The way out is for the
app to keep a bounded copy of its own recent log and hand it over on the
device: the two are already on the same phone, so this needs no tunnel, no
token and no second enrolment.
That is a **contract any app served here can implement**, not a feature
for one project. Implement it and that component gets a **Runtime** tab
beside its build log, showing the same view a service's runtime log gets.
Expose a `ContentProvider`, exported and read-only:
| | |
|---|---|
| authority | `<applicationId>.devlog` |
| read permission | `dev.updater.permission.READ_DEVLOG` (`android:readPermission`) |
| `content://<authority>/lines?since=<seq>` | every held line with `seq >= since`, ascending: `seq INTEGER, t_ms INTEGER, level TEXT, target TEXT, message TEXT` |
| `content://<authority>/status` | one row: `held INTEGER, dropped INTEGER, newest_seq INTEGER` |
`insert`, `update` and `delete` throw — there is nothing for anyone else to
change. `t_ms` is unix milliseconds from the app's own clock, because a
line is timestamped when it happened rather than when it was read.
`dropped` is what the app's own bound discarded, counted rather than
inferred, so "the log starts here" and "the log was cut off here" can be
told apart. `newest_seq` is `-1` for a log nothing has been written to,
and it is also what makes a restart visible: an in-memory log starts again
at zero, and a reader whose stored cursor is now past the newest sequence
starts again from the beginning rather than silently skipping everything
since.
The authority is derived from the `applicationId` rather than written
down, so a project's debug and release builds — installed side by side
under different ids — each get their own and cannot read each other's.
The permission is declared by Dev Updater at `protectionLevel="normal"`.
`signature` is not available: the updater and the apps it delivers are
built on one machine but signed with *different* locally generated keys,
so a signature permission would be held by nothing at all. The cost of
`normal` is real and worth saying plainly — on a phone with Dev Updater
installed, any app that requests `dev.updater.permission.READ_DEVLOG` by
name can read another app's dev log. These are development builds on a
development phone, and the alternative was no log at all.
Dev Updater's side of it: while the Runtime tab is open it asks the
provider once a second for what it has not seen, and forwards those lines
to this server, into that component's runtime log. It is a poll rather
than a `ContentObserver` because the contract does not oblige a provider
to call `notifyChange` — implementing it should be cheap. Forwarding
rather than rendering straight from the provider is what makes the history
outlive the phone and what lets one tab render both kinds. The lines
arrive here already formatted, one string each; this server appends them
and parses nothing, exactly as it does with a service's stdout, so an app
can change its own log format without anything here being taught about it.
A component with no provider still gets the tab, and the tab says which of
the several reasons there is nothing to read — the app is not installed,
it exposes no devlog, its provider refused us, or it simply has not logged
anything yet.
The reference implementation is iris's
`iris/android-app/app/src/main/java/dev/iris/android/demo/DevLogProvider.java`
in `~/repos/ai-app-2` (the `rustify` branch), over a ring in Rust.
## Testing ## Testing
The Kotlin half has no unit tests, but it does have two checks that The Kotlin half has no unit tests, but it does have two checks that
@@ -26,6 +26,28 @@
MainActivity.kt's runtime request. --> MainActivity.kt's runtime request. -->
<uses-permission android:name="android.permission.ACCESS_LOCAL_NETWORK" /> <uses-permission android:name="android.permission.ACCESS_LOCAL_NETWORK" />
<!-- An app this updater delivers can expose its own recent log through
a ContentProvider, which is the only way its lines can reach a
phone with no adb: Android forbids one app reading another's
logcat. This app defines the permission that guards it and holds
it itself; the contract is in README.md under "An app's own log".
protectionLevel="normal" rather than "signature", deliberately, and with a cost. These apps are built and signed on one machine but
with *different* locally generated keys: the updater's own, and
each project's. so a signature permission would be held by
nothing at all and the feature could not exist. What normal means
is that any app on the phone that requests this permission by name
can read another app's dev log. That is a development phone
carrying development builds, and the alternative was no log; the
reasoning is in AGENTS.md and in ai-app's docs/DECISIONS.md
(2026-09-07). -->
<permission
android:name="dev.updater.permission.READ_DEVLOG"
android:label="@string/devlog_permission_label"
android:description="@string/devlog_permission_description"
android:protectionLevel="normal" />
<uses-permission android:name="dev.updater.permission.READ_DEVLOG" />
<!-- Package visibility (API 30+): without this, PackageManager.getPackageInfo() <!-- Package visibility (API 30+): without this, PackageManager.getPackageInfo()
for another app throws NameNotFoundException even when it's for another app throws NameNotFoundException even when it's
installed, see InstalledBuilds.kt, which queries lastUpdateTime to installed, see InstalledBuilds.kt, which queries lastUpdateTime to
@@ -365,6 +365,27 @@ fun componentLog(
) )
} }
/**
* Forwards lines this phone read out of an installed app's devlog provider into that APK
* component's runtime log on the build machine.
*
* Already rendered, one string per line (see [DevLogLine.render]). The server appends the bytes and
* parses nothing, which is what it also does with a service's stdout -- so an app is free to change
* its own log format without anything on the build machine being taught about it.
*
* An APK runs on this phone, so this phone is the only thing that can read what it wrote. Sending
* it is what makes the tab render from the same store a service's runtime log does, and what makes
* the history outlive the phone.
*/
fun postRuntimeLog(key: String, component: String, lines: List<String>) {
val body = JSONObject().put("lines", JSONArray(lines)).toString()
requestFromServer(
"/apps/$key/components/$component/runtime-log",
method = "POST",
jsonBody = body,
) {}
}
// --------------------------------------------------------------------------- // ---------------------------------------------------------------------------
// The rescue contract. // The rescue contract.
// //
@@ -30,6 +30,7 @@ import androidx.compose.material3.TextButton
import androidx.compose.runtime.Composable import androidx.compose.runtime.Composable
import androidx.compose.runtime.LaunchedEffect import androidx.compose.runtime.LaunchedEffect
import androidx.compose.runtime.getValue import androidx.compose.runtime.getValue
import androidx.compose.runtime.mutableIntStateOf
import androidx.compose.runtime.mutableStateOf import androidx.compose.runtime.mutableStateOf
import androidx.compose.runtime.remember import androidx.compose.runtime.remember
import androidx.compose.runtime.setValue import androidx.compose.runtime.setValue
@@ -45,6 +46,8 @@ import androidx.compose.ui.text.input.KeyboardType
import androidx.compose.ui.text.style.TextOverflow import androidx.compose.ui.text.style.TextOverflow
import androidx.compose.ui.unit.dp import androidx.compose.ui.unit.dp
import kotlinx.coroutines.Dispatchers import kotlinx.coroutines.Dispatchers
import kotlinx.coroutines.delay
import kotlinx.coroutines.isActive
import kotlinx.coroutines.withContext import kotlinx.coroutines.withContext
/** What the line field means when it is empty or zero: as much as the server will read. */ /** What the line field means when it is empty or zero: as much as the server will read. */
@@ -66,6 +69,21 @@ private val FOOT_BUTTON_PADDING = PaddingValues(horizontal = 8.dp)
/** Wide enough for four digits, which is more lines than anybody asks for by hand. */ /** Wide enough for four digits, which is more lines than anybody asks for by hand. */
private val LINES_FIELD_WIDTH = 76.dp private val LINES_FIELD_WIDTH = 76.dp
/**
* How often an installed app's devlog provider is asked for what it has said since last time.
*
* A second, and only while this tab is open the poll stops with the dialog. An app's log is
* something somebody is watching happen, so anything slower reads as a tab that is not working;
* anything faster is a binder round trip and a request to the build machine per frame, for a
* process that logs a handful of lines a minute.
*
* It is a poll rather than a `ContentObserver` because the contract does not require a provider to
* call `notifyChange` an app whose ring is filled from arbitrary threads would have to add that
* plumbing to be readable at all, and the point of the contract is that implementing it is cheap. A
* provider that does notify loses nothing by this.
*/
private const val DEVLOG_POLL_MS = 1000L
/** /**
* The log's own panel, a step *down* the surface ladder rather than up. * The log's own panel, a step *down* the surface ladder rather than up.
* *
@@ -110,19 +128,41 @@ fun ComponentLogDialog(
var requestedLines by remember { mutableStateOf(DEFAULT_LINES) } var requestedLines by remember { mutableStateOf(DEFAULT_LINES) }
val submitLines = { requestedLines = lines.toIntOrNull() ?: ALL_LINES } val submitLines = { requestedLines = lines.toIntOrNull() ?: ALL_LINES }
var generation by remember { mutableStateOf(0) } var generation by remember { mutableStateOf(0) }
// Only a server runs here, so only a server can have a runtime log to // Both kinds for every component. A server's runtime log is what its
// switch to. An APK gets no tab row rather than a row of one, which // service script reports; an APK's is what this phone reads out of
// would be a control that cannot do anything. // that app's own devlog provider and forwards. The tab is drawn even
val hasBothKinds = component.kind == "server" // where there is neither, because its absence would be the signal --
// "this app exposes no log" and "nobody has looked" are different
// things, and only one of them is worth acting on.
// What it is doing now is the usual question, so the runtime log is // What it is doing now is the usual question, so the runtime log is
// the default -- except for the component a build stopped at, where // the default -- except for the component a build stopped at, where
// the thing worth reading is why it stopped, and for an APK, which // the thing worth reading is why it stopped.
// has no runtime here and so no tab to escape to.
var kind by remember { var kind by remember {
mutableStateOf( mutableStateOf(if (component.buildFailed) LogKind.Build else LogKind.Runtime)
if (!hasBothKinds || component.buildFailed) LogKind.Build else LogKind.Runtime
)
} }
// What this phone can find out about the app this component installs.
// Null while it is being asked, which is its own state: a binder round
// trip is fast but not instant, and "we have not looked yet" must not
// draw as "there is nothing here".
var source by remember { mutableStateOf<DevLogSource?>(null) }
// Bumped by each poll that actually forwarded something, which is what
// re-reads the log below. Only when there was something, so an idle
// app does not cost a request a second to the build machine.
var forwarded by remember { mutableIntStateOf(0) }
// Whether the build machine has anything stored for this component
// yet. It starts as what the manifest said and turns true the moment
// this tab forwards a line, because the card's snapshot predates that.
var storedRuntime by remember { mutableStateOf(component.hasRuntimeLogs) }
// Kept apart from the read's own failure below: what is on screen came
// back fine and what the app is saying now is not getting through, so
// clearing one on the other's success would hide whichever failed
// second.
var forwardFailure by remember { mutableStateOf<String?>(null) }
// What the app's own ring last reported about itself. Shown because
// it is the only thing on screen that says the provider is answering
// *now* -- a stored log that has stopped growing looks the same
// whether the app is quiet or this phone has lost sight of it.
var ring by remember { mutableStateOf<DevLogStatus?>(null) }
var log by remember { mutableStateOf<ComponentLog?>(null) } var log by remember { mutableStateOf<ComponentLog?>(null) }
// Rendered once per read rather than per recomposition, and kept out // Rendered once per read rather than per recomposition, and kept out
// here so Copy can reach it: what goes on the clipboard is // here so Copy can reach it: what goes on the clipboard is
@@ -136,12 +176,53 @@ fun ComponentLogDialog(
val available = val available =
when (kind) { when (kind) {
LogKind.Build -> component.hasBuildLogs LogKind.Build -> component.hasBuildLogs
LogKind.Runtime -> component.hasRuntimeLogs LogKind.Runtime -> storedRuntime
} }
// Asked once per component, not per tab switch: the answer is about
// what is installed on this phone, which the dialog cannot change.
LaunchedEffect(component.name, component.apk?.packageName) {
source =
if (component.isServer) null
else withContext(Dispatchers.IO) { devLogSource(context, component.apk?.packageName) }
}
// The poll, and the only thing that writes this component's runtime
// log. It runs while the Runtime tab is open and stops when it closes
// or the dialog goes -- a cancelled LaunchedEffect is the whole of
// that, so there is nothing left running behind a dialog nobody can
// see.
val readable = source as? DevLogSource.Available
LaunchedEffect(entryKey, component.name, kind, readable) {
val authority = readable?.authority ?: return@LaunchedEffect
if (kind != LogKind.Runtime) return@LaunchedEffect
while (isActive) {
try {
val poll =
withContext(Dispatchers.IO) {
forwardDevLog(context, authority, entryKey, component.name)
}
ring = poll.status
if (poll.sent > 0) {
storedRuntime = true
forwarded += 1
}
forwardFailure = null
} catch (e: DownloadServerException) {
// Reported here rather than swallowed: with the send
// failing, what is on screen stops being what the app is
// saying, and nothing else would say so. The poll keeps
// going -- the cursor did not move, so the next one sends
// the same lines.
forwardFailure = e.message ?: "Couldn't send this app's log to the build machine"
}
delay(DEVLOG_POLL_MS)
}
}
// Re-read whenever any control moves. Keyed rather than driven by a // Re-read whenever any control moves. Keyed rather than driven by a
// callback so the two cannot disagree about what is on screen. // callback so the two cannot disagree about what is on screen.
LaunchedEffect(entryKey, component.name, requestedLines, generation, kind) { LaunchedEffect(entryKey, component.name, requestedLines, generation, kind, forwarded) {
failure = null failure = null
// Nothing to fetch, and asking anyway would come back as a failure // Nothing to fetch, and asking anyway would come back as a failure
// in red -- which is the wrong thing to say about a log that // in red -- which is the wrong thing to say about a log that
@@ -175,7 +256,7 @@ fun ComponentLogDialog(
title = { Text("${component.name} · log") }, title = { Text("${component.name} · log") },
text = { text = {
Column { Column {
if (hasBothKinds) { run {
// Primary rather than the plain `TabRow`, which is // Primary rather than the plain `TabRow`, which is
// deprecated in favour of the two that say where they // deprecated in favour of the two that say where they
// sit -- these are this dialog's top-level // sit -- these are this dialog's top-level
@@ -225,7 +306,7 @@ fun ComponentLogDialog(
ProgressBar() ProgressBar()
Spacer(Modifier.height(8.dp)) Spacer(Modifier.height(8.dp))
} }
failure?.let { listOfNotNull(failure, forwardFailure).forEach {
OutputText(it) OutputText(it)
Spacer(Modifier.height(8.dp)) Spacer(Modifier.height(8.dp))
} }
@@ -239,12 +320,22 @@ fun ComponentLogDialog(
when (kind) { when (kind) {
LogKind.Build -> LogKind.Build ->
"No build log yet — this component hasn't been built from here." "No build log yet — this component hasn't been built from here."
LogKind.Runtime -> "This component reports no runtime log." LogKind.Runtime -> runtimeAbsence(component, source)
}, },
style = MaterialTheme.typography.bodySmall, style = MaterialTheme.typography.bodySmall,
color = MaterialTheme.colorScheme.onSurfaceVariant, color = MaterialTheme.colorScheme.onSurfaceVariant,
) )
} }
ring?.let { held ->
if (kind == LogKind.Runtime) {
Text(
"the app is holding ${held.held} line(s)" +
if (held.dropped > 0) ", ${held.dropped} dropped" else "",
style = MaterialTheme.typography.bodySmall,
color = MaterialTheme.colorScheme.onSurfaceVariant,
)
}
}
log?.let { loaded -> log?.let { loaded ->
if (loaded.truncated) { if (loaded.truncated) {
Text( Text(
@@ -370,3 +461,35 @@ private fun copyToClipboard(context: Context, label: String, text: String) {
val clipboard = context.getSystemService(Context.CLIPBOARD_SERVICE) as ClipboardManager val clipboard = context.getSystemService(Context.CLIPBOARD_SERVICE) as ClipboardManager
clipboard.setPrimaryClip(ClipData.newPlainText(label, text)) clipboard.setPrimaryClip(ClipData.newPlainText(label, text))
} }
/**
* What the Runtime tab says when there is nothing stored for this component yet.
*
* Five different things, because they are five different situations and only one of them is worth
* acting on. A component that runs on the build machine reports through its service script, and a
* script that offers no log is an ordinary script rather than a failure. A component that runs on
* this phone reports through the devlog contract, and there the question is what this phone found
* when it asked: nothing to ask about, nothing installed, an app that implements no provider, or an
* app whose provider refused us which is the only one that is a fault, and the only one that
* names its cause.
*
* Never one sentence covering several: a check that came back empty and a check that could not be
* made must not share a wording, or nothing on screen ever says which happened.
*/
private fun runtimeAbsence(component: ProjectComponent, source: DevLogSource?): String =
when {
component.isServer -> "This component reports no runtime log."
source == null -> "Asking this phone what this app exposes…"
source is DevLogSource.NoPackage ->
"This component hasn't been built, so there is no app on this phone to read."
source is DevLogSource.NotInstalled ->
"${source.packageName} isn't installed on this phone, so there is no log to read."
source is DevLogSource.NoProvider ->
"${source.packageName} exposes no devlog, so this phone can't read what it logs. " +
"See the contract in dev-updater's README."
source is DevLogSource.Refused ->
"${source.packageName} has a devlog and refused this app: ${source.reason}"
// Readable, and nothing forwarded yet -- the poll is running and
// the app has said nothing since this phone started watching.
else -> "Nothing logged yet. This app's log appears here as it arrives."
}
@@ -0,0 +1,250 @@
package com.example.devupdater
import android.content.ContentResolver
import android.content.Context
import android.net.Uri
import androidx.core.content.edit
import androidx.core.net.toUri
/*
* Reading an installed app's own recent log, on this phone.
*
* Android forbids one app reading another's `logcat`, so an app that a
* person can only reach through this updater -- no `adb`, no terminal --
* has no way to say what it did. The way out is for the app to carry a
* bounded copy of its own log and expose it, and the cheapest place to
* hand it over is the phone the two are already on: no tunnel, no token,
* no second enrolment.
*
* So this is a *contract*, not a feature for one app. Any app this server
* delivers can implement it and get a Runtime tab; the whole of it is in
* the README under "An app's own log", and the reading half is here. What
* this app then does with the lines is forward them to the build machine,
* so the tab renders from the same store a service's runtime log does and
* the history outlives the phone.
*
* Read access is guarded by `dev.updater.permission.READ_DEVLOG`, which
* this app defines and holds -- declared once, in `AndroidManifest.xml`,
* where the reason it is `normal` rather than `signature` is written down.
*/
/** Where an app's devlog provider lives, derived from the package rather than declared anywhere. */
fun devLogAuthority(packageName: String) = "$packageName.devlog"
/** One line of an app's own log, as its provider reports it. */
data class DevLogLine(
val seq: Long,
val atMillis: Long,
val level: String,
val target: String,
val message: String,
) {
/**
* `12:34:56.789 INFO some::target: the message` one line of text, which is what gets
* forwarded.
*
* Rendered here rather than on the build machine, deliberately: the server appends bytes and
* knows nothing about levels or targets, exactly as it knows nothing about what a service
* prints to stdout. Teaching it this shape would make every managed app's log format something
* to keep in step over there.
*
* UTC, because the phone's offset is not what the log is read against -- the build machine's
* own log is, and it is in UTC too.
*/
fun render(): String {
val ms = atMillis % 1000
val secondsOfDay = (atMillis / 1000) % 86_400
val clock =
String.format(
java.util.Locale.ROOT,
"%02d:%02d:%02d.%03d",
secondsOfDay / 3600,
(secondsOfDay % 3600) / 60,
secondsOfDay % 60,
ms,
)
return String.format(java.util.Locale.ROOT, "%s %-5s %s: %s", clock, level, target, message)
}
}
/**
* What an app's provider says about its ring as a whole.
*
* [dropped] is what the ring's own bound discarded, which the app counts rather than this app
* inferring from a gap: "the log starts here" and "the log was cut off here" are different things
* to be told. [newestSeq] is -1 for a ring nothing has been written to, and it is also what makes a
* restart detectable -- see [forwardDevLog].
*/
data class DevLogStatus(val held: Long, val dropped: Long, val newestSeq: Long)
/**
* What this phone can find out about one component's devlog.
*
* Four answers rather than a nullable authority, because the dialog has something different to say
* about each and three of them are not faults. The one that would be a fault -- a provider that is
* there and refuses us -- is [Refused], which is the state a missing permission produces and the
* one worth naming.
*/
sealed interface DevLogSource {
/** The provider answered, so there is something to read. */
data class Available(val authority: String) : DevLogSource
/** This component has never been built, so there is no package to ask about. */
data object NoPackage : DevLogSource
/** The app this component installs is not on this phone. */
data class NotInstalled(val packageName: String) : DevLogSource
/** It is installed and exposes no devlog provider — the ordinary case for most apps. */
data class NoProvider(val packageName: String) : DevLogSource
/** There is a provider and it would not let this app read it. */
data class Refused(val packageName: String, val reason: String) : DevLogSource
}
private fun statusUri(authority: String): Uri = "content://$authority/status".toUri()
private fun linesUri(authority: String, since: Long): Uri =
"content://$authority/lines?since=$since".toUri()
/**
* Asks the provider outright rather than looking it up in `PackageManager`.
*
* A resolved `ProviderInfo` says a provider is declared; a successful query says it answers, which
* is the thing actually being reported. It is also the only way to tell a provider that refuses
* this app from one that isn't there -- both look identical from the metadata.
*
* Blocking (a binder round trip): invoke from a background dispatcher.
*/
fun devLogSource(context: Context, packageName: String?): DevLogSource {
if (packageName == null) return DevLogSource.NoPackage
if (!isInstalled(context, packageName)) return DevLogSource.NotInstalled(packageName)
val authority = devLogAuthority(packageName)
return try {
context.contentResolver.query(statusUri(authority), null, null, null, null).use { cursor ->
if (cursor == null) DevLogSource.NoProvider(packageName)
else DevLogSource.Available(authority)
}
} catch (e: SecurityException) {
DevLogSource.Refused(packageName, e.message ?: "the provider refused this app")
}
}
/** The provider's `/status` row, or null if it stopped answering since it was resolved. */
private fun devLogStatus(resolver: ContentResolver, authority: String): DevLogStatus? =
resolver.query(statusUri(authority), null, null, null, null).use { cursor ->
if (cursor == null || !cursor.moveToFirst()) return null
DevLogStatus(
held = cursor.getLong(cursor.getColumnIndexOrThrow("held")),
dropped = cursor.getLong(cursor.getColumnIndexOrThrow("dropped")),
newestSeq = cursor.getLong(cursor.getColumnIndexOrThrow("newest_seq")),
)
}
/** Every line the provider holds from [since] on, oldest first. */
private fun devLogLines(
resolver: ContentResolver,
authority: String,
since: Long,
): List<DevLogLine> =
resolver.query(linesUri(authority, since), null, null, null, null).use { cursor ->
if (cursor == null) return emptyList()
val seq = cursor.getColumnIndexOrThrow("seq")
val atMillis = cursor.getColumnIndexOrThrow("t_ms")
val level = cursor.getColumnIndexOrThrow("level")
val target = cursor.getColumnIndexOrThrow("target")
val message = cursor.getColumnIndexOrThrow("message")
buildList {
while (cursor.moveToNext()) {
add(
DevLogLine(
seq = cursor.getLong(seq),
atMillis = cursor.getLong(atMillis),
level = cursor.getString(level).orEmpty(),
target = cursor.getString(target).orEmpty(),
message = cursor.getString(message).orEmpty(),
)
)
}
}
}
/**
* Reads whatever the provider has that this phone has not forwarded yet, sends it to the build
* machine, and answers how many lines that was.
*
* Zero is the ordinary answer between two polls and means nothing needs redrawing.
*
* The cursor is stored on this device rather than being asked for each time, so reopening the tab
* does not post the whole ring again. **It is reset when the app's own sequence has gone
* backwards**: the ring is in memory, so an app that restarted starts again at zero, and a cursor
* left where it was would skip everything that app has said since -- silently, which is the failure
* worth guarding rather than the one worth reporting.
*
* Blocking on both halves: invoke from a background dispatcher.
*/
fun forwardDevLog(
context: Context,
authority: String,
key: String,
component: String,
): DevLogForward {
val resolver = context.contentResolver
val status = devLogStatus(resolver, authority) ?: return DevLogForward(null, 0)
val stored = devLogCursor(context, key, component)
val since = if (status.newestSeq >= 0 && status.newestSeq + 1 < stored) 0 else stored
val lines = devLogLines(resolver, authority, since)
if (lines.isEmpty()) {
// Still worth writing back, so a reset is not re-decided every
// second while an app that restarted says nothing.
setDevLogCursor(context, key, component, since)
return DevLogForward(status, 0)
}
// The ring is bounded, so an app that logged faster than this poll
// reads has already thrown some away. Said in the log rather than
// left as a jump in the sequence numbers nobody reads: a log missing
// its middle looks exactly like one that was quiet.
val missed = lines.first().seq - since
val rendered =
if (missed > 0) listOf(gapLine(missed)) + lines.map(DevLogLine::render)
else lines.map(DevLogLine::render)
postRuntimeLog(key, component, rendered)
// Only after the post: a failed send must be retried from the same
// place, exactly as the app's own uploader retries from its cursor.
setDevLogCursor(context, key, component, lines.last().seq + 1)
return DevLogForward(status, lines.size)
}
/** What one poll found: the ring as a whole, and how many lines it forwarded. */
data class DevLogForward(val status: DevLogStatus?, val sent: Int)
private fun gapLine(missed: Long) =
"-- $missed line(s) were dropped from this app's own log before the next one --"
private const val CURSORS_PREFS = "devlog-cursors"
/** Keyed like every other per-component preference here; see `VariantChoice.kt`. */
private fun slot(key: String, component: String) = "$key/$component"
private fun devLogCursor(context: Context, key: String, component: String): Long =
context
.getSharedPreferences(CURSORS_PREFS, Context.MODE_PRIVATE)
.getLong(slot(key, component), 0)
private fun setDevLogCursor(context: Context, key: String, component: String, seq: Long) {
context.getSharedPreferences(CURSORS_PREFS, Context.MODE_PRIVATE).edit {
putLong(slot(key, component), seq)
}
}
/**
* Forgets where this phone had got to in every component of a project being removed.
*
* The path out for what [forwardDevLog] writes, and the same one [forgetVariants] is: a key reused
* by a later project would otherwise inherit a cursor nobody set, and skip that app's log up to
* whatever number it happened to be at.
*/
fun forgetDevLogCursors(context: Context, key: String) {
val prefs = context.getSharedPreferences(CURSORS_PREFS, Context.MODE_PRIVATE)
prefs.edit { prefs.all.keys.filter { it == key || it.startsWith("$key/") }.forEach(::remove) }
}
@@ -1743,6 +1743,7 @@ private fun AppListScreen(
}, },
onRemove = { onRemove = {
forgetVariants(context, entry.key) forgetVariants(context, entry.key)
forgetDevLogCursors(context, entry.key)
manage(entry, removes = true) { manage(entry, removes = true) {
removeApp(entry.key) removeApp(entry.key)
} }
@@ -3392,9 +3393,13 @@ private fun ComponentCard(
// whatever the text does. Unconditional, so the settings // whatever the text does. Unconditional, so the settings
// button sits in the same place whether or not there is a // button sits in the same place whether or not there is a
// log beside it -- the log's own absence must not move it. // log beside it -- the log's own absence must not move it.
if (component.hasLogs) { // Unconditional like the gear beside it, and for the
IconGlyphButton(LOG_GLYPH, "Show ${component.name}'s log") { showingLog = true } // same reason: a component always has both kinds of log
} // to ask about, and a button that comes and goes makes
// its own absence the answer. There is nothing here yet
// and nobody has looked are different things, and the
// dialog is where the difference gets said.
IconGlyphButton(LOG_GLYPH, "Show ${component.name}'s log") { showingLog = true }
// Always drawn, including for a component with a single // Always drawn, including for a component with a single
// build mode and nothing to strip: what a component can be // build mode and nothing to strip: what a component can be
// told is part of what it is, and a control that comes and // told is part of what it is, and a control that comes and
@@ -0,0 +1,11 @@
<?xml version="1.0" encoding="utf-8"?>
<resources>
<!-- The permission declared in AndroidManifest.xml. Android shows
these to a person deciding whether to install an app that asks
for it, so they say what it gives away rather than naming the
mechanism. -->
<string name="devlog_permission_label">Read a development app\'s own log</string>
<string name="devlog_permission_description">Lets this app read the recent log lines that
another locally-built app is keeping about itself, so they can be shown and sent to the
build machine.</string>
</resources>
+137 -6
View File
@@ -88,6 +88,18 @@ fn build_log_dir() -> PathBuf {
data_dir().join("builds") data_dir().join("builds")
} }
/// Where this server keeps the runtime lines a *phone* forwarded for an
/// APK component.
///
/// Beside the build logs and under the same rule, because it is the same
/// kind of thing: generated state this server owns, which the uninstall
/// dialog's "remove logs" toggle already reaches through
/// [`data_dir`]. An APK does not run here, so there is no service script
/// to report a path and nothing else would ever write this file.
fn devlog_dir() -> PathBuf {
data_dir().join("devlogs")
}
/// Everything this server generates for itself, under `$XDG_DATA_HOME`. /// Everything this server generates for itself, under `$XDG_DATA_HOME`.
/// ///
/// One answer to "where does generated state go", so the build logs and /// One answer to "where does generated state go", so the build logs and
@@ -117,8 +129,12 @@ pub fn data_dir() -> PathBuf {
pub enum LogKind { pub enum LogKind {
/// Written by this server while building the component. /// Written by this server while building the component.
Build, Build,
/// Written by the component itself while running, reported by its /// Written by the component itself while running. For a `Server`
/// service script. Never present for an APK, which does not run here. /// that is what its service script reports; for an `Apk` it is what
/// the phone forwarded out of that app's own devlog provider (see
/// [`append_devlog`]). Two sources, because the component runs in two
/// different places -- but one kind, so the tab and the route that
/// feeds it stay one mechanism.
Runtime, Runtime,
} }
@@ -132,9 +148,17 @@ pub fn build_logs(key: &str, component: &str) -> Vec<PathBuf> {
} }
fn build_log_path(key: &str, component: &str) -> PathBuf { fn build_log_path(key: &str, component: &str) -> PathBuf {
// Both are already route-safe identifiers, but a component name comes log_path(&build_log_dir(), key, component)
// from a project's own file, so anything that could climb out of the }
// directory is flattened rather than trusted.
/// `<dir>/<key>-<component>.log`.
///
/// Both parts are already route-safe identifiers, but a component name
/// comes from a project's own file, so anything that could climb out of
/// the directory is flattened rather than trusted. One definition, so the
/// build store and the devlog store cannot come to disagree about what a
/// component's file is called.
fn log_path(dir: &Path, key: &str, component: &str) -> PathBuf {
let safe = |text: &str| -> String { let safe = |text: &str| -> String {
text.chars() text.chars()
.map(|c| { .map(|c| {
@@ -146,7 +170,68 @@ fn build_log_path(key: &str, component: &str) -> PathBuf {
}) })
.collect() .collect()
}; };
build_log_dir().join(format!("{}-{}.log", safe(key), safe(component))) dir.join(format!("{}-{}.log", safe(key), safe(component)))
}
/// How large one component's devlog grows before the current generation is
/// rotated aside.
///
/// The same two-generation split the build logs use, for the same reason:
/// what a reader wants is the recent end, and one file that only ever
/// grows would eventually be all this server keeps. Rotating at a size
/// rather than per run is the only thing available here -- a phone
/// forwards a stream, and there is no "run" for this server to notice the
/// start of.
const DEVLOG_ROTATE_BYTES: u64 = 4 * 1024 * 1024;
/// The runtime log files a phone has forwarded for one APK component,
/// newest first.
///
/// The same shape [`build_logs`] answers with, so the route that serves
/// either does not have to care which produced it.
pub fn devlog_logs(key: &str, component: &str) -> Vec<PathBuf> {
let current = log_path(&devlog_dir(), key, component);
let previous = previous_of(&current);
[current, previous]
.into_iter()
.filter(|path| path.is_file())
.collect()
}
/// Appends lines a phone read out of an installed app's devlog provider.
///
/// **This server does not parse them.** What arrives is already one line
/// of text per log line, rendered on the phone from the provider's
/// columns, and what is stored is those bytes -- so nothing here knows
/// what a level or a target is, and a managed app is free to change its
/// own log format without this server being taught about it. That is the
/// same posture it takes towards a service's stdout, which is the other
/// thing this kind of log is.
pub fn append_devlog(key: &str, component: &str, lines: &[String]) -> Result<()> {
append_devlog_in(&devlog_dir(), key, component, lines)
}
/// The half that does not know where the directory is, so a test can hand
/// it one.
fn append_devlog_in(dir: &Path, key: &str, component: &str, lines: &[String]) -> Result<()> {
let path = log_path(dir, key, component);
let parent = path.parent().expect("a log path has a directory");
wg_app_link::private::create_dir(parent)
.with_context(|| format!("make {}", parent.display()))?;
if std::fs::metadata(&path).is_ok_and(|meta| meta.len() >= DEVLOG_ROTATE_BYTES) {
let _ = std::fs::rename(&path, previous_of(&path));
}
// Owner-only on creation for the same reason every other file this
// server writes is: a phone's log is whatever that app wrote.
let mut file = wg_app_link::private::append_file(&path)
.with_context(|| format!("open {}", path.display()))?;
let mut body = String::new();
for line in lines {
body.push_str(line);
body.push('\n');
}
std::io::Write::write_all(&mut file, body.as_bytes())
.with_context(|| format!("write {}", path.display()))
} }
fn previous_of(path: &Path) -> PathBuf { fn previous_of(path: &Path) -> PathBuf {
@@ -232,6 +317,52 @@ mod tests {
assert!(tail.truncated); assert!(tail.truncated);
} }
/// The store an APK component's runtime log is: appended to, read
/// back through the same `tail` a service's log goes through.
#[test]
fn forwarded_lines_are_appended_and_read_back_in_order() {
let dir = tempfile::tempdir().expect("tempdir");
let lines = |texts: &[&str]| texts.iter().map(|t| t.to_string()).collect::<Vec<_>>();
append_devlog_in(dir.path(), "ai-app", "app", &lines(&["one", "two"])).expect("append");
append_devlog_in(dir.path(), "ai-app", "app", &lines(&["three"])).expect("append again");
let path = log_path(dir.path(), "ai-app", "app");
assert_eq!(tail(&path, 0).expect("tail").text, "one\ntwo\nthree");
}
/// Two components of one project keep their own, so a phone forwarding
/// for one cannot land in the other's tab.
#[test]
fn each_component_has_its_own_forwarded_log() {
let dir = tempfile::tempdir().expect("tempdir");
append_devlog_in(dir.path(), "p", "one", &["a".to_string()]).expect("append");
append_devlog_in(dir.path(), "p", "two", &["b".to_string()]).expect("append");
assert_eq!(
tail(&log_path(dir.path(), "p", "one"), 0).unwrap().text,
"a"
);
assert_eq!(
tail(&log_path(dir.path(), "p", "two"), 0).unwrap().text,
"b"
);
}
/// The half that is easy to leave out: without rotation the file only
/// ever grows, and a phone forwarding a stream has no run boundary for
/// this server to rotate on.
#[test]
fn a_devlog_past_the_bound_rotates_rather_than_growing_for_ever() {
let dir = tempfile::tempdir().expect("tempdir");
let big = vec!["x".repeat(DEVLOG_ROTATE_BYTES as usize)];
append_devlog_in(dir.path(), "p", "app", &big).expect("append");
append_devlog_in(dir.path(), "p", "app", &["after".to_string()]).expect("append");
let current = log_path(dir.path(), "p", "app");
assert_eq!(tail(&current, 0).expect("tail").text, "after");
assert!(
previous_of(&current).is_file(),
"and what was there is the previous generation, not gone"
);
}
#[test] #[test]
fn zero_means_everything_it_is_allowed_to_read() { fn zero_means_everything_it_is_allowed_to_read() {
let dir = tempfile::tempdir().expect("tempdir"); let dir = tempfile::tempdir().expect("tempdir");
+15 -3
View File
@@ -276,9 +276,21 @@ impl AppEntry {
}; };
match kind { match kind {
crate::logs::LogKind::Build => crate::logs::build_logs(&self.key, name), crate::logs::LogKind::Build => crate::logs::build_logs(&self.key, name),
crate::logs::LogKind::Runtime => crate::service::driver(&self.key, component) // A component's runtime log comes from wherever that
.map(|script| crate::service::logs(&script, &self.project_path, component.cwd())) // component runs. A `Server` runs on this machine and its
.unwrap_or_default(), // script says where it writes; an `Apk` runs on a phone, and
// what this machine has is what the phone forwarded out of
// that app's devlog provider. One kind with two sources
// rather than two kinds, because the reader is asking the
// same question either way.
crate::logs::LogKind::Runtime => match component {
Component::Apk { .. } => crate::logs::devlog_logs(&self.key, name),
Component::Server { .. } => crate::service::driver(&self.key, component)
.map(|script| {
crate::service::logs(&script, &self.project_path, component.cwd())
})
.unwrap_or_default(),
},
} }
} }
+66 -2
View File
@@ -32,8 +32,13 @@
//! POST /apps/{key}/components/{name}/enroll-link //! POST /apps/{key}/components/{name}/enroll-link
//! run that component's `enroll:` and //! run that component's `enroll:` and
//! answer the URL it printed //! answer the URL it printed
//! GET /apps/{key}/components/{name}/logs[?lines=&generation=] //! GET /apps/{key}/components/{name}/logs[?lines=&generation=&kind=]
//! what that component wrote //! what that component wrote
//! POST /apps/{key}/components/{name}/runtime-log {lines}
//! lines a phone read out of an
//! installed app's devlog provider,
//! appended to that APK component's
//! runtime log
//! POST /apps/{key}/components/{name}/{action} //! POST /apps/{key}/components/{name}/{action}
//! install|uninstall|start|stop|restart //! install|uninstall|start|stop|restart
//! a server component, on the *build //! a server component, on the *build
@@ -132,6 +137,15 @@ pub fn tls_router(state: Arc<AppState>) -> Router {
"/apps/{key}/components/{name}/enroll-link", "/apps/{key}/components/{name}/enroll-link",
post(enrollment_link), post(enrollment_link),
) )
// Ahead of `{action}` like its neighbours. The write half of the
// runtime log an APK component has: the component runs on the
// phone, so the phone is the only thing that can read it, and
// this is where what it read is kept so the tab renders from the
// same store a service's does and the history outlives the phone.
.route(
"/apps/{key}/components/{name}/runtime-log",
post(append_runtime_log),
)
.route( .route(
"/apps/{key}/components/{name}/{action}", "/apps/{key}/components/{name}/{action}",
post(service_action), post(service_action),
@@ -422,7 +436,14 @@ impl ManifestComponent {
// script costs a process and this path is fetched on every open, // script costs a process and this path is fetched on every open,
// resume and Refresh. // resume and Refresh.
let has_build_logs = !crate::logs::build_logs(key, &name).is_empty(); let has_build_logs = !crate::logs::build_logs(key, &name).is_empty();
let has_runtime_logs = is_server && !state.service_checks.logs(key, &name).is_empty(); // A server's runtime log is its script's answer, cached by the
// background check; an APK's is what a phone has forwarded here,
// which is a stat like the build log beside it.
let has_runtime_logs = if is_server {
!state.service_checks.logs(key, &name).is_empty()
} else {
!crate::logs::devlog_logs(key, &name).is_empty()
};
// Only a server keeps anything on this machine, and only a // Only a server keeps anything on this machine, and only a
// project that says where. Both halves have to be true before // project that says where. Both halves have to be true before
// there is a path to show. // there is a path to show.
@@ -1386,6 +1407,49 @@ async fn enrollment_link(
Ok(Json(EnrollmentLink { url })) Ok(Json(EnrollmentLink { url }))
} }
/// Lines a phone read out of an installed app's devlog provider.
///
/// Already rendered: one string per log line, formatted on the phone from
/// the provider's columns. This server appends the bytes and parses
/// nothing, which is the same thing it does with a service's stdout --
/// what a level or a target looks like is the managed app's business, and
/// teaching this server about it would make every app's log format
/// something to keep in step here.
#[derive(Deserialize)]
struct RuntimeLogBody {
lines: Vec<String>,
}
/// Appends those lines to an APK component's runtime log.
///
/// An APK runs on the phone, so the phone is the only thing that can read
/// what it wrote -- and a phone is replaced, wiped and reinstalled, where
/// this store is what makes the history outlive it. Refused for a
/// `Server`, whose runtime log is its own script's answer: two writers of
/// one file is two versions of the truth about what a service printed.
async fn append_runtime_log(
State(state): State<Arc<AppState>>,
UrlPath((key, name)): UrlPath<(String, String)>,
Json(body): Json<RuntimeLogBody>,
) -> Result<StatusCode, ApiError> {
let entry = state.entry(&key).ok_or(ApiError::UnknownApp(key.clone()))?;
let component = entry
.component(&name)
.ok_or_else(|| ApiError::UnknownComponent(key.clone(), name.clone()))?;
if !matches!(component, crate::config::Component::Apk { .. }) {
return Err(ApiError::BadRequest(format!(
"{name} runs on this machine, so its runtime log is its service script's"
)));
}
if body.lines.is_empty() {
return Ok(StatusCode::NO_CONTENT);
}
tokio::task::spawn_blocking(move || crate::logs::append_devlog(&key, &name, &body.lines))
.await
.context("appending a forwarded runtime log")??;
Ok(StatusCode::NO_CONTENT)
}
/// What somebody chose for one component on the settings sheet. /// What somebody chose for one component on the settings sheet.
/// ///
/// `mode` absent means "no choice, take the first declared one", which is /// `mode` absent means "no choice, take the first declared one", which is