diff --git a/android-shell/Cargo.lock b/android-shell/Cargo.lock index 3f93d65..7629fee 100644 --- a/android-shell/Cargo.lock +++ b/android-shell/Cargo.lock @@ -83,6 +83,7 @@ name = "client-core" version = "0.1.0" dependencies = [ "event-model", + "log", "pulldown-cmark", "serde", "serde_json", diff --git a/client-core/src/log_ring.rs b/client-core/src/log_ring.rs index ec975ad..a20b159 100644 --- a/client-core/src/log_ring.rs +++ b/client-core/src/log_ring.rs @@ -17,7 +17,7 @@ //! the report, and a report taken twice must say the same thing. use std::collections::VecDeque; -use std::sync::{Arc, Mutex}; +use std::sync::{Arc, Mutex, OnceLock}; use std::time::{SystemTime, UNIX_EPOCH}; /// How many lines a default ring holds, and how many bytes of message. @@ -309,6 +309,37 @@ pub fn install( Ok(()) } +/// The one ring this process records into. +/// +/// **A deliberate process-global, where this project's rules otherwise say +/// pass context explicitly.** What is being modelled is already one: `log` +/// has exactly one backend per process, set once, and every `log::info!` +/// anywhere in the binary goes to it. A ring handed around as a parameter +/// would be a *second* answer to "which lines exist" -- the report would +/// show one ring while the logger filled another, and which one a caller +/// got would depend on how far down the call tree it was. The tests above +/// all use their own [`LogRing`], so nothing here needs this to be +/// testable. +static PROCESS_RING: OnceLock = OnceLock::new(); + +/// The process's ring, created on first use with the default bounds. +/// Safe to call before [`install_process_logger`] -- it will simply be +/// empty. +pub fn process_ring() -> &'static LogRing { + PROCESS_RING.get_or_init(LogRing::with_defaults) +} + +/// Installs [`process_ring`] as the recording half of the process logger, +/// forwarding to `inner` (the platform's own logger, already configured). +/// The platform half of AGENTS.md's sharing rule is `inner`; everything +/// else is shared. +pub fn install_process_logger( + inner: Box, + max_level: log::LevelFilter, +) -> Result<(), log::SetLoggerError> { + install(process_ring().clone(), inner, max_level) +} + #[cfg(test)] mod tests { use super::*; diff --git a/iris/Cargo.lock b/iris/Cargo.lock index 4be3e00..0981c68 100644 --- a/iris/Cargo.lock +++ b/iris/Cargo.lock @@ -721,6 +721,7 @@ name = "client-core" version = "0.1.0" dependencies = [ "event-model", + "log", "pulldown-cmark", "serde", "serde_json", diff --git a/iris/android-app/Cargo.lock b/iris/android-app/Cargo.lock index 6c4a19c..b6a5b94 100644 --- a/iris/android-app/Cargo.lock +++ b/iris/android-app/Cargo.lock @@ -745,6 +745,7 @@ name = "client-core" version = "0.1.0" dependencies = [ "event-model", + "log", "pulldown-cmark", "serde", "serde_json", diff --git a/iris/android-app/build.rs b/iris/android-app/build.rs index f6cb3fb..fe8ea50 100644 --- a/iris/android-app/build.rs +++ b/iris/android-app/build.rs @@ -22,6 +22,17 @@ fn main() { if std::env::var_os("CARGO_FEATURE_TRANSCRIPT_SCREEN").is_none() { return; } + // Where this build sends its own log ring, if anywhere. Emitted for + // every build that has `client-core` (so the `bench` build, which + // returns below, gets it too): the log route is the one thing a bench + // APK on a phone with no `logcat` needs a server for even though it + // opens a checked-in fixture and talks to nothing else. + // + // **Optional, unlike the transcript config below.** A build with none + // of these set still keeps its ring and still shows it in `Copy + // report`; it just has nowhere to send it. So the same `build-apk.sh` + // works on a machine that has not decided where logs go. + emit_log_config(); // P0's bench build (docs/RUST.md) opens the checked-in fixture with no // server at all -- `bench_client.rs` never references the `pinned` // module this generates, so requiring a live server's host/port/token/ @@ -49,6 +60,84 @@ fn main() { "the bearer token -- ~/.config/ai-app/sandbox-token, or the start banner's enrollment link", ); + let ca_pem = read_pinned_ca(); + + let out_dir = PathBuf::from(std::env::var_os("OUT_DIR").unwrap()); + let generated = format!( + "// Generated by build.rs from {host}:{port}. Do not edit.\n\ + pub const HOST: &str = {host_lit:?};\n\ + pub const PORT: u16 = {port};\n\ + pub const TOKEN: &str = {token_lit:?};\n\ + pub const CA_PEM: &str = {ca_lit:?};\n", + host = host, + port = port + .parse::() + .unwrap_or_else(|e| panic!("AI_APP_TRANSCRIPT_PORT={port:?} is not a u16: {e}")), + host_lit = host, + token_lit = token, + ca_lit = ca_pem, + ); + std::fs::write(out_dir.join("pinned_config.rs"), generated).unwrap(); +} + +/// Writes `log_config.rs` into `OUT_DIR`: the server this build's log ring +/// uploads to, or `None`. +/// +/// Read from the environment at build time rather than from anything in +/// the repository, which is the same trust boundary the CA below uses and +/// the reason no token is ever committed. On the host, Dev Updater builds +/// this APK on the machine `ai-server` runs on, so the values are that +/// machine's own -- an APK is good for the server that built it, which is +/// already true of the pinned CA. +fn emit_log_config() { + println!("cargo:rerun-if-env-changed=AI_APP_LOG_HOST"); + println!("cargo:rerun-if-env-changed=AI_APP_LOG_PORT"); + println!("cargo:rerun-if-env-changed=AI_APP_LOG_TOKEN"); + + let out_dir = PathBuf::from(std::env::var_os("OUT_DIR").unwrap()); + let host = std::env::var("AI_APP_LOG_HOST").ok(); + let port = std::env::var("AI_APP_LOG_PORT").ok(); + let token = std::env::var("AI_APP_LOG_TOKEN").ok(); + + let generated = match (host, port, token) { + (Some(host), Some(port), Some(token)) => { + let port: u16 = port + .parse() + .unwrap_or_else(|e| panic!("AI_APP_LOG_PORT={port:?} is not a u16: {e}")); + let ca_pem = read_pinned_ca(); + format!( + "// Generated by build.rs. Do not edit.\n\ + pub const LOG_SERVER: Option = Some(LogServer {{\n\ + \x20 host: {host:?},\n\ + \x20 port: {port},\n\ + \x20 token: {token:?},\n\ + \x20 ca_pem: {ca_pem:?},\n\ + }});\n" + ) + } + // All three or none: two of the three is a half-configured build + // that would fail at runtime with nothing on screen saying why. + (host, port, token) => { + assert!( + host.is_none() && port.is_none() && token.is_none(), + "AI_APP_LOG_HOST, AI_APP_LOG_PORT and AI_APP_LOG_TOKEN are set together \ + or not at all -- a build with some of them has nowhere to send its log \ + and no way to say so" + ); + "// Generated by build.rs. Do not edit.\n\ + pub const LOG_SERVER: Option = None;\n" + .to_string() + } + }; + std::fs::write(out_dir.join("log_config.rs"), generated).unwrap(); +} + +/// The CA this machine's `ai-server` signs with: `AI_APP_CA`, else +/// `$XDG_CONFIG_HOME/ai-app/certs/ca.pem`. One reader for both generated +/// configs -- the log destination and the transcript destination are the +/// same server's certificate, and two copies of this would be two ways to +/// disagree about which one was pinned. +fn read_pinned_ca() -> String { let ca_path = std::env::var_os("AI_APP_CA") .map(PathBuf::from) .unwrap_or_else(|| { @@ -63,34 +152,18 @@ fn main() { let ca_pem = std::fs::read_to_string(&ca_path).unwrap_or_else(|e| { panic!( "no CA certificate at {} ({e}).\n\ - Start ai-server (or app/ui-sandbox.sh) once on this machine first -- it \ - generates the CA this build pins. Set AI_APP_CA=/path/to/ca.pem to build \ - against a different one.", + Start ai-server once on this machine first -- it generates the CA this \ + build pins. Set AI_APP_CA=/path/to/ca.pem to build against a different one.", ca_path.display() ) }); - let ca_pem = ca_pem.trim(); - if !ca_pem.starts_with("-----BEGIN CERTIFICATE-----") { - panic!("{} is not a PEM certificate.", ca_path.display()); - } - - let out_dir = PathBuf::from(std::env::var_os("OUT_DIR").unwrap()); - let generated = format!( - "// Generated by build.rs from {host}:{port} and {ca}. Do not edit.\n\ - pub const HOST: &str = {host_lit:?};\n\ - pub const PORT: u16 = {port};\n\ - pub const TOKEN: &str = {token_lit:?};\n\ - pub const CA_PEM: &str = {ca_lit:?};\n", - host = host, - port = port - .parse::() - .unwrap_or_else(|e| panic!("AI_APP_TRANSCRIPT_PORT={port:?} is not a u16: {e}")), - ca = ca_path.display(), - host_lit = host, - token_lit = token, - ca_lit = ca_pem, + let ca_pem = ca_pem.trim().to_string(); + assert!( + ca_pem.starts_with("-----BEGIN CERTIFICATE-----"), + "{} is not a PEM certificate.", + ca_path.display() ); - std::fs::write(out_dir.join("pinned_config.rs"), generated).unwrap(); + ca_pem } fn require_env(name: &str, what: &str) -> String { diff --git a/iris/android-app/src/app_log.rs b/iris/android-app/src/app_log.rs new file mode 100644 index 0000000..c95be19 --- /dev/null +++ b/iris/android-app/src/app_log.rs @@ -0,0 +1,108 @@ +//! The platform half of this app's logging: what `client_core::log_ring` +//! and `client_core::log_upload` need that only Android can supply. +//! +//! Everything general -- the ring, its bounds, the `log::Log` backend, the +//! batching and the upload -- is in `client-core`, shared with the desktop +//! app (AGENTS.md's sharing rule). What is here is the two things that are +//! genuinely this platform's: `android_logger` as the logger to forward +//! to, and the destination baked in at build time by `build.rs`. +//! +//! **Why an app carries its own log at all**: Iris tests these builds on a +//! GrapheneOS phone with no `adb`, and Android forbids one app reading +//! another's `logcat`. Nothing outside this process can recover what it +//! wrote, so the process keeps a copy and sends it. See +//! `docs/DECISIONS.md`, 2026-09-07. + +use client_core::log_ring::{self, LogRing}; +pub use client_core::log_upload::LogUpload; +use std::sync::Arc; +use std::time::Duration; + +/// Where this build's log goes, or `None` for a build that was not told. +/// Generated by `build.rs` from `AI_APP_LOG_HOST`/`_PORT`/`_TOKEN` and the +/// pinned CA -- never from anything committed. +pub struct LogServer { + pub host: &'static str, + pub port: u16, + pub token: &'static str, + pub ca_pem: &'static str, +} + +include!(concat!(env!("OUT_DIR"), "/log_config.rs")); + +/// How often the uploader sends what has accumulated. +/// +/// Ten seconds rather than per line: a line at a time is a radio wake per +/// `log::info!`, and this app logs per surface change and per benchmark +/// phase. `Copy report` flushes immediately, so the case where somebody is +/// waiting does not wait for this. +const UPLOAD_EVERY: Duration = Duration::from_secs(10); + +/// Installs the ring in front of `android_logger`, so `logcat` still sees +/// exactly what it saw before and the ring sees it too. +/// +/// Called once, from `JNI_OnLoad`. A second call is refused by `log` +/// itself; the message says which caller, since two initialisation paths +/// is a programmer error rather than something to recover from. +pub fn install(max_level: log::LevelFilter) { + let inner = android_logger::AndroidLogger::new( + android_logger::Config::default() + .with_max_level(max_level) + .with_tag("iris-android-app"), + ); + if log_ring::install_process_logger(Box::new(inner), max_level).is_err() { + // Not a panic: a logger already installed means logging works, + // just without the ring, and taking the app down over a + // diagnostic would be worse than the diagnostic being missing. + // The line goes through whatever logger did win. + log::warn!("iris app log: a logger was already installed, so there is no ring"); + } +} + +/// The process's ring -- what `Copy report` appends and the diagnostics +/// pane counts. +pub fn ring() -> &'static LogRing { + log_ring::process_ring() +} + +/// Starts the upload loop, if this build was told where to send it. +/// `None` is an ordinary answer, not a failure: a build with no +/// destination still keeps its ring and still copies it. +pub fn start_upload(source: &str) -> Option { + let server = LOG_SERVER.as_ref()?; + let transport = client_core::api::UreqTransport::new( + format!("https://{}:{}", server.host, server.port), + server.token, + server.ca_pem.as_bytes(), + ) + .inspect_err(|err| log::warn!("iris app log: no upload -- {}", err.message)) + .ok()?; + Some(LogUpload::spawn( + ring().clone(), + Arc::new(transport), + source.to_string(), + UPLOAD_EVERY, + )) +} + +/// Only the bench build has a diagnostics pane to put this in; the +/// transcript build's screen is the app's own and has no room for a +/// readout. Gated rather than left dead so the build stays warning-clean. +#[cfg(feature = "bench")] +/// One or two lines for the diagnostics pane: how much is held, and what +/// the uploader last did. Both, because "nothing is arriving on the +/// server" has two very different causes and the pane is where somebody +/// looks for which. +pub fn diagnostics_line(upload: Option<&LogUpload>) -> String { + let ring = ring().summary(); + match (upload, LOG_SERVER.as_ref()) { + (Some(upload), _) => format!("{ring}\n{}", upload.status().summary()), + (None, None) => format!("{ring}\nlog upload: this build has no server configured"), + // Configured but not started: the client never called + // `start_upload`, or its transport refused the pinned CA. + (None, Some(server)) => format!( + "{ring}\nlog upload: configured for {}:{} but not running", + server.host, server.port + ), + } +} diff --git a/iris/android-app/src/bench_client.rs b/iris/android-app/src/bench_client.rs index f0ef93b..dc732f1 100644 --- a/iris/android-app/src/bench_client.rs +++ b/iris/android-app/src/bench_client.rs @@ -80,6 +80,12 @@ const KEYBOARD_WAIT_MS: u64 = 1_000; /// when a later step in the same phase needs to read state back. const ANIM_STEP_MS: u64 = 16; +/// What this build calls itself in `ai-server`'s log. Names the app and +/// the build type, not the device: two phones running this APK are meant +/// to be told apart by what they say, and a device identifier in a log is +/// something to explain rather than something anybody asked for. +const LOG_SOURCE: &str = "iris-bench"; + /// How much of the screen a *filled* benchmark report may take before it /// scrolls instead of growing -- roughly a third of a phone screen, the /// share the pane used to reserve unconditionally. An empty report takes @@ -122,6 +128,13 @@ pub struct BenchClient { /// The status-bar inset `top_bar` was last padded by -- see /// `on_insets_changed`'s own comment for why this guards the rebuild. last_top_pad: f32, + /// The background upload of this app's own log ring (`app_log`), where + /// this build was told a server. Held as a field rather than left + /// running for the process's lifetime so its path out is this client + /// being dropped -- `LogUpload`'s `Drop` stops and joins the thread. + /// `None` for a build with no destination, which is the ordinary case + /// for a bench APK built without `AI_APP_LOG_*`. + log_upload: Option, } /// See `BenchClient::ime_state`'s doc. `shown_events`/`hidden_events` @@ -283,6 +296,7 @@ impl AndroidAppState for BenchClient { ime_state: Arc::new(Mutex::new(ImeState::default())), keyboard_was_visible: false, last_top_pad: 0.0, + log_upload: crate::app_log::start_upload(LOG_SOURCE), }; match transcript_fixture::build_screen(rsc) { @@ -544,7 +558,11 @@ impl BenchClient { // logcat on her phone, and "the keyboard does not push the // composer up" cannot be told from "the listener never fired" // without it (`AndroidUiState::insets_report`). - format!("{renderer}\n{}", self.android_state().insets_report()) + format!( + "{renderer}\n{}\n{}", + self.android_state().insets_report(), + crate::app_log::diagnostics_line(self.log_upload.as_ref()) + ) } /// The keyboard's own diagnostics capture -- see `on_insets_changed`'s @@ -566,7 +584,7 @@ impl BenchClient { } fn copy_report(&mut self) { - let Some(report) = &self.last_report else { + let Some(report) = self.last_report.clone() else { log::info!("iris bench report: nothing to copy -- run the benchmark first"); return; }; @@ -574,7 +592,21 @@ impl BenchClient { log::info!("iris bench report: no platform handle, can't reach the clipboard"); return; }; - if platform.copy_to_clipboard("iris bench report", report) { + // The ring goes on the clipboard, not into the pane: the pane is + // on screen and a thousand log lines in it would bury the report + // somebody pressed the button for, while the clipboard is going + // straight into a message to be read elsewhere. + let report = format!( + "{report}\n\n=== app log ({}) ===\n{}", + crate::app_log::ring().summary(), + crate::app_log::ring().to_text() + ); + // And on the server, if this build has one -- so the lines are + // already there by the time the message describing them arrives. + if let Some(upload) = &self.log_upload { + upload.flush_now(); + } + if platform.copy_to_clipboard("iris bench report", &report) { log::info!("iris bench report: copied to clipboard"); } else { log::info!("iris bench report: clipboard copy failed"); diff --git a/iris/android-app/src/lib.rs b/iris/android-app/src/lib.rs index 8825688..a3c7a2d 100644 --- a/iris/android-app/src/lib.rs +++ b/iris/android-app/src/lib.rs @@ -51,6 +51,11 @@ use iris::prelude::*; use log::LevelFilter; use std::ffi::c_void; +/// The app's own log ring and its upload -- only where `client-core` is +/// linked, which is every build that has a server to send to. The plain +/// tabs demo keeps `android_logger` alone, as it always had. +#[cfg(feature = "transcript-screen")] +mod app_log; #[cfg(feature = "bench")] mod bench_client; #[cfg(feature = "bench")] @@ -119,6 +124,13 @@ extern "system" fn new_view_peer<'local>( /// mirrors android-view's own demo, which carries the same comment. #[unsafe(no_mangle)] pub unsafe extern "system" fn JNI_OnLoad(vm: *mut RawJavaVM, _: *mut c_void) -> jint { + // The ring in front of `android_logger` where there is one (see + // `app_log`), and `android_logger` alone otherwise. Both install the + // same tag and level, so `logcat` cannot tell the two builds apart -- + // the ring only adds a second reader. + #[cfg(feature = "transcript-screen")] + app_log::install(LevelFilter::Debug); + #[cfg(not(feature = "transcript-screen"))] android_logger::init_once( android_logger::Config::default() .with_max_level(LevelFilter::Debug) diff --git a/iris/android-app/src/transcript_client.rs b/iris/android-app/src/transcript_client.rs index 9e2b76f..e6a382c 100644 --- a/iris/android-app/src/transcript_client.rs +++ b/iris/android-app/src/transcript_client.rs @@ -74,6 +74,10 @@ pub struct TranscriptClient { /// only ever one session here (no list to switch away to), but the /// guard still matters for the *first* fetch racing a `stop`/`start`. generation: Arc, + /// The background upload of this app's own log ring (`app_log`). Held + /// here so its path out is this client being dropped; see + /// `bench_client`'s field of the same name. + _log_upload: Option, } impl HasAndroidUiState for TranscriptClient { @@ -182,6 +186,7 @@ impl AndroidAppState for TranscriptClient { items: Vec::new(), session_id: None, generation: Arc::new(AtomicU64::new(0)), + _log_upload: crate::app_log::start_upload("iris-transcript"), }; client.spawn_fetch_sessions(rsc); client diff --git a/server/src/routes.rs b/server/src/routes.rs index 1a85d68..0cbf0f1 100644 --- a/server/src/routes.rs +++ b/server/src/routes.rs @@ -1417,6 +1417,16 @@ async fn defaults(State(manager): State>) -> axum::Json) -> Result { - tracing::error!(target: "client_log", "[{source} {at} #{seq}] {target}: {message}") + tracing::error!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: {message}") } "WARN" => { - tracing::warn!(target: "client_log", "[{source} {at} #{seq}] {target}: {message}") + tracing::warn!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: {message}") } "DEBUG" => { - tracing::debug!(target: "client_log", "[{source} {at} #{seq}] {target}: {message}") + tracing::debug!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: {message}") } "TRACE" => { - tracing::trace!(target: "client_log", "[{source} {at} #{seq}] {target}: {message}") + tracing::trace!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: {message}") } "INFO" => { - tracing::info!(target: "client_log", "[{source} {at} #{seq}] {target}: {message}") + tracing::info!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: {message}") } other => { - tracing::info!(target: "client_log", "[{source} {at} #{seq}] {target}: <{other}> {message}") + tracing::info!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: <{other}> {message}") } } }