diff --git a/crates/ralphy-agent-opencode/src/command.rs b/crates/ralphy-agent-opencode/src/command.rs index 264966e3..be739c70 100644 --- a/crates/ralphy-agent-opencode/src/command.rs +++ b/crates/ralphy-agent-opencode/src/command.rs @@ -31,7 +31,20 @@ pub(crate) fn build_opencode_command( cmd.arg("run") .arg("--format") .arg("json") - .arg("--dangerously-skip-permissions"); + .arg("--dangerously-skip-permissions") + // Route opencode's own logs (logfmt) onto stderr at ERROR level. Some + // providers (Z.ai `zai-coding-plan`/GLM) never emit a `{type:"error"}` + // JSON event on a quota block: their ai-sdk treats the `AI_APICallError: + // Usage limit reached` as a *retryable* stream error and loops on backoff, + // printing it only to the server log — so the `--format json` stream stays + // silent and the run stalls until the wall timeout. `--print-logs` brings + // that line onto the stderr we already drain, where `parse_opencode_log_limit` + // can see it and classify the run as `Limit` instead of a mute `Timeout` + // (observed live 2026-07-11, FinCal #71, glm-5.2). ERROR keeps the combined + // log lean; the quota line is logged at ERROR. + .arg("--print-logs") + .arg("--log-level") + .arg("ERROR"); if let Some(m) = model { cmd.arg("-m").arg(m); } @@ -84,6 +97,12 @@ mod tests { ); assert!(args.contains(&"--format".to_string()), "argv: {args:?}"); assert!(args.contains(&"json".to_string()), "argv: {args:?}"); + // `--print-logs`/`--log-level ERROR` route opencode's own logs to stderr so + // a provider quota block that never reaches the JSON stream is still visible + // to the limit detector (D9 — silent-quota fix, FinCal #71). + assert!(args.contains(&"--print-logs".to_string()), "argv: {args:?}"); + assert!(args.contains(&"--log-level".to_string()), "argv: {args:?}"); + assert!(args.contains(&"ERROR".to_string()), "argv: {args:?}"); } #[test] diff --git a/crates/ralphy-agent-opencode/src/events.rs b/crates/ralphy-agent-opencode/src/events.rs index 040c43f9..c27d47a8 100644 --- a/crates/ralphy-agent-opencode/src/events.rs +++ b/crates/ralphy-agent-opencode/src/events.rs @@ -194,6 +194,55 @@ pub(crate) fn parse_opencode_limit(stdout: &str) -> Option> { }) } +/// The usage-limit sentinels as they read in opencode's own logs (logfmt on +/// stderr under `--print-logs`), NOT the `--format json` event stream. Some +/// providers never surface a quota block as a `{type:"error"}` JSON event: Z.ai's +/// `zai-coding-plan` (GLM) treats the `AI_APICallError: Usage limit reached` as a +/// retryable stream error and loops on backoff, logging it only here (observed +/// live 2026-07-11, FinCal #71, glm-5.2). Keyed on the specific "usage limit" +/// wording so an ordinary transient stream error is not misread as a limit. +const LOG_LIMIT_SENTINELS: &[&str] = &["usage limit reached", "usage limit for this billing cycle"]; + +/// Scan opencode's raw combined log (stdout+stderr) for a usage-limit sentinel in +/// the logfmt lines `--print-logs` prints to stderr — the path a JSON-event scan +/// ([`parse_opencode_limit`], which reads the `--format json` stream) structurally +/// cannot see. Same contract as [`parse_opencode_limit`]: `Some(Some(hint))` when a +/// limit is seen with a reset hint, `Some(None)` when seen without one, `None` +/// otherwise (ADR-0005 D9). +pub(crate) fn parse_opencode_log_limit(log: &str) -> Option> { + for line in log.lines() { + let lower = line.to_ascii_lowercase(); + if LOG_LIMIT_SENTINELS.iter().any(|s| lower.contains(s)) { + return Some(parse_reset_hint_from_text(line)); + } + } + None +} + +/// Best-effort reset-time extraction from a raw log line (the logfmt path, where +/// the field lives inside a quoted `error.error="…"` value rather than a JSON +/// field). Recognises Z.ai's `… reset at ` wording alongside the common +/// `try again at/in` phrasings; the reset value can carry a space (e.g. +/// `2026-07-11 22:14:08`), so it runs to the quote/newline/period, not the first +/// space. Returns `None` when absent (a reset hint is not guaranteed). +fn parse_reset_hint_from_text(line: &str) -> Option { + let lower = line.to_ascii_lowercase(); + for prefix in &["reset at ", "try again at ", "try again in "] { + if let Some(pos) = lower.find(prefix) { + let rest = &line[pos + prefix.len()..]; + let hint: String = rest + .chars() + .take_while(|c| *c != '"' && *c != '\n' && *c != '.') + .collect(); + let hint = hint.trim().to_string(); + if !hint.is_empty() { + return Some(hint); + } + } + } + None +} + #[cfg(test)] mod tests { use super::*; @@ -363,6 +412,55 @@ mod tests { assert_eq!(parse_opencode_limit(stream), None); } + // ── parse_opencode_log_limit ───────────────────────────────────────────── + + #[test] + fn log_limit_detects_zai_5h_cap_with_reset() { + // The exact logfmt line opencode prints to stderr under `--print-logs` when + // Z.ai's `zai-coding-plan` (GLM) hits its 5-hour cap — captured live + // 2026-07-11 (FinCal #71). No `{type:"error"}` JSON event accompanies it, so + // only the log-scan (not `parse_opencode_limit`) can catch it. The reset + // value carries a space and must survive intact. + let log = concat!( + "{\"type\":\"step_finish\",\"reason\":\"stop\"}\n", + "timestamp=2026-07-11T09:48:22.735Z level=ERROR run=d9ec1918 ", + "message=\"stream error\" providerID=zai-coding-plan modelID=glm-5.2 ", + "session.id=ses_x error.error=\"AI_APICallError: Usage limit reached for ", + "5 hour. Your limit will reset at 2026-07-11 22:14:08\"", + ); + assert_eq!( + parse_opencode_log_limit(log), + Some(Some("2026-07-11 22:14:08".into())), + ); + } + + #[test] + fn log_limit_detects_kimi_billing_cycle_without_reset() { + // Kimi's billing-cycle block as it reads in the logfmt log: a usage limit + // with no reset timestamp → `Some(None)`. + let log = concat!( + "timestamp=2026-07-09T23:19:01.732Z level=ERROR message=\"stream error\" ", + "providerID=kimi-for-coding error.error=\"AI_APICallError: You've reached ", + "your usage limit for this billing cycle. Your quota will be refreshed in ", + "the next cycle.\"", + ); + assert_eq!(parse_opencode_log_limit(log), Some(None)); + } + + #[test] + fn log_limit_ignores_ordinary_and_non_limit_error_lines() { + // An INFO runtime line and a non-limit ERROR (transient backend blip) must + // not be misread as a usage limit. + let log = concat!( + "{\"type\":\"text\",\"text\":\"working\"}\n", + "timestamp=2026-07-11T09:47:41.590Z level=INFO message=\"llm runtime ", + "selected\" llm.provider=zai-coding-plan llm.model=glm-5.2\n", + "timestamp=2026-07-11T09:48:22.735Z level=ERROR message=\"stream error\" ", + "error.error=\"AI_APICallError: Unexpected server error\"", + ); + assert_eq!(parse_opencode_log_limit(log), None); + } + // ── parse_opencode_events ──────────────────────────────────────────────── #[test] diff --git a/crates/ralphy-agent-opencode/src/lib.rs b/crates/ralphy-agent-opencode/src/lib.rs index 2099e0e3..ab0d6484 100644 --- a/crates/ralphy-agent-opencode/src/lib.rs +++ b/crates/ralphy-agent-opencode/src/lib.rs @@ -44,7 +44,8 @@ pub const ACCEPTS_IMAGES: bool = false; use command::build_opencode_command; use events::{ - is_opencode_auth_error, parse_opencode_events, parse_opencode_limit, OPENCODE_AUTH_ERROR_MSG, + is_opencode_auth_error, parse_opencode_events, parse_opencode_limit, parse_opencode_log_limit, + OPENCODE_AUTH_ERROR_MSG, }; use outcome::classify_opencode_outcome; use skills::{materialize_opencode_skills, opencode_skills_config}; @@ -243,7 +244,11 @@ impl Agent for OpenCodeAgent { let after_sha = git::head_sha(ws.repo_root()).unwrap_or_default(); let committed = before_sha != after_sha; let (text, saw_error) = parse_opencode_events(&stdout_text); - let limit = parse_opencode_limit(&stdout_text); + // Prefer the JSON-event limit (structured, carries reset hints); fall back to + // the logfmt scan over the combined stdout+stderr log for providers whose + // quota block only prints to `--print-logs` stderr and never reaches the JSON + // stream (Z.ai `zai-coding-plan`/GLM, kimi — D9, FinCal #71). + let limit = parse_opencode_limit(&stdout_text).or_else(|| parse_opencode_log_limit(&r.log)); let outcome = classify_opencode_outcome( r.exited_cleanly,