Compare commits
2
Commits
e10582a2cd
...
3c80d9d696
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
3c80d9d696 | ||
|
|
06b8a1f4b0 |
No files matched your search
@@ -9,7 +9,6 @@ pub mod durations;
|
|||||||
pub mod event_stream;
|
pub mod event_stream;
|
||||||
pub mod highlight;
|
pub mod highlight;
|
||||||
pub mod log_ring;
|
pub mod log_ring;
|
||||||
pub mod log_upload;
|
|
||||||
pub mod markdown_blocks;
|
pub mod markdown_blocks;
|
||||||
pub mod notifications;
|
pub mod notifications;
|
||||||
pub mod sse;
|
pub mod sse;
|
||||||
|
|||||||
@@ -11,10 +11,12 @@
|
|||||||
//!
|
//!
|
||||||
//! Two consumers, both reading the same ring rather than each keeping
|
//! Two consumers, both reading the same ring rather than each keeping
|
||||||
//! their own: the bench app's `Copy report`/`Diagnostics` (which reads
|
//! their own: the bench app's `Copy report`/`Diagnostics` (which reads
|
||||||
//! [`LogRing::to_text`] and [`LogRing::summary`]) and the uploader in
|
//! [`LogRing::to_text`] and [`LogRing::summary`]) and whatever hands the
|
||||||
//! [`crate::log_upload`] (which reads [`LogRing::since`]). That is why
|
//! log out of the process -- on Android, the `DevLogProvider` Dev Updater
|
||||||
//! reading does not consume: a line the uploader has sent must still be in
|
//! queries, which reads [`LogRing::since`] and [`LogRing::newest_seq`].
|
||||||
//! the report, and a report taken twice must say the same thing.
|
//! That is why reading does not consume: a line already handed over must
|
||||||
|
//! still be in the report, and a report taken twice must say the same
|
||||||
|
//! thing.
|
||||||
|
|
||||||
use std::collections::VecDeque;
|
use std::collections::VecDeque;
|
||||||
use std::sync::{Arc, Mutex, OnceLock};
|
use std::sync::{Arc, Mutex, OnceLock};
|
||||||
@@ -207,6 +209,21 @@ impl LogRing {
|
|||||||
self.with(|inner| inner.dropped)
|
self.with(|inner| inner.dropped)
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// The sequence number of the newest line held, or `None` for a ring
|
||||||
|
/// nothing has been written to.
|
||||||
|
///
|
||||||
|
/// What a reader needs to notice that this process **restarted**: the
|
||||||
|
/// ring is in memory, so a new process starts again at zero, and a
|
||||||
|
/// reader holding a cursor from the previous one would otherwise ask
|
||||||
|
/// for lines after a number nothing will reach for hours and see
|
||||||
|
/// nothing at all -- silently, which is worse than seeing the log
|
||||||
|
/// begin again. Answering `None` rather than 0 for an empty ring is
|
||||||
|
/// the same distinction [`Self::summary`] draws: "nothing has been
|
||||||
|
/// logged" is not a sequence number.
|
||||||
|
pub fn newest_seq(&self) -> Option<u64> {
|
||||||
|
self.with(|inner| inner.lines.back().map(|line| line.seq))
|
||||||
|
}
|
||||||
|
|
||||||
/// When the newest line was written, in unix milliseconds, or `None`
|
/// When the newest line was written, in unix milliseconds, or `None`
|
||||||
/// for a ring nothing has been written to.
|
/// for a ring nothing has been written to.
|
||||||
pub fn last_at_ms(&self) -> Option<u64> {
|
pub fn last_at_ms(&self) -> Option<u64> {
|
||||||
@@ -426,6 +443,24 @@ mod tests {
|
|||||||
assert_eq!(cursor, 4);
|
assert_eq!(cursor, 4);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// The restart signal: a reader that saw sequence 4 and is now told
|
||||||
|
/// the newest is 0 knows the process is not the one it was reading.
|
||||||
|
#[test]
|
||||||
|
fn the_newest_sequence_says_where_the_ring_is_and_nothing_for_an_empty_one() {
|
||||||
|
let ring = LogRing::new(100, 1 << 20);
|
||||||
|
assert_eq!(ring.newest_seq(), None, "an empty ring has no newest line");
|
||||||
|
fill(&ring, 5);
|
||||||
|
assert_eq!(ring.newest_seq(), Some(4));
|
||||||
|
|
||||||
|
let restarted = LogRing::new(100, 1 << 20);
|
||||||
|
fill(&restarted, 1);
|
||||||
|
assert_eq!(
|
||||||
|
restarted.newest_seq(),
|
||||||
|
Some(0),
|
||||||
|
"a fresh ring starts again, which is exactly what a reader has to notice"
|
||||||
|
);
|
||||||
|
}
|
||||||
|
|
||||||
#[test]
|
#[test]
|
||||||
fn reading_does_not_consume() {
|
fn reading_does_not_consume() {
|
||||||
let ring = LogRing::new(100, 1 << 20);
|
let ring = LogRing::new(100, 1 << 20);
|
||||||
|
|||||||
@@ -1,427 +0,0 @@
|
|||||||
//! Sending [`crate::log_ring`]'s lines to `ai-server`, so a phone with no
|
|
||||||
//! `logcat` still has a way for a `log::info!` to reach a person.
|
|
||||||
//!
|
|
||||||
//! **Where they end up**: `POST /client-log` re-emits each line into
|
|
||||||
//! `ai-server`'s own `tracing` output, which Dev Updater already shows as
|
|
||||||
//! that component's *runtime log* (it runs `ai-server` as a `Managed`
|
|
||||||
//! service, and a managed service's stdout is redirected to a file its
|
|
||||||
//! service script reports). So this needs no new route, storage or viewer
|
|
||||||
//! in Dev Updater at all -- see `docs/DECISIONS.md`, 2026-09-07.
|
|
||||||
//!
|
|
||||||
//! **Nothing here calls `log!`.** Every line this module logged would land
|
|
||||||
//! in the ring it is draining and be uploaded, so a server that is down
|
|
||||||
//! would produce a growing conversation with itself. Failures are recorded
|
|
||||||
//! in [`UploadStatus`] instead and shown in the app's diagnostics pane,
|
|
||||||
//! which is where somebody looking for "why is nothing arriving" is
|
|
||||||
//! already looking (UI_RULES.md: a failure is reported where it happened).
|
|
||||||
|
|
||||||
use std::sync::{Arc, Condvar, Mutex};
|
|
||||||
use std::time::Duration;
|
|
||||||
|
|
||||||
use crate::api::{ApiError, Body, Transport};
|
|
||||||
use crate::log_ring::LogRing;
|
|
||||||
|
|
||||||
/// The most lines one request carries. A phone that has been offline for
|
|
||||||
/// an hour has thousands waiting, and one request holding all of them is a
|
|
||||||
/// body the server has to buffer whole; the rest go in the next batch,
|
|
||||||
/// which the loop takes immediately rather than after the next interval.
|
|
||||||
pub const MAX_LINES_PER_BATCH: usize = 500;
|
|
||||||
|
|
||||||
/// How much of one message is sent. Long enough for a stack trace line,
|
|
||||||
/// short enough that one pathological message cannot dominate a batch.
|
|
||||||
/// Truncation is marked, because a silently shortened line reads as a line
|
|
||||||
/// that ended there.
|
|
||||||
pub const MAX_MESSAGE_BYTES: usize = 4096;
|
|
||||||
|
|
||||||
/// The route this posts to, on `server/src/routes.rs`'s surface.
|
|
||||||
pub const CLIENT_LOG_PATH: &str = "/client-log";
|
|
||||||
|
|
||||||
/// What the last upload attempt did, for a diagnostics pane. `None` for
|
|
||||||
/// "nothing has been tried yet", which is deliberately distinct from a
|
|
||||||
/// success that sent nothing.
|
|
||||||
#[derive(Debug, Clone, Default)]
|
|
||||||
pub struct UploadStatus {
|
|
||||||
pub sent: u64,
|
|
||||||
pub last_error: Option<String>,
|
|
||||||
pub attempted: bool,
|
|
||||||
}
|
|
||||||
|
|
||||||
impl UploadStatus {
|
|
||||||
/// One line for the diagnostics pane, in the same voice as
|
|
||||||
/// [`LogRing::summary`].
|
|
||||||
pub fn summary(&self) -> String {
|
|
||||||
match (&self.last_error, self.attempted) {
|
|
||||||
(Some(err), _) => format!("log upload: failing -- {err} ({} sent so far)", self.sent),
|
|
||||||
(None, false) => "log upload: not tried yet".to_string(),
|
|
||||||
(None, true) => format!("log upload: {} lines sent", self.sent),
|
|
||||||
}
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
/// Drains a [`LogRing`] into `POST /client-log`, remembering how far it
|
|
||||||
/// got so a line is sent once and stays in the ring for the report.
|
|
||||||
pub struct LogUploader {
|
|
||||||
ring: LogRing,
|
|
||||||
transport: Arc<dyn Transport>,
|
|
||||||
source: String,
|
|
||||||
cursor: u64,
|
|
||||||
status: Arc<Mutex<UploadStatus>>,
|
|
||||||
}
|
|
||||||
|
|
||||||
impl LogUploader {
|
|
||||||
/// `source` names the build these lines came from -- it is what
|
|
||||||
/// distinguishes them in `ai-server`'s log from the server's own
|
|
||||||
/// lines and from another device's.
|
|
||||||
pub fn new(ring: LogRing, transport: Arc<dyn Transport>, source: impl Into<String>) -> Self {
|
|
||||||
Self {
|
|
||||||
ring,
|
|
||||||
transport,
|
|
||||||
source: source.into(),
|
|
||||||
cursor: 0,
|
|
||||||
status: Arc::new(Mutex::new(UploadStatus::default())),
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
/// A handle on what the last attempt did, shareable with the UI.
|
|
||||||
pub fn status(&self) -> Arc<Mutex<UploadStatus>> {
|
|
||||||
Arc::clone(&self.status)
|
|
||||||
}
|
|
||||||
|
|
||||||
/// Sends up to [`MAX_LINES_PER_BATCH`] waiting lines. Answers how many
|
|
||||||
/// went, and whether more are waiting -- the loop uses the second to
|
|
||||||
/// decide whether to go round again at once.
|
|
||||||
pub fn flush_once(&mut self) -> Result<(usize, bool), ApiError> {
|
|
||||||
let (mut lines, mut next) = self.ring.since(self.cursor);
|
|
||||||
let more = lines.len() > MAX_LINES_PER_BATCH;
|
|
||||||
if more {
|
|
||||||
lines.truncate(MAX_LINES_PER_BATCH);
|
|
||||||
next = lines.last().map(|line| line.seq + 1).unwrap_or(next);
|
|
||||||
}
|
|
||||||
if lines.is_empty() {
|
|
||||||
return Ok((0, false));
|
|
||||||
}
|
|
||||||
|
|
||||||
let body = serde_json::json!({
|
|
||||||
"source": self.source,
|
|
||||||
"lines": lines.iter().map(|line| serde_json::json!({
|
|
||||||
"seq": line.seq,
|
|
||||||
"at": line.at_ms,
|
|
||||||
"level": line.level.as_str(),
|
|
||||||
"target": line.target,
|
|
||||||
"message": truncate(&line.message),
|
|
||||||
})).collect::<Vec<_>>(),
|
|
||||||
});
|
|
||||||
|
|
||||||
let result = self
|
|
||||||
.transport
|
|
||||||
.request("POST", CLIENT_LOG_PATH, Some(Body::Json(body)));
|
|
||||||
let mut status = self.status.lock().unwrap_or_else(|e| e.into_inner());
|
|
||||||
status.attempted = true;
|
|
||||||
match result {
|
|
||||||
Ok(response) if (200..300).contains(&response.status) => {
|
|
||||||
// Only on success: a failed batch is retried from the same
|
|
||||||
// cursor next time, which is what makes a dropped tunnel
|
|
||||||
// cost nothing but a delay.
|
|
||||||
self.cursor = next;
|
|
||||||
status.sent += lines.len() as u64;
|
|
||||||
status.last_error = None;
|
|
||||||
Ok((lines.len(), more))
|
|
||||||
}
|
|
||||||
Ok(response) => {
|
|
||||||
let message = format!("{} from {CLIENT_LOG_PATH}", response.status);
|
|
||||||
status.last_error = Some(message.clone());
|
|
||||||
Err(ApiError {
|
|
||||||
message,
|
|
||||||
status: Some(response.status),
|
|
||||||
})
|
|
||||||
}
|
|
||||||
Err(err) => {
|
|
||||||
status.last_error = Some(err.message.clone());
|
|
||||||
Err(err)
|
|
||||||
}
|
|
||||||
}
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
/// Cuts a message to [`MAX_MESSAGE_BYTES`] on a character boundary, saying
|
|
||||||
/// so, rather than letting one line dominate a batch.
|
|
||||||
fn truncate(message: &str) -> String {
|
|
||||||
if message.len() <= MAX_MESSAGE_BYTES {
|
|
||||||
return message.to_string();
|
|
||||||
}
|
|
||||||
let mut end = MAX_MESSAGE_BYTES;
|
|
||||||
while end > 0 && !message.is_char_boundary(end) {
|
|
||||||
end -= 1;
|
|
||||||
}
|
|
||||||
format!("{}… [{} bytes cut]", &message[..end], message.len() - end)
|
|
||||||
}
|
|
||||||
|
|
||||||
/// The background half: a thread that flushes on a timer and on demand.
|
|
||||||
///
|
|
||||||
/// Its path out is [`Drop`] -- dropping the handle stops the thread and
|
|
||||||
/// waits for it, so an app that tears the uploader down does not leave one
|
|
||||||
/// posting behind it.
|
|
||||||
pub struct LogUpload {
|
|
||||||
signal: Arc<(Mutex<Signal>, Condvar)>,
|
|
||||||
thread: Option<std::thread::JoinHandle<()>>,
|
|
||||||
status: Arc<Mutex<UploadStatus>>,
|
|
||||||
}
|
|
||||||
|
|
||||||
/// Only "stop": a nudge from [`LogUpload::flush_now`] needs no flag,
|
|
||||||
/// because the thread's reaction to waking is to flush, and flushing an
|
|
||||||
/// empty ring costs nothing -- so a spurious wakeup is already correct.
|
|
||||||
#[derive(Default)]
|
|
||||||
struct Signal {
|
|
||||||
stop: bool,
|
|
||||||
}
|
|
||||||
|
|
||||||
impl LogUpload {
|
|
||||||
/// Starts the loop. `every` is how long it waits between flushes when
|
|
||||||
/// nobody nudges it -- a compromise between a line arriving promptly
|
|
||||||
/// and a radio the app woke for one line.
|
|
||||||
pub fn spawn(
|
|
||||||
ring: LogRing,
|
|
||||||
transport: Arc<dyn Transport>,
|
|
||||||
source: impl Into<String>,
|
|
||||||
every: Duration,
|
|
||||||
) -> Self {
|
|
||||||
let mut uploader = LogUploader::new(ring, transport, source);
|
|
||||||
let status = uploader.status();
|
|
||||||
let signal = Arc::new((Mutex::new(Signal::default()), Condvar::new()));
|
|
||||||
let thread = {
|
|
||||||
let signal = Arc::clone(&signal);
|
|
||||||
std::thread::Builder::new()
|
|
||||||
.name("client-log-upload".into())
|
|
||||||
.spawn(move || {
|
|
||||||
loop {
|
|
||||||
// Keep going while a batch was capped, so a
|
|
||||||
// backlog drains at once rather than one batch per
|
|
||||||
// interval.
|
|
||||||
while let Ok((_, more)) = uploader.flush_once() {
|
|
||||||
if !more {
|
|
||||||
break;
|
|
||||||
}
|
|
||||||
}
|
|
||||||
let (lock, condvar) = &*signal;
|
|
||||||
let state = lock.lock().unwrap_or_else(|e| e.into_inner());
|
|
||||||
if state.stop {
|
|
||||||
return;
|
|
||||||
}
|
|
||||||
let (state, _) = condvar
|
|
||||||
.wait_timeout(state, every)
|
|
||||||
.unwrap_or_else(|e| e.into_inner());
|
|
||||||
if state.stop {
|
|
||||||
return;
|
|
||||||
}
|
|
||||||
}
|
|
||||||
})
|
|
||||||
.expect("spawning the log upload thread")
|
|
||||||
};
|
|
||||||
Self {
|
|
||||||
signal,
|
|
||||||
thread: Some(thread),
|
|
||||||
status,
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
/// Sends what is waiting now -- what `Copy report` calls, so the lines
|
|
||||||
/// a person is about to describe are already on the server.
|
|
||||||
pub fn flush_now(&self) {
|
|
||||||
let (lock, condvar) = &*self.signal;
|
|
||||||
let _state = lock.lock().unwrap_or_else(|e| e.into_inner());
|
|
||||||
condvar.notify_all();
|
|
||||||
}
|
|
||||||
|
|
||||||
pub fn status(&self) -> UploadStatus {
|
|
||||||
self.status
|
|
||||||
.lock()
|
|
||||||
.unwrap_or_else(|e| e.into_inner())
|
|
||||||
.clone()
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
impl Drop for LogUpload {
|
|
||||||
fn drop(&mut self) {
|
|
||||||
{
|
|
||||||
let (lock, condvar) = &*self.signal;
|
|
||||||
let mut state = lock.lock().unwrap_or_else(|e| e.into_inner());
|
|
||||||
state.stop = true;
|
|
||||||
condvar.notify_all();
|
|
||||||
}
|
|
||||||
if let Some(thread) = self.thread.take() {
|
|
||||||
let _ = thread.join();
|
|
||||||
}
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
#[cfg(test)]
|
|
||||||
mod tests {
|
|
||||||
use super::*;
|
|
||||||
use crate::api::RawResponse;
|
|
||||||
use log::Level;
|
|
||||||
|
|
||||||
/// Records every body posted, and answers whatever status the test set.
|
|
||||||
struct Fake {
|
|
||||||
posted: Mutex<Vec<serde_json::Value>>,
|
|
||||||
status: Mutex<u16>,
|
|
||||||
}
|
|
||||||
|
|
||||||
impl Fake {
|
|
||||||
fn new() -> Arc<Self> {
|
|
||||||
Arc::new(Self {
|
|
||||||
posted: Mutex::new(Vec::new()),
|
|
||||||
status: Mutex::new(200),
|
|
||||||
})
|
|
||||||
}
|
|
||||||
fn bodies(&self) -> Vec<serde_json::Value> {
|
|
||||||
self.posted.lock().unwrap().clone()
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
impl Transport for Fake {
|
|
||||||
fn request(
|
|
||||||
&self,
|
|
||||||
method: &str,
|
|
||||||
path: &str,
|
|
||||||
body: Option<Body>,
|
|
||||||
) -> Result<RawResponse, ApiError> {
|
|
||||||
assert_eq!(method, "POST");
|
|
||||||
assert_eq!(path, CLIENT_LOG_PATH);
|
|
||||||
if let Some(Body::Json(value)) = body {
|
|
||||||
self.posted.lock().unwrap().push(value);
|
|
||||||
} else {
|
|
||||||
panic!("the client log is posted as JSON");
|
|
||||||
}
|
|
||||||
Ok(RawResponse {
|
|
||||||
status: *self.status.lock().unwrap(),
|
|
||||||
body: Vec::new(),
|
|
||||||
})
|
|
||||||
}
|
|
||||||
fn stream(&self, _path: &str) -> Result<Box<dyn std::io::Read + Send>, ApiError> {
|
|
||||||
unreachable!("the log uploader never streams")
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
fn ring_with(count: usize) -> LogRing {
|
|
||||||
let ring = LogRing::with_defaults();
|
|
||||||
for n in 0..count {
|
|
||||||
ring.push(Level::Info, "t", format!("line {n}"));
|
|
||||||
}
|
|
||||||
ring
|
|
||||||
}
|
|
||||||
|
|
||||||
#[test]
|
|
||||||
fn an_empty_ring_posts_nothing() {
|
|
||||||
let fake = Fake::new();
|
|
||||||
let mut uploader = LogUploader::new(LogRing::with_defaults(), fake.clone(), "test");
|
|
||||||
assert_eq!(uploader.flush_once().unwrap(), (0, false));
|
|
||||||
assert!(
|
|
||||||
fake.bodies().is_empty(),
|
|
||||||
"no request at all, not an empty one"
|
|
||||||
);
|
|
||||||
}
|
|
||||||
|
|
||||||
#[test]
|
|
||||||
fn a_line_is_sent_once() {
|
|
||||||
let fake = Fake::new();
|
|
||||||
let ring = ring_with(3);
|
|
||||||
let mut uploader = LogUploader::new(ring.clone(), fake.clone(), "test");
|
|
||||||
assert_eq!(uploader.flush_once().unwrap().0, 3);
|
|
||||||
assert_eq!(
|
|
||||||
uploader.flush_once().unwrap(),
|
|
||||||
(0, false),
|
|
||||||
"nothing repeats"
|
|
||||||
);
|
|
||||||
|
|
||||||
ring.push(Level::Warn, "t", "later".into());
|
|
||||||
assert_eq!(uploader.flush_once().unwrap().0, 1);
|
|
||||||
assert_eq!(fake.bodies().len(), 2);
|
|
||||||
assert_eq!(ring.len(), 4, "and the report still holds all of them");
|
|
||||||
}
|
|
||||||
|
|
||||||
/// The half the change had no reason to touch: a server that refuses
|
|
||||||
/// must not lose the lines.
|
|
||||||
#[test]
|
|
||||||
fn a_failed_batch_is_retried_from_the_same_place() {
|
|
||||||
let fake = Fake::new();
|
|
||||||
*fake.status.lock().unwrap() = 503;
|
|
||||||
let mut uploader = LogUploader::new(ring_with(2), fake.clone(), "test");
|
|
||||||
assert!(uploader.flush_once().is_err());
|
|
||||||
assert!(
|
|
||||||
uploader.status().lock().unwrap().last_error.is_some(),
|
|
||||||
"and it says why, where somebody can see it"
|
|
||||||
);
|
|
||||||
|
|
||||||
*fake.status.lock().unwrap() = 200;
|
|
||||||
assert_eq!(uploader.flush_once().unwrap().0, 2, "the same two lines");
|
|
||||||
assert!(uploader.status().lock().unwrap().last_error.is_none());
|
|
||||||
}
|
|
||||||
|
|
||||||
#[test]
|
|
||||||
fn a_backlog_is_capped_per_batch_and_says_there_is_more() {
|
|
||||||
let fake = Fake::new();
|
|
||||||
let ring = LogRing::new(MAX_LINES_PER_BATCH * 3, 1 << 30);
|
|
||||||
for n in 0..(MAX_LINES_PER_BATCH + 7) {
|
|
||||||
ring.push(Level::Info, "t", format!("{n}"));
|
|
||||||
}
|
|
||||||
let mut uploader = LogUploader::new(ring, fake.clone(), "test");
|
|
||||||
assert_eq!(uploader.flush_once().unwrap(), (MAX_LINES_PER_BATCH, true));
|
|
||||||
assert_eq!(uploader.flush_once().unwrap(), (7, false));
|
|
||||||
}
|
|
||||||
|
|
||||||
#[test]
|
|
||||||
fn the_body_carries_the_source_and_each_line_whole() {
|
|
||||||
let fake = Fake::new();
|
|
||||||
let ring = LogRing::with_defaults();
|
|
||||||
ring.push(Level::Error, "iris::android", "surface lost".into());
|
|
||||||
LogUploader::new(ring, fake.clone(), "iris-bench 1.2")
|
|
||||||
.flush_once()
|
|
||||||
.unwrap();
|
|
||||||
let body = &fake.bodies()[0];
|
|
||||||
assert_eq!(body["source"], "iris-bench 1.2");
|
|
||||||
let line = &body["lines"][0];
|
|
||||||
assert_eq!(line["level"], "ERROR");
|
|
||||||
assert_eq!(line["target"], "iris::android");
|
|
||||||
assert_eq!(line["message"], "surface lost");
|
|
||||||
assert!(line["at"].as_u64().is_some(), "the app's own clock");
|
|
||||||
}
|
|
||||||
|
|
||||||
#[test]
|
|
||||||
fn an_enormous_message_is_cut_and_says_so() {
|
|
||||||
let cut = truncate(&"x".repeat(MAX_MESSAGE_BYTES + 100));
|
|
||||||
assert!(cut.starts_with("xxxx"));
|
|
||||||
assert!(cut.contains("bytes cut"), "{cut}");
|
|
||||||
assert!(cut.len() < MAX_MESSAGE_BYTES + 64);
|
|
||||||
let short = truncate("fine");
|
|
||||||
assert_eq!(short, "fine", "a short message is untouched");
|
|
||||||
}
|
|
||||||
|
|
||||||
#[test]
|
|
||||||
fn the_status_line_distinguishes_untried_from_sent_nothing() {
|
|
||||||
let untried = UploadStatus::default();
|
|
||||||
assert_eq!(untried.summary(), "log upload: not tried yet");
|
|
||||||
let sent_none = UploadStatus {
|
|
||||||
attempted: true,
|
|
||||||
..Default::default()
|
|
||||||
};
|
|
||||||
assert_eq!(sent_none.summary(), "log upload: 0 lines sent");
|
|
||||||
}
|
|
||||||
|
|
||||||
/// The path out: dropping the handle must stop the thread, not leave
|
|
||||||
/// it posting.
|
|
||||||
#[test]
|
|
||||||
fn dropping_the_handle_stops_the_thread() {
|
|
||||||
let fake = Fake::new();
|
|
||||||
let upload = LogUpload::spawn(
|
|
||||||
ring_with(1),
|
|
||||||
fake.clone(),
|
|
||||||
"test",
|
|
||||||
Duration::from_millis(10),
|
|
||||||
);
|
|
||||||
upload.flush_now();
|
|
||||||
drop(upload);
|
|
||||||
let after = fake.bodies().len();
|
|
||||||
std::thread::sleep(Duration::from_millis(60));
|
|
||||||
assert_eq!(fake.bodies().len(), after, "nothing posted after the drop");
|
|
||||||
}
|
|
||||||
}
|
|
||||||
+61
-2
@@ -46,7 +46,61 @@ marked **DEFERRED** are ones the agent chose not to decide alone.
|
|||||||
unaffected (still resolves monospace correctly, confirmed unchanged).
|
unaffected (still resolves monospace correctly, confirmed unchanged).
|
||||||
docs/RUST.md's "Platform fonts (2026-09-07)" has the full account.
|
docs/RUST.md's "Platform fonts (2026-09-07)" has the full account.
|
||||||
|
|
||||||
## 2026-09-07 (how a phone log reaches Iris)
|
## 2026-09-07 (a phone log reaches Iris through Dev Updater's own tab)
|
||||||
|
|
||||||
|
**Supersedes the "how a phone log reaches Iris" entry below, same day.**
|
||||||
|
Iris's call once the route was working: put it in Dev Updater properly
|
||||||
|
rather than smuggling the lines through `ai-server`'s log.
|
||||||
|
|
||||||
|
- **The app exposes its own log on the device, and Dev Updater reads it
|
||||||
|
there.** A `ContentProvider` at `<applicationId>.devlog`, one table of
|
||||||
|
lines queried with `?since=<seq>` so a poll is incremental, plus a
|
||||||
|
`status` row (`held`, `dropped`, `newest_seq`). Dev Updater's phone app
|
||||||
|
polls it while the component's **Runtime** tab is open and forwards what
|
||||||
|
is new to its own build machine, into that APK component's runtime log
|
||||||
|
-- so the same tab renders both kinds and the history outlives the
|
||||||
|
phone. No tunnel, no token, no second enrolment: the two apps are on the
|
||||||
|
same phone.
|
||||||
|
|
||||||
|
**It is a contract, not a feature for iris.** Written down in
|
||||||
|
dev-updater's `README.md` ("An app's own log"), so any app that server
|
||||||
|
delivers gets the tab by implementing it; the Compose app in `app/` can
|
||||||
|
do the same later. That is the reason it beat the route below on its
|
||||||
|
second look -- the earlier one only ever worked for the one project that
|
||||||
|
had a server, and put a phone's lines under a *different component* than
|
||||||
|
the one they came from.
|
||||||
|
|
||||||
|
- **Read access is `protectionLevel="normal"`, and that is a real trade.**
|
||||||
|
`signature` is what this wants and is not available: Dev 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. What `normal` costs is that any app on that phone which
|
||||||
|
requests `dev.updater.permission.READ_DEVLOG` by name can read another
|
||||||
|
app's dev log. Accepted because these are development builds on a
|
||||||
|
development phone and the alternative was no log; stated in the manifest
|
||||||
|
beside the declaration and in dev-updater's README so it is not
|
||||||
|
rediscovered as a surprise.
|
||||||
|
|
||||||
|
- **The provider polls rather than notifying.** `notifyChange` was not
|
||||||
|
implemented: the ring is filled by a `log::Log` backend on whatever
|
||||||
|
thread logged, and giving that a route to a `ContentProvider` means
|
||||||
|
plumbing a callback through `client-core` for every platform. Dev
|
||||||
|
Updater's contract therefore says it polls (about a second, only while
|
||||||
|
the tab is open), which is what keeps implementing the contract cheap --
|
||||||
|
a provider that does notify loses nothing.
|
||||||
|
|
||||||
|
- **What was deleted, so there is one mechanism**: `client-core`'s
|
||||||
|
`log_upload` module, `POST /client-log` on `ai-server`, the
|
||||||
|
`AI_APP_LOG_HOST`/`_PORT`/`_TOKEN` baking in `iris/android-app/build.rs`
|
||||||
|
(which left that file with nothing to do, so it is gone too), and the
|
||||||
|
uploader fields on both Android clients. Kept: the ring, `RingLogger`,
|
||||||
|
`install_process_logger`, and the Diagnostics line counting what is
|
||||||
|
held. The upload-status line there is now **"devlog provider:
|
||||||
|
content://<authority>"** -- named from what the provider registered
|
||||||
|
rather than composed from the package here, so a screenshot of that pane
|
||||||
|
is evidence the contract is live and says which package's log it is.
|
||||||
|
|
||||||
|
## 2026-09-07 (how a phone log reaches Iris) -- superseded, see above
|
||||||
|
|
||||||
- **The app sends its own log to `ai-server`, and Dev Updater shows it as
|
- **The app sends its own log to `ai-server`, and Dev Updater shows it as
|
||||||
`ai-server`'s runtime log.** Iris has no `adb`/`logcat` on her phone, and
|
`ai-server`'s runtime log.** Iris has no `adb`/`logcat` on her phone, and
|
||||||
@@ -60,7 +114,9 @@ marked **DEFERRED** are ones the agent chose not to decide alone.
|
|||||||
component. So **no change to Dev Updater at all** -- one route on
|
component. So **no change to Dev Updater at all** -- one route on
|
||||||
`ai-server`, and the client in `client-core`.
|
`ai-server`, and the client in `client-core`.
|
||||||
|
|
||||||
**Rejected: posting to Dev Updater's own server** (the first candidate).
|
**Rejected: posting to Dev Updater's own server** (the first candidate,
|
||||||
|
and what the entry above went on to build -- the estimate below was
|
||||||
|
right about the work and wrong about it being too much).
|
||||||
It would need a new authenticated *write* route on a TLS surface whose
|
It would need a new authenticated *write* route on a TLS surface whose
|
||||||
module doc says every route on it "is, or decides, the bytes that get
|
module doc says every route on it "is, or decides, the bytes that get
|
||||||
handed to `REQUEST_INSTALL_PACKAGES` next"; a per-app device-log store;
|
handed to `REQUEST_INSTALL_PACKAGES` next"; a per-app device-log store;
|
||||||
@@ -90,6 +146,9 @@ marked **DEFERRED** are ones the agent chose not to decide alone.
|
|||||||
|
|
||||||
- **The destination is baked in at build time, from the build machine's
|
- **The destination is baked in at build time, from the build machine's
|
||||||
own files** (`AI_APP_LOG_HOST`/`_PORT`/`_TOKEN` plus the pinned CA) --
|
own files** (`AI_APP_LOG_HOST`/`_PORT`/`_TOKEN` plus the pinned CA) --
|
||||||
|
*gone; the provider above replaced it.* What is worth keeping from it is
|
||||||
|
the reason it went: an APK good only for the server that built it cannot
|
||||||
|
be built in this VM for Iris's phone, which is the case that mattered.
|
||||||
all three or none, never two. The same trust boundary the transcript
|
all three or none, never two. The same trust boundary the transcript
|
||||||
config and the Compose APK's CA already use: nothing secret is
|
config and the Compose APK's CA already use: nothing secret is
|
||||||
committed, and an APK is good for the server that built it. A build told
|
committed, and an APK is good for the server that built it. A build told
|
||||||
|
|||||||
+19
-12
@@ -46,10 +46,9 @@ scrolling never consults the one in `ViewConfiguration`.
|
|||||||
## 2026-09-07: `client-core` carries the app's own log
|
## 2026-09-07: `client-core` carries the app's own log
|
||||||
|
|
||||||
Not iris itself but the crate beside it, and it is a new public surface an
|
Not iris itself but the crate beside it, and it is a new public surface an
|
||||||
app author will use: `client_core::log_ring` and `client_core::log_upload`.
|
app author will use: `client_core::log_ring`. Because Iris's phone has no
|
||||||
Because Iris's phone has no `logcat`, an app now keeps a bounded copy of
|
`logcat`, an app now keeps a bounded copy of its own log and hands it to
|
||||||
its own log and can send it to `ai-server`, where Dev Updater already
|
Dev Updater on the device.
|
||||||
shows it.
|
|
||||||
|
|
||||||
Before, an app installed a platform logger and that was the end of it:
|
Before, an app installed a platform logger and that was the end of it:
|
||||||
|
|
||||||
@@ -68,17 +67,25 @@ what they saw before:
|
|||||||
ring.to_text(); // for a report
|
ring.to_text(); // for a report
|
||||||
ring.summary(); // "1801 lines held, 12 dropped, last 20:09:24"
|
ring.summary(); // "1801 lines held, 12 dropped, last 20:09:24"
|
||||||
|
|
||||||
// and, where the app has a server:
|
// and, for whatever hands the log out of the process:
|
||||||
let upload = LogUpload::spawn(ring.clone(), transport, "iris-bench", Duration::from_secs(10));
|
let (lines, next) = ring.since(cursor); // inclusive of `cursor`
|
||||||
upload.flush_now(); // what `Copy report` calls
|
ring.newest_seq(); // None for a ring nothing was written to
|
||||||
upload.status().summary(); // "not tried yet" / "failing -- <why>" / "N lines sent"
|
|
||||||
|
|
||||||
`process_ring` is a deliberate process-global, unusually for this project:
|
`process_ring` is a deliberate process-global, unusually for this project:
|
||||||
`log` already has exactly one backend per process, and a ring passed around
|
`log` already has exactly one backend per process, and a ring passed around
|
||||||
as a parameter would be a second answer to "which lines exist". Dropping
|
as a parameter would be a second answer to "which lines exist".
|
||||||
the `LogUpload` handle stops and joins its thread. The wire format is one
|
|
||||||
new route on `ai-server`, `POST /client-log`; the reasoning and the
|
**Amended later the same day.** `client_core::log_upload` and
|
||||||
rejected alternatives are in docs/DECISIONS.md, 2026-09-07.
|
`ai-server`'s `POST /client-log` are **gone** -- an app no longer sends
|
||||||
|
its log anywhere. It exposes it on the device instead, and Dev Updater
|
||||||
|
reads it there: on Android that is a `ContentProvider` at
|
||||||
|
`<applicationId>.devlog`, which is Dev Updater's own contract (its
|
||||||
|
`README.md`, "An app's own log") rather than anything iris-specific.
|
||||||
|
`LogRing::newest_seq()` is the one addition that went with it: a reader
|
||||||
|
holding a cursor uses it to notice the process **restarted**, since the
|
||||||
|
ring is in memory and a new process starts again at sequence zero.
|
||||||
|
The reasoning and the rejected alternatives are in docs/DECISIONS.md,
|
||||||
|
2026-09-07.
|
||||||
|
|
||||||
## 2026-09-07: `TextData` no longer bundles a font
|
## 2026-09-07: `TextData` no longer bundles a font
|
||||||
|
|
||||||
|
|||||||
+91
-78
@@ -89,83 +89,77 @@ Three things this says about the rig, since the rig is new:
|
|||||||
claimed of it -- asserted at the end of every draw, and the test
|
claimed of it -- asserted at the end of every draw, and the test
|
||||||
checks both directions.
|
checks both directions.
|
||||||
|
|
||||||
### Phone logging, 2026-09-07 (built and verified end to end)
|
### Phone logging, 2026-09-07 (rebuilt on Dev Updater's own tab)
|
||||||
|
|
||||||
**The problem**: Iris tests these builds on a phone with no `adb`, and
|
**The problem**: Iris tests these builds on a phone with no `adb`, and
|
||||||
Android forbids one app reading another's `logcat`, so a `log::info!` in
|
Android forbids one app reading another's `logcat`, so a `log::info!` in
|
||||||
the iris app could not reach her at all. What she asked for was Dev
|
the iris app could not reach her at all. What she asked for was Dev
|
||||||
Updater, which she already reads.
|
Updater, which she already reads.
|
||||||
|
|
||||||
**The route, in one line**: the app keeps its own bounded log ring, posts
|
**The route, in one line**: the app keeps its own bounded log ring and
|
||||||
it to `ai-server`, and `ai-server` re-emits each line into its own
|
**exposes it on the device** through a `ContentProvider`; Dev Updater's
|
||||||
`tracing` output -- which Dev Updater *already* shows as that component's
|
phone app -- on the same phone -- reads that while the component's
|
||||||
**runtime log**, because it runs `ai-server` as a `Managed` service and
|
**Runtime** tab is open and forwards what is new to its own build machine,
|
||||||
that service's script redirects stdout to
|
into that APK component's runtime log. No tunnel, no token, no second
|
||||||
`$XDG_DATA_HOME/dev-updater/services/<key>-<component>/<...>.log` and
|
enrolment.
|
||||||
reports the path. **Nothing in dev-updater changed.** The alternatives and
|
|
||||||
what each would have cost are in docs/DECISIONS.md.
|
**It is Dev Updater's contract, not iris's feature.** Written down in
|
||||||
|
dev-updater's `README.md` under "An app's own log", so any app that server
|
||||||
|
delivers gets the tab by implementing it. The shape:
|
||||||
|
|
||||||
|
| | |
|
||||||
|
|---|---|
|
||||||
|
| authority | `<applicationId>.devlog` |
|
||||||
|
| read permission | `dev.updater.permission.READ_DEVLOG` (`android:readPermission`) |
|
||||||
|
| `lines?since=<seq>` | held lines with `seq >= since`, ascending: `seq, t_ms, level, target, message` |
|
||||||
|
| `status` | one row: `held, dropped, newest_seq` |
|
||||||
|
|
||||||
|
`newest_seq` is `-1` for an empty ring and is what makes a **restart**
|
||||||
|
visible: the ring is in memory, so a new process starts again at zero and
|
||||||
|
a reader holding a cursor would otherwise skip everything since, silently.
|
||||||
|
`insert`/`update`/`delete` throw. `notifyChange` is **not** implemented --
|
||||||
|
the ring is filled by a `log::Log` backend on whatever thread logged, and
|
||||||
|
routing that to a provider means a callback through `client-core` for
|
||||||
|
every platform, so Dev Updater polls (about a second, only while the tab
|
||||||
|
is open) and the contract says so.
|
||||||
|
|
||||||
What exists now:
|
What exists now:
|
||||||
|
|
||||||
- `client_core::log_ring` -- `LogRing` (2000 lines / 256 KiB, whichever
|
- `client_core::log_ring` -- `LogRing` (2000 lines / 256 KiB, whichever
|
||||||
bites first, with `dropped` reported rather than inferred), `RingLogger`
|
bites first, with `dropped` reported rather than inferred), `since(seq)`,
|
||||||
(a `log::Log` backend that records *and* forwards to the platform's own
|
`newest_seq()`, `RingLogger` (a `log::Log` backend that records *and*
|
||||||
logger), and `install_process_logger`. Reading does not consume, so the
|
forwards to the platform's own logger), and `install_process_logger`.
|
||||||
report and the uploader are two readers of one ring.
|
Reading does not consume, so the report and the provider are two readers
|
||||||
- `client_core::log_upload` -- `LogUploader::flush_once` (batched at 500
|
of one ring.
|
||||||
lines, retried from the same cursor on failure) and `LogUpload::spawn`
|
- `iris/android-app/src/devlog.rs` and
|
||||||
(a thread flushing every 10s, stopped by dropping the handle).
|
`app/src/main/java/dev/iris/android/demo/DevLogProvider.java` -- the
|
||||||
**Nothing in it calls `log!`**: those lines would land in the ring it is
|
platform glue only (the sharing rule): a `String[]` across JNI, a
|
||||||
draining.
|
`MatrixCursor` on the Java side, and `nativeReady` telling Rust the
|
||||||
- `POST /client-log` on `ai-server` -- `{source, lines:[{seq, at, level,
|
authority the provider actually registered under.
|
||||||
target, message}]}`, re-emitted at the client's own level under the
|
- `iris/android-app/src/app_log.rs` -- `android_logger` as the logger to
|
||||||
target **`ai_server::client_log`**. Under the crate's path deliberately:
|
forward to, and the Diagnostics pane's two lines: how many lines are
|
||||||
a bare `client_log` target is dropped by `RUST_LOG=ai_server=debug`, the
|
held, and **`devlog provider: content://<authority>`** (or "declared,
|
||||||
filter AGENTS.md tells people to run with, so every line a phone sent
|
not created yet", since Android creates a provider lazily). Named from
|
||||||
vanished with nothing saying so. Found by running it.
|
what the provider registered rather than composed from the package here,
|
||||||
- `iris/android-app/src/app_log.rs` -- the platform half only:
|
so a screenshot of that pane is evidence the contract is live.
|
||||||
`android_logger` as the logger to forward to, and the destination baked
|
- On the Dev Updater side (its own repo, commit `013d711`): the tab for
|
||||||
in by `build.rs` from `AI_APP_LOG_HOST`/`_PORT`/`_TOKEN` plus the pinned
|
every component rather than only a server's, `DevLog.kt`'s reader and
|
||||||
CA (all three or none). `Copy report` appends the ring to the clipboard
|
cursor, `POST /apps/{key}/components/{name}/runtime-log`, and
|
||||||
text and flushes the uploader first; `Diagnostics` gains two lines --
|
`$XDG_DATA_HOME/dev-updater/devlogs/<key>-<component>.log` with one
|
||||||
how many lines are held and when the last arrived, and what the uploader
|
rotation at 4 MiB.
|
||||||
last did.
|
|
||||||
|
|
||||||
**Superseded 2026-09-07, and left standing rather than edited**: Dev
|
**Deleted with it, so there is one mechanism**: `client-core`'s
|
||||||
Updater is growing an on-device runtime-log reader, so this whole route --
|
`log_upload`, `POST /client-log` on `ai-server`, the `AI_APP_LOG_*` baking
|
||||||
`log_upload`, `POST /client-log` and the `AI_APP_LOG_*` baking -- is being
|
in `iris/android-app/build.rs` (which left that file with nothing to do,
|
||||||
removed rather than kept current. The app's *server* destination no longer
|
so it is gone), and the uploader fields on both Android clients.
|
||||||
comes from any of it: that is the enrolment link (the queue item above).
|
|
||||||
What follows describes the route as built.
|
|
||||||
|
|
||||||
**How to use it.** Build the APK with the destination in the environment,
|
**How to use it.** Build and install the bench APK; open Dev Updater ->
|
||||||
on the machine `ai-server` runs on:
|
the ai-app project -> the **app** component's log button -> the
|
||||||
|
**Runtime** tab. Nothing to configure: the tab finds the provider from the
|
||||||
|
package the component installs. A component whose package exposes none
|
||||||
|
says so in as many words, which is a different sentence from an empty log.
|
||||||
|
|
||||||
AI_APP_LOG_HOST=10.66.0.1 AI_APP_LOG_PORT=8443 \
|
**Verified 2026-09-07 end to end** -- see "Verified" below.
|
||||||
AI_APP_LOG_TOKEN=<a token that server accepts> \
|
|
||||||
./build-apk.sh release
|
|
||||||
|
|
||||||
Then read it on the phone: Dev Updater -> the ai-app project -> the
|
|
||||||
**server** component's log button -> the **Runtime** tab. The app's lines
|
|
||||||
are the ones tagged `ai_server::client_log`, each carrying `[<source>
|
|
||||||
<the app's own clock> #<seq>]` before the target and message. A build with
|
|
||||||
none of those variables set still keeps its ring and still puts it on the
|
|
||||||
clipboard from `Copy report`; the Diagnostics pane says so in as many
|
|
||||||
words.
|
|
||||||
|
|
||||||
**Verified 2026-09-07, all four hops.** ai-server on 127.0.0.1:8455 with a
|
|
||||||
scratch config; the bench APK built `--abi x86_64` with
|
|
||||||
`AI_APP_LOG_HOST=10.0.2.2 AI_APP_LOG_PORT=8455 AI_APP_LOG_TOKEN=...`;
|
|
||||||
installed and launched on this checkout's emulator. Twenty seconds later
|
|
||||||
the server's log held
|
|
||||||
|
|
||||||
INFO ai_server::client_log: [iris-bench 20:17:02.284 #0]
|
|
||||||
iris::android::view: iris: new_peer content_scale=2.625
|
|
||||||
|
|
||||||
and a scratch `dev-updater` (port 8492, `XDG_DATA_HOME=/tmp/du-test/data`)
|
|
||||||
with this checkout registered served exactly those lines back from
|
|
||||||
`GET /apps/ai-app-2/components/server/logs?kind=runtime` -- which is the
|
|
||||||
JSON the phone's Runtime tab renders.
|
|
||||||
|
|
||||||
**Two rig traps this cost an hour to find, both in `build-apk.sh`, both
|
**Two rig traps this cost an hour to find, both in `build-apk.sh`, both
|
||||||
still there.** Written down rather than fixed because fixing them belongs
|
still there.** Written down rather than fixed because fixing them belongs
|
||||||
@@ -193,7 +187,9 @@ Also: the bench APK's package is `dev.iris.android.demo.bench`, not
|
|||||||
`dev.iris.android.demo`. An older non-bench build left installed answers
|
`dev.iris.android.demo`. An older non-bench build left installed answers
|
||||||
to the second name, runs, looks right, and reports whatever *it* was built
|
to the second name, runs, looks right, and reports whatever *it* was built
|
||||||
with -- which is how "log upload: this build has no server configured"
|
with -- which is how "log upload: this build has no server configured"
|
||||||
came from a build that had one.
|
came from a build that had one. The devlog authority carries the
|
||||||
|
`applicationId` for exactly that reason: the two packages each get their
|
||||||
|
own and neither can read the other's log.
|
||||||
|
|
||||||
### `iris::input`/`iris::frame` diagnostics, 2026-09-07
|
### `iris::input`/`iris::frame` diagnostics, 2026-09-07
|
||||||
|
|
||||||
@@ -263,11 +259,15 @@ unconditionally `true` by design ("the ring wants everything"), so a
|
|||||||
`log::Level::Debug` line reaches the ring regardless of what this
|
`log::Level::Debug` line reaches the ring regardless of what this
|
||||||
instrument would prefer -- the gate has to be a crate-level flag, checked
|
instrument would prefer -- the gate has to be a crate-level flag, checked
|
||||||
before `log::debug!` is even reached, and that is what `trace_enabled()`
|
before `log::debug!` is even reached, and that is what `trace_enabled()`
|
||||||
is. **Not wired to a button yet**: the Diagnostics pane that would hold
|
is. **The switch is the bench header's fourth control**, beside Run
|
||||||
the switch is in `iris/android-app/src/bench_client.rs`, which another
|
benchmark / Copy report / Diagnostics: it reads `Trace off` or `Trace on`,
|
||||||
agent had open at the same time this was written; `set_trace` is the whole
|
because a toggle whose own appearance never changes is a button that looks
|
||||||
surface a control needs, so wiring one is a follow-up for whoever is free
|
like it did nothing. Its accessibility label stays the fixed `Trace input
|
||||||
to touch that file next.
|
and frames` -- that is what `run-bench.sh` and `ui-trace --do "tap '...'"`
|
||||||
|
find it by, and a control that renames itself when pressed is one no
|
||||||
|
script can find twice. Pressing it rebuilds the header (the same
|
||||||
|
`bench_controls` path `on_insets_changed` already uses) and shows the
|
||||||
|
diagnostics pane, so the state is on screen at the moment of the press.
|
||||||
|
|
||||||
**Why default off, and why the ring's size is the actual constraint**: the
|
**Why default off, and why the ring's size is the actual constraint**: the
|
||||||
ring is 2000 lines / 256 KiB
|
ring is 2000 lines / 256 KiB
|
||||||
@@ -277,8 +277,12 @@ seconds, so a caller turns tracing on only for the length of whatever is
|
|||||||
being investigated, not for a whole session. This is also why the report
|
being investigated, not for a whole session. This is also why the report
|
||||||
should say at its top whether tracing was on -- a caller reading
|
should say at its top whether tracing was on -- a caller reading
|
||||||
`iris::diagnostics::trace_enabled()` when building the report can print
|
`iris::diagnostics::trace_enabled()` when building the report can print
|
||||||
that; nothing here does it automatically since nothing here owns the
|
that. Both reports do: `bench_client::trace_line` is the one wording, and
|
||||||
report's own header.
|
it takes the flag **read at the start of the run as well as at the end**,
|
||||||
|
so a switch flipped half way through is reported as exactly that rather
|
||||||
|
than as a confident "on" about a log covering half the run. Three states,
|
||||||
|
because that third one happens -- the switch is on screen while a
|
||||||
|
benchmark runs.
|
||||||
|
|
||||||
**D1 from `docs/REVIEW-2026-09-07.md`**: the review found that this gate
|
**D1 from `docs/REVIEW-2026-09-07.md`**: the review found that this gate
|
||||||
existed (as `iris/src/diagnostics.rs`, uncommitted at the time) but four
|
existed (as `iris/src/diagnostics.rs`, uncommitted at the time) but four
|
||||||
@@ -637,8 +641,16 @@ closes it.
|
|||||||
- [ ] Scroll clamped at both ends, and Compose's impulse velocity
|
- [ ] Scroll clamped at both ends, and Compose's impulse velocity
|
||||||
estimator with min/max fling velocity (docs/IRIS_TODO.md, 2026-09-07
|
estimator with min/max fling velocity (docs/IRIS_TODO.md, 2026-09-07
|
||||||
later). After the culling fix lands (same file).
|
later). After the culling fix lands (same file).
|
||||||
- [ ] **APK runtime logs in Dev Updater (Iris, 2026-09-07: "please add
|
- [x] **APK runtime logs in Dev Updater (Iris, 2026-09-07: "please add
|
||||||
android / apk runtime log support to dev updater").** Supersedes the
|
android / apk runtime log support to dev updater").** **Done
|
||||||
|
2026-09-07** -- dev-updater `013d711`, and this repo's provider half;
|
||||||
|
"Phone logging" above is the account, docs/DECISIONS.md the decision.
|
||||||
|
What was designed and what was built agree except in one place: the
|
||||||
|
provider does **not** call `notifyChange` (the reason is in both), and
|
||||||
|
the tab is drawn for every component rather than only where a provider
|
||||||
|
resolves, since its absence would be the one thing that could not say
|
||||||
|
which of the several reasons there was nothing to read. The design as
|
||||||
|
written: Supersedes the
|
||||||
ai-server `POST /client-log` route, which becomes the second mechanism
|
ai-server `POST /client-log` route, which becomes the second mechanism
|
||||||
and is deleted once this works (`log_upload.rs`, `app_log.rs`'s
|
and is deleted once this works (`log_upload.rs`, `app_log.rs`'s
|
||||||
upload half, the route). Design: Android forbids reading another
|
upload half, the route). Design: Android forbids reading another
|
||||||
@@ -684,10 +696,11 @@ closes it.
|
|||||||
Dev Updater needed no change: its Enroll button already opens the minted
|
Dev Updater needed no change: its Enroll button already opens the minted
|
||||||
link with `ACTION_VIEW`, and Android offers the chooser between this app
|
link with `ACTION_VIEW`, and Android offers the chooser between this app
|
||||||
and the Compose one.
|
and the Compose one.
|
||||||
**The log upload was deliberately left out of it**: Dev Updater is
|
**The log upload was deliberately left out of it**: Dev Updater grew an
|
||||||
growing an on-device runtime-log reader instead (Iris, 2026-09-07), so
|
on-device runtime-log reader instead (Iris, 2026-09-07), so
|
||||||
`log_upload`, `POST /client-log` and the `AI_APP_LOG_*` baking are on
|
`log_upload`, `POST /client-log` and the `AI_APP_LOG_*` baking went out
|
||||||
their way out whole rather than being rewired first.
|
whole rather than being rewired first -- done the same day, "Phone
|
||||||
|
logging" above. `build.rs` had nothing left to do and is gone with them.
|
||||||
- [ ] `iris/android-app/build-apk.sh`: clear Gradle's merged-native-libs
|
- [ ] `iris/android-app/build-apk.sh`: clear Gradle's merged-native-libs
|
||||||
cache when the ABI changes (the x86_64 trap), and make the debug bench
|
cache when the ABI changes (the x86_64 trap), and make the debug bench
|
||||||
APK installable (648 MB) -- RUST.md's logging section names both.
|
APK installable (648 MB) -- RUST.md's logging section names both.
|
||||||
|
|||||||
@@ -41,6 +41,28 @@
|
|||||||
|
|
||||||
<meta-data android:name="android.app.lib_name" android:value="main" />
|
<meta-data android:name="android.app.lib_name" android:value="main" />
|
||||||
</activity>
|
</activity>
|
||||||
|
|
||||||
|
<!-- This app's own recent log, for Dev Updater to read on the
|
||||||
|
phone. Iris runs these builds with no adb, and Android
|
||||||
|
forbids one app reading another's logcat, so this is the
|
||||||
|
only way a log::info! here reaches her. The shape is Dev
|
||||||
|
Updater's contract (its README.md, "An app's own log"), not
|
||||||
|
something invented for this app.
|
||||||
|
|
||||||
|
The authority carries ${applicationId}, so the bench package
|
||||||
|
and the ordinary one each get their own and neither can read
|
||||||
|
the other's log. Exported, because the whole point is
|
||||||
|
another app reading it, and guarded by a permission Dev
|
||||||
|
Updater declares at protectionLevel="normal" (a signature
|
||||||
|
permission is not available: the two apps are signed with
|
||||||
|
different locally generated keys). Read-only: insert,
|
||||||
|
update and delete throw. -->
|
||||||
|
<provider
|
||||||
|
android:name=".DevLogProvider"
|
||||||
|
android:authorities="${applicationId}.devlog"
|
||||||
|
android:exported="true"
|
||||||
|
android:readPermission="dev.updater.permission.READ_DEVLOG" />
|
||||||
|
|
||||||
</application>
|
</application>
|
||||||
|
|
||||||
</manifest>
|
</manifest>
|
||||||
@@ -0,0 +1,186 @@
|
|||||||
|
package dev.iris.android.demo;
|
||||||
|
|
||||||
|
import android.content.ContentProvider;
|
||||||
|
import android.content.ContentValues;
|
||||||
|
import android.content.UriMatcher;
|
||||||
|
import android.database.Cursor;
|
||||||
|
import android.database.MatrixCursor;
|
||||||
|
import android.net.Uri;
|
||||||
|
|
||||||
|
/**
|
||||||
|
* This app's own recent log, exposed on the device.
|
||||||
|
*
|
||||||
|
* Iris runs these builds on a phone with no {@code adb}, and Android
|
||||||
|
* forbids one app reading another's {@code logcat} -- so nothing outside
|
||||||
|
* this process can recover what it wrote. The process already keeps a
|
||||||
|
* bounded copy of its log (Rust: {@code client_core::log_ring}); this
|
||||||
|
* hands it to Dev Updater, which is on the same phone, so it needs no
|
||||||
|
* tunnel, no token and no second enrolment.
|
||||||
|
*
|
||||||
|
* <p>The shape is <em>Dev Updater's contract</em>, not something invented
|
||||||
|
* here -- see that project's {@code README.md}, "An app's own log". Any
|
||||||
|
* app it delivers can implement the same and get the same Runtime tab.
|
||||||
|
* Two paths:
|
||||||
|
*
|
||||||
|
* <ul>
|
||||||
|
* <li>{@code lines?since=<seq>} -- every held line with a sequence at or
|
||||||
|
* after {@code since}, oldest first.
|
||||||
|
* <li>{@code status} -- one row: how many lines are held, how many the
|
||||||
|
* ring's own bound has dropped, and the newest sequence ({@code -1}
|
||||||
|
* for a log nothing has been written to, which is also how a reader
|
||||||
|
* notices this process restarted).
|
||||||
|
* </ul>
|
||||||
|
*
|
||||||
|
* <p>Read-only: there is nothing here for anyone else to change, so the
|
||||||
|
* three writing methods throw rather than silently doing nothing.
|
||||||
|
*
|
||||||
|
* <p>The authority is {@code <applicationId>.devlog}, filled in from
|
||||||
|
* Gradle so the bench build and the ordinary one each get their own and
|
||||||
|
* neither can read the other's. Read access is guarded by
|
||||||
|
* {@code dev.updater.permission.READ_DEVLOG}, declared in the manifest.
|
||||||
|
*
|
||||||
|
* <p>No {@code notifyChange}: the ring is filled by a {@code log::Log}
|
||||||
|
* backend on whatever thread logged, and giving that a way to reach a
|
||||||
|
* provider would mean plumbing a callback through {@code client-core} for
|
||||||
|
* every platform. Dev Updater polls while its tab is open, which its
|
||||||
|
* contract says it does precisely so implementing this stays cheap.
|
||||||
|
*/
|
||||||
|
public final class DevLogProvider extends ContentProvider {
|
||||||
|
static {
|
||||||
|
// The provider is created before any activity, so it cannot rely
|
||||||
|
// on MainActivity's own load. Loading twice is a no-op.
|
||||||
|
System.loadLibrary("main");
|
||||||
|
}
|
||||||
|
|
||||||
|
/** Matches {@link #nativeLinesSince}'s flat answer. Both sides say it once. */
|
||||||
|
private static final int FIELDS_PER_LINE = 5;
|
||||||
|
|
||||||
|
private static final String[] LINE_COLUMNS = {"seq", "t_ms", "level", "target", "message"};
|
||||||
|
private static final String[] STATUS_COLUMNS = {"held", "dropped", "newest_seq"};
|
||||||
|
|
||||||
|
private static final int LINES = 1;
|
||||||
|
private static final int STATUS = 2;
|
||||||
|
|
||||||
|
private UriMatcher matcher;
|
||||||
|
|
||||||
|
/** Every held line, {@link #FIELDS_PER_LINE} strings each, oldest first. */
|
||||||
|
private static native String[] nativeLinesSince(long since);
|
||||||
|
|
||||||
|
/** Three strings: held, dropped, newest sequence. */
|
||||||
|
private static native String[] nativeStatus();
|
||||||
|
|
||||||
|
/**
|
||||||
|
* Tells the Rust side which authority this build registered under, so
|
||||||
|
* the diagnostics pane can name somewhere a reader can actually query
|
||||||
|
* -- and so "declared but never created" is a state it can say. Only
|
||||||
|
* the provider knows it was instantiated; Android creates one lazily.
|
||||||
|
*/
|
||||||
|
private static native void nativeReady(String authority);
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public boolean onCreate() {
|
||||||
|
// The authority is not a constant here: it is derived from this
|
||||||
|
// build's applicationId, so the bench package and the ordinary one
|
||||||
|
// do not share one. Read back from the manifest rather than
|
||||||
|
// recomposed, so there is one answer to what it is.
|
||||||
|
String authority = getContext().getPackageName() + ".devlog";
|
||||||
|
matcher = new UriMatcher(UriMatcher.NO_MATCH);
|
||||||
|
matcher.addURI(authority, "lines", LINES);
|
||||||
|
matcher.addURI(authority, "status", STATUS);
|
||||||
|
nativeReady(authority);
|
||||||
|
return true;
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public Cursor query(
|
||||||
|
Uri uri,
|
||||||
|
String[] projection,
|
||||||
|
String selection,
|
||||||
|
String[] selectionArgs,
|
||||||
|
String sortOrder) {
|
||||||
|
switch (matcher.match(uri)) {
|
||||||
|
case LINES:
|
||||||
|
return lines(sinceOf(uri));
|
||||||
|
case STATUS:
|
||||||
|
return status();
|
||||||
|
default:
|
||||||
|
// Null rather than an exception: an unknown path is a
|
||||||
|
// reader asking for something this app does not have, and
|
||||||
|
// the contract's own answer for that is no cursor.
|
||||||
|
return null;
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
/**
|
||||||
|
* {@code ?since=} as a number, or 0 for a reader starting from the
|
||||||
|
* beginning. A value that is not a number is treated as 0 rather than
|
||||||
|
* refused -- what a caller wants from a malformed cursor is the log,
|
||||||
|
* not a stack trace about the query string.
|
||||||
|
*/
|
||||||
|
private static long sinceOf(Uri uri) {
|
||||||
|
String since = uri.getQueryParameter("since");
|
||||||
|
if (since == null) {
|
||||||
|
return 0;
|
||||||
|
}
|
||||||
|
try {
|
||||||
|
return Long.parseLong(since);
|
||||||
|
} catch (NumberFormatException ignored) {
|
||||||
|
return 0;
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
private static Cursor lines(long since) {
|
||||||
|
String[] fields = nativeLinesSince(since);
|
||||||
|
if (fields == null) {
|
||||||
|
return null;
|
||||||
|
}
|
||||||
|
MatrixCursor cursor = new MatrixCursor(LINE_COLUMNS, fields.length / FIELDS_PER_LINE);
|
||||||
|
for (int at = 0; at + FIELDS_PER_LINE <= fields.length; at += FIELDS_PER_LINE) {
|
||||||
|
cursor.addRow(
|
||||||
|
new Object[] {
|
||||||
|
Long.parseLong(fields[at]),
|
||||||
|
Long.parseLong(fields[at + 1]),
|
||||||
|
fields[at + 2],
|
||||||
|
fields[at + 3],
|
||||||
|
fields[at + 4],
|
||||||
|
});
|
||||||
|
}
|
||||||
|
return cursor;
|
||||||
|
}
|
||||||
|
|
||||||
|
private static Cursor status() {
|
||||||
|
String[] fields = nativeStatus();
|
||||||
|
if (fields == null || fields.length != STATUS_COLUMNS.length) {
|
||||||
|
return null;
|
||||||
|
}
|
||||||
|
MatrixCursor cursor = new MatrixCursor(STATUS_COLUMNS, 1);
|
||||||
|
cursor.addRow(
|
||||||
|
new Object[] {
|
||||||
|
Long.parseLong(fields[0]), Long.parseLong(fields[1]), Long.parseLong(fields[2]),
|
||||||
|
});
|
||||||
|
return cursor;
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public String getType(Uri uri) {
|
||||||
|
// A MIME type is for something meant to be handed to another app
|
||||||
|
// as data; these rows are read by one reader that knows the
|
||||||
|
// columns. Saying nothing is the honest answer, not a gap.
|
||||||
|
return null;
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public Uri insert(Uri uri, ContentValues values) {
|
||||||
|
throw new UnsupportedOperationException("this app's log is read-only");
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public int update(Uri uri, ContentValues values, String selection, String[] selectionArgs) {
|
||||||
|
throw new UnsupportedOperationException("this app's log is read-only");
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public int delete(Uri uri, String selection, String[] selectionArgs) {
|
||||||
|
throw new UnsupportedOperationException("this app's log is read-only");
|
||||||
|
}
|
||||||
|
}
|
||||||
@@ -1,112 +0,0 @@
|
|||||||
// Only does anything under the `transcript-screen` feature (RUST.md's I5
|
|
||||||
// Android integration) -- the plain tabs build (I2/I4) needs none of this
|
|
||||||
// and stays untouched, same reasoning as the feature gate in Cargo.toml.
|
|
||||||
//
|
|
||||||
// **Nothing about the server this app talks to is baked in any more.** It
|
|
||||||
// used to be (`AI_APP_TRANSCRIPT_HOST`/`_PORT`/`_TOKEN` plus the machine's
|
|
||||||
// own CA), which made an APK good for exactly the emulator/server pair
|
|
||||||
// that built it -- and useless for the case that matters, an APK
|
|
||||||
// cross-compiled in this VM and run against the server on the host. The
|
|
||||||
// destination arrives at runtime instead, from an `aiapp://enroll` link
|
|
||||||
// carrying the CA with it (`src/enrollment.rs`), the same way the Compose
|
|
||||||
// app and `desktop-app` are told.
|
|
||||||
//
|
|
||||||
// What is left here is the log upload's own destination, which is on its
|
|
||||||
// way out for a different reason (Dev Updater is growing a runtime-log
|
|
||||||
// view of its own, 2026-09-07) and is left untouched for that change.
|
|
||||||
use std::path::PathBuf;
|
|
||||||
|
|
||||||
fn main() {
|
|
||||||
if std::env::var_os("CARGO_FEATURE_TRANSCRIPT_SCREEN").is_none() {
|
|
||||||
return;
|
|
||||||
}
|
|
||||||
// Where this build sends its own log ring, if anywhere -- the one
|
|
||||||
// thing left that a build is told rather than enrolled with. A build
|
|
||||||
// told none of it still keeps its ring and still shows it in `Copy
|
|
||||||
// report`; it just has nowhere to send it.
|
|
||||||
emit_log_config();
|
|
||||||
}
|
|
||||||
|
|
||||||
/// 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<LogServer> = 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<LogServer> = 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`. Only the log upload pins this
|
|
||||||
/// now; the screen's own server arrives with its CA at enrolment time.
|
|
||||||
fn read_pinned_ca() -> String {
|
|
||||||
let ca_path = std::env::var_os("AI_APP_CA")
|
|
||||||
.map(PathBuf::from)
|
|
||||||
.unwrap_or_else(|| {
|
|
||||||
let base = std::env::var_os("XDG_CONFIG_HOME")
|
|
||||||
.map(PathBuf::from)
|
|
||||||
.unwrap_or_else(|| {
|
|
||||||
let home = std::env::var_os("HOME").expect("HOME must be set");
|
|
||||||
PathBuf::from(home).join(".config")
|
|
||||||
});
|
|
||||||
base.join("ai-app").join("certs").join("ca.pem")
|
|
||||||
});
|
|
||||||
let ca_pem = std::fs::read_to_string(&ca_path).unwrap_or_else(|e| {
|
|
||||||
panic!(
|
|
||||||
"no CA certificate at {} ({e}).\n\
|
|
||||||
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().to_string();
|
|
||||||
assert!(
|
|
||||||
ca_pem.starts_with("-----BEGIN CERTIFICATE-----"),
|
|
||||||
"{} is not a PEM certificate.",
|
|
||||||
ca_path.display()
|
|
||||||
);
|
|
||||||
ca_pem
|
|
||||||
}
|
|
||||||
@@ -1,42 +1,19 @@
|
|||||||
//! The platform half of this app's logging: what `client_core::log_ring`
|
//! The platform half of this app's logging: what
|
||||||
//! and `client_core::log_upload` need that only Android can supply.
|
//! `client_core::log_ring` needs that only Android can supply, which is
|
||||||
|
//! `android_logger` as the logger to forward to and nothing else.
|
||||||
//!
|
//!
|
||||||
//! Everything general -- the ring, its bounds, the `log::Log` backend, the
|
//! Everything general -- the ring, its bounds, the `log::Log` backend --
|
||||||
//! batching and the upload -- is in `client-core`, shared with the desktop
|
//! is in `client-core`, shared with the desktop app (AGENTS.md's sharing
|
||||||
//! app (AGENTS.md's sharing rule). What is here is the two things that are
|
//! rule).
|
||||||
//! 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
|
//! **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
|
//! GrapheneOS phone with no `adb`, and Android forbids one app reading
|
||||||
//! another's `logcat`. Nothing outside this process can recover what it
|
//! another's `logcat`. Nothing outside this process can recover what it
|
||||||
//! wrote, so the process keeps a copy and sends it. See
|
//! wrote, so the process keeps a copy -- and hands it to Dev Updater on
|
||||||
|
//! the same phone through `devlog`'s `ContentProvider`. See
|
||||||
//! `docs/DECISIONS.md`, 2026-09-07.
|
//! `docs/DECISIONS.md`, 2026-09-07.
|
||||||
|
|
||||||
use client_core::log_ring::{self, LogRing};
|
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
|
/// Installs the ring in front of `android_logger`, so `logcat` still sees
|
||||||
/// exactly what it saw before and the ring sees it too.
|
/// exactly what it saw before and the ring sees it too.
|
||||||
@@ -59,50 +36,30 @@ pub fn install(max_level: log::LevelFilter) {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
/// The process's ring -- what `Copy report` appends and the diagnostics
|
/// The process's ring -- what `Copy report` appends, what the diagnostics
|
||||||
/// pane counts.
|
/// pane counts, and what `devlog`'s provider hands to Dev Updater.
|
||||||
pub fn ring() -> &'static LogRing {
|
pub fn ring() -> &'static LogRing {
|
||||||
log_ring::process_ring()
|
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<LogUpload> {
|
|
||||||
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
|
/// 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
|
/// 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.
|
/// readout. Gated rather than left dead so the build stays warning-clean.
|
||||||
#[cfg(feature = "bench")]
|
#[cfg(feature = "bench")]
|
||||||
/// One or two lines for the diagnostics pane: how much is held, and what
|
/// Two lines for the diagnostics pane: how much of this app's log is held,
|
||||||
/// the uploader last did. Both, because "nothing is arriving on the
|
/// and where it can be read from.
|
||||||
/// server" has two very different causes and the pane is where somebody
|
///
|
||||||
/// looks for which.
|
/// The second names the provider's authority rather than saying "logging
|
||||||
pub fn diagnostics_line(upload: Option<&LogUpload>) -> String {
|
/// is on", so a screenshot of this pane is enough to tell whether the
|
||||||
let ring = ring().summary();
|
/// contract is live and which package's log it is -- the bench build and
|
||||||
match (upload, LOG_SERVER.as_ref()) {
|
/// the ordinary one have different ones.
|
||||||
(Some(upload), _) => format!("{ring}\n{}", upload.status().summary()),
|
pub fn diagnostics_line() -> String {
|
||||||
(None, None) => format!("{ring}\nlog upload: this build has no server configured"),
|
let where_to_read = match crate::devlog::authority() {
|
||||||
// Configured but not started: the client never called
|
Some(authority) => format!("devlog provider: content://{authority}"),
|
||||||
// `start_upload`, or its transport refused the pinned CA.
|
// Not "off": Android creates a provider lazily, so this is what
|
||||||
(None, Some(server)) => format!(
|
// "nobody has asked for it yet" looks like, and it is a different
|
||||||
"{ring}\nlog upload: configured for {}:{} but not running",
|
// thing from a build that does not have one.
|
||||||
server.host, server.port
|
None => "devlog provider: declared, not created yet".to_string(),
|
||||||
),
|
};
|
||||||
}
|
format!("{}\n{where_to_read}", ring().summary())
|
||||||
}
|
}
|
||||||
@@ -80,12 +80,6 @@ const KEYBOARD_WAIT_MS: u64 = 1_000;
|
|||||||
/// when a later step in the same phase needs to read state back.
|
/// when a later step in the same phase needs to read state back.
|
||||||
const ANIM_STEP_MS: u64 = 16;
|
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
|
/// 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
|
/// scrolls instead of growing -- roughly a third of a phone screen, the
|
||||||
/// share the pane used to reserve unconditionally. An empty report takes
|
/// share the pane used to reserve unconditionally. An empty report takes
|
||||||
@@ -128,13 +122,6 @@ pub struct BenchClient {
|
|||||||
/// The status-bar inset `top_bar` was last padded by -- see
|
/// The status-bar inset `top_bar` was last padded by -- see
|
||||||
/// `on_insets_changed`'s own comment for why this guards the rebuild.
|
/// `on_insets_changed`'s own comment for why this guards the rebuild.
|
||||||
last_top_pad: f32,
|
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<crate::app_log::LogUpload>,
|
|
||||||
}
|
}
|
||||||
|
|
||||||
/// See `BenchClient::ime_state`'s doc. `shown_events`/`hidden_events`
|
/// See `BenchClient::ime_state`'s doc. `shown_events`/`hidden_events`
|
||||||
@@ -296,7 +283,6 @@ impl AndroidAppState for BenchClient {
|
|||||||
ime_state: Arc::new(Mutex::new(ImeState::default())),
|
ime_state: Arc::new(Mutex::new(ImeState::default())),
|
||||||
keyboard_was_visible: false,
|
keyboard_was_visible: false,
|
||||||
last_top_pad: 0.0,
|
last_top_pad: 0.0,
|
||||||
log_upload: crate::app_log::start_upload(LOG_SOURCE),
|
|
||||||
};
|
};
|
||||||
|
|
||||||
match transcript_fixture::build_screen(rsc) {
|
match transcript_fixture::build_screen(rsc) {
|
||||||
@@ -429,6 +415,29 @@ const KEYBOARD_DIAGNOSTICS_DELAY_MS: u64 = 500;
|
|||||||
|
|
||||||
type Rsc = AndroidRsc<BenchClient>;
|
type Rsc = AndroidRsc<BenchClient>;
|
||||||
|
|
||||||
|
/// What a report says about the `iris::input`/`iris::frame` trace, from
|
||||||
|
/// the flag read at the start of what is being reported and again at the
|
||||||
|
/// end.
|
||||||
|
///
|
||||||
|
/// Three answers rather than two. Those lines are default-off and the
|
||||||
|
/// switch that turns them on is on screen while a benchmark runs, so
|
||||||
|
/// "somebody moved it half way through" is a state that actually happens
|
||||||
|
/// -- and reported as either "on" or "off" it is a confident sentence
|
||||||
|
/// about a log that only covers part of the run. The "on" wording also
|
||||||
|
/// says what it costs, because a traced run fills the ring in seconds and
|
||||||
|
/// a reader looking at a log with nothing else in it should know why.
|
||||||
|
fn trace_line(at_start: bool, at_end: bool) -> String {
|
||||||
|
match (at_start, at_end) {
|
||||||
|
(true, true) => "input/frame trace: on (iris::input and iris::frame lines are in \
|
||||||
|
the app log, and a traced run fills the ring in seconds)"
|
||||||
|
.to_string(),
|
||||||
|
(false, false) => "input/frame trace: off".to_string(),
|
||||||
|
_ => "input/frame trace: switched during this run, so those lines cover only part \
|
||||||
|
of it"
|
||||||
|
.to_string(),
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
/// The header row's own backdrop -- see `bench_controls`'s doc comment on
|
/// The header row's own backdrop -- see `bench_controls`'s doc comment on
|
||||||
/// why it needs one at all. A dark neutral rather than pure black
|
/// why it needs one at all. A dark neutral rather than pure black
|
||||||
/// (`android::render::CLEAR_COLOR`) so the row reads as a distinct panel
|
/// (`android::render::CLEAR_COLOR`) so the row reads as a distinct panel
|
||||||
@@ -456,6 +465,18 @@ const HEADER_SURFACE: UiColor = UiColor::new(28, 28, 34, 255);
|
|||||||
/// pixels) to `dp(...)` (IRIS_TODO.md's density-independent length unit),
|
/// pixels) to `dp(...)` (IRIS_TODO.md's density-independent length unit),
|
||||||
/// so the row's reserved height in the outer `Span::DOWN`
|
/// so the row's reserved height in the outer `Span::DOWN`
|
||||||
/// (`AndroidAppState::new`) matches what is actually painted.
|
/// (`AndroidAppState::new`) matches what is actually painted.
|
||||||
|
/// The size every label in the header row is drawn at.
|
||||||
|
///
|
||||||
|
/// One constant for all four rather than a number per button, because the
|
||||||
|
/// whole row has to be sized together: it was 18 with three controls, and
|
||||||
|
/// adding the trace switch made four labels overlap each other on a
|
||||||
|
/// 1080px screen. Shrinking *one* label to fit is what the UI rules
|
||||||
|
/// forbid -- a label a different size from its neighbours for a reason the
|
||||||
|
/// reader cannot see; changing the row's own type size is a layout
|
||||||
|
/// decision, and all four still match. Whoever adds a fifth control has
|
||||||
|
/// one number to reconsider rather than four.
|
||||||
|
const HEADER_TEXT: f32 = 13.0;
|
||||||
|
|
||||||
fn bench_controls(rsc: &mut Rsc, top_pad: f32) -> StrongWidget {
|
fn bench_controls(rsc: &mut Rsc, top_pad: f32) -> StrongWidget {
|
||||||
let run_rect = rect(Color::rgb(40, 70, 40))
|
let run_rect = rect(Color::rgb(40, 70, 40))
|
||||||
.on(
|
.on(
|
||||||
@@ -467,7 +488,9 @@ fn bench_controls(rsc: &mut Rsc, top_pad: f32) -> StrongWidget {
|
|||||||
.label("Run benchmark");
|
.label("Run benchmark");
|
||||||
let run = (
|
let run = (
|
||||||
run_rect,
|
run_rect,
|
||||||
wtext("Run benchmark").size(18).text_align(Align::CENTER),
|
wtext("Run benchmark")
|
||||||
|
.size(HEADER_TEXT)
|
||||||
|
.text_align(Align::CENTER),
|
||||||
)
|
)
|
||||||
.stack()
|
.stack()
|
||||||
.pad(dp(8))
|
.pad(dp(8))
|
||||||
@@ -483,7 +506,9 @@ fn bench_controls(rsc: &mut Rsc, top_pad: f32) -> StrongWidget {
|
|||||||
.label("Copy report");
|
.label("Copy report");
|
||||||
let copy = (
|
let copy = (
|
||||||
copy_rect,
|
copy_rect,
|
||||||
wtext("Copy report").size(18).text_align(Align::CENTER),
|
wtext("Copy report")
|
||||||
|
.size(HEADER_TEXT)
|
||||||
|
.text_align(Align::CENTER),
|
||||||
)
|
)
|
||||||
.stack()
|
.stack()
|
||||||
.pad(dp(8))
|
.pad(dp(8))
|
||||||
@@ -499,13 +524,49 @@ fn bench_controls(rsc: &mut Rsc, top_pad: f32) -> StrongWidget {
|
|||||||
.label("Diagnostics");
|
.label("Diagnostics");
|
||||||
let diagnostics = (
|
let diagnostics = (
|
||||||
diag_rect,
|
diag_rect,
|
||||||
wtext("Diagnostics").size(18).text_align(Align::CENTER),
|
wtext("Diagnostics")
|
||||||
|
.size(HEADER_TEXT)
|
||||||
|
.text_align(Align::CENTER),
|
||||||
)
|
)
|
||||||
.stack()
|
.stack()
|
||||||
.pad(dp(8))
|
.pad(dp(8))
|
||||||
.add(rsc);
|
.add(rsc);
|
||||||
|
|
||||||
let buttons = (run, copy, diagnostics).span(Dir::RIGHT).add(rsc);
|
// A switch rather than a button, so its own appearance says which
|
||||||
|
// state it is in: the two `iris::input`/`iris::frame` targets are
|
||||||
|
// default-off (`iris::diagnostics`'s module doc) because a 120Hz
|
||||||
|
// session fills the 2000-line ring in seconds, so "is it on right
|
||||||
|
// now" is the question somebody has while looking at a log that is
|
||||||
|
// either full of trace or has none.
|
||||||
|
//
|
||||||
|
// The visible text carries the state and the accessibility label does
|
||||||
|
// not, deliberately: the label is also what `run-bench.sh` taps by
|
||||||
|
// name, and a control that renames itself when pressed is one no
|
||||||
|
// script can find twice.
|
||||||
|
let tracing = iris::diagnostics::trace_enabled();
|
||||||
|
let trace_rect = rect(if tracing {
|
||||||
|
Color::rgb(90, 70, 30)
|
||||||
|
} else {
|
||||||
|
Color::rgb(50, 50, 60)
|
||||||
|
})
|
||||||
|
.on(
|
||||||
|
CursorSense::click(),
|
||||||
|
|ctx: EventIdCtx<'_, Rsc, _, _>, rsc: &mut Rsc| {
|
||||||
|
ctx.state.toggle_trace(rsc);
|
||||||
|
},
|
||||||
|
)
|
||||||
|
.label("Trace input and frames");
|
||||||
|
let trace = (
|
||||||
|
trace_rect,
|
||||||
|
wtext(if tracing { "Trace on" } else { "Trace off" })
|
||||||
|
.size(HEADER_TEXT)
|
||||||
|
.text_align(Align::CENTER),
|
||||||
|
)
|
||||||
|
.stack()
|
||||||
|
.pad(dp(8))
|
||||||
|
.add(rsc);
|
||||||
|
|
||||||
|
let buttons = (run, copy, diagnostics, trace).span(Dir::RIGHT).add(rsc);
|
||||||
|
|
||||||
(rect(HEADER_SURFACE), buttons)
|
(rect(HEADER_SURFACE), buttons)
|
||||||
.stack()
|
.stack()
|
||||||
@@ -540,6 +601,25 @@ impl BenchClient {
|
|||||||
self.last_report = Some(report);
|
self.last_report = Some(report);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// Turns the `iris::input`/`iris::frame` trace on or off, redraws the
|
||||||
|
/// switch that says so, and shows the pane that now reports it.
|
||||||
|
///
|
||||||
|
/// Showing the pane is the point rather than a convenience: this is a
|
||||||
|
/// control whose whole effect is on what a *later* report says, so
|
||||||
|
/// putting the state on screen at the moment of the press is the only
|
||||||
|
/// thing that distinguishes it from a button that did nothing.
|
||||||
|
fn toggle_trace(&mut self, rsc: &mut Rsc) {
|
||||||
|
let on = !iris::diagnostics::trace_enabled();
|
||||||
|
iris::diagnostics::set_trace(on);
|
||||||
|
log::info!(
|
||||||
|
"iris diagnostics: input/frame trace {}",
|
||||||
|
if on { "on" } else { "off" }
|
||||||
|
);
|
||||||
|
let controls = bench_controls(rsc, self.last_top_pad);
|
||||||
|
(self.top_bar)(rsc).set(controls);
|
||||||
|
self.show_diagnostics(rsc);
|
||||||
|
}
|
||||||
|
|
||||||
/// The diagnostics report as text, with no side effect on what is on
|
/// The diagnostics report as text, with no side effect on what is on
|
||||||
/// screen -- shared by the `Diagnostics` button (which shows it) and
|
/// screen -- shared by the `Diagnostics` button (which shows it) and
|
||||||
/// the keyboard-open capture (which only logs it), so the two can
|
/// the keyboard-open capture (which only logs it), so the two can
|
||||||
@@ -559,14 +639,18 @@ impl BenchClient {
|
|||||||
// composer up" cannot be told from "the listener never fired"
|
// composer up" cannot be told from "the listener never fired"
|
||||||
// without it (`AndroidUiState::insets_report`).
|
// without it (`AndroidUiState::insets_report`).
|
||||||
format!(
|
format!(
|
||||||
"{renderer}\n{}\n{}\n{}",
|
"{renderer}\n{}\n{}\n{}\n{}",
|
||||||
|
trace_line(
|
||||||
|
iris::diagnostics::trace_enabled(),
|
||||||
|
iris::diagnostics::trace_enabled()
|
||||||
|
),
|
||||||
self.android_state().insets_report(),
|
self.android_state().insets_report(),
|
||||||
// Which server this build talks to, and what to do when the
|
// Which server this build talks to, and what to do when the
|
||||||
// answer is "none" -- the bench itself opens a checked-in
|
// answer is "none" -- the bench itself opens a checked-in
|
||||||
// fixture and needs no server, so this pane is the only place
|
// fixture and needs no server, so this pane is the only place
|
||||||
// an enrolment can be seen to have taken.
|
// an enrolment can be seen to have taken.
|
||||||
crate::enrollment::status_line(),
|
crate::enrollment::status_line(),
|
||||||
crate::app_log::diagnostics_line(self.log_upload.as_ref())
|
crate::app_log::diagnostics_line()
|
||||||
)
|
)
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -606,11 +690,6 @@ impl BenchClient {
|
|||||||
crate::app_log::ring().summary(),
|
crate::app_log::ring().summary(),
|
||||||
crate::app_log::ring().to_text()
|
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) {
|
if platform.copy_to_clipboard("iris bench report", &report) {
|
||||||
log::info!("iris bench report: copied to clipboard");
|
log::info!("iris bench report: copied to clipboard");
|
||||||
} else {
|
} else {
|
||||||
@@ -640,6 +719,11 @@ impl BenchClient {
|
|||||||
.and_then(|p| p.refresh_rate_hz())
|
.and_then(|p| p.refresh_rate_hz())
|
||||||
.unwrap_or(60.0);
|
.unwrap_or(60.0);
|
||||||
let cpu_start = process_cpu_ms();
|
let cpu_start = process_cpu_ms();
|
||||||
|
// Read at the start as well as the end, because the switch is on
|
||||||
|
// screen while a run is going: a report that only asked afterwards
|
||||||
|
// would say "on" about a run whose first half has no trace in it
|
||||||
|
// -- the inferred answer presented as the measured one.
|
||||||
|
let trace_at_start = iris::diagnostics::trace_enabled();
|
||||||
let run_started_at = Instant::now();
|
let run_started_at = Instant::now();
|
||||||
|
|
||||||
rsc.spawn_task(async move |mut ctx| {
|
rsc.spawn_task(async move |mut ctx| {
|
||||||
@@ -737,9 +821,11 @@ impl BenchClient {
|
|||||||
" type: {} characters inserted then deleted, one per {TYPE_CHAR_MS}ms",
|
" type: {} characters inserted then deleted, one per {TYPE_CHAR_MS}ms",
|
||||||
TYPE_TEXT.chars().count()
|
TYPE_TEXT.chars().count()
|
||||||
);
|
);
|
||||||
|
let traced = trace_line(trace_at_start, iris::diagnostics::trace_enabled());
|
||||||
let report = format!(
|
let report = format!(
|
||||||
"iris bench report\n{per_phase}{frames_block}\n\nbench:\n{fling_line}\n\
|
"iris bench report\n{traced}\n{per_phase}{frames_block}\n\nbench:\n\
|
||||||
{scroll_line}\n{type_line}\n{keyboard}\n{cpu_line}\n{rss_line}\n{battery}"
|
{fling_line}\n{scroll_line}\n{type_line}\n{keyboard}\n{cpu_line}\n\
|
||||||
|
{rss_line}\n{battery}"
|
||||||
);
|
);
|
||||||
log::info!("iris bench report: {report}");
|
log::info!("iris bench report: {report}");
|
||||||
state.report_display.edit(rsc).set(&report);
|
state.report_display.edit(rsc).set(&report);
|
||||||
|
|||||||
@@ -0,0 +1,183 @@
|
|||||||
|
//! The JNI half of `DevLogProvider`: reading this process's own log ring
|
||||||
|
//! for a `ContentProvider` that Dev Updater queries.
|
||||||
|
//!
|
||||||
|
//! **Why**: Iris runs these builds on a phone with no `adb`, and Android
|
||||||
|
//! forbids one app reading another's `logcat`, so nothing outside this
|
||||||
|
//! process can recover what it wrote. The app already keeps a bounded copy
|
||||||
|
//! (`client_core::log_ring`); this is how the copy leaves the process. Dev
|
||||||
|
//! Updater is on the same phone, so handing it over needs no tunnel, no
|
||||||
|
//! token and no second enrolment -- and it is Dev Updater's own contract
|
||||||
|
//! rather than something invented here, so any app it delivers can do the
|
||||||
|
//! same (its `README.md`, "An app's own log").
|
||||||
|
//!
|
||||||
|
//! **Everything general stays in `client-core`** (AGENTS.md's sharing
|
||||||
|
//! rule). What is here is only what Android forces: the JNI boundary and
|
||||||
|
//! the Java class on the other side of it.
|
||||||
|
//!
|
||||||
|
//! Both entry points answer a **flat `String[]`** rather than a row of
|
||||||
|
//! typed columns. That is the whole of the JNI, and it is one array type
|
||||||
|
//! instead of three interleaved ones for a payload the provider is about
|
||||||
|
//! to hand back over binder as a `MatrixCursor` anyway; `DevLogProvider`
|
||||||
|
//! parses the two numeric fields. Kept flat rather than nested for the
|
||||||
|
//! same reason -- an array of arrays is four more JNI calls per line.
|
||||||
|
|
||||||
|
use android_view::jni::JNIEnv;
|
||||||
|
use android_view::jni::objects::{JClass, JObject, JString};
|
||||||
|
use android_view::jni::sys::{jlong, jobjectArray};
|
||||||
|
use std::sync::OnceLock;
|
||||||
|
|
||||||
|
/// How many `String`s each log line occupies in the flat answer:
|
||||||
|
/// `seq`, `t_ms`, `level`, `target`, `message`, in that order. The Java
|
||||||
|
/// side has the same constant, and the two are the one place the shape is
|
||||||
|
/// written down on each side.
|
||||||
|
const FIELDS_PER_LINE: usize = 5;
|
||||||
|
|
||||||
|
/// The authority the provider registered itself under, once it has been
|
||||||
|
/// created. `None` until then, which is a state worth being able to say:
|
||||||
|
/// a provider Android never instantiated and one that is answering look
|
||||||
|
/// the same from inside this process otherwise.
|
||||||
|
static AUTHORITY: OnceLock<String> = OnceLock::new();
|
||||||
|
|
||||||
|
/// Where this app's log can be read from, for the diagnostics pane.
|
||||||
|
///
|
||||||
|
/// The provider's own answer rather than one composed from the package
|
||||||
|
/// name here: what makes the line worth showing is that it names an
|
||||||
|
/// authority somebody can actually query, and only the provider knows it
|
||||||
|
/// registered.
|
||||||
|
#[cfg(feature = "bench")]
|
||||||
|
pub fn authority() -> Option<&'static str> {
|
||||||
|
AUTHORITY.get().map(String::as_str)
|
||||||
|
}
|
||||||
|
|
||||||
|
/// `DevLogProvider.nativeReady` -- the provider announcing the authority
|
||||||
|
/// it registered under, from its own `onCreate`.
|
||||||
|
///
|
||||||
|
/// # Safety
|
||||||
|
/// Called by the JVM with the arguments its `native` declaration names.
|
||||||
|
#[unsafe(no_mangle)]
|
||||||
|
pub extern "system" fn Java_dev_iris_android_demo_DevLogProvider_nativeReady(
|
||||||
|
mut env: JNIEnv,
|
||||||
|
_class: JClass,
|
||||||
|
authority: JString,
|
||||||
|
) {
|
||||||
|
if authority.is_null() {
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
let Ok(authority) = env.get_string(&authority) else {
|
||||||
|
return;
|
||||||
|
};
|
||||||
|
let authority: String = authority.into();
|
||||||
|
log::info!("iris devlog: serving this app's log at content://{authority}");
|
||||||
|
let _ = AUTHORITY.set(authority);
|
||||||
|
}
|
||||||
|
|
||||||
|
/// `DevLogProvider.nativeStatus` -- `held`, `dropped`, `newest_seq`, as
|
||||||
|
/// three strings.
|
||||||
|
///
|
||||||
|
/// `newest_seq` is `-1` for a ring nothing has been written to, which is
|
||||||
|
/// what tells a reader holding a cursor that this process **restarted**:
|
||||||
|
/// the ring is in memory, so a new process starts again at zero and a
|
||||||
|
/// stale cursor would otherwise skip everything silently.
|
||||||
|
///
|
||||||
|
/// Exported by name rather than registered, matching this crate's other
|
||||||
|
/// activity-side natives: the mangled name is the whole of what a class
|
||||||
|
/// this app owns needs.
|
||||||
|
///
|
||||||
|
/// # Safety
|
||||||
|
/// Called by the JVM with the arguments its `native` declaration names.
|
||||||
|
#[unsafe(no_mangle)]
|
||||||
|
pub extern "system" fn Java_dev_iris_android_demo_DevLogProvider_nativeStatus(
|
||||||
|
mut env: JNIEnv,
|
||||||
|
_class: JClass,
|
||||||
|
) -> jobjectArray {
|
||||||
|
string_array(&mut env, &status_fields())
|
||||||
|
}
|
||||||
|
|
||||||
|
/// `DevLogProvider.nativeLinesSince` -- every held line with a sequence at
|
||||||
|
/// or after `since`, oldest first, [`FIELDS_PER_LINE`] strings each.
|
||||||
|
///
|
||||||
|
/// Inclusive of `since` because [`client_core::log_ring::LogRing::since`]
|
||||||
|
/// is, and one definition of the cursor is what keeps the app's own
|
||||||
|
/// uploaded report and this provider describing the same lines.
|
||||||
|
///
|
||||||
|
/// # Safety
|
||||||
|
/// Called by the JVM with the arguments its `native` declaration names.
|
||||||
|
#[unsafe(no_mangle)]
|
||||||
|
pub extern "system" fn Java_dev_iris_android_demo_DevLogProvider_nativeLinesSince(
|
||||||
|
mut env: JNIEnv,
|
||||||
|
_class: JClass,
|
||||||
|
since: jlong,
|
||||||
|
) -> jobjectArray {
|
||||||
|
// A negative cursor is a caller asking for everything, not an error to
|
||||||
|
// take the app down over: the provider is a diagnostic.
|
||||||
|
string_array(&mut env, &line_fields(since.max(0) as u64))
|
||||||
|
}
|
||||||
|
|
||||||
|
/// The three status numbers, as the provider's row.
|
||||||
|
#[cfg(feature = "transcript-screen")]
|
||||||
|
fn status_fields() -> Vec<String> {
|
||||||
|
let ring = client_core::log_ring::process_ring();
|
||||||
|
vec![
|
||||||
|
ring.len().to_string(),
|
||||||
|
ring.dropped().to_string(),
|
||||||
|
ring.newest_seq().map_or(-1, |seq| seq as i64).to_string(),
|
||||||
|
]
|
||||||
|
}
|
||||||
|
|
||||||
|
/// The tabs demo links no `client-core` and keeps no ring, so it holds
|
||||||
|
/// nothing and has never dropped anything -- which is the truth, not a
|
||||||
|
/// stand-in. The natives are still exported there, because a `native`
|
||||||
|
/// method Java declares and the library does not is an
|
||||||
|
/// `UnsatisfiedLinkError` the moment the class loads.
|
||||||
|
#[cfg(not(feature = "transcript-screen"))]
|
||||||
|
fn status_fields() -> Vec<String> {
|
||||||
|
vec!["0".to_string(), "0".to_string(), "-1".to_string()]
|
||||||
|
}
|
||||||
|
|
||||||
|
#[cfg(feature = "transcript-screen")]
|
||||||
|
fn line_fields(since: u64) -> Vec<String> {
|
||||||
|
let (lines, _next) = client_core::log_ring::process_ring().since(since);
|
||||||
|
let mut fields = Vec::with_capacity(lines.len() * FIELDS_PER_LINE);
|
||||||
|
for line in lines {
|
||||||
|
fields.push(line.seq.to_string());
|
||||||
|
fields.push(line.at_ms.to_string());
|
||||||
|
fields.push(line.level.to_string());
|
||||||
|
fields.push(line.target);
|
||||||
|
fields.push(line.message);
|
||||||
|
}
|
||||||
|
fields
|
||||||
|
}
|
||||||
|
|
||||||
|
#[cfg(not(feature = "transcript-screen"))]
|
||||||
|
fn line_fields(_since: u64) -> Vec<String> {
|
||||||
|
Vec::new()
|
||||||
|
}
|
||||||
|
|
||||||
|
/// A Java `String[]` of those, or a null array if the JVM refused one.
|
||||||
|
///
|
||||||
|
/// Null rather than a panic across the JNI boundary: `DevLogProvider`
|
||||||
|
/// reads it as "the provider could not answer" and returns no cursor,
|
||||||
|
/// which Dev Updater already draws as a distinct state. Taking the app
|
||||||
|
/// down to report that its diagnostic is unavailable would be worse than
|
||||||
|
/// the diagnostic being unavailable.
|
||||||
|
fn string_array(env: &mut JNIEnv, fields: &[String]) -> jobjectArray {
|
||||||
|
let null = std::ptr::null_mut();
|
||||||
|
let Ok(class) = env.find_class("java/lang/String") else {
|
||||||
|
return null;
|
||||||
|
};
|
||||||
|
let Ok(array) = env.new_object_array(fields.len() as i32, class, JObject::null()) else {
|
||||||
|
return null;
|
||||||
|
};
|
||||||
|
for (index, field) in fields.iter().enumerate() {
|
||||||
|
let Ok(value) = env.new_string(field) else {
|
||||||
|
return null;
|
||||||
|
};
|
||||||
|
if env
|
||||||
|
.set_object_array_element(&array, index as i32, value)
|
||||||
|
.is_err()
|
||||||
|
{
|
||||||
|
return null;
|
||||||
|
}
|
||||||
|
}
|
||||||
|
array.into_raw()
|
||||||
|
}
|
||||||
@@ -61,6 +61,11 @@ mod app_log;
|
|||||||
mod bench_client;
|
mod bench_client;
|
||||||
#[cfg(feature = "bench")]
|
#[cfg(feature = "bench")]
|
||||||
mod bench_jni;
|
mod bench_jni;
|
||||||
|
/// This app's log ring, handed to Dev Updater on the phone through a
|
||||||
|
/// `ContentProvider`. Declared in every build for the reason the module
|
||||||
|
/// gives: the Java class is in the manifest either way, and a `native`
|
||||||
|
/// method the library does not export fails the class load.
|
||||||
|
mod devlog;
|
||||||
/// Which server this app talks to, told to it at runtime by an
|
/// Which server this app talks to, told to it at runtime by an
|
||||||
/// `aiapp://enroll` link. Only where `client-core` is linked -- the plain
|
/// `aiapp://enroll` link. Only where `client-core` is linked -- the plain
|
||||||
/// tabs demo makes no network call and has nothing to enrol against.
|
/// tabs demo makes no network call and has nothing to enrol against.
|
||||||
|
|||||||
@@ -70,10 +70,6 @@ pub struct TranscriptClient {
|
|||||||
/// only ever one session here (no list to switch away to), but the
|
/// only ever one session here (no list to switch away to), but the
|
||||||
/// guard still matters for the *first* fetch racing a `stop`/`start`.
|
/// guard still matters for the *first* fetch racing a `stop`/`start`.
|
||||||
generation: Arc<AtomicU64>,
|
generation: Arc<AtomicU64>,
|
||||||
/// 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<crate::app_log::LogUpload>,
|
|
||||||
}
|
}
|
||||||
|
|
||||||
impl HasAndroidUiState for TranscriptClient {
|
impl HasAndroidUiState for TranscriptClient {
|
||||||
@@ -180,7 +176,6 @@ impl AndroidAppState for TranscriptClient {
|
|||||||
items: Vec::new(),
|
items: Vec::new(),
|
||||||
session_id: None,
|
session_id: None,
|
||||||
generation: Arc::new(AtomicU64::new(0)),
|
generation: Arc::new(AtomicU64::new(0)),
|
||||||
_log_upload: crate::app_log::start_upload("iris-transcript"),
|
|
||||||
};
|
};
|
||||||
client.spawn_fetch_sessions(rsc);
|
client.spawn_fetch_sessions(rsc);
|
||||||
client
|
client
|
||||||
|
|||||||
@@ -62,9 +62,6 @@
|
|||||||
//! once the account's usage limit lifts
|
//! once the account's usage limit lifts
|
||||||
//! GET /notifications SSE: every session's attention-wanting
|
//! GET /notifications SSE: every session's attention-wanting
|
||||||
//! moments, live only (see `notifications`)
|
//! moments, live only (see `notifications`)
|
||||||
//! POST /client-log {source, lines} -- a client's own recent log,
|
|
||||||
//! re-emitted into this server's log (see
|
|
||||||
//! `client_log`; the phone has no logcat)
|
|
||||||
//! GET /defaults {effort} -- what a new session starts at
|
//! GET /defaults {effort} -- what a new session starts at
|
||||||
//! POST /defaults {effort} -- null for the CLI's own default
|
//! POST /defaults {effort} -- null for the CLI's own default
|
||||||
//! GET /usage cached usage windows per provider
|
//! GET /usage cached usage windows per provider
|
||||||
@@ -161,7 +158,6 @@ pub fn router(manager: Arc<SessionManager>) -> Router {
|
|||||||
.route("/sessions/{id}/permission-mode", post(set_permission_mode))
|
.route("/sessions/{id}/permission-mode", post(set_permission_mode))
|
||||||
.route("/sessions/{id}/effort", post(set_effort))
|
.route("/sessions/{id}/effort", post(set_effort))
|
||||||
.route("/defaults", get(defaults).post(set_defaults))
|
.route("/defaults", get(defaults).post(set_defaults))
|
||||||
.route("/client-log", post(client_log))
|
|
||||||
.route("/sessions/{id}/notify", post(set_notify))
|
.route("/sessions/{id}/notify", post(set_notify))
|
||||||
.route("/sessions/{id}/auto-resume", post(set_auto_resume))
|
.route("/sessions/{id}/auto-resume", post(set_auto_resume))
|
||||||
.route("/notifications", get(notifications))
|
.route("/notifications", get(notifications))
|
||||||
@@ -1411,121 +1407,6 @@ async fn defaults(State(manager): State<Arc<SessionManager>>) -> axum::Json<Defa
|
|||||||
})
|
})
|
||||||
}
|
}
|
||||||
|
|
||||||
/// How many lines one `POST /client-log` may carry, matching
|
|
||||||
/// `client_core::log_upload::MAX_LINES_PER_BATCH`. A client that sends more
|
|
||||||
/// is refused rather than silently shortened: a log with a hole in it that
|
|
||||||
/// nothing mentions is worse than a rejected batch the client retries.
|
|
||||||
const CLIENT_LOG_MAX_LINES: usize = 500;
|
|
||||||
|
|
||||||
/// The tracing target every re-emitted client line carries.
|
|
||||||
///
|
|
||||||
/// **Under `ai_server::`, deliberately.** A bare `client_log` target is
|
|
||||||
/// filtered out by `RUST_LOG=ai_server=debug` -- the exact filter
|
|
||||||
/// AGENTS.md tells people to run with -- so every line a phone sent would
|
|
||||||
/// vanish with nothing saying so. Under the crate's own path it is on
|
|
||||||
/// wherever the server's own lines are, which is the only filter its
|
|
||||||
/// reader knows about.
|
|
||||||
const CLIENT_LOG_TARGET: &str = "ai_server::client_log";
|
|
||||||
|
|
||||||
/// One line of a client's own log. `at` is that client's clock, not this
|
|
||||||
/// machine's -- see [`client_log`].
|
|
||||||
#[derive(Deserialize)]
|
|
||||||
#[serde(rename_all = "camelCase")]
|
|
||||||
#[serde(deny_unknown_fields)]
|
|
||||||
struct ClientLogLine {
|
|
||||||
/// The client's ring sequence. Carried so a gap -- lines its bound
|
|
||||||
/// dropped -- is visible here rather than looking like a quiet client.
|
|
||||||
seq: u64,
|
|
||||||
/// Milliseconds since the unix epoch, from the client's own clock.
|
|
||||||
at: u64,
|
|
||||||
level: String,
|
|
||||||
target: String,
|
|
||||||
message: String,
|
|
||||||
}
|
|
||||||
|
|
||||||
#[derive(Deserialize)]
|
|
||||||
#[serde(rename_all = "camelCase")]
|
|
||||||
#[serde(deny_unknown_fields)]
|
|
||||||
struct ClientLogBody {
|
|
||||||
/// Which client this is -- an app name and build, not a device
|
|
||||||
/// identifier. It is what tells two phones' lines apart in the log.
|
|
||||||
source: String,
|
|
||||||
lines: Vec<ClientLogLine>,
|
|
||||||
}
|
|
||||||
|
|
||||||
/// Takes a client's own recent log lines and re-emits them into this
|
|
||||||
/// server's `tracing` output.
|
|
||||||
///
|
|
||||||
/// **Why a route rather than something on the phone**: Android forbids one
|
|
||||||
/// app reading another's `logcat`, and the phone this project is tested on
|
|
||||||
/// has no `adb` at all, so a `log::info!` in the app can only reach a
|
|
||||||
/// person if the app carries its own copy and sends it somewhere. This
|
|
||||||
/// server is the somewhere it already has a tunnel, a pinned CA and a
|
|
||||||
/// bearer token for -- and Dev Updater already shows this server's log as
|
|
||||||
/// its runtime log, so the line arrives where its reader is already
|
|
||||||
/// looking with nothing new built there. `docs/DECISIONS.md`, 2026-09-07.
|
|
||||||
///
|
|
||||||
/// Each line is emitted separately, at the level the client recorded it
|
|
||||||
/// at, with the client's own timestamp in the text -- the tracing
|
|
||||||
/// subscriber stamps the moment of *arrival*, which can be minutes later
|
|
||||||
/// or on the other side of a tunnel outage, and presenting that as when it
|
|
||||||
/// happened would be an inferred value shown as a measured one.
|
|
||||||
async fn client_log(axum::Json(body): axum::Json<ClientLogBody>) -> Result<StatusCode, ApiError> {
|
|
||||||
if body.lines.len() > CLIENT_LOG_MAX_LINES {
|
|
||||||
return Err(ApiError::BadRequest(format!(
|
|
||||||
"{} lines in one batch; the limit is {CLIENT_LOG_MAX_LINES}",
|
|
||||||
body.lines.len()
|
|
||||||
)));
|
|
||||||
}
|
|
||||||
for line in &body.lines {
|
|
||||||
let at = client_log_time(line.at);
|
|
||||||
let source = &body.source;
|
|
||||||
let target = &line.target;
|
|
||||||
let seq = line.seq;
|
|
||||||
let message = &line.message;
|
|
||||||
// The level is chosen here rather than passed, because a tracing
|
|
||||||
// macro's level is part of the callsite. Anything unrecognised is
|
|
||||||
// reported at INFO with the word it sent kept, so a client using a
|
|
||||||
// level this server has not heard of loses the level rather than
|
|
||||||
// the line.
|
|
||||||
match line.level.to_ascii_uppercase().as_str() {
|
|
||||||
"ERROR" => {
|
|
||||||
tracing::error!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: {message}")
|
|
||||||
}
|
|
||||||
"WARN" => {
|
|
||||||
tracing::warn!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: {message}")
|
|
||||||
}
|
|
||||||
"DEBUG" => {
|
|
||||||
tracing::debug!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: {message}")
|
|
||||||
}
|
|
||||||
"TRACE" => {
|
|
||||||
tracing::trace!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: {message}")
|
|
||||||
}
|
|
||||||
"INFO" => {
|
|
||||||
tracing::info!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: {message}")
|
|
||||||
}
|
|
||||||
other => {
|
|
||||||
tracing::info!(target: CLIENT_LOG_TARGET, "[{source} {at} #{seq}] {target}: <{other}> {message}")
|
|
||||||
}
|
|
||||||
}
|
|
||||||
}
|
|
||||||
Ok(StatusCode::NO_CONTENT)
|
|
||||||
}
|
|
||||||
|
|
||||||
/// `HH:MM:SS.mmm` UTC from the client's unix milliseconds -- the same
|
|
||||||
/// formatting `client_core::log_ring` uses, so a line read here and the
|
|
||||||
/// same line in the app's own copied report say the same time.
|
|
||||||
fn client_log_time(at_ms: u64) -> String {
|
|
||||||
let secs_of_day = (at_ms / 1000) % 86_400;
|
|
||||||
format!(
|
|
||||||
"{:02}:{:02}:{:02}.{:03}",
|
|
||||||
secs_of_day / 3600,
|
|
||||||
(secs_of_day % 3600) / 60,
|
|
||||||
secs_of_day % 60,
|
|
||||||
at_ms % 1000
|
|
||||||
)
|
|
||||||
}
|
|
||||||
|
|
||||||
/// Sets what a new session's thinking level is. Applied when a session is
|
/// Sets what a new session's thinking level is. Applied when a session is
|
||||||
/// spawned, so nothing already running changes underneath anybody.
|
/// spawned, so nothing already running changes underneath anybody.
|
||||||
async fn set_defaults(
|
async fn set_defaults(
|
||||||
|
|||||||
Reference in new issue
Block a user