diff --git a/doc/testing-native-remote-continuity.md b/doc/testing-native-remote-continuity.md index 0b8fa199bd7..91887a1b71b 100644 --- a/doc/testing-native-remote-continuity.md +++ b/doc/testing-native-remote-continuity.md @@ -283,3 +283,121 @@ This is protocol and persistence evidence. The separate `everyday-workflows.runner-codex.daytona.recover-controller` Product E2E cell qualifies the actual Daytona/provider path, including completion and workspace finalization. Neither test substitutes for the other's failure boundary. + +## Required native usage acceptance + +Built-in native remote Runner execution accepts structured accounting before +its PRP transport ACK. `usage.reported`, turn-start, and turn-terminal facts +produce immutable `run_usage_receipts` rows. The receipt stores only structured +usage and turn identity. It does not depend on output logs or raw trace capture. +The source UUID derives from the run and Runner identity. Provider-turn IDs and +turn-start source facts preserve aggregation when several provider turns share +one PRP envelope turn. Source event IDs and +sequences remain stable across receiver replacement. Repeated delivery checks +the saved fact and does not create another receipt for the same report. + +A failed receipt transaction rejects acceptance. The remote Runner keeps its +outbox report and reconnects through its existing protocol lifecycle. A lost +commit response can replay the same immutable receipt. A replacement receiver +restores accepted per-turn aggregation from Postgres, then accepts pending +reports from the same producer. The existing source fence prevents a retired +producer from replacing the current source's usage. Missing or partial usage +keeps accounting pending; it does not produce a zero-cost charge. + +The native session authority epoch supplies the current run's accounting owner +to reused warm transports. The usual controller checkpoint and generation checks +still control transport acknowledgement and attachment. Ledger settlement, +pricing, reservations, and budget enforcement retain their existing owners. +No accounting receipt directory is created for this supported remote path. + +Local native execution, legacy adapters, and external Dot/Muse execution retain +their existing recorder behavior. This change does not establish disposable-web +accounting durability for those paths. Server-originated model calls keep their +existing admission and settlement records. No S3 accounting spool is introduced. +The independent run-log/trace storage change can consume its own persisted +sources; output acceptance is not accounting acceptance. + +Run the focused PostgreSQL/Runner experiment with: + +```sh +pnpm exec vitest run server/src/services/native-runtime/native-usage-delivery.integration.test.ts --maxWorkers=1 +``` + +The provider fixture emits a real PRP usage report through the durable Rust +Runner. A PostgreSQL trigger fails receipt insertion. The test removes the first +receiver directory, replaces its accounting owner, reconnects the same Runner, +and independently reads the receipt and ledger. The provider is controlled; +no paid provider request is made. Additional cases cover lost commit responses, +replay conflicts, per-turn aggregation, partial usage, source replacement, and +budget holds. Optional log and trace callbacks are absent from the experiment. + +The cold fixture build runs before opening PostgreSQL, with the existing native +integration build budget. PR CI routes this suite through the existing cached +native Runner lane. CI builds the release fixture; local execution uses debug. +The behavior test has its own bounded receiver/process deadline after compilation. + +### Codex usage authority and release order + +The qualified Codex producer keeps its current-run baseline and latest session +totals in its existing durable provider state. It observes historical resume +snapshots, preserves that baseline across process recovery, and resets the +baseline to the latest totals when attaching the next run. Multiple request +reports therefore emit the whole run delta, rather than the provider's last +request. Regressing or incomplete live counters cannot certify completion. + +Authoritative Codex reports carry `runDeltaBasis: "run"`. This requires a Runner +artifact built from the provider baseline implementation in this change. A +version string alone does not establish support; use the qualified artifact +digest. Existing unmarked Codex reports remain incomplete and unpriced in the +new accounting path. Their budget debt remains pending for reconciliation. +No deployed Runner artifact has been qualified by this source-only change. + +PRP negotiates envelope versions and the admitted Runner digest. It does not +negotiate this usage payload field. The existing event envelope validators leave +usage payloads open, but an old standalone usage-schema consumer rejects this +new field. Update receivers and strict usage-schema consumers first, then +release the matching Runner artifact before claiming this durability guarantee. +Finish or explicitly reconcile older admitted Codex runs during cutover. Do not +claim that an old producer's final-request delta is a whole-run receipt. + +Heartbeat completion reads the current immutable accepted receipt, including its +saved exact rate-card amount and provenance. It does not reprice with current +rates or replace that accepted estimate with an absent provider dollar amount. +The terminal UPDATE preserves the current producer-owned accounting projection +atomically. If another report arrived after completion read its checkpoint, the +newer receipt, readiness, price, and budget exposure win; unrelated session and +completion metadata can still update. A newer partial receipt stays pending. +Non-accounting attachment control events keep their existing handoff acceptance; +an old run's accounting report still cannot acquire a successor's authority. + +The provider drains its bounded settled-turn usage tail before publishing the +terminal event that closes the run. An authoritative active goal keeps its +existing continuation path unless an uncorrected completion rejection closes +the run. The +same owner predicate selects both final usage drain and terminal outcome. A +completed turn remains authoritative after a +fully drained provider exit; ordinary session-exit handling still records an +unavailable process independently. This keeps a late cumulative increase on the old run before the +next run resets its baseline. Readiness and attachment retain accounting facts +in the existing provider checkpoint instead of discarding them, including facts +consumed before a later quiescence error. An increase +that arrives after authoritative completion requires explicit reconciliation: +PostgreSQL rejects changed finalized native usage or authoritative monetary evidence, so the existing Runner +outbox retains it under the old source identity without another charge. Equal +snapshots are harmless. No recurring scan or automatic adjustment is added. + +If delayed usage arrives after attachment and cannot belong to the current +provider turn, the provider retains its cumulative evidence and the matching +saved prior identity, leaves the successor baseline unchanged, and emits a +failed run terminal. The existing reconciliation lifecycle blocks further work, +including after restart. Unknown older ownership stays explicit rather than +being inferred from provider-supplied run identity. Manual reconciliation or a +fresh session is required for this rare unsupported timing case. + +Prior-turn increases are checked against the saved attachment baseline, even +when a successor has already reported a higher session total. Required usage +bypasses the optional diagnostic limit. An affected successor publishes an +explicit incomplete usage report before failure; this preserves known budget +exposure without settling ambiguous usage. That required report and its receipt +retain the accounting measurements and matching saved prior identity, so an +optional diagnostic acknowledgement cannot discard reconciliation evidence. diff --git a/packages/paperclip-runner/protocol/manifest.json b/packages/paperclip-runner/protocol/manifest.json index 6e2bd463f70..6082b67c456 100644 --- a/packages/paperclip-runner/protocol/manifest.json +++ b/packages/paperclip-runner/protocol/manifest.json @@ -140,7 +140,7 @@ { "path": "schemas/usage.schema.json", "id": "https://paperclip.dev/schemas/prp/v1/usage.schema.json", - "sha256": "34b1478d2054f898d64b54b62a9bb738670087893bb1e5967da541539d2daf36" + "sha256": "be9609768b224459546b800236045b375448f2cb2cb47ccb337e149e0b016361" }, { "path": "schemas/workspace-diff.schema.json", diff --git a/packages/paperclip-runner/protocol/schemas/usage.schema.json b/packages/paperclip-runner/protocol/schemas/usage.schema.json index c1a57e17bf3..1f6bf2e1094 100644 --- a/packages/paperclip-runner/protocol/schemas/usage.schema.json +++ b/packages/paperclip-runner/protocol/schemas/usage.schema.json @@ -11,6 +11,73 @@ "providerRequestId": { "type": ["string", "null"], "maxLength": 240 }, "cumulative": { "$ref": "#/$defs/measurement" }, "runDeltaAvailable": { "type": "boolean" }, + "runDeltaBasis": { "const": "run" }, + "reconciliation": { + "type": "object", + "required": [ + "reason", + "receivedTurnId", + "cumulative", + "priorOrigin" + ], + "properties": { + "reason": { + "const": "accounting_reconciliation_required" + }, + "receivedTurnId": { + "type": [ + "string", + "null" + ], + "maxLength": 240 + }, + "cumulative": { + "$ref": "#/$defs/measurement" + }, + "priorOrigin": { + "type": [ + "object", + "null" + ], + "required": [ + "runnerInstanceId", + "runId", + "normalizedSessionId", + "turnId", + "itemId" + ], + "properties": { + "runnerInstanceId": { + "type": "string", + "minLength": 1, + "maxLength": 240 + }, + "runId": { + "type": "string", + "minLength": 1, + "maxLength": 240 + }, + "normalizedSessionId": { + "type": "string", + "minLength": 1, + "maxLength": 240 + }, + "turnId": { + "type": "string", + "minLength": 1, + "maxLength": 240 + }, + "itemId": { + "type": "string", + "minLength": 1, + "maxLength": 240 + } + }, + "additionalProperties": false + } + }, + "additionalProperties": false + }, "runDelta": { "$ref": "#/$defs/measurement" } }, "additionalProperties": false, diff --git a/packages/paperclip-runner/runner/crates/runner-core/examples/recovery-fixture.rs b/packages/paperclip-runner/runner/crates/runner-core/examples/recovery-fixture.rs index 0398a6b2f3f..9a514bc3de9 100644 --- a/packages/paperclip-runner/runner/crates/runner-core/examples/recovery-fixture.rs +++ b/packages/paperclip-runner/runner/crates/runner-core/examples/recovery-fixture.rs @@ -21,6 +21,8 @@ struct Script { retention_limit: usize, release_file: PathBuf, receipt_file: PathBuf, + #[serde(default)] + accounting: bool, } #[derive(Default)] @@ -86,11 +88,37 @@ fn workload(script: Script, shared: Shared) { digest = Sha256::digest(digest); } work = lock.lock().unwrap(); + let (event_type, payload) = if script.accounting { + if step == 1 { + ( + "usage.reported", + json!({"provider":"openai", "model":"test-model", + "runDeltaAvailable":true, "runDeltaBasis":"run", "runDelta":{"inputTokens":120,"outputTokens":10,"providerCostUsd":0.25}}), + ) + } else if step == 2 { + ("turn.completed", json!({"status":"completed"})) + } else { + ( + "usage.reported", + json!({"provider":"openai","model":"test-model","runDeltaAvailable":true,"runDeltaBasis":"run", + "runDelta":{"inputTokens":150,"outputTokens":15,"providerCostUsd":0.5}}), + ) + } + } else { + ( + "item.delta", + json!({"text": format!("step={step} sha256={digest:x}\n")}), + ) + }; work.events.push_back(PolledEvent { executor_event_id: format!("fixture-step-{step}"), - event_type: "item.delta".to_owned(), - priority: EventPriority::P2, - payload: json!({"text": format!("step={step} sha256={digest:x}\n")}), + event_type: event_type.to_owned(), + priority: if script.accounting { + EventPriority::P0 + } else { + EventPriority::P2 + }, + payload, }); work.completed = step; work.peak_retained = work.peak_retained.max(work.events.len()); diff --git a/packages/paperclip-runner/runner/crates/runner-core/src/bin/fake-codex-app-server.rs b/packages/paperclip-runner/runner/crates/runner-core/src/bin/fake-codex-app-server.rs index 47c83bc81b5..88f6c18c27e 100644 --- a/packages/paperclip-runner/runner/crates/runner-core/src/bin/fake-codex-app-server.rs +++ b/packages/paperclip-runner/runner/crates/runner-core/src/bin/fake-codex-app-server.rs @@ -333,20 +333,60 @@ fn finish_turn_with_send( "text": "Codex completed the fake turn." }} }))?; + let cumulative_accounting = std::env::args().any(|arg| arg == "--cumulative-accounting-usage"); + let warm_tail_accounting = std::env::args().any(|arg| arg == "--warm-tail-accounting"); + let total_input = if warm_tail_accounting { + if state.next_turn == 1 { + 100 + } else { + 150 + } + } else if cumulative_accounting { + 100 + state.next_turn * 100 + } else { + 12 + }; + let total_output = if warm_tail_accounting { + if state.next_turn == 1 { + 10 + } else { + 15 + } + } else if cumulative_accounting { + 20 + state.next_turn * 10 + } else { + 3 + }; + if cumulative_accounting { + send( + json!({"method":"thread/tokenUsage/updated","params":{"threadId":state.thread_id,"turnId":turn_id, + "tokenUsage":{"total":{"inputTokens":total_input-40,"outputTokens":total_output-4},"last":{"inputTokens":10,"outputTokens":1}}}}), + )?; + } send(json!({ "method": "thread/tokenUsage/updated", "params": { "threadId": state.thread_id, "tokenUsage": { - "total": {"inputTokens": 12, "outputTokens": 3}, - "last": {"inputTokens": 12, "outputTokens": 3, "requests": 1} + "total": {"inputTokens": total_input, "outputTokens": total_output}, + "last": {"inputTokens": if cumulative_accounting {40} else {12}, "outputTokens": if cumulative_accounting {4} else {3}, "requests": 1} } } }))?; + if state.next_turn > 1 && std::env::args().any(|arg| arg == "--hold-second-accounting-terminal") + { + return Ok(()); + } send(json!({ "method": "turn/completed", "params": {"turn": {"id": turn_id, "status": status}} }))?; + if std::env::args().any(|arg| arg == "--accounting-tail-after-terminal") { + send( + json!({"method":"thread/tokenUsage/updated","params":{"threadId":state.thread_id,"turnId":turn_id, + "tokenUsage":{"total":{"inputTokens":120,"outputTokens":12},"last":{"inputTokens":20,"outputTokens":2}}}}), + )?; + } Ok(()) } @@ -1285,7 +1325,7 @@ fn run() -> Result<(), Box> { for _ in 0..2 { send(json!({"method": "thread/tokenUsage/updated", "params": { "threadId": state.thread_id, "turnId": format!("provider-turn-{}", state.next_turn), - "tokenUsage": {"total": {"inputTokens": 100, "outputTokens": 20}, "last": {"inputTokens": 50, "outputTokens": 10}} + "tokenUsage": {"total": {"inputTokens": if args.iter().any(|arg| arg == "--cumulative-accounting-usage") {100 + state.next_turn * 100} else {100}, "outputTokens": if args.iter().any(|arg| arg == "--cumulative-accounting-usage") {20 + state.next_turn * 10} else {20}}, "last": {"inputTokens": 50, "outputTokens": 10}} }}))?; } } @@ -1889,6 +1929,43 @@ fn run() -> Result<(), Box> { } }))?; } + if state.next_turn == 1 { + if let Some(gate) = + argument(&args, "--late-accounting-tail-gate").map(PathBuf::from) + { + let thread_id = state.thread_id.clone(); + let turn_id = provider_turn_id.clone(); + let unsafe_tail = + args.iter().any(|arg| arg == "--unsafe-after-late-usage"); + let duplicate_burst = args + .iter() + .any(|arg| arg == "--late-accounting-duplicate-burst"); + thread::spawn(move || { + let deadline = std::time::Instant::now() + Duration::from_secs(10); + while !gate.is_file() && std::time::Instant::now() < deadline { + thread::sleep(Duration::from_millis(1)); + } + if gate.is_file() { + if duplicate_burst { + for _ in 0..33 { + let _ = send( + json!({"method":"thread/tokenUsage/updated","params":{"threadId":thread_id,"turnId":turn_id,"tokenUsage":{"total":{"inputTokens":100,"outputTokens":10}}}}), + ); + } + } + let _ = send( + json!({"method":"thread/tokenUsage/updated","params":{"threadId":thread_id,"turnId":turn_id, + "tokenUsage":{"total":{"inputTokens":120,"outputTokens":12},"last":{"inputTokens":20,"outputTokens":2}}}}), + ); + if unsafe_tail { + let _ = send( + json!({"method":"turn/started","params":{"threadId":thread_id,"turn":{"id":"unsafe-next-turn"}}}), + ); + } + } + }); + } + } if emit_post_completion_warning { send(json!({ "method": "warning", @@ -1900,7 +1977,7 @@ fn run() -> Result<(), Box> { json!({ "method": "thread/tokenUsage/updated", "params": {"threadId": state.thread_id, "turnId": provider_turn_id, - "tokenUsage": {"total": {"inputTokens": 120, "outputTokens": 12}, + "tokenUsage": {"total": {"inputTokens": if args.iter().any(|arg| arg == "--warm-tail-accounting") && state.next_turn > 1 {150} else {120}, "outputTokens": if args.iter().any(|arg| arg == "--warm-tail-accounting") && state.next_turn > 1 {15} else {12}}, "last": {"inputTokens": 20, "outputTokens": 2}}} }), json!({ diff --git a/packages/paperclip-runner/runner/crates/runner-core/src/codex_provider.rs b/packages/paperclip-runner/runner/crates/runner-core/src/codex_provider.rs index 5f16baf89df..50f00d18adf 100644 --- a/packages/paperclip-runner/runner/crates/runner-core/src/codex_provider.rs +++ b/packages/paperclip-runner/runner/crates/runner-core/src/codex_provider.rs @@ -1342,6 +1342,7 @@ impl CodexProvider { &mut self, authorized_tools: impl IntoIterator, completion_contract: Option<(&str, &[String])>, + accounting: &mut Vec<(String, Value)>, ) -> Result { let authorized_tools = authorized_tools.into_iter().collect::>(); let completion_contract = @@ -1354,7 +1355,15 @@ impl CodexProvider { { return Ok(false); } - let blockers = self.warm_run_attachment_blockers(true)?; + let (tail, result) = self.drain_completed_turn_tail_for_warm_attachment(); + accounting.extend(tail); + result?; + if !accounting.is_empty() { + return Err(LocalRunnerError::invalid( + "Codex warm run attachment requires pending accounting reconciliation", + )); + } + let blockers = self.warm_run_attachment_blockers()?; if !blockers.is_empty() { return Err(LocalRunnerError::invalid( format!( @@ -1375,49 +1384,53 @@ impl CodexProvider { Ok(true) } - fn drain_completed_turn_tail_for_warm_attachment(&mut self) -> Result<(), LocalRunnerError> { - let Some(completed_turn_id) = self - .completed_turn_authority - .as_ref() - .map(|authority| authority.provider_turn_id.clone()) - else { - return Ok(()); - }; - if self.active_provider_turn_id.is_some() { - return Ok(()); - } - - // Readiness probes run over the PRP command channel while provider - // stdout is drained by runnerd's adjacent control-loop iteration. A - // final usage/warning/item frame can therefore land after the last - // successful probe but before run.attach executes. Close that race in - // the same critical section as authority rotation. Only bounded tail - // notifications for the already-settled turn may be discarded: a new - // turn, provider request, process exit, or mismatched turn remains a - // fail-closed attachment error. - let deadline = std::time::Instant::now() + WARM_ATTACHMENT_DRAIN_DEADLINE; - let mut quiet_since: Option = None; - let mut drained = 0usize; - loop { - if std::time::Instant::now() >= deadline { - return Err(LocalRunnerError::invalid( - "Codex warm run attachment tail did not become quiescent", - )); + pub(crate) fn drain_completed_turn_tail_for_warm_attachment( + &mut self, + ) -> (Vec<(String, Value)>, Result<(), LocalRunnerError>) { + let mut accounting = Vec::new(); + let result = (|| { + let Some(completed_turn_id) = self + .completed_turn_authority + .as_ref() + .map(|authority| authority.provider_turn_id.clone()) + else { + return Ok(()); + }; + if self.active_provider_turn_id.is_some() { + return Ok(()); } - match self.poll()? { - Some(CodexProviderEvent::Notification { method, params }) => { - quiet_since = None; - drained = drained.saturating_add(1); - if drained > WARM_ATTACHMENT_TAIL_DRAIN_LIMIT { - return Err(LocalRunnerError::invalid( - "Codex warm run attachment tail exceeded its bounded frame limit", - )); - } - let names_other_turn = notification_turn_id(¶ms) - .is_some_and(|turn_id| turn_id != completed_turn_id); - let safe_tail_method = matches!( - method.as_str(), - "warning" + + // Readiness probes run over the PRP command channel while provider + // stdout is drained by runnerd's adjacent control-loop iteration. A + // final usage/warning/item frame can therefore land after the last + // successful probe but before run.attach executes. Close that race in + // the same critical section as authority rotation. Only bounded tail + // notifications for the already-settled turn may be discarded: a new + // turn, provider request, process exit, or mismatched turn remains a + // fail-closed attachment error. + let deadline = std::time::Instant::now() + WARM_ATTACHMENT_DRAIN_DEADLINE; + let mut quiet_since: Option = None; + let mut drained = 0usize; + loop { + if std::time::Instant::now() >= deadline { + return Err(LocalRunnerError::invalid( + "Codex warm run attachment tail did not become quiescent", + )); + } + match self.poll()? { + Some(CodexProviderEvent::Notification { method, params }) => { + quiet_since = None; + drained = drained.saturating_add(1); + if drained > WARM_ATTACHMENT_TAIL_DRAIN_LIMIT { + return Err(LocalRunnerError::invalid( + "Codex warm run attachment tail exceeded its bounded frame limit", + )); + } + let names_other_turn = notification_turn_id(¶ms) + .is_some_and(|turn_id| turn_id != completed_turn_id); + let safe_tail_method = matches!( + method.as_str(), + "warning" | "configWarning" | "remoteControl/status/changed" | "mcpServer/startupStatus/updated" @@ -1436,73 +1449,82 @@ impl CodexProvider { | "thread/status/changed" | "turn/diff/updated" | "turn/plan/updated" - ); - if names_other_turn || !safe_tail_method { - return Err(LocalRunnerError::invalid(format!( + ); + if names_other_turn || !safe_tail_method { + return Err(LocalRunnerError::invalid(format!( "Codex warm run attachment observed unsafe post-terminal provider method {}", bounded_method(&method) ))); - } - if let Some(frame_id) = self.take_provider_trace_frame_id() { - self.record_provider_trace_interpretation( + } + if matches!( + method.as_str(), + "thread/tokenUsage/updated" | "paperclip/resumeUsageSnapshot" + ) { + accounting.push((method, params)); + continue; + } + if let Some(frame_id) = self.take_provider_trace_frame_id() { + self.record_provider_trace_interpretation( frame_id, "codex.warm_attachment.completed_turn_tail", "ignored", Vec::new(), "Provider emitted a bounded tail notification after the prior turn terminal and before run attachment", ); + } } - } - Some(CodexProviderEvent::ResourceLimit { .. }) => { - return Err(LocalRunnerError::invalid("Codex descendant capacity requires reconciliation before fresh-session continuation")); - } - Some(CodexProviderEvent::ProtocolFailure { .. }) => { - return Err(LocalRunnerError::invalid( - "Codex protocol integrity failed during warm attachment", - )); - } - Some(CodexProviderEvent::DescendantNotification { .. }) => { - // Child output cannot certify a quiescent root attachment. - return Err(LocalRunnerError::invalid( - "Codex descendant remains active during warm run attachment", - )); - } - Some(CodexProviderEvent::ToolCall { .. }) - | Some(CodexProviderEvent::RuntimeRequest { .. }) - | Some(CodexProviderEvent::McpPermissionRequest { .. }) => { - return Err(LocalRunnerError::invalid( - "Codex warm run attachment observed a post-terminal provider request", - )); - } - Some(CodexProviderEvent::Exited { .. }) => { - return Err(LocalRunnerError::invalid( - "Codex exited while quiescing for warm run attachment", - )); - } - None => { - let now = std::time::Instant::now(); - let quiet_start = quiet_since.get_or_insert(now); - if now.duration_since(*quiet_start) >= WARM_ATTACHMENT_QUIET_WINDOW { - return Ok(()); + Some(CodexProviderEvent::ResourceLimit { .. }) => { + return Err(LocalRunnerError::invalid("Codex descendant capacity requires reconciliation before fresh-session continuation")); + } + Some(CodexProviderEvent::ProtocolFailure { .. }) => { + return Err(LocalRunnerError::invalid( + "Codex protocol integrity failed during warm attachment", + )); + } + Some(CodexProviderEvent::DescendantNotification { .. }) => { + // Child output cannot certify a quiescent root attachment. + return Err(LocalRunnerError::invalid( + "Codex descendant remains active during warm run attachment", + )); + } + Some(CodexProviderEvent::ToolCall { .. }) + | Some(CodexProviderEvent::RuntimeRequest { .. }) + | Some(CodexProviderEvent::McpPermissionRequest { .. }) => { + return Err(LocalRunnerError::invalid( + "Codex warm run attachment observed a post-terminal provider request", + )); + } + Some(CodexProviderEvent::Exited { + completed_turn_authoritative, + completion_reconciles_exit, + .. + }) if completion_reconciles_exit + || (completed_turn_authoritative && self.process.stdout_drained()) => + { + return Ok(()) + } + Some(CodexProviderEvent::Exited { .. }) => { + return Err(LocalRunnerError::invalid( + "Codex exited while quiescing for warm run attachment", + )); + } + None => { + let now = std::time::Instant::now(); + let quiet_start = quiet_since.get_or_insert(now); + if now.duration_since(*quiet_start) >= WARM_ATTACHMENT_QUIET_WINDOW { + return Ok(()); + } + std::thread::sleep(Duration::from_millis(1)); } - std::thread::sleep(Duration::from_millis(1)); } } - } + })(); + (accounting, result) } pub(crate) fn warm_run_attachment_blockers( &mut self, - quiesce_completed_tail: bool, ) -> Result, LocalRunnerError> { - // Only an explicit attachment-readiness probe may consume the bounded, - // already-settled provider suffix. Ordinary checkpoint snapshots run - // immediately after a terminal frame while the provider can still be - // unwinding; turning those observations into quiescence barriers can - // quarantine an otherwise reusable runner before its next turn. - if quiesce_completed_tail { - self.drain_completed_turn_tail_for_warm_attachment()?; - } let mut blockers = Vec::new(); if self.process.try_wait()?.is_some() { blockers.push("process_exited"); @@ -1517,7 +1539,18 @@ impl CodexProvider { blockers.push("ambiguous_turn_start"); } if !self.pending_messages.is_empty() { - blockers.push("pending_messages"); + blockers.push( + if self.pending_messages.iter().any(|message| { + matches!( + message.value.get("method").and_then(Value::as_str), + Some("paperclip/resumeUsageSnapshot" | "thread/tokenUsage/updated") + ) + }) { + "pending_accounting_reconciliation" + } else { + "pending_messages" + }, + ); } if !self.deferred_ambiguous_messages.is_empty() { blockers.push("deferred_messages"); @@ -2919,13 +2952,11 @@ impl CodexProvider { .and_then(Value::as_str); if notification_turn_id.is_some() && notification_turn_id != self.active_provider_turn_id.as_deref() - && notification_turn_id + && (notification_turn_id .is_some_and(|turn_id| self.settled_provider_turn_ids.contains(turn_id)) + || (self.active_provider_turn_id.is_none() + && method == "thread/tokenUsage/updated")) { - self.notification_identity_diagnostics += 1; - if self.notification_identity_diagnostics > 32 { - return Ok(None); - } // Resume replays the cumulative usage of the last settled turn. // Keep its identity and baseline, but never bill its `last` // measurement to the newly attached run. @@ -2941,6 +2972,10 @@ impl CodexProvider { }), })); } + self.notification_identity_diagnostics += 1; + if self.notification_identity_diagnostics > 32 { + return Ok(None); + } return Ok(Some(CodexProviderEvent::Notification { method: "warning".to_owned(), params: json!({ @@ -4392,9 +4427,58 @@ done }); // poll() normalizes settled-turn usage to paperclip/resumeUsageSnapshot. // That accounting fact is not new work and must not force replacement. - let result = provider.drain_completed_turn_tail_for_warm_attachment(); + let (accounting, result) = provider.drain_completed_turn_tail_for_warm_attachment(); provider.shutdown().unwrap(); - result.expect("historical usage must not break provider continuity"); + result.expect("historical usage must remain available to its owner"); + assert_eq!(accounting.len(), 1); + assert_eq!(accounting[0].1["total"]["inputTokens"], 120); + } + + #[cfg(unix)] + #[test] + fn failed_warm_drain_retains_consumed_usage_before_unsafe_tail() { + for attach in [false, true] { + let mut provider = completion_tail_provider(); + provider + .restore_completed_turn_authority(true, Some(1), Some("reader-tail-1")) + .unwrap(); + provider.active_provider_turn_id = None; + for value in [ + json!({"method":"thread/tokenUsage/updated","params":{"threadId":"reader-tail-thread","turnId":"reader-tail-1","tokenUsage":{"total":{"inputTokens":120,"outputTokens":12}}}}), + json!({"method":"turn/started","params":{"threadId":"reader-tail-thread","turn":{"id":"unsafe-next-turn"}}}), + ] { + provider + .pending_messages + .push_back(BufferedProviderMessage { + value, + trace_frame_id: None, + }); + } + let (accounting, result) = if attach { + let mut accounting = Vec::new(); + let tools = provider.authorized_tools.clone(); + let contract = provider.completion_contract.clone(); + let result = provider + .attach_run_in_place( + tools, + contract.as_ref().map(|contract| { + ( + contract.revision.as_str(), + contract.criterion_ids.as_slice(), + ) + }), + &mut accounting, + ) + .map(|_| ()); + (accounting, result) + } else { + provider.drain_completed_turn_tail_for_warm_attachment() + }; + provider.shutdown().unwrap(); + assert!(result.is_err()); + assert_eq!(accounting.len(), 1); + assert_eq!(accounting[0].1["total"]["inputTokens"], 120); + } } #[cfg(unix)] diff --git a/packages/paperclip-runner/runner/crates/runner-core/src/codex_usage.rs b/packages/paperclip-runner/runner/crates/runner-core/src/codex_usage.rs new file mode 100644 index 00000000000..41e282ffe97 --- /dev/null +++ b/packages/paperclip-runner/runner/crates/runner-core/src/codex_usage.rs @@ -0,0 +1,234 @@ +use std::collections::BTreeMap; + +use serde::{Deserialize, Serialize}; +use serde_json::{json, Value}; + +#[derive(Clone, Debug, Deserialize, Serialize, PartialEq)] +pub(crate) struct CodexRunUsage { + baseline: Option>, + latest: BTreeMap, +} + +impl CodexRunUsage { + pub(crate) fn new(requires_baseline: bool) -> Self { + Self { + baseline: (!requires_baseline).then(BTreeMap::new), + latest: BTreeMap::new(), + } + } + + pub(crate) fn is_valid(&self) -> bool { + self.baseline + .iter() + .flat_map(|values| values.values()) + .chain(self.latest.values()) + .all(|value| { + value + .as_f64() + .is_some_and(|value| value.is_finite() && value >= 0.0) + }) + } + + pub(crate) fn increases_known_usage(&self, total: &Value) -> bool { + !self.latest.is_empty() + && total.as_object().is_some_and(|total| { + total.iter().any(|(key, value)| { + value.as_f64().is_some_and(|value| { + value > self.latest.get(key).and_then(Value::as_f64).unwrap_or(0.0) + }) + }) + }) + } + + pub(crate) fn increases_run_baseline(&self, total: &Value) -> bool { + self.baseline.as_ref().is_some_and(|baseline| { + total.as_object().is_some_and(|total| { + total.iter().any(|(key, value)| { + value.as_f64().is_some_and(|value| { + value > baseline.get(key).and_then(Value::as_f64).unwrap_or(0.0) + }) + }) + }) + }) + } + + pub(crate) fn has_baseline(&self) -> bool { + self.baseline.is_some() + } + + pub(crate) fn begin_run(&mut self) { + if self.latest.is_empty() { + return; + } + self.baseline = (valid_token(self.latest.get("inputTokens")) + && valid_token(self.latest.get("outputTokens"))) + .then(|| self.latest.clone()); + } + + pub(crate) fn observe(&mut self, total: &Value, historical: bool) -> (Value, bool) { + let measurement: BTreeMap = total + .as_object() + .into_iter() + .flat_map(|value| value.iter()) + .filter(|(_, value)| { + value + .as_f64() + .is_some_and(|value| value.is_finite() && value >= 0.0) + }) + .map(|(key, value)| (key.clone(), value.clone())) + .collect(); + let complete = self.baseline.is_some() + && (historical + || measurement.iter().all(|(key, value)| { + !key.ends_with("Tokens") + || value.as_u64().is_some_and(|value| { + value >= self.latest.get(key).and_then(Value::as_u64).unwrap_or(0) + && value + >= self + .baseline + .as_ref() + .and_then(|baseline| baseline.get(key)) + .and_then(Value::as_u64) + .unwrap_or(0) + }) + })) + && valid_token(measurement.get("inputTokens")) + && valid_token(measurement.get("outputTokens")) + && measurement + .iter() + .all(|(key, value)| !key.ends_with("Tokens") || valid_token(Some(value))) + && self + .latest + .keys() + .all(|key| !key.ends_with("Tokens") || valid_token(measurement.get(key))); + if historical + && self.baseline.is_none() + && valid_token(measurement.get("inputTokens")) + && valid_token(measurement.get("outputTokens")) + { + self.baseline = Some(measurement.clone()); + } + for (key, value) in measurement { + if value.as_f64().unwrap() + >= self.latest.get(&key).and_then(Value::as_f64).unwrap_or(0.0) + { + self.latest.insert(key, value); + } + } + let delta: serde_json::Map = self + .latest + .iter() + .map(|(key, value)| { + let baseline = self + .baseline + .as_ref() + .and_then(|baseline| baseline.get(key)); + let delta = if let Some(value) = value.as_u64() { + json!(value.saturating_sub(baseline.and_then(Value::as_u64).unwrap_or(0))) + } else { + json!((value.as_f64().unwrap() + - baseline.and_then(Value::as_f64).unwrap_or(0.0)) + .max(0.0)) + }; + (key.clone(), delta) + }) + .collect(); + (Value::Object(delta), complete) + } +} + +fn valid_token(value: Option<&Value>) -> bool { + value + .and_then(Value::as_u64) + .is_some_and(|value| value <= 9_007_199_254_740_991) +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn preserves_resumed_baselines_across_requests_recovery_and_attachment() { + let mut usage = CodexRunUsage::new(true); + usage.observe( + &json!({"inputTokens":100,"outputTokens":10,"cachedInputTokens":20}), + true, + ); + let (first, complete) = usage.observe( + &json!({"inputTokens":140,"outputTokens":16,"cachedInputTokens":25}), + false, + ); + assert!(complete); + assert_eq!(first["inputTokens"], 40); + let mut restored: CodexRunUsage = + serde_json::from_value(serde_json::to_value(&usage).unwrap()).unwrap(); + let (second, complete) = restored.observe( + &json!({"inputTokens":190,"outputTokens":25,"cachedInputTokens":30}), + false, + ); + assert!(complete); + assert_eq!( + second, + json!({"inputTokens":90,"outputTokens":15,"cachedInputTokens":10}) + ); + restored.begin_run(); + let (next, complete) = restored.observe( + &json!({"inputTokens":220,"outputTokens":29,"cachedInputTokens":32}), + false, + ); + assert!(complete); + assert_eq!( + next, + json!({"inputTokens":30,"outputTokens":4,"cachedInputTokens":2}) + ); + } + + #[test] + fn attachment_before_paid_work_preserves_a_proven_empty_baseline() { + let mut usage = CodexRunUsage::new(false); + usage.begin_run(); + let (delta, complete) = usage.observe(&json!({"inputTokens":100,"outputTokens":10}), false); + assert!(complete); + assert_eq!(delta, json!({"inputTokens":100,"outputTokens":10})); + let mut unknown = CodexRunUsage::new(true); + unknown.begin_run(); + assert!( + !unknown + .observe(&json!({"inputTokens":100,"outputTokens":10}), false) + .1 + ); + } + + #[test] + fn regressing_live_totals_remain_incomplete_without_losing_known_exposure() { + let mut usage = CodexRunUsage::new(false); + usage.observe(&json!({"inputTokens":100,"outputTokens":10}), false); + let (delta, complete) = usage.observe(&json!({"inputTokens":90,"outputTokens":9}), false); + assert!(!complete); + assert_eq!(delta, json!({"inputTokens":100,"outputTokens":10})); + let mut resumed = CodexRunUsage::new(true); + resumed.observe(&json!({"inputTokens":100,"outputTokens":10}), true); + assert!( + !resumed + .observe(&json!({"inputTokens":90,"outputTokens":9}), false) + .1 + ); + } + + #[test] + fn unknown_baselines_and_missing_counters_cannot_certify_usage() { + let mut usage = CodexRunUsage::new(true); + assert!( + !usage + .observe(&json!({"inputTokens":140,"outputTokens":16}), false) + .1 + ); + usage.observe(&json!({"inputTokens":100,"outputTokens":10}), true); + assert!(!usage.observe(&json!({"inputTokens":160}), false).1); + assert!( + usage + .observe(&json!({"inputTokens":170,"outputTokens":20}), false) + .1 + ); + } +} diff --git a/packages/paperclip-runner/runner/crates/runner-core/src/lib.rs b/packages/paperclip-runner/runner/crates/runner-core/src/lib.rs index 5c1d58d335f..ffbc524010e 100644 --- a/packages/paperclip-runner/runner/crates/runner-core/src/lib.rs +++ b/packages/paperclip-runner/runner/crates/runner-core/src/lib.rs @@ -13,6 +13,7 @@ pub mod aws_agentcore_provider; pub mod claude_managed_provider; pub mod codex_provider; mod codex_startup_trust; +mod codex_usage; mod configured_environment; mod credential_observer; pub mod dot_provider_backend; diff --git a/packages/paperclip-runner/runner/crates/runner-core/src/provider_backend.rs b/packages/paperclip-runner/runner/crates/runner-core/src/provider_backend.rs index c84f57773e8..74a14c53002 100644 --- a/packages/paperclip-runner/runner/crates/runner-core/src/provider_backend.rs +++ b/packages/paperclip-runner/runner/crates/runner-core/src/provider_backend.rs @@ -17,6 +17,7 @@ use crate::codex_provider::{ ProviderStartupObservation, ProviderStartupStage, RejectedAcceptedTurn, MAX_SETTLED_PROVIDER_TURN_IDS, }; +use crate::codex_usage::CodexRunUsage; use crate::durable::{ create_private_temporary_file, current_unix_ms, open_private_regular_file, sanitize_value, validate_semantic_tool_input, verify_private_directory, Command, CommandExecution, @@ -93,6 +94,13 @@ struct ProviderEventIdentity { item_id: String, } +#[derive(Clone, Debug, Deserialize, Serialize, PartialEq)] +#[serde(rename_all = "camelCase", deny_unknown_fields)] +struct CodexAccountingOrigin { + identity: ProviderEventIdentity, + provider_turn_id: String, +} + #[derive(Clone, Debug, Deserialize, Serialize, PartialEq)] #[serde(rename_all = "camelCase", deny_unknown_fields)] struct ProviderStartupCommand { @@ -608,6 +616,105 @@ fn normalize_provider_notification( method: &str, params: &Value, ) -> Result, DurableRunnerError> { + if state.config.provider == "codex" + && ["thread/tokenUsage/updated", "paperclip/resumeUsageSnapshot"].contains(&method) + { + let historical = method == "paperclip/resumeUsageSnapshot"; + let total = if historical { + params.get("total") + } else { + params.pointer("/tokenUsage/total") + } + .unwrap_or(&Value::Null); + let increases_known_usage = state + .codex_usage + .as_ref() + .is_some_and(|usage| usage.increases_known_usage(total)); + let received_turn = params.get("turnId").and_then(Value::as_str); + let increases_prior_baseline = state.previous_accounting_origin.is_some() + && received_turn != state.completed_provider_turn_id.as_deref() + && state + .codex_usage + .as_ref() + .is_some_and(|usage| usage.increases_run_baseline(total)); + if historical + && (increases_known_usage || increases_prior_baseline) + && params.get("turnId").and_then(Value::as_str) + != state.active_provider_turn_id.as_deref() + { + state.lifecycle = "reconciliation_required".to_owned(); + let owns_completed_turn = state.active_provider_turn_id.is_none() + && state + .completed_provider_turn_id + .as_deref() + .is_some_and(|id| params.get("turnId").and_then(Value::as_str) == Some(id)); + if !owns_completed_turn { + if state.active_provider_turn_id.is_some() { + state.settle_active_provider_turn_identity()?; + } + state.active_provider_turn_id = None; + let mut invalidation = normalize_codex_notification("thread/tokenUsage/updated", &json!({ + "threadId":params.get("threadId"), "model":state.config.model, "tokenUsage":{"total":total} + })).remove(0); + invalidation.payload["runDeltaBasis"] = json!("run"); + invalidation.payload["reconciliation"] = json!({"reason":"accounting_reconciliation_required", + "receivedTurnId":params.get("turnId"),"cumulative":invalidation.payload["cumulative"], + "priorOrigin":state.previous_accounting_origin.as_ref().filter(|origin| received_turn == Some(origin.provider_turn_id.as_str())).map(|origin| &origin.identity)}); + return Ok(vec![ + NormalizedProviderEvent { + event_type: "harness.diagnostic".to_owned(), + priority: EventPriority::P0, + payload: json!({"code":"codex_usage_accounting_integrity", "classification":"accounting_reconciliation_required", + "receivedTurnId":params.get("turnId"),"cumulative":total,"priorOrigin":state.previous_accounting_origin.as_ref().filter(|origin| params.get("turnId").and_then(Value::as_str) == Some(origin.provider_turn_id.as_str())).map(|origin| &origin.identity), + "message":"Late provider usage cannot be attributed to the attached run; explicit reconciliation is required"}), + }, + invalidation, + NormalizedProviderEvent { + event_type: "turn.failed".to_owned(), + priority: EventPriority::P0, + payload: json!({"provider":"codex","status":"failed","code":"codex_usage_accounting_integrity","recoverable":false, + "message":"Late provider usage requires explicit accounting reconciliation"}), + }, + NormalizedProviderEvent { + event_type: "run.terminal".to_owned(), + priority: EventPriority::P0, + payload: json!({"schema":"paperclip.prp.terminal.v1","provider":"codex","turnTerminalState":"failed","runTerminalState":"failed","reportedWorkDisposition":"needs_review"}), + }, + ]); + } + } + let had_baseline = state + .codex_usage + .as_ref() + .is_some_and(CodexRunUsage::has_baseline); + let (delta, complete) = state + .codex_usage + .get_or_insert_with(|| CodexRunUsage::new(true)) + .observe(total, historical); + let mut normalized_params = params.clone(); + let emit_usage = !historical || (had_baseline && increases_known_usage); + if historical && emit_usage { + normalized_params = json!({"threadId": params.get("threadId"), "turnId": params.get("turnId"), + "tokenUsage":{"total":total,"last":delta}}); + } else if !historical { + normalized_params["tokenUsage"]["last"] = delta; + } + let mut events = normalize_codex_notification( + if emit_usage { + "thread/tokenUsage/updated" + } else { + method + }, + &normalized_params, + ); + for event in &mut events { + if event.event_type == "usage.reported" { + event.payload["runDeltaAvailable"] = json!(complete); + event.payload["runDeltaBasis"] = json!("run"); + } + } + return Ok(events); + } if method != "paperclip/runResult" { return Ok(normalize_codex_notification(method, params) .into_iter() @@ -640,14 +747,21 @@ fn normalize_provider_notification( } } +fn terminal_completion_rejected(state: &CodexProviderState) -> bool { + state.active_terminal_tool_rejected && state.active_provider_result_fingerprint.is_none() +} + +fn goal_continues_after_turn(state: &CodexProviderState, goal_active: bool) -> bool { + goal_active && !terminal_completion_rejected(state) +} + fn terminal_events( state: &CodexProviderState, event_type: &str, goal_status: Option<&str>, ) -> Vec { - let rejected_completion = - state.active_terminal_tool_rejected && state.active_provider_result_fingerprint.is_none(); - if goal_status == Some("active") && !rejected_completion { + let rejected_completion = terminal_completion_rejected(state); + if goal_continues_after_turn(state, goal_status == Some("active")) { return Vec::new(); } let Some(contract) = state.completion_contract.as_ref() else { @@ -1007,6 +1121,10 @@ struct CodexProviderState { #[serde(default)] opencode_launch_profile_digest: Option, #[serde(default)] + codex_usage: Option, + #[serde(default)] + previous_accounting_origin: Option, + #[serde(default)] completion_contract: Option, #[serde(default)] tool_bridge: ProviderToolBridge, @@ -1107,11 +1225,15 @@ impl CodexProviderState { tool_bridge: ProviderToolBridge, ) -> Self { let thread_id = config.provider_session_id.clone(); + let codex_usage = + (config.provider == "codex").then(|| CodexRunUsage::new(thread_id.is_some())); Self { schema: PROVIDER_STATE_SCHEMA.to_owned(), lifecycle: "prepared".to_owned(), config, opencode_launch_profile_digest: None, + codex_usage, + previous_accounting_origin: None, completion_contract, tool_bridge, thread_id, @@ -1154,6 +1276,13 @@ impl CodexProviderState { self.tool_bridge.validate_recovered().map_err(|error| { DurableRunnerError::invalid(format!("Codex semantic tool state is invalid: {error}")) })?; + if self + .codex_usage + .as_ref() + .is_some_and(|usage| !usage.is_valid()) + { + return Err(DurableRunnerError::invalid("invalid Codex usage baseline")); + } let mut pending_event_ids = HashSet::new(); if self.descendant_thread_ids.len() > crate::codex_provider::MAX_DESCENDANT_THREAD_IDS || self @@ -2501,7 +2630,43 @@ impl CodexCommandExecutor { stable } + fn persist_completed_accounting_tail( + &mut self, + tail: Vec<(String, Value)>, + failed: bool, + ) -> Result<(), DurableRunnerError> { + if !tail.is_empty() || failed { + let state = self.state.as_mut().ok_or_else(|| { + DurableRunnerError::invalid("Codex provider has not been prepared") + })?; + for (method, params) in tail { + let events = normalize_provider_notification(state, &method, ¶ms)?; + state.extend_events(events)?; + } + if failed { + state.lifecycle = "reconciliation_required".to_owned(); + } + self.save_state()?; + } + Ok(()) + } + + fn retain_completed_accounting_tail(&mut self) -> Result<(), DurableRunnerError> { + let (tail, result) = self + .provider + .as_mut() + .map(CodexProvider::drain_completed_turn_tail_for_warm_attachment) + .unwrap_or_else(|| (Vec::new(), Ok(()))); + self.persist_completed_accounting_tail(tail, result.is_err())?; + result.map_err(|error| { + DurableRunnerError::invalid(format!( + "failed to retain completed Codex accounting: {error}" + )) + }) + } + fn attach_run(&mut self, payload: &Value) -> Result<(), DurableRunnerError> { + self.retain_completed_accounting_tail()?; let mut next_state = self .state .clone() @@ -2600,6 +2765,17 @@ impl CodexCommandExecutor { "run.attach tool contract could not be rebound: {error}" )) })?; + if let Some(usage) = next_state.codex_usage.as_mut() { + usage.begin_run(); + } + next_state.previous_accounting_origin = self + .event_identity + .clone() + .zip(next_state.completed_provider_turn_id.clone()) + .map(|(identity, provider_turn_id)| CodexAccountingOrigin { + identity, + provider_turn_id, + }); next_state.completion_contract = completion_contract; next_state.completed_turn_authoritative = false; next_state.completed_turn_process_generation = None; @@ -2613,10 +2789,12 @@ impl CodexCommandExecutor { next_state.active_provider_result_disposition = None; next_state.active_terminal_tool_rejected = false; next_state.last_agent_message = None; - let retained_provider = if let Some(provider) = self.provider.as_mut() { - !runtime_launch_changed - && !upgraded_skill_config - && provider + let mut attachment_accounting = Vec::new(); + let retention = if let Some(provider) = self.provider.as_mut() { + if runtime_launch_changed || upgraded_skill_config { + Ok(false) + } else { + provider .attach_run_in_place( next_state.tool_bridge.authorized_tools().cloned(), next_state.completion_contract.as_ref().map(|contract| { @@ -2625,12 +2803,14 @@ impl CodexCommandExecutor { contract.criterion_ids.as_slice(), ) }), + &mut attachment_accounting, ) .map_err(|error| { DurableRunnerError::invalid(format!( "failed to retain Codex for warm run attachment: {error}" )) - })? + }) + } } else if next_state.lifecycle == "prepared" && next_state.provider_process_generation > 0 && next_state.pending_events.iter().all(is_startup_audit_event) @@ -2640,12 +2820,17 @@ impl CodexCommandExecutor { // validated run-scoped settings here; open_session then restores // that same thread under the new authority. Never restart during // drain/suspend or require the stopped process to still exist. - false + Ok(false) } else { return Err(DurableRunnerError::invalid( "run.attach requires the restored Codex provider process", )); }; + self.persist_completed_accounting_tail(attachment_accounting, retention.is_err())?; + let retained_provider = match retention { + Ok(retained) => retained, + Err(error) => return Err(error), + }; if !retained_provider { if let Some(provider) = self.provider.as_mut() { provider.shutdown().map_err(|error| { @@ -4044,10 +4229,13 @@ impl CodexCommandExecutor { .get("quiesceForWarmAttach") .and_then(Value::as_bool) .unwrap_or(false); + if quiesce_for_warm_attach { + self.retain_completed_accounting_tail()?; + } let mut warm_attach_blockers = self .provider .as_mut() - .map(|provider| provider.warm_run_attachment_blockers(quiesce_for_warm_attach)) + .map(|provider| provider.warm_run_attachment_blockers()) .transpose() .map_err(|error| { DurableRunnerError::invalid(format!( @@ -4071,6 +4259,9 @@ impl CodexCommandExecutor { if !state.queued_events.is_empty() { warm_attach_blockers.push("durable_queued_events"); } + if state.lifecycle == "reconciliation_required" { + warm_attach_blockers.push("reconciliation_required"); + } let warm_attach_ready = warm_attach_blockers.is_empty(); Ok(CommandExecution::result(json!({ "status": state.lifecycle, @@ -4281,6 +4472,22 @@ impl CodexCommandExecutor { } else { None }; + let goal_remains_active = match &goal_reconciliation { + Some(Ok(snapshot)) => normalize_codex_goal(snapshot, false) + .is_some_and(|goal| goal.status == "active"), + _ => self + .state + .as_ref() + .and_then(|state| state.goal.as_ref()) + .is_some_and(|goal| goal.status == "active"), + }; + let run_continues = self + .state + .as_ref() + .is_some_and(|state| goal_continues_after_turn(state, goal_remains_active)); + if terminal_event_type.as_deref() == Some("turn.completed") && !run_continues { + self.retain_completed_accounting_tail()?; + } let working_now = self .provider .as_ref() @@ -4370,7 +4577,9 @@ impl CodexCommandExecutor { state.receipt_limit_interrupt_attempts = 0; state.receipt_limit_interrupt_deadline_unix_ms = None; state.ambiguous_turn_start_pending = false; - state.lifecycle = "session_open".to_owned(); + if state.lifecycle != "reconciliation_required" { + state.lifecycle = "session_open".to_owned(); + } if let Some(goal) = state.goal.as_mut() { goal.working_now = false; state.goal_revision = state.goal_revision.saturating_add(1); @@ -4473,6 +4682,13 @@ impl CodexCommandExecutor { }) .unwrap_or_default(); self.save_state()?; + if self + .state + .as_ref() + .is_some_and(|state| state.lifecycle == "reconciliation_required") + { + break; + } if let (Some(frame_id), Some(provider)) = (trace_frame_id, self.provider.as_mut()) { @@ -5894,6 +6110,8 @@ mod tests { conversation_mode: None, }, opencode_launch_profile_digest: None, + codex_usage: Some(CodexRunUsage::new(false)), + previous_accounting_origin: None, completion_contract: None, tool_bridge: ProviderToolBridge::default(), thread_id: Some("thread-1".to_owned()), diff --git a/packages/paperclip-runner/runner/crates/runner-core/tests/codex_provider.rs b/packages/paperclip-runner/runner/crates/runner-core/tests/codex_provider.rs index ead00ee0f33..09368feb54a 100644 --- a/packages/paperclip-runner/runner/crates/runner-core/tests/codex_provider.rs +++ b/packages/paperclip-runner/runner/crates/runner-core/tests/codex_provider.rs @@ -3964,6 +3964,7 @@ fn durable_backend_drains_completed_turn_usage_and_passive_tail_during_warm_atta "--durable-turn-ids", "--emit-post-completion-warning", "--emit-post-completion-passive-statuses", + "--warm-tail-accounting", ], ); let runner_config = durable_config(&directory); @@ -3991,6 +3992,7 @@ fn durable_backend_drains_completed_turn_usage_and_passive_tail_during_warm_atta )) .expect("start the first turn"); + let mut old_usage = Vec::new(); let deadline = std::time::Instant::now() + std::time::Duration::from_secs(5); loop { assert!( @@ -3998,6 +4000,12 @@ fn durable_backend_drains_completed_turn_usage_and_passive_tail_during_warm_atta "the first turn must settle before attachment" ); let events = poll_and_ack(&mut executor).expect("poll the first turn terminal"); + old_usage.extend( + events + .iter() + .filter(|event| event.event_type == "usage.reported") + .cloned(), + ); if events .iter() .any(|event| event.event_type == "turn.completed") @@ -4010,6 +4018,11 @@ fn durable_backend_drains_completed_turn_usage_and_passive_tail_during_warm_atta std::thread::sleep(std::time::Duration::from_millis(1)); } + assert_eq!( + old_usage.last().unwrap().payload["runDelta"]["inputTokens"], + 120 + ); + assert_eq!(old_usage.last().unwrap().payload["runDeltaAvailable"], true); let readiness = executor .execute(&command( "readiness", @@ -4034,6 +4047,23 @@ fn durable_backend_drains_completed_turn_usage_and_passive_tail_during_warm_atta .iter() .any(|(event_type, _, _)| event_type == "run.attached")); + executor + .execute(&command( + "next-turn", + 6, + "turn.start", + json!({"text":"Complete the next paid turn."}), + )) + .unwrap(); + let next_events = wait_for_executor_event_batch(&mut executor, "turn.completed"); + let next_usage = next_events + .iter() + .filter(|event| event.event_type == "usage.reported") + .last() + .unwrap(); + assert_eq!(next_usage.payload["runDelta"]["inputTokens"], 30); + assert_eq!(next_usage.payload["runDelta"]["outputTokens"], 3); + assert_eq!(next_usage.payload["runDeltaAvailable"], true); executor.shutdown().expect("stop the warm provider"); fs::remove_dir_all(directory).expect("remove Codex integration-test directory"); } @@ -6256,6 +6286,9 @@ fn rejected_declared_completion_stays_failed_when_the_provider_completes() { let mut config = provider_config(&directory, &["--complete-after-tool-call"]); if scenario == "controller-goal" { config.args.push("--agent-created-goal-on-open".to_owned()); + config + .args + .push("--accounting-tail-after-terminal".to_owned()); } config.args.extend([ "--terminal-result-file".to_owned(), @@ -6327,6 +6360,13 @@ fn rejected_declared_completion_stays_failed_when_the_provider_completes() { .unwrap(); assert!(failure < turn && turn < terminal); if scenario == "controller-goal" { + let final_usage = emitted + .iter() + .rposition(|event| event.event_type == "usage.reported") + .unwrap(); + assert!(final_usage < failure && final_usage < turn && final_usage < terminal); + assert_eq!(emitted[final_usage].payload["runDelta"]["inputTokens"], 120); + assert_eq!(emitted[final_usage].payload["runDeltaAvailable"], true); let settled_goal = emitted .iter() .rposition(|event| { @@ -6687,7 +6727,11 @@ fn resume_usage_is_a_historical_diagnostic_not_a_warning_or_charge() { let directory = temporary_directory("resume-usage-snapshot"); let config = provider_config( &directory, - &["--durable-turn-ids", "--resume-usage-snapshot"], + &[ + "--durable-turn-ids", + "--resume-usage-snapshot", + "--cumulative-accounting-usage", + ], ); let runner_config = durable_config(&directory); let mut first = CodexCommandExecutor::with_runner_config(&directory, &runner_config); @@ -6756,7 +6800,7 @@ fn resume_usage_is_a_historical_diagnostic_not_a_warning_or_charge() { .collect(); assert_eq!(snapshots.len(), 2); assert_eq!(snapshots[0].payload["receivedTurnId"], "provider-turn-1"); - assert_eq!(snapshots[0].payload["cumulative"]["inputTokens"], 100); + assert_eq!(snapshots[0].payload["cumulative"]["inputTokens"], 200); assert!(!events.iter().any(|event| matches!( event.event_type.as_str(), "provider.notice.recorded" | "usage.reported" @@ -6988,3 +7032,361 @@ fn skill_flag_can_be_added_to_an_old_checkpoint_at_settled_run_attach() { ); fs::remove_dir_all(directory).unwrap(); } + +#[test] +fn durable_codex_usage_keeps_run_baselines_through_requests_recovery_and_attachment() { + let directory = temporary_directory("accounting-run-baseline"); + fs::write( + directory.join("fake-state.json"), + serde_json::to_vec(&json!({"threadId":"thread-1","activeTurnId":null,"nextTurn":1})) + .unwrap(), + ) + .unwrap(); + let mut config = provider_config( + &directory, + &[ + "--durable-turn-ids", + "--resume-usage-snapshot", + "--cumulative-accounting-usage", + ], + ); + config.provider_session_id = Some("thread-1".to_owned()); + let runner_config = durable_config(&directory); + let mut executor = CodexCommandExecutor::with_runner_config(&directory, &runner_config); + executor + .execute(&command( + "prepare", + 1, + "run.prepare", + json!({"provider":config,"authorizedTools":task_context_tool_set()}), + )) + .unwrap(); + executor + .execute(&command("open", 2, "session.open", json!({}))) + .unwrap(); + for _ in 0..20 { + if poll_and_ack(&mut executor) + .unwrap() + .iter() + .any(|event| event.payload["code"] == "codex_resume_usage_snapshot") + { + break; + } + std::thread::sleep(std::time::Duration::from_millis(5)); + } + fn run( + executor: &mut CodexCommandExecutor, + sequence: u64, + expected_input: u64, + expected_output: u64, + ) { + executor + .execute(&command( + &format!("turn-{sequence}"), + sequence, + "turn.start", + json!({"text":"Complete the accounting turn."}), + )) + .unwrap(); + let events = wait_for_executor_event_batch(executor, "turn.completed"); + let usage = events + .iter() + .filter(|event| event.event_type == "usage.reported") + .last() + .expect("provider emitted usage"); + assert_eq!(usage.payload["runDeltaBasis"], "run"); + assert_eq!(usage.payload["runDeltaAvailable"], true); + assert_eq!(usage.payload["runDelta"]["inputTokens"], expected_input); + assert_eq!(usage.payload["runDelta"]["outputTokens"], expected_output); + for _ in 0..20 { + if poll_and_ack(executor).unwrap().is_empty() { + break; + } + } + } + run(&mut executor, 3, 100, 10); + run(&mut executor, 4, 200, 20); + executor.shutdown().unwrap(); + drop(executor); + let mut executor = CodexCommandExecutor::with_runner_config(&directory, &runner_config); + run(&mut executor, 5, 300, 30); + executor + .execute(&command( + "attach", + 6, + "run.attach", + json!({"authorizedTools":task_context_tool_set()}), + )) + .unwrap(); + run(&mut executor, 7, 100, 10); + executor.shutdown().unwrap(); + fs::remove_dir_all(directory).unwrap(); +} + +#[test] +fn late_codex_usage_requires_durable_reconciliation_before_or_after_handoff() { + for mode in ["before", "after", "after-paid", "unsafe"] { + let handoff_first = mode.starts_with("after"); + let directory = temporary_directory("late-accounting-reconciliation"); + let gate = directory.join("release-late-usage"); + let gate_arg = gate.to_string_lossy().into_owned(); + let config = provider_config( + &directory, + &[ + "--durable-turn-ids", + "--warm-tail-accounting", + "--late-accounting-tail-gate", + &gate_arg, + if mode == "after-paid" { + "--hold-second-accounting-terminal" + } else { + "--ordinary-terminal" + }, + if mode == "after-paid" { + "--late-accounting-duplicate-burst" + } else { + "--ordinary-tail-count" + }, + if mode == "unsafe" { + "--unsafe-after-late-usage" + } else { + "--ordinary-late-usage" + }, + ], + ); + let runner_config = durable_config(&directory); + let mut executor = CodexCommandExecutor::with_runner_config(&directory, &runner_config); + executor + .execute(&command( + "prepare", + 1, + "run.prepare", + json!({"provider":config,"authorizedTools":task_context_tool_set()}), + )) + .unwrap(); + executor + .execute(&command("open", 2, "session.open", json!({}))) + .unwrap(); + executor + .execute(&command( + "turn", + 3, + "turn.start", + json!({"text":"Finish before the delayed accounting report."}), + )) + .unwrap(); + let events = wait_for_executor_event_batch(&mut executor, "turn.completed"); + assert_eq!( + events + .iter() + .filter(|event| event.event_type == "usage.reported") + .last() + .unwrap() + .payload["runDelta"]["inputTokens"], + 100 + ); + if handoff_first { + executor + .execute(&command( + "attach", + 4, + "run.attach", + json!({"authorizedTools":task_context_tool_set()}), + )) + .unwrap(); + let mut next = runner_config.clone(); + next.run_id = "run-2".to_owned(); + executor.rotate_authority(&next); + } + if mode == "after-paid" { + executor + .execute(&command( + "successor-turn", + 5, + "turn.start", + json!({"text":"Start successor paid work."}), + )) + .unwrap(); + let deadline = std::time::Instant::now() + std::time::Duration::from_secs(5); + loop { + assert!(std::time::Instant::now() < deadline); + let events = poll_and_ack(&mut executor).unwrap(); + assert!(!events + .iter() + .any(|event| event.event_type == "turn.completed")); + if let Some(usage) = events + .iter() + .find(|event| event.event_type == "usage.reported") + { + assert_eq!(usage.payload["runDelta"]["inputTokens"], 50); + break; + } + } + } + fs::write(&gate, "release").unwrap(); + let deadline = std::time::Instant::now() + std::time::Duration::from_secs(5); + let retained = loop { + assert!(std::time::Instant::now() < deadline); + let events = if mode == "unsafe" { + match executor.execute(&command( + "quiesce", + 4, + "session.snapshot", + json!({"quiesceForWarmAttach":true}), + )) { + Ok(_) => { + std::thread::sleep(std::time::Duration::from_millis(1)); + continue; + } + Err(error) => { + assert!(error + .to_string() + .contains("failed to retain completed Codex accounting")); + executor.retained_events().unwrap() + } + } + } else { + executor.poll_events().unwrap() + }; + if events.iter().any(|event| { + event.event_type == "usage.reported" + || event.payload["code"] == "codex_usage_accounting_integrity" + }) { + break events; + } + executor.acknowledge_events(events.len()).unwrap(); + }; + if handoff_first { + assert!(retained + .iter() + .filter(|event| event.event_type == "usage.reported") + .all(|event| event.payload["runDeltaAvailable"] == false)); + assert!(retained + .iter() + .any(|event| event.event_type == "usage.reported" + && event.payload["runDeltaAvailable"] == false)); + assert!(retained + .iter() + .any(|event| event.event_type == "run.terminal" + && event.payload["runTerminalState"] == "failed")); + let required = retained + .iter() + .find(|event| event.event_type == "usage.reported") + .unwrap(); + assert_eq!( + required.payload["reconciliation"]["cumulative"]["inputTokens"], + 120 + ); + assert_eq!( + required.payload["reconciliation"]["priorOrigin"]["runId"], + "run-1" + ); + let evidence = retained + .iter() + .find(|event| event.payload["code"] == "codex_usage_accounting_integrity") + .unwrap(); + assert_eq!(evidence.payload["priorOrigin"]["runId"], "run-1"); + assert_eq!(evidence.payload["receivedTurnId"], "provider-turn-1"); + assert_eq!(evidence.payload["cumulative"]["inputTokens"], 120); + } else { + assert_eq!( + retained + .iter() + .find(|event| event.event_type == "usage.reported") + .unwrap() + .payload["runDelta"]["inputTokens"], + 120 + ); + } + let saved: Value = + serde_json::from_slice(&fs::read(directory.join("codex-provider-state.json")).unwrap()) + .unwrap(); + assert_eq!(saved["lifecycle"], "reconciliation_required"); + assert!(!saved["pendingEvents"].as_array().unwrap().is_empty()); + let error = executor + .execute(&command( + "blocked-attach", + 5, + "run.attach", + json!({"authorizedTools":task_context_tool_set()}), + )) + .unwrap_err(); + assert!(error + .to_string() + .contains("requires explicit reconciliation")); + executor.shutdown().unwrap(); + drop(executor); + let mut restored = CodexCommandExecutor::with_runner_config(&directory, &runner_config); + let error = restored + .execute(&command( + "blocked-after-restart", + 6, + "run.attach", + json!({"authorizedTools":task_context_tool_set()}), + )) + .unwrap_err(); + assert!(error + .to_string() + .contains("requires explicit reconciliation")); + restored.shutdown().unwrap(); + fs::remove_dir_all(directory).unwrap(); + } +} + +#[test] +fn durable_codex_usage_keeps_completed_turn_through_reconciled_provider_exit() { + for exit_flag in [ + "--exit-after-turn-completion", + "--fail-after-turn-completion", + ] { + let directory = temporary_directory("accounting-reconciled-exit"); + let config = provider_config( + &directory, + &[ + "--durable-turn-ids", + "--warm-tail-accounting", + "--emit-post-completion-passive-statuses", + exit_flag, + ], + ); + let mut executor = + CodexCommandExecutor::with_runner_config(&directory, &durable_config(&directory)); + executor + .execute(&command( + "prepare", + 1, + "run.prepare", + json!({"provider":config,"authorizedTools":task_context_tool_set()}), + )) + .unwrap(); + executor + .execute(&command("open", 2, "session.open", json!({}))) + .unwrap(); + executor + .execute(&command( + "turn", + 3, + "turn.start", + json!({"text":"Complete accounting before exiting."}), + )) + .unwrap(); + let events = wait_for_executor_event_batch(&mut executor, "turn.completed"); + assert_eq!( + events + .iter() + .filter(|event| event.event_type == "usage.reported") + .last() + .unwrap() + .payload["runDelta"]["inputTokens"], + 120 + ); + assert!(!events.iter().any(|event| event.event_type == "turn.failed")); + let saved: Value = + serde_json::from_slice(&fs::read(directory.join("codex-provider-state.json")).unwrap()) + .unwrap(); + assert_ne!(saved["lifecycle"], "reconciliation_required"); + assert_eq!(saved["completedTurnAuthoritative"], true); + executor.shutdown().unwrap(); + fs::remove_dir_all(directory).unwrap(); + } +} diff --git a/packages/paperclip-runner/src/live/runnerd-codex-transport.test.ts b/packages/paperclip-runner/src/live/runnerd-codex-transport.test.ts index c09a2c50ea0..4b351a656f3 100644 --- a/packages/paperclip-runner/src/live/runnerd-codex-transport.test.ts +++ b/packages/paperclip-runner/src/live/runnerd-codex-transport.test.ts @@ -1123,6 +1123,43 @@ it("refuses a reusable close checkpoint when the local provider snapshot is unre } }, 15_000); +it("installs required accounting acceptance before the Runner acknowledgement callback returns", async () => { + const directory = await mkdtemp(join(tmpdir(), "runnerd-required-accounting-")); + const OriginalCore = durableControlPlane.DurablePrpControlPlane; + let callbacks!: ConstructorParameters[0]; + const spy = vi.spyOn(durableControlPlane, "DurablePrpControlPlane").mockImplementation(function (options) { + callbacks = options; + return new OriginalCore(options); + }); + let release!: () => void; + const accepted = new Promise(resolve => { release = resolve; }); + const onAccountingEvent = vi.fn(async () => accepted); + const bundle = createCapabilityRunnerdCodexTransport({ stateDirectory: directory, sourceCodexHome: "", environment: {}, + runnerBinary: process.execPath, runnerArtifact: { version: "test", digest: `sha256:${"a".repeat(64)}` }, + codexCommand: process.execPath, codexArgs: [], onAccountingEvent, + controlPlaneRegistration: async () => { throw new Error("stop before Runner dispatch"); }, + }); + try { + await expect(bundle.transport.request("thread/start", { cwd: directory })).rejects.toThrow(); + const report = { eventType: "usage.reported", sourceEventId: "required-usage" } as PrpEvent; + let returned = false; + const result = callbacks.onCommittedEvent!(report).then(() => { returned = true; }); + await vi.waitFor(() => expect(onAccountingEvent).toHaveBeenCalledExactlyOnceWith(report)); + expect(returned).toBe(false); + release(); + await result; + expect(returned).toBe(true); + const failure = new Error("receipt unavailable"); + onAccountingEvent.mockRejectedValueOnce(failure); + await expect(callbacks.onCommittedEvent!(report)).rejects.toBe(failure); + } finally { + release(); + await bundle.transport.close().catch(() => undefined); + spy.mockRestore(); + await rm(directory, { recursive: true, force: true }); + } +}); + it("uses the same API result envelope for live dispatch and recovered receipts", async () => { const stateDirectory = await mkdtemp(join(tmpdir(), "runnerd-recovered-api-")); const OriginalCore = durableControlPlane.DurablePrpControlPlane; diff --git a/packages/paperclip-runner/src/live/runnerd-codex-transport.ts b/packages/paperclip-runner/src/live/runnerd-codex-transport.ts index d994f6466de..23ab1f1721e 100644 --- a/packages/paperclip-runner/src/live/runnerd-codex-transport.ts +++ b/packages/paperclip-runner/src/live/runnerd-codex-transport.ts @@ -1240,6 +1240,7 @@ export interface CapabilityRunnerdCodexTransportOptions extends RunnerExecutionD provider?: "codex" | "opencode" | "claude_managed" | "aws_agentcore" | "acpx"; observeCredentials?: boolean; onCredentialsUpdated?: (event: PrpEvent) => Promise; + onAccountingEvent?: (event: PrpEvent) => Promise; recoverSemanticToolInput?: DurablePrpControlPlaneOptions["recoverSemanticToolInput"]; opencodePermissionMode?: NativeOpenCodePermissionMode; acpxAgent?: QualifiedAcpxAgent; @@ -5239,6 +5240,7 @@ class DurablePrpCodexTransport implements CodexAppServerTransport { onSemanticToolInput: (call) => this.#handleSemanticToolInput(call), recoverSemanticToolInput: call => this.#recoverSemanticToolInput(call), onCommittedEvent: async (event) => { + await this.options.onAccountingEvent?.(event); if (event.eventType === "auth.credentials.updated") { await this.options.onCredentialsUpdated?.(event); } @@ -5691,6 +5693,7 @@ class DurablePrpCodexTransport implements CodexAppServerTransport { onSemanticToolInput: (call) => this.#handleSemanticToolInput(call), recoverSemanticToolInput: call => this.#recoverSemanticToolInput(call), onCommittedEvent: async (event) => { + await this.options.onAccountingEvent?.(event); if (event.eventType === "auth.credentials.updated") { await this.options.onCredentialsUpdated?.(event); } diff --git a/packages/paperclip-runner/src/protocol/generated/schema-bundle.ts b/packages/paperclip-runner/src/protocol/generated/schema-bundle.ts index 2720e4a5326..92905627855 100644 --- a/packages/paperclip-runner/src/protocol/generated/schema-bundle.ts +++ b/packages/paperclip-runner/src/protocol/generated/schema-bundle.ts @@ -3385,6 +3385,75 @@ export const usageSchema = { "runDeltaAvailable": { "type": "boolean" }, + "runDeltaBasis": { + "const": "run" + }, + "reconciliation": { + "type": "object", + "required": [ + "reason", + "receivedTurnId", + "cumulative", + "priorOrigin" + ], + "properties": { + "reason": { + "const": "accounting_reconciliation_required" + }, + "receivedTurnId": { + "type": [ + "string", + "null" + ], + "maxLength": 240 + }, + "cumulative": { + "$ref": "#/$defs/measurement" + }, + "priorOrigin": { + "type": [ + "object", + "null" + ], + "required": [ + "runnerInstanceId", + "runId", + "normalizedSessionId", + "turnId", + "itemId" + ], + "properties": { + "runnerInstanceId": { + "type": "string", + "minLength": 1, + "maxLength": 240 + }, + "runId": { + "type": "string", + "minLength": 1, + "maxLength": 240 + }, + "normalizedSessionId": { + "type": "string", + "minLength": 1, + "maxLength": 240 + }, + "turnId": { + "type": "string", + "minLength": 1, + "maxLength": 240 + }, + "itemId": { + "type": "string", + "minLength": 1, + "maxLength": 240 + } + }, + "additionalProperties": false + } + }, + "additionalProperties": false + }, "runDelta": { "$ref": "#/$defs/measurement" } diff --git a/packages/paperclip-runner/src/protocol/replay-contract.test.ts b/packages/paperclip-runner/src/protocol/replay-contract.test.ts index 3f17ecf2b62..bad4d2536ee 100644 --- a/packages/paperclip-runner/src/protocol/replay-contract.test.ts +++ b/packages/paperclip-runner/src/protocol/replay-contract.test.ts @@ -1,3 +1,5 @@ +import Ajv2020 from "ajv/dist/2020.js"; +import { usageSchema } from "./generated/schema-bundle.js"; import { readFile } from "node:fs/promises"; import { describe, expect, it } from "vitest"; @@ -6,6 +8,7 @@ import { negotiateProtocolVersion, parsePrpFixtureText, PRP_PROTOCOL_VERSION, + validatePrpEvent, } from "./replay-contract.js"; import { reducePrpFixture } from "../reducer/session-reducer.js"; @@ -371,3 +374,24 @@ describe("PRP v1 JSON Schema contract", () => { ).toBeNull(); }); }); + +it("accepts marked whole-run usage through the runtime standalone event validator", async () => { + const fixture = await readFixture(); + const event = (fixture.events as Array>)[0]; + const measurement = { inputTokens: 120, outputTokens: 10, cacheReadTokens: 0, cacheWriteTokens: 0, + activeSeconds: 0, requests: 1, providerCostUsd: 0 }; + const result = validatePrpEvent({ ...event, eventType: "usage.reported", priority: 0, + payload: { provider: "codex", model: "gpt-6.1-sol", cumulative: measurement, runDelta: measurement, + runDeltaAvailable: true, runDeltaBasis: "run" } }); + expect(result).toMatchObject({ ok: true }); +}); + +it("declares required incomplete reconciliation evidence in the strict usage contract", () => { + const validate = new Ajv2020({ strict: true, allErrors: true }).compile(usageSchema); + const measurement = { inputTokens: 120, outputTokens: 12, cacheReadTokens: 0, cacheWriteTokens: 0, activeSeconds: 0, requests: 0, providerCostUsd: 0 }; + const payload = { provider: "codex", model: null, cumulative: measurement, runDelta: { ...measurement, inputTokens: 0, outputTokens: 0 }, runDeltaAvailable: false, runDeltaBasis: "run", + reconciliation: { reason: "accounting_reconciliation_required", receivedTurnId: "provider-turn-1", cumulative: measurement, + priorOrigin: { runnerInstanceId: "runner-1", runId: "old-run", normalizedSessionId: "session", turnId: "turn", itemId: "item" } } }; + expect(validate(payload), JSON.stringify(validate.errors)).toBe(true); + expect(validate({ ...payload, reconciliation: { ...payload.reconciliation, arbitraryProviderData: "excluded" } })).toBe(false); +}); diff --git a/scripts/__tests__/run-vitest-stable-shard.test.mjs b/scripts/__tests__/run-vitest-stable-shard.test.mjs index c4dd568a72f..52209944424 100644 --- a/scripts/__tests__/run-vitest-stable-shard.test.mjs +++ b/scripts/__tests__/run-vitest-stable-shard.test.mjs @@ -320,6 +320,7 @@ test("the real serialized shard partition is complete, non-overlapping and durat const chatSuitePath = "server/src/__tests__/chat-channels.integration.test.ts"; const nativeRunnerSuitePath = "server/src/services/native-runtime/native-codex-runner.integration.test.ts"; +const usageDeliverySuitePath = "server/src/services/native-runtime/native-usage-delivery.integration.test.ts"; const dotRunnerSuitePath = "server/src/__tests__/dot-runner.test.ts"; const restartRecoverySuitePath = "server/src/services/native-runtime/native-runner-restart-recovery.integration.test.ts"; @@ -363,7 +364,8 @@ test("12 PR without-chat shards plus the dedicated chat and native-runner lanes assert.ok(!files.includes(nativeRunnerSuitePath)); assert.ok(!files.includes(dotRunnerSuitePath)); assert.ok(!files.includes(restartRecoverySuitePath)); - assert.deepEqual([...files, chatSuitePath, nativeRunnerSuitePath, dotRunnerSuitePath, restartRecoverySuitePath, "server/src/services/native-runtime/plugin-runner-probe.test.ts"].sort(), full.selectedGeneralServerSuites.sort()); + assert.ok(!files.includes(usageDeliverySuitePath)); + assert.deepEqual([...files, chatSuitePath, nativeRunnerSuitePath, dotRunnerSuitePath, restartRecoverySuitePath, usageDeliverySuitePath, "server/src/services/native-runtime/plugin-runner-probe.test.ts"].sort(), full.selectedGeneralServerSuites.sort()); assert.equal(new Set(files).size, files.length); const defaultRun = dryRunJson([], prEnv); assert.ok(defaultRun.generalServerSuiteCount === full.generalServerSuiteCount); @@ -412,6 +414,7 @@ test("the native-runner lane runs exactly the cargo-dependent suites", () => { "server/src/services/native-runtime/native-codex-runner.integration.test.ts", dotRunnerSuitePath, restartRecoverySuitePath, + usageDeliverySuitePath, ]); }); diff --git a/scripts/run-vitest-stable.mjs b/scripts/run-vitest-stable.mjs index ce3ee317239..d72bd532e57 100644 --- a/scripts/run-vitest-stable.mjs +++ b/scripts/run-vitest-stable.mjs @@ -92,6 +92,7 @@ const nativeRunnerSuites = [ "server/src/__tests__/dot-runner.test.ts", // These process cases otherwise skip in server shards without Runner binaries. "server/src/services/native-runtime/native-runner-restart-recovery.integration.test.ts", + "server/src/services/native-runtime/native-usage-delivery.integration.test.ts", ]; // In the PR workflow (pr.yml, the caller of pr-trusted.yml — reusable // workflows inherit the caller's GITHUB_WORKFLOW), the last Verify Paperclip diff --git a/server/src/services/heartbeat/run-completion.test.ts b/server/src/services/heartbeat/run-completion.test.ts index 1dc15b06e9c..62ce16df460 100644 --- a/server/src/services/heartbeat/run-completion.test.ts +++ b/server/src/services/heartbeat/run-completion.test.ts @@ -1,3 +1,5 @@ +import { createNativeUsageDelivery } from "../native-runtime/native-usage-delivery.js"; +import type { PrpEvent } from "../../vendor/paperclip-runner/index.js"; import { randomUUID } from "node:crypto"; import type { Db } from "@paperclipai/db"; import { agents, agentWakeupRequests, caseHandoffs, cases, companies, costEvents, createDb, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS, heartbeatRuns, issues, nativeRunFinalizations } from "@paperclipai/db"; @@ -158,6 +160,57 @@ describe.skipIf(!support.supported && !process.env.PAPERCLIP_TEST_DATABASE_URL)( expect(f.deps.finalizeAgentStatus).toHaveBeenCalledWith(f.agent.id, "succeeded", null, expect.any(Object)); }); + it("settles the accepted native exact rate-card price without replacing it with zero", async () => { + const f = await fixture({ runtimeMode: "native" }); + const runnerInstanceId = randomUUID(); + const delivery = await createNativeUsageDelivery(db, { companyId: f.run.companyId, runId: f.run.id, runnerInstanceId, + provider: { kind: "codex", model: "gpt-6.1-sol" }, billing: { provider: "openai", biller: "openai", billingType: "metered_api" } }); + const event = (sourceSeq: number, eventType: string, payload: Record): PrpEvent => ({ + sourceKind: "runner", sourceInstanceId: runnerInstanceId, runId: f.run.id, sourceSeq, sourceEventId: `rate-card-${sourceSeq}`, + turnId: "price-turn", eventType, emittedAt: new Date().toISOString(), payload, + } as PrpEvent); + await delivery.capture(event(1, "usage.reported", { runDeltaBasis: "run", runDeltaAvailable: true, + runDelta: { inputTokens: 1000, outputTokens: 100000, providerCostUsd: 0 } })); + await delivery.capture(event(2, "turn.completed", {})); + const accepted = await usageReceipts.readAcceptedRunUsageCheckpoint(db, { companyId: f.run.companyId, runId: f.run.id }); + expect(accepted?.costStatus).toBe("estimated"); + const exact = accepted!.costUsdExact; + f.input.adapterResult = { exitCode: 0, signal: null, timedOut: false, ...accepted, usageComplete: accepted!.complete }; + await f.completion.completeRun(f.input); + const saved = await read(f.run.id); + expect(saved).toMatchObject({ status: "succeeded", costAccountingPending: false, costAccountedAt: expect.any(Date), + usageJson: { costUsdExact: exact, costStatus: "estimated" } }); + const ledger = await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, f.run.id)); + expect(ledger).toHaveLength(1); + expect(ledger[0].costCents).toBe(100.2); + }); + + it("retains newer accepted native usage when completion consumed an older receipt", async () => { + const f = await fixture({ runtimeMode: "native", usageJson: { sessionRotated: true, configFreshness: { version: 0 } } }); + const runnerInstanceId = randomUUID(); + const delivery = await createNativeUsageDelivery(db, { companyId: f.run.companyId, runId: f.run.id, runnerInstanceId, + provider: { kind: "codex", model: "test-model" }, billing: { provider: "openai", biller: "openai", billingType: "metered_api" } }); + const event = (sourceSeq: number, eventType: string, inputTokens = 100): PrpEvent => ({ + sourceInstanceId: runnerInstanceId, runId: f.run.id, sourceSeq, sourceEventId: `racing-${sourceSeq}`, turnId: "turn-1", + emittedAt: new Date().toISOString(), eventType, payload: eventType === "usage.reported" + ? { runDeltaBasis: "run", runDeltaAvailable: true, runDelta: { inputTokens, outputTokens: 10, providerCostUsd: inputTokens / 1000 } } : {}, + } as PrpEvent); + await delivery.capture(event(1, "usage.reported")); + await delivery.capture(event(2, "turn.completed")); + const acceptedA = await usageReceipts.readAcceptedRunUsageCheckpoint(db, { companyId: f.run.companyId, runId: f.run.id }); + await delivery.capture(event(3, "usage.reported", 120)); + f.input.adapterResult = { exitCode: 0, signal: null, timedOut: false, ...acceptedA, usageComplete: acceptedA!.complete }; + await f.completion.completeRun(f.input); + expect(await read(f.run.id)).toMatchObject({ status: "succeeded", costAccountingPending: true, costAccountedAt: null, + usageJson: { inputTokens: 120, costUsd: 0.12, accountingReceiptSequence: 3, accountingReceiptReady: false, sessionRotated: false, configFreshness: { version: 1 } } }); + expect(await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, f.run.id))).toHaveLength(0); + await delivery.capture(event(4, "turn.completed", 120)); + expect(await (await import("../run-cost-accounting.js")).accountRunCost(db, f.run.id)).toBe(true); + const ledger = await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, f.run.id)); + expect(ledger).toHaveLength(1); + expect(ledger[0].costCents).toBe(12); + }); + it.each([ { timedOut: true, expected: "timed_out", errorCode: "timeout" }, { signal: "SIGTERM", expected: "failed", errorCode: "adapter_failed" }, diff --git a/server/src/services/heartbeat/run-completion.ts b/server/src/services/heartbeat/run-completion.ts index 39bb4a509ab..c82816f384b 100644 --- a/server/src/services/heartbeat/run-completion.ts +++ b/server/src/services/heartbeat/run-completion.ts @@ -1,3 +1,4 @@ +import { preserveAcceptedRunUsageProjectionSql } from "../usage-receipts.js"; import { notifyChatRunMilestones } from "../chat-run-milestone-notifications.js"; import { measureRunPhase } from "../execution-preparation-timing.js"; import { PROJECT_ACCESS_DENIED, ProjectAccessDeniedError } from "../project-access-denial.js"; @@ -686,7 +687,7 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC cancellationResultJson(persistedRunWrite.run, status, finalRunPatch.resultJson, runErrorCode, runErrorMessage) ?? null, ), - usageJson: { ...parseObject(persistedRunWrite.run.usageJson), ...parseObject(finalRunPatch.usageJson) }, + usageJson: preserveAcceptedRunUsageProjectionSql({ ...parseObject(persistedRunWrite.run.usageJson), ...parseObject(finalRunPatch.usageJson) }), finishedAt: persistedRunWrite.run.finishedAt ?? finalRunPatch.finishedAt, updatedAt: new Date(), diff --git a/server/src/services/heartbeat/run-lifecycle.ts b/server/src/services/heartbeat/run-lifecycle.ts index 1922364615a..00a27c1faf2 100644 --- a/server/src/services/heartbeat/run-lifecycle.ts +++ b/server/src/services/heartbeat/run-lifecycle.ts @@ -1,3 +1,4 @@ +import { preserveAcceptedRunUsageProjectionSql } from "../usage-receipts.js"; import { notifyNativeEnvironmentSettlement } from "../native-environment-settlement-notifications.js"; import { notifyExternalAgentSettlement } from "../../modules/external-agents/index.js"; import { notifyExternalConversationSettlement } from "../external-conversation-settlement-notifications.js"; @@ -1202,6 +1203,7 @@ export function createHeartbeatLifecycle(db: Db, dependencies: HeartbeatLifecycl .set({ status, ...patch, + ...(patch?.usageJson ? { usageJson: preserveAcceptedRunUsageProjectionSql(patch.usageJson) } : {}), executionStatusDeliveryId: randomUUID(), updatedAt: new Date(), }) diff --git a/server/src/services/heartbeat/runtime-execution.test.ts b/server/src/services/heartbeat/runtime-execution.test.ts index f40166ebd45..4f5b9c349dc 100644 --- a/server/src/services/heartbeat/runtime-execution.test.ts +++ b/server/src/services/heartbeat/runtime-execution.test.ts @@ -1,8 +1,10 @@ +import { createNativeUsageDelivery } from "../native-runtime/native-usage-delivery.js"; +import type { PrpEvent } from "../../vendor/paperclip-runner/index.js"; import { randomUUID } from "node:crypto"; import { mkdtemp, rm } from "node:fs/promises"; import { tmpdir } from "node:os"; import { join } from "node:path"; -import { agents, companies, createDb, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS, heartbeatRuns, issues, executionWorkspaces, nativeRunFinalizations, runUsageReceipts, workspaceOperations, type Db } from "@paperclipai/db"; +import { agents, budgetPolicies, companies, createDb, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS, heartbeatRuns, issues, executionWorkspaces, nativeRunFinalizations, runUsageReceipts, workspaceOperations, type Db } from "@paperclipai/db"; import { eq, sql } from "drizzle-orm"; import { afterAll, beforeAll, beforeEach, describe, expect, it, vi } from "vitest"; import { trace } from "@opentelemetry/api"; @@ -213,6 +215,38 @@ describe.skipIf(!support.supported)("heartbeat runtime execution boundary", () = expectCleanup(input); }); + it("returns the accepted exact native rate-card price and preserves its live budget hold", async () => { + const { input, run } = await fixture(true); + input.workspace.executionTarget = { kind: "remote", transport: "sandbox", remoteCwd: home }; + input.runtime.nativeExecution!.provider = { kind: "codex", model: "gpt-6.1-sol" }; + await db.insert(budgetPolicies).values({ companyId: run.companyId, scopeType: "agent", scopeId: input.agent.id, + metric: "billed_cents", windowKind: "lifetime", amount: 100, notifyEnabled: false }); + let exact: string | undefined; + vi.mocked(executePaperclipNativeSession).mockImplementationOnce(async native => { + expect(native.onUsage).toBeUndefined(); + const delivery = await createNativeUsageDelivery(db, { companyId: run.companyId, runId: run.id, + runnerInstanceId: native.runnerInstanceId, provider: native.execution.provider, + billing: { provider: "openai", biller: "openai", billingType: "metered_api" } }); + const event = (sourceSeq: number, eventType: string, payload: Record): PrpEvent => ({ + sourceKind: "runner", sourceInstanceId: native.runnerInstanceId, runId: run.id, sourceSeq, sourceEventId: `priced-${sourceSeq}`, + turnId: "priced-turn", eventType, emittedAt: new Date().toISOString(), payload, + } as PrpEvent); + await delivery.capture(event(1, "usage.reported", { runDeltaBasis: "run", runDeltaAvailable: true, + runDelta: { inputTokens: 1000, outputTokens: 100000, providerCostUsd: 0 } })); + await delivery.capture(event(2, "turn.completed", {})); + const saved = (await read(run.id)).usageJson!; + exact = saved.costUsdExact as string; + expect(Number(exact)).toBe(1.002); + expect(saved.budgetExposure).toMatchObject({ costCents: "100.2000000" }); + expect((await db.select().from(agents).where(eq(agents.id, input.agent.id)))[0].lifecycleHolds).toContain("budget"); + return { exitCode: 0, signal: null, timedOut: false, usageComplete: true, costUsd: null, model: "gpt-6.1-sol" }; + }); + const result = await executeHeartbeatRuntime(db, input); + if (!result.dispatched) throw new Error("expected native dispatch"); + expect(result.adapterResult).toMatchObject({ costUsdExact: exact, costStatus: "estimated", usageComplete: true, + pricingProvenance: { source: "rate_card" }, usage: { inputTokens: 1000, outputTokens: 100000 } }); + }); + it.each(["expected", "wrong"])("finalizes a plugin worktree through its owner (branch: %s)", async branch => { const { input } = await fixture(true); const [workspace] = await db.insert(executionWorkspaces).values({ companyId: input.agent.companyId, diff --git a/server/src/services/heartbeat/runtime-execution.ts b/server/src/services/heartbeat/runtime-execution.ts index 32ad4d9a004..b5b64abc948 100644 --- a/server/src/services/heartbeat/runtime-execution.ts +++ b/server/src/services/heartbeat/runtime-execution.ts @@ -1,3 +1,4 @@ +import { usesNativeUsageDelivery } from "../native-runtime/native-usage-accounting.js"; import { DELIVERY_QUEUES } from "../delivery-work-notifications.js"; import { writeExecutionControl } from "../execution-control-notifications.js"; import { inspectPluginWorkspaceForFinalization } from "../native-runtime/native-plugin-workspace-finalization.js"; @@ -33,7 +34,7 @@ import { NativeWorkspaceFinalizationOwnershipLostError, type NativeWorkspaceFinalizationOwnership, } from "../native-runtime/native-workspace-finalization-ownership.js"; -import { createRunUsageRecorder } from "../usage-receipts.js"; +import { createRunUsageRecorder, readAcceptedRunUsageCheckpoint } from "../usage-receipts.js"; import { applyWorkspaceRestoreFailure } from "@paperclipai/adapter-utils/workspace-restore-result"; import { hasWorkspaceRestoreFailure } from "@paperclipai/shared"; import { isConversation } from "../agent-conversations.js"; @@ -496,9 +497,13 @@ export async function executeHeartbeatRuntime(db: Db, input: HeartbeatRuntimeExe adapterFinalizeOutcome = status; }; - const usageRecorder = await measureRunPhase("execution.usage_startup", () => + const producerOwnsUsage = usesNativeUsageDelivery({ + runnerd: nativeRuntimeResolution.kind === "native" && agent.adapterType === "paperclip_runner", + remote: executionTarget?.kind === "remote", provider: nativeExecution?.provider, + }); + const usageRecorder = producerOwnsUsage ? undefined : await measureRunPhase("execution.usage_startup", () => createRunUsageRecorder(db, { companyId: run.companyId, runId: run.id, adapterType: agent.adapterType })); - input.effects.onUsageCaptureReady(usageRecorder.persistFailure); + input.effects.onUsageCaptureReady(usageRecorder?.persistFailure ?? (async () => {})); let adapterResult: AdapterExecutionResult; const runGoalControlRequestId = readNonEmptyString( context.goalControlRequestId, @@ -634,7 +639,7 @@ export async function executeHeartbeatRuntime(db: Db, input: HeartbeatRuntimeExe onEvent: onAdapterEvent, instructionWorkingCopy: nativeInstructionWorkingCopy(), - onUsage: async receipt => { await usageRecorder.capture(receipt); }, + onUsage: usageRecorder ? async receipt => { await usageRecorder.capture(receipt); } : undefined, preparationSpans: nativeRunnerPreparationSpans, // Bootstrap with executable/home discovery while keeping // configured provider values and the server-selected @@ -836,7 +841,7 @@ export async function executeHeartbeatRuntime(db: Db, input: HeartbeatRuntimeExe onLog, onMeta: onAdapterMeta, onEvent: onAdapterEvent, - onUsage: async receipt => { await usageRecorder.capture(receipt); }, + onUsage: usageRecorder ? async receipt => { await usageRecorder.capture(receipt); } : undefined, onExecutionPhase: executionControl.phases.enter, startupTraceContext: getStartupTraceContext(), onRuntimeProgress: async (progress) => { @@ -915,8 +920,14 @@ export async function executeHeartbeatRuntime(db: Db, input: HeartbeatRuntimeExe if (instructionSave) adapterResult.resultJson = { ...adapterResult.resultJson, instructionSave }; if (parseObject(adapterResult.executionRecovery).providerWorkStarted !== false) { - const captured = await measureRunPhase("execution.usage", () => usageRecorder.complete(adapterResult)); - adapterResult = { ...adapterResult, ...captured, usageComplete: captured.complete }; + if (usageRecorder) { + const captured = await measureRunPhase("execution.usage", () => usageRecorder.complete(adapterResult)); + adapterResult = { ...adapterResult, ...captured, usageComplete: captured.complete }; + } else { + const accepted = await measureRunPhase("execution.usage", () => readAcceptedRunUsageCheckpoint(db, { companyId: run.companyId, runId: run.id })); + adapterResult = { ...adapterResult, ...accepted, usageComplete: accepted?.complete ?? false, + ...(!accepted ? { costStatus: "unpriced" as const } : {}) }; + } } else { // Stop may already own the terminal result. Preserve its metadata // while durably recording the proof needed to release admission. diff --git a/server/src/services/native-runtime/__fixtures__/usage-receiver.ts b/server/src/services/native-runtime/__fixtures__/usage-receiver.ts new file mode 100644 index 00000000000..8b5a2805397 --- /dev/null +++ b/server/src/services/native-runtime/__fixtures__/usage-receiver.ts @@ -0,0 +1,45 @@ +import { resolve } from "node:path"; +import { createDb } from "@paperclipai/db"; +import { DurablePrpControlPlane, decodeDurablePrpCheckpoint, type DurablePrpCheckpoint } from "../../../vendor/paperclip-runner/index.js"; +import { createNativeUsageDelivery } from "../native-usage-delivery.js"; + +type Start = { + kind: "start"; requestId: number; connectionString: string; directory: string; port?: number; + identity: ConstructorParameters[0]["identity"]; + input: Parameters[1]; + checkpoint?: [string, string][]; +}; +let core: DurablePrpControlPlane | undefined; +let checkpoint: DurablePrpCheckpoint | undefined; +process.on("message", async (message: Start | { kind: "command"; requestId: number; type: string; commandId: string } | { kind: "stop"; requestId: number }) => { + try { + if (message.kind === "start") { + const delivery = await createNativeUsageDelivery(createDb(message.connectionString), message.input); + if (message.checkpoint) decodeDurablePrpCheckpoint(new Map(message.checkpoint)).restoreSessionDirectory(message.directory); + core = new DurablePrpControlPlane({ stateDirectory: resolve(message.directory, "control-plane"), identity: message.identity, + expectedRunnerVersion: "0.3.0", expectedRunnerDigest: `sha256:${"c".repeat(64)}`, + onCommittedEvent: async event => { + try { await delivery.capture(event); } + catch (error) { process.send?.({ kind: "capture-failed", cause: error instanceof Error ? error.message : String(error) }); throw error; } + }, + }); + core.setCheckpointPersistence(async saved => { checkpoint = saved; }); + await core.start(message.port); + const ticket = message.checkpoint ? undefined : core.issueBootstrapTicket(); + await core.flushCheckpoint(); + process.send?.({ requestId: message.requestId, connectUrl: core.connectUrl, ticket }); + } else if (message.kind === "command") { + core!.queueCommand(message.type, {}, message.commandId, true); + process.send?.({ requestId: message.requestId }); + } else { + await core?.stop(); + await core?.drainPendingConnectionProcessing(); + await core?.flushCheckpoint(); + process.send?.({ requestId: message.requestId, checkpoint: [...checkpoint!.records] }, () => process.exit(0)); + } + } catch (error) { + process.send?.({ requestId: message.requestId, error: error instanceof Error ? error.message : String(error) }); + } +}); + +process.send?.({ kind: "ready" }); diff --git a/server/src/services/native-runtime/native-session-executor.test.ts b/server/src/services/native-runtime/native-session-executor.test.ts index b29cb148597..e65220098a7 100644 --- a/server/src/services/native-runtime/native-session-executor.test.ts +++ b/server/src/services/native-runtime/native-session-executor.test.ts @@ -110,6 +110,10 @@ vi.mock("../usage-receipts.js", async (importOriginal) => ({ createRunUsageRecorder: usageRecorder.create, })); +vi.mock("./native-usage-delivery.js", () => ({ + createNativeUsageDelivery: vi.fn(async () => ({ capture: async () => undefined })), +})); + const githubAccess = vi.hoisted(() => ({ activate: vi.fn((_binding: { runId: string }) => vi.fn()), stop: vi.fn(async () => undefined), @@ -140,6 +144,7 @@ type BackendFactoryOptions = { }; type RunnerTransportOptions = { + onAccountingEvent?: (event: PrpEvent) => Promise; environment?: NodeJS.ProcessEnv; acpxRuntimeDirectory?: string; adoptExistingRunner?: { pid: number; isAlive: () => Promise | boolean }; @@ -7154,6 +7159,36 @@ describe("native terminal-turn accounting", () => { expect(onUsage).toHaveBeenLastCalledWith(expect.objectContaining({ complete: true })); expect(usageRecorder.create).not.toHaveBeenCalled(); }); + it("binds retained warm transport usage to the successor run authority", async () => { + const directory = await mkdtemp(join(tmpdir(), "native-warm-usage-")); + const previous = process.env.PAPERCLIP_RUNNER_STATE_DIR; + process.env.PAPERCLIP_RUNNER_STATE_DIR = directory; + const first = { ...execution, binding: { ...execution.binding, runId: "first-warm-usage", executionWorkspaceId: "warm-usage-workspace" }, + session: { ...execution.session, normalizedSessionId: "warm-usage-session", lifecyclePolicy: { mode: "warm" as const, idleTimeoutMs: 60000 } } } as NativeExecutionInputV1; + const second = { ...first, binding: { ...first.binding, runId: "second-warm-usage" } }; + const firstCapture = vi.fn(async (_event: PrpEvent) => {}), secondCapture = vi.fn(async (_event: PrpEvent) => {}); + try { + await createRunnerdBackend({ db: leaseDb(first), execution: first, runnerInstanceId: "warm-producer", onAccountingEvent: firstCapture }); + state.createBackend.mock.calls.at(-1)![1].codexTransportFactory!(); + const retainedHook = state.createTransport.mock.calls.at(-1)![0].onAccountingEvent!; + const firstReport = { eventType: "usage.reported", runId: first.binding.runId, sourceInstanceId: "warm-producer" } as PrpEvent; + await retainedHook(firstReport); + expect(firstCapture).toHaveBeenCalledExactlyOnceWith(firstReport); + await rm(state.createTransport.mock.calls.at(-1)![0].stateDirectory!, { recursive: true, force: true }); + await createRunnerdBackend({ db: leaseDb(second), execution: second, runnerInstanceId: "warm-producer", onAccountingEvent: secondCapture }); + await expect(retainedHook({ ...firstReport, eventType: "run.attached" })).resolves.toBeUndefined(); + expect(secondCapture).not.toHaveBeenCalled(); + const secondReport = { ...firstReport, runId: second.binding.runId }; + await retainedHook(secondReport); + expect(secondCapture).toHaveBeenCalledExactlyOnceWith(secondReport); + expect(firstCapture).toHaveBeenCalledTimes(1); + await expect(retainedHook(firstReport)).rejects.toThrow("native_usage_run_binding_mismatch"); + } finally { + if (previous === undefined) delete process.env.PAPERCLIP_RUNNER_STATE_DIR; else process.env.PAPERCLIP_RUNNER_STATE_DIR = previous; + await rm(directory, { recursive: true, force: true }); + } + }); + it("uses the canonical recorder for partial and completed usage when no onUsage callback is supplied", async () => { const updates: Array<{ table: unknown; values: Record }> = []; state.execute.mockReset().mockImplementationOnce(async () => { diff --git a/server/src/services/native-runtime/native-session-executor.ts b/server/src/services/native-runtime/native-session-executor.ts index 72bbe39c36a..6778fd46f2c 100644 --- a/server/src/services/native-runtime/native-session-executor.ts +++ b/server/src/services/native-runtime/native-session-executor.ts @@ -1,3 +1,6 @@ +import { createNativeUsageDelivery } from "./native-usage-delivery.js"; +import { createNativeTurnAccounting, nativeUsageCostUsd, nativeUsageBiller, normalizeNativeUsage, usesNativeUsageDelivery, isNativeUsageAccountingEvent } from "./native-usage-accounting.js"; +export { nativeUsageCostUsd, nativeUsageBiller, normalizeNativeUsage } from "./native-usage-accounting.js"; import { measureRunnerOperation, recordRunnerTimingReceipt } from "./runner-operation-timing.js"; import { formatNativeRunLogEvent } from "./native-run-log-export.js"; import { notifyExternalAgentSettlement } from "../../modules/external-agents/index.js"; @@ -108,7 +111,7 @@ import type { AdapterExecutionResult, AdapterRuntimeEvent, } from "../../adapters/index.js"; -import { usdToUnits, type NativeFinalizationResult } from "@paperclipai/shared"; +import type { NativeFinalizationResult } from "@paperclipai/shared"; import type { DurablePrpControlPlane, HarnessRuntimeRequestResolution, @@ -1753,12 +1756,13 @@ export async function synchronizeCompletedProviderPlan(input: { }; } -class SessionToolAuthorityEpoch { +class SessionAuthorityEpoch { readonly runId: string; #authority: PaperclipRunnerToolAuthority; #revoked = false; - constructor(runId: string, authority: PaperclipRunnerToolAuthority, private readonly toolTrace?: NativeToolTrace) { + constructor(runId: string, authority: PaperclipRunnerToolAuthority, private readonly toolTrace?: NativeToolTrace, + private readonly onAccountingEvent?: (event: PrpEvent) => Promise) { this.runId = runId; this.#authority = authority; } @@ -1774,6 +1778,14 @@ class SessionToolAuthorityEpoch { } } + async acceptAccountingEvent(event: PrpEvent) { + if (!isNativeUsageAccountingEvent(event)) return; + this.#assertCurrent(); + if (event.runId !== this.runId) throw new Error("native_usage_run_binding_mismatch"); + await this.onAccountingEvent?.(event); + this.#assertCurrent(); + } + definitions() { this.#assertCurrent(); return this.#authority.definitions(); @@ -1794,7 +1806,7 @@ class SessionToolAuthorityEpoch { } } -const sessionToolAuthorityEpochs = new Map(); +const sessionToolAuthorityEpochs = new Map(); const initializingSessionToolAuthorities = new Set(); const executingRunnerdSessionScopes = new Map(); const executingNativeOwnerScopes = new Map(); @@ -8561,7 +8573,15 @@ async function executePaperclipNativeSessionWithinScope( for (const row of history) turnAccounting.observe(record(row.payload).prpEvent as PrpEvent); } let fallbackUsageRecorder: ReturnType | undefined; + const producerOwnsUsage = usesNativeUsageDelivery({ runnerd: input.useRunnerd === true, + remote: input.runnerExecutionTarget?.kind === "remote", provider: input.execution.provider }); + const producerUsage = producerOwnsUsage ? await createNativeUsageDelivery(input.db, { + companyId: input.execution.binding.companyId, runId: input.execution.binding.runId, + runnerInstanceId: effectiveRunnerInstanceId, provider: input.execution.provider, + billing: resolveNativeBilling(input.execution.provider, input.runnerEnvironment, input.billingIdentity), + }) : undefined; const persistAccountingUsage = async (usage: Record | null, complete: boolean) => { + if (producerOwnsUsage) return; const accountingUsage = normalizeNativeUsage(usage, { inputIncludesCacheReads: input.execution.provider.kind === "codex" }); const accountingCost = accountingUsage ? nativeUsageCostUsd(usage, input.execution.provider) : undefined; complete = complete && accountingUsage !== undefined; @@ -9179,6 +9199,7 @@ async function executePaperclipNativeSessionWithinScope( input.useRunnerd && input.backend === undefined ? await timeController("backend_setup", () => createRunnerdBackend({ ...input, + onAccountingEvent: producerUsage?.capture, controllerPersistence: input.runnerExecutionTarget?.kind === "remote" ? { bootId: controller.bootId, runnerArtifact: restoredController ? { version: restoredController.runnerVersion, digest: restoredController.runnerDigest } : undefined, @@ -9218,7 +9239,7 @@ async function executePaperclipNativeSessionWithinScope( persistWarmNativeCheckpoint(remoteWarmRecovery.previousExecution, nativeSessionConfigDigest(remoteWarmRecovery.previousExecution, "remote"), await recovered.session.snapshot()); persistedWarmSession = loadWarmNativeCheckpoint(input.execution, warmConfigDigest!, "remote"); - runnerdBackend = await createRunnerdBackend({ ...input, runnerInstanceId: effectiveRunnerInstanceId, + runnerdBackend = await createRunnerdBackend({ ...input, onAccountingEvent: producerUsage?.capture, runnerInstanceId: effectiveRunnerInstanceId, controllerPersistence: input.runnerExecutionTarget?.kind === "remote" ? { bootId: controller.bootId } : undefined, durableEnvironmentLeaseId: durableRunnerBinding?.environmentLeaseId, trace, toolTrace }); } @@ -10262,151 +10283,6 @@ async function executePaperclipNativeSessionWithinScope( return adapterResult; } -function numericUsageField( - usage: Record | null, - keys: string[], -): number | undefined { - if (!usage) return undefined; - for (const key of keys) { - const value = usage[key]; - if (typeof value === "number" && Number.isFinite(value) && value >= 0) - return value; - } - return undefined; -} - -function nativeUsageMeasurement(usage: Record) { - const nestedUsage = record(usage.usage); - // An explicit partial delta must not fall through to a full session total. - if (Object.hasOwn(usage, "runDelta")) return record(usage.runDelta); - if (Object.hasOwn(nestedUsage, "runDelta")) return record(nestedUsage.runDelta); - const candidates = [ - record(usage.runDelta), - record(nestedUsage.runDelta), - record(usage.total), - record(nestedUsage.total), - record(usage.cumulative), - record(nestedUsage.cumulative), - nestedUsage, - usage, - ]; - return ( - candidates.find( - (candidate) => - numericUsageField(candidate, [ - "inputTokens", - "input", - "promptTokens", - "outputTokens", - "output", - "completionTokens", - ]) !== undefined, - ) ?? usage - ); -} - -export function nativeUsageBiller(provider: NativeExecutionInput["provider"]): string { - if (provider.kind === "acpx") { - if (provider.agent === "cursor") return "cursor"; - if (provider.agent === "copilot") return "github"; - if (provider.agent === "pi") return "openrouter"; - } - return "openai"; -} - -function createNativeTurnAccounting(provider: NativeExecutionInput["provider"]) { - const turns = new Map | null; terminal: boolean }>(); - const sequences = new Map(); - let currentTurn: string | undefined; - const terminalTypes = ["turn.completed", "turn.failed", "turn.cancelled", "turn.interrupted"]; - const snapshot = () => { - if (turns.size === 0) return { usage: null, turnId: undefined, complete: false }; - let inputTokens = 0, outputTokens = 0, cacheReadTokens = 0, cacheWriteTokens = 0; - let cost = 0n, costKnown = false, costIncomplete = false, complete = true; - for (const [turnId, turn] of turns) { - const normalized = normalizeNativeUsage(turn.usage); - complete &&= turnId !== "unattributed" && turn.terminal && normalized !== undefined; - inputTokens += (normalized?.inputTokens ?? 0) - (normalized?.cacheWriteTokens ?? 0); - outputTokens += normalized?.outputTokens ?? 0; - cacheReadTokens += normalized?.cachedInputTokens ?? 0; - cacheWriteTokens += normalized?.cacheWriteTokens ?? 0; - const price = nativeUsageCostUsd(turn.usage, provider); - if (price === undefined) costIncomplete = true; - else { cost += usdToUnits(price); costKnown = true; } - } - // A free empty attempt contributes no price evidence for later paid work. - // Keep an incomplete zero subtotal absent so complete aggregate tokens can - // still receive an estimate. Preserve positive known spend and true zero totals. - const retainCost = costKnown && (!costIncomplete || cost > 0n); - const runDelta = { inputTokens, outputTokens, cacheReadTokens, cacheWriteTokens, - ...(retainCost ? { providerCostUsd: Number(cost) / 1_000_000_000 } : {}) }; - const current = currentTurn ? turns.get(currentTurn) : undefined; - return { usage: { runDelta, accountingCostIncomplete: costIncomplete, - ...(retainCost ? { accountingCostUsdExact: `${cost / 1_000_000_000n}.${String(cost % 1_000_000_000n).padStart(9, "0")}` } : {}) }, - turnId: current && normalizeNativeUsage(current.usage) ? currentTurn : undefined, complete }; - }; - return { - observe(event: PrpEvent) { - if (!event) return false; - const payload = record(event.payload); - const terminal = terminalTypes.includes(event.eventType); - if (payload.kind !== "usage" && event.eventType !== "turn.started" && !terminal) return false; - // Historical replay can revisit an earlier report after restoration. - // Re-persist its aggregate, but never rewind or count that report twice. - if (event.sourceInstanceId && Number.isSafeInteger(event.sourceSeq)) { - if (event.sourceSeq <= (sequences.get(event.sourceInstanceId) ?? -1)) return true; - sequences.set(event.sourceInstanceId, event.sourceSeq); - } - const key = event.turnId ?? "unattributed"; - const turn = turns.get(key) ?? { usage: null, terminal: false }; - if (event.eventType === "turn.started") { - currentTurn = event.turnId; - turn.usage = null; - turn.terminal = false; - } else if (payload.kind === "usage" && (!currentTurn || !turns.has(key))) currentTurn = event.turnId; - if (payload.kind === "usage") { - const usage = record(payload.usage); - turn.usage = Object.hasOwn(usage, "runDelta") - ? { runDelta: record(usage.runDelta), runDeltaComplete: usage.runDeltaComplete } : null; - } - if (terminal) turn.terminal = true; - turns.set(key, turn); - return true; - }, - snapshot, - finish(turnId: string | null) { - const turn = turnId ? turns.get(turnId) : undefined; - if (turn) turn.terminal = true; - return snapshot(); - }, - }; -} - -export function nativeUsageCostUsd( - usage: Record | null, - provider?: NativeExecutionInput["provider"], -) { - // The ACP normalization contract fills absent per-turn cost with zero and - // reports actual cost cumulatively. Until it carries an authoritative run - // delta with provenance, neither value is a candidate's billed USD receipt. - if (provider?.kind === "acpx" && ["cursor", "copilot", "pi"].includes(provider.agent)) return undefined; - if (!usage) return undefined; - const measurement = nativeUsageMeasurement(usage); - const hasRunDelta = Object.hasOwn(usage, "runDelta") || Object.hasOwn(record(usage.usage), "runDelta"); - const direct = numericUsageField(measurement, ["cacheAdjustedCostUsd", "providerCostUsd", "costUsd"]) - ?? (hasRunDelta ? undefined : numericUsageField(usage, ["cacheAdjustedCostUsd", "providerCostUsd", "costUsd"])); - // PRP currently defaults an absent providerCostUsd to zero. That zero is - // not proof of a free request when the runtime observed token consumption. - if (direct !== undefined && direct > 0) return direct; - const normalized = normalizeNativeUsage(usage); - if (direct === 0 && normalized && Object.values(normalized).every(value => value === 0)) return 0; - const cost = record(hasRunDelta ? measurement.cost : usage.cost); - const currency = - typeof cost.currency === "string" ? cost.currency.toUpperCase() : "USD"; - if (currency !== "USD") return undefined; - return numericUsageField(cost, ["amount", "total"]); -} - /** Billing identity follows the selected runtime and resolved credentials. * Unknown authentication remains unknown; a provider name does not prove billing mode. */ export function resolveNativeBilling(provider: NativeExecutionInput["provider"], env: NodeJS.ProcessEnv = {}, identity?: Pick): Pick { @@ -10439,33 +10315,6 @@ export function resolveNativeBilling(provider: NativeExecutionInput["provider"], return { provider: "openai", biller: billingType === "metered_api" ? inferOpenAiCompatibleBiller(env, "openai") : "unknown", billingType }; } -export function normalizeNativeUsage(usage: Record | null, options: { inputIncludesCacheReads?: boolean } = {}) { - if (!usage || usage.runDeltaComplete === false || record(usage.usage).runDeltaComplete === false) return undefined; - const measurement = nativeUsageMeasurement(usage); - const cache = record(measurement.cache); - const count = (source: Record, keys: string[]) => { - for (const key of keys) { - if (source[key] === undefined) continue; - const value = source[key]; - return typeof value === "number" && Number.isSafeInteger(value) && value >= 0 ? value : NaN; - } - return undefined; - }; - const input = count(measurement, ["inputTokens", "input", "promptTokens"]); - const outputTokens = count(measurement, ["outputTokens", "output", "completionTokens"]); - const cachedInputTokens = count(measurement, ["cachedInputTokens", "cacheReadInputTokens", "cacheReadTokens", "cachedReadTokens"]) ?? count(cache, ["read"]); - const cacheWriteTokens = count(measurement, ["cacheWriteTokens", "cacheCreationInputTokens", "cachedWriteTokens"]) ?? count(cache, ["write"]); - if (input === undefined || outputTokens === undefined - || ![input, outputTokens, cachedInputTokens ?? 0, cacheWriteTokens ?? 0].every(Number.isSafeInteger)) return undefined; - const inputTokens = input - (options.inputIncludesCacheReads ? cachedInputTokens ?? 0 : 0) - + (options.inputIncludesCacheReads ? 0 : cacheWriteTokens ?? 0); - if (!Number.isSafeInteger(inputTokens) || inputTokens < (cacheWriteTokens ?? 0)) return undefined; - return { - inputTokens, outputTokens, - ...(cachedInputTokens === undefined ? {} : { cachedInputTokens }), - ...(cacheWriteTokens === undefined ? {} : { cacheWriteTokens }), - }; -} function processEnvironment( environment: NodeJS.ProcessEnv, @@ -11851,6 +11700,7 @@ export async function createRunnerdBackend(input: { casesEnabled?: boolean; db: Db; controllerPersistence?: { bootId: string; runnerArtifact?: { version: string; digest: string } }; + onAccountingEvent?: (event: PrpEvent) => Promise; execution: NativeExecutionInput; runnerInstanceId: string; chatAttachmentReadScope?: NativeChatAttachmentReadScope; @@ -12166,13 +12016,14 @@ async function createRunnerdBackendWithinSessionClaim( syncIssueExternalObjects: input.syncIssueExternalObjects, enqueueWakeup: input.enqueueWakeup, }); - const authorityEpoch = new SessionToolAuthorityEpoch( + const authorityEpoch = new SessionAuthorityEpoch( input.execution.binding.runId, authority, input.toolTrace, + input.onAccountingEvent, ); let dynamicTools: Awaited< - ReturnType + ReturnType >; try { dynamicTools = await timeController("tool_authority", () => authorityEpoch.definitions()); @@ -12274,7 +12125,7 @@ async function createRunnerdBackendWithinSessionClaim( authority.binding.readRemoteTaskFile = file => owner.readWorkspaceFile(file.contentRef, file.byteSize); dynamicTools = await authorityEpoch.definitions(); } - const executeTool = (call: Parameters[0]) => { + const executeTool = (call: Parameters[0]) => { const current = sessionToolAuthorityEpochs.get(sessionScopeId); if (!current) throw new Error("native_session_tool_authority_unavailable"); return current.execute(call); @@ -12369,7 +12220,7 @@ async function createRunnerdBackendWithinSessionClaim( }; const backendOptions = { onSpawn: input.onSpawn, dynamicTools, - dynamicToolHandler: async (call: Parameters[0]) => { + dynamicToolHandler: async (call: Parameters[0]) => { await assertExternalNativeRunAuthority(input.db, externalExecution); return authorityEpoch.execute(call); }, completionFeedback: async (result: PrpStructuredRunResult) => { @@ -13710,7 +13561,7 @@ async function createRunnerdBackendWithinSessionClaim( markSpawned?.(); } const executeCurrentToolAuthority = ( - call: Parameters[0], + call: Parameters[0], ) => { const current = sessionToolAuthorityEpochs.get(sessionScopeId); if (!current) throw new Error("native_session_tool_authority_unavailable"); @@ -13758,6 +13609,11 @@ async function createRunnerdBackendWithinSessionClaim( onSpawn: input.onSpawn, ...(input.execution.provider.kind === "codex" ? { disableCodexWebSearch: "webSearch" in input.execution.provider && input.execution.provider.webSearch === "disabled" } : {}), homeMode: preconfiguredHome ? "preconfigured" : "isolated", + onAccountingEvent: input.onAccountingEvent ? async event => { + const current = sessionToolAuthorityEpochs.get(sessionScopeId); + if (!current) throw new Error("native_session_authority_unavailable"); + await current.acceptAccountingEvent(event); + } : undefined, onCredentialsUpdated: (event) => appendNativeCredentialUpdate(input.db, { companyId: input.execution.binding.companyId, agentId: input.execution.binding.agentId, diff --git a/server/src/services/native-runtime/native-usage-accounting.test.ts b/server/src/services/native-runtime/native-usage-accounting.test.ts new file mode 100644 index 00000000000..7e40c08fd3f --- /dev/null +++ b/server/src/services/native-runtime/native-usage-accounting.test.ts @@ -0,0 +1,43 @@ +import { describe, expect, it } from "vitest"; +import type { PrpEvent } from "../../vendor/paperclip-runner/index.js"; +import { createNativeTurnAccounting, nativeUsageCostUsd, normalizeNativeUsage, usesNativeUsageDelivery } from "./native-usage-accounting.js"; + +const provider = { kind: "opencode" as const, model: "test-model" }; +const event = (sourceSeq: number, eventType: string, turnId = "turn-1", payload: Record = {}) => ({ + sourceInstanceId: "producer", sourceSeq, eventType, turnId, payload, +} as PrpEvent); + +describe("native turn accounting", () => { + it("selects producer delivery only for supported remote Runner execution", () => { + expect(usesNativeUsageDelivery({ runnerd: true, remote: true, provider })).toBe(true); + expect(usesNativeUsageDelivery({ runnerd: false, remote: true, provider })).toBe(false); + expect(usesNativeUsageDelivery({ runnerd: true, remote: false, provider })).toBe(false); + expect(usesNativeUsageDelivery({ runnerd: true, remote: true })).toBe(false); + expect(usesNativeUsageDelivery({ runnerd: true, remote: true, provider: { kind: "muse", model: null } as never })).toBe(false); + }); + + it("reconstructs cumulative turn usage without counting repeated producer events twice", () => { + const accounting = createNativeTurnAccounting(provider); + const usage = { kind: "usage", usage: { runDeltaComplete: true, runDelta: { inputTokens: 120, outputTokens: 10, providerCostUsd: 0.25 } } }; + const history = [event(1, "turn.started"), event(2, "item.completed", "turn-1", usage), event(3, "turn.completed"), + event(4, "turn.started", "turn-2"), event(5, "item.completed", "turn-2", usage), event(6, "turn.completed", "turn-2")]; + history.forEach(value => accounting.observe(value)); + history.forEach(value => accounting.observe(value)); + const snapshot = accounting.snapshot(); + expect(snapshot.complete).toBe(true); + expect(normalizeNativeUsage(snapshot.usage)).toEqual({ inputTokens: 240, outputTokens: 20, cachedInputTokens: 0, cacheWriteTokens: 0 }); + expect(nativeUsageCostUsd(snapshot.usage, provider)).toBe(0.5); + }); + + it("keeps an incomplete provider report pending instead of trusting placeholder zeroes", () => { + const accounting = createNativeTurnAccounting(provider); + accounting.observe(event(1, "turn.started")); + accounting.observe(event(2, "item.completed", "turn-1", { kind: "usage", usage: { + runDeltaComplete: false, runDelta: { inputTokens: 0, outputTokens: 0, providerCostUsd: 0 }, + } })); + accounting.observe(event(3, "turn.completed")); + expect(accounting.snapshot().complete).toBe(false); + expect(accounting.snapshot().usage?.accountingCostIncomplete).toBe(true); + expect(normalizeNativeUsage({ runDeltaComplete: false, runDelta: { inputTokens: 0, outputTokens: 0 } })).toBeUndefined(); + }); +}); diff --git a/server/src/services/native-runtime/native-usage-accounting.ts b/server/src/services/native-runtime/native-usage-accounting.ts new file mode 100644 index 00000000000..9bbeb41ba93 --- /dev/null +++ b/server/src/services/native-runtime/native-usage-accounting.ts @@ -0,0 +1,187 @@ +import { usdToUnits } from "@paperclipai/shared"; +import type { NativeExecutionInput, PrpEvent } from "../../vendor/paperclip-runner/index.js"; +const record = (value: unknown): Record => value && typeof value === "object" && !Array.isArray(value) ? value as Record : {}; + +function numericUsageField( + usage: Record | null, + keys: string[], +): number | undefined { + if (!usage) return undefined; + for (const key of keys) { + const value = usage[key]; + if (typeof value === "number" && Number.isFinite(value) && value >= 0) + return value; + } + return undefined; +} + +function nativeUsageMeasurement(usage: Record) { + const nestedUsage = record(usage.usage); + // An explicit partial delta must not fall through to a full session total. + if (Object.hasOwn(usage, "runDelta")) return record(usage.runDelta); + if (Object.hasOwn(nestedUsage, "runDelta")) return record(nestedUsage.runDelta); + const candidates = [ + record(usage.runDelta), + record(nestedUsage.runDelta), + record(usage.total), + record(nestedUsage.total), + record(usage.cumulative), + record(nestedUsage.cumulative), + nestedUsage, + usage, + ]; + return ( + candidates.find( + (candidate) => + numericUsageField(candidate, [ + "inputTokens", + "input", + "promptTokens", + "outputTokens", + "output", + "completionTokens", + ]) !== undefined, + ) ?? usage + ); +} + +export function nativeUsageBiller(provider: NativeExecutionInput["provider"]): string { + if (provider.kind === "acpx") { + if (provider.agent === "cursor") return "cursor"; + if (provider.agent === "copilot") return "github"; + if (provider.agent === "pi") return "openrouter"; + } + return "openai"; +} + +export function createNativeTurnAccounting(provider: NativeExecutionInput["provider"]) { + const turns = new Map | null; terminal: boolean }>(); + const sequences = new Map(); + let currentTurn: string | undefined; + const terminalTypes = ["turn.completed", "turn.failed", "turn.cancelled", "turn.interrupted"]; + const snapshot = () => { + if (turns.size === 0) return { usage: null, turnId: undefined, complete: false }; + let inputTokens = 0, outputTokens = 0, cacheReadTokens = 0, cacheWriteTokens = 0; + let cost = 0n, costKnown = false, costIncomplete = false, complete = true; + for (const [turnId, turn] of turns) { + const normalized = normalizeNativeUsage(turn.usage); + complete &&= turnId !== "unattributed" && turn.terminal && normalized !== undefined; + inputTokens += (normalized?.inputTokens ?? 0) - (normalized?.cacheWriteTokens ?? 0); + outputTokens += normalized?.outputTokens ?? 0; + cacheReadTokens += normalized?.cachedInputTokens ?? 0; + cacheWriteTokens += normalized?.cacheWriteTokens ?? 0; + const price = nativeUsageCostUsd(turn.usage, provider); + if (price === undefined) costIncomplete = true; + else { cost += usdToUnits(price); costKnown = true; } + } + // A free empty attempt contributes no price evidence for later paid work. + // Keep an incomplete zero subtotal absent so complete aggregate tokens can + // still receive an estimate. Preserve positive known spend and true zero totals. + const retainCost = costKnown && (!costIncomplete || cost > 0n); + const runDelta = { inputTokens, outputTokens, cacheReadTokens, cacheWriteTokens, + ...(retainCost ? { providerCostUsd: Number(cost) / 1_000_000_000 } : {}) }; + const current = currentTurn ? turns.get(currentTurn) : undefined; + return { usage: { runDelta, accountingCostIncomplete: costIncomplete, + ...(retainCost ? { accountingCostUsdExact: `${cost / 1_000_000_000n}.${String(cost % 1_000_000_000n).padStart(9, "0")}` } : {}) }, + turnId: current && normalizeNativeUsage(current.usage) ? currentTurn : undefined, complete }; + }; + return { + observe(event: PrpEvent) { + if (!event) return false; + const payload = record(event.payload); + const terminal = terminalTypes.includes(event.eventType); + if (payload.kind !== "usage" && event.eventType !== "turn.started" && !terminal) return false; + // Historical replay can revisit an earlier report after restoration. + // Re-persist its aggregate, but never rewind or count that report twice. + if (event.sourceInstanceId && Number.isSafeInteger(event.sourceSeq)) { + if (event.sourceSeq <= (sequences.get(event.sourceInstanceId) ?? -1)) return true; + sequences.set(event.sourceInstanceId, event.sourceSeq); + } + const key = event.turnId ?? "unattributed"; + const turn = turns.get(key) ?? { usage: null, terminal: false }; + if (event.eventType === "turn.started") { + currentTurn = event.turnId; + turn.usage = null; + turn.terminal = false; + } else if (payload.kind === "usage" && (!currentTurn || !turns.has(key))) currentTurn = event.turnId; + if (payload.kind === "usage") { + const usage = record(payload.usage); + turn.usage = Object.hasOwn(usage, "runDelta") + ? { runDelta: record(usage.runDelta), runDeltaComplete: usage.runDeltaComplete } : null; + } + if (terminal) turn.terminal = true; + turns.set(key, turn); + return true; + }, + snapshot, + finish(turnId: string | null) { + const turn = turnId ? turns.get(turnId) : undefined; + if (turn) turn.terminal = true; + return snapshot(); + }, + }; +} + +export function nativeUsageCostUsd( + usage: Record | null, + provider?: NativeExecutionInput["provider"], +) { + // The ACP normalization contract fills absent per-turn cost with zero and + // reports actual cost cumulatively. Until it carries an authoritative run + // delta with provenance, neither value is a candidate's billed USD receipt. + if (provider?.kind === "acpx" && ["cursor", "copilot", "pi"].includes(provider.agent)) return undefined; + if (!usage) return undefined; + const measurement = nativeUsageMeasurement(usage); + const hasRunDelta = Object.hasOwn(usage, "runDelta") || Object.hasOwn(record(usage.usage), "runDelta"); + const direct = numericUsageField(measurement, ["cacheAdjustedCostUsd", "providerCostUsd", "costUsd"]) + ?? (hasRunDelta ? undefined : numericUsageField(usage, ["cacheAdjustedCostUsd", "providerCostUsd", "costUsd"])); + // PRP currently defaults an absent providerCostUsd to zero. That zero is + // not proof of a free request when the runtime observed token consumption. + if (direct !== undefined && direct > 0) return direct; + const normalized = normalizeNativeUsage(usage); + if (direct === 0 && normalized && Object.values(normalized).every(value => value === 0)) return 0; + const cost = record(hasRunDelta ? measurement.cost : usage.cost); + const currency = + typeof cost.currency === "string" ? cost.currency.toUpperCase() : "USD"; + if (currency !== "USD") return undefined; + return numericUsageField(cost, ["amount", "total"]); +} + +export function normalizeNativeUsage(usage: Record | null, options: { inputIncludesCacheReads?: boolean } = {}) { + if (!usage || usage.runDeltaComplete === false || record(usage.usage).runDeltaComplete === false) return undefined; + const measurement = nativeUsageMeasurement(usage); + const cache = record(measurement.cache); + const count = (source: Record, keys: string[]) => { + for (const key of keys) { + if (source[key] === undefined) continue; + const value = source[key]; + return typeof value === "number" && Number.isSafeInteger(value) && value >= 0 ? value : NaN; + } + return undefined; + }; + const input = count(measurement, ["inputTokens", "input", "promptTokens"]); + const outputTokens = count(measurement, ["outputTokens", "output", "completionTokens"]); + const cachedInputTokens = count(measurement, ["cachedInputTokens", "cacheReadInputTokens", "cacheReadTokens", "cachedReadTokens"]) ?? count(cache, ["read"]); + const cacheWriteTokens = count(measurement, ["cacheWriteTokens", "cacheCreationInputTokens", "cachedWriteTokens"]) ?? count(cache, ["write"]); + if (input === undefined || outputTokens === undefined + || ![input, outputTokens, cachedInputTokens ?? 0, cacheWriteTokens ?? 0].every(Number.isSafeInteger)) return undefined; + const inputTokens = input - (options.inputIncludesCacheReads ? cachedInputTokens ?? 0 : 0) + + (options.inputIncludesCacheReads ? 0 : cacheWriteTokens ?? 0); + if (!Number.isSafeInteger(inputTokens) || inputTokens < (cacheWriteTokens ?? 0)) return undefined; + return { + inputTokens, outputTokens, + ...(cachedInputTokens === undefined ? {} : { cachedInputTokens }), + ...(cacheWriteTokens === undefined ? {} : { cacheWriteTokens }), + }; +} + +export function usesNativeUsageDelivery(input: { + runnerd: boolean; remote: boolean; provider?: NativeExecutionInput["provider"] | null; +}) { + return input.runnerd && input.remote && input.provider !== undefined && input.provider !== null + && ["codex", "opencode", "acpx", "claude_managed", "aws_agentcore"].includes(input.provider.kind); +} + +export function isNativeUsageAccountingEvent(event: Pick) { + return ["usage.reported", "turn.started", "turn.completed", "turn.failed", "turn.cancelled", "turn.interrupted"].includes(event.eventType); +} diff --git a/server/src/services/native-runtime/native-usage-delivery.integration.test.ts b/server/src/services/native-runtime/native-usage-delivery.integration.test.ts new file mode 100644 index 00000000000..21eab93cb2c --- /dev/null +++ b/server/src/services/native-runtime/native-usage-delivery.integration.test.ts @@ -0,0 +1,283 @@ +import { compareCents, usdToUnits } from "@paperclipai/shared"; +import { spawn, execFileSync, type ChildProcess } from "node:child_process"; +import { once } from "node:events"; +import { randomUUID } from "node:crypto"; +import { mkdtempSync, readFileSync, writeFileSync, rmSync, existsSync } from "node:fs"; +import { tmpdir } from "node:os"; +import { resolve } from "node:path"; +import { fileURLToPath } from "node:url"; +import { and, eq, sql } from "drizzle-orm"; +import { afterAll, beforeAll, describe, expect, it, vi } from "vitest"; +import { agents, budgetPolicies, companies, costEvents, createDb, heartbeatRuns, runUsageReceipts, type Db } from "@paperclipai/db"; +import { type PrpEvent } from "../../vendor/paperclip-runner/index.js"; +import { startEmbeddedPostgresTestDatabase } from "../../__tests__/helpers/embedded-postgres.js"; +import { accountRunCost } from "../run-cost-accounting.js"; +import { usageReceiptSpoolPath } from "../usage-receipts.js"; +import { createNativeUsageDelivery } from "./native-usage-delivery.js"; + +const runnerRoot = fileURLToPath(new URL("../../../../packages/paperclip-runner/runner/", import.meta.url)); +const fixtureProfile = process.env.CI ? "release" : "debug"; +const billing = { provider: "openai", biller: "openai", billingType: "metered_api" as const }; + +describe("producer-owned native usage", () => { + let database: Awaited>; + let db: Db; + beforeAll(async () => { + execFileSync("cargo", ["build", ...(fixtureProfile === "release" ? ["--release"] : []), "--locked", + "--manifest-path", resolve(runnerRoot, "Cargo.toml"), "-p", "paperclip-runner-core", "--example", "recovery-fixture"], + { timeout: 600_000, stdio: "pipe" }); + database = await startEmbeddedPostgresTestDatabase("native-usage-delivery-"); + db = createDb(database.connectionString); + }, 660_000); + afterAll(async () => { await database?.cleanup(); }); + const seed = async () => { + const companyId = randomUUID(), agentId = randomUUID(), runId = randomUUID(); + await db.insert(companies).values({ id: companyId, name: "Usage delivery", issuePrefix: randomUUID().slice(0, 8) }); + await db.insert(agents).values({ id: agentId, companyId, name: "Producer", adapterType: "paperclip_runner" }); + await db.insert(heartbeatRuns).values({ id: runId, companyId, agentId, invocationSource: "on_demand", status: "running", runtimeMode: "native", costAccountingPending: true }); + return { companyId, agentId, runId, runnerInstanceId: randomUUID(), provider: { kind: "codex" as const, model: "test-model" }, billing }; + }; + const event = (input: Pick>, "runId" | "runnerInstanceId">, sequence: number, type: string, turnId = "turn-1", amount = 0.25): PrpEvent => ({ + schema: "paperclip.prp.event.v1", schemaVersion: 1, sourceKind: "runner", sourceInstanceId: input.runnerInstanceId, + sourceEventId: `usage-${sequence}`, sourceSeq: sequence, priority: 0, runId: input.runId, + normalizedSessionId: "session-1", turnId, emittedAt: new Date().toISOString(), eventType: type, + payload: type === "usage.reported" ? { runDeltaAvailable: true, runDeltaBasis: "run", runDelta: { inputTokens: 120, outputTokens: 10, providerCostUsd: amount } } : {}, + } as PrpEvent); + + it("retains the same Runner report through a failed Postgres receipt and an empty replacement receiver", async () => { + const input = await seed(); + expect(existsSync(usageReceiptSpoolPath())).toBe(false); + const root = mkdtempSync(resolve(tmpdir(), "native-usage-runner-")); + const receiverA = resolve(root, "receiver-a"), receiverB = resolve(root, "receiver-b"); + const identity = { runnerInstanceId: input.runnerInstanceId, environmentLeaseId: randomUUID(), runId: input.runId, + normalizedSessionId: randomUUID(), turnId: "turn-1", itemId: "item-1" }; + const expectedRunnerVersion = "0.3.0", expectedRunnerDigest = `sha256:${"c".repeat(64)}`; + let receiver: ChildProcess | undefined, child: ChildProcess | undefined; + let exit: Promise | undefined, failed = 0, lastCaptureError = ""; + const receiptFile = resolve(root, "producer.json"), releaseFile = resolve(root, "release"), scriptFile = resolve(root, "script.json"); + writeFileSync(scriptFile, JSON.stringify({ steps: 3, waitAfter: 2, retentionLimit: 8, receiptFile, releaseFile, accounting: true })); + const receipts = () => db.select().from(runUsageReceipts).where(eq(runUsageReceipts.runId, input.runId)); + try { + + await db.execute(sql`CREATE FUNCTION fail_native_usage_receipt() RETURNS trigger LANGUAGE plpgsql AS $$ BEGIN RAISE EXCEPTION 'receipt database unavailable'; END $$`); + await db.execute(sql`CREATE TRIGGER fail_native_usage BEFORE INSERT ON run_usage_receipts FOR EACH ROW EXECUTE FUNCTION fail_native_usage_receipt()`); + const startReceiver = () => new Promise((resolve, reject) => { + const process = spawn(globalThis.process.execPath, ["--import", fileURLToPath(new URL("../../../node_modules/tsx/dist/loader.mjs", import.meta.url)), fileURLToPath(new URL("./__fixtures__/usage-receiver.ts", import.meta.url))], { + cwd: fileURLToPath(new URL("../../../../", import.meta.url)), stdio: ["ignore", "ignore", "pipe", "ipc"], env: { ...globalThis.process.env }, + }); + let diagnostics = ""; + process.stderr!.on("data", bytes => { diagnostics = (diagnostics + String(bytes)).slice(-16000); }); + const timer = setTimeout(() => { process.kill("SIGKILL"); reject(new Error(`receiver startup timeout: ${diagnostics}`)); }, 60_000); + process.once("exit", code => { clearTimeout(timer); reject(new Error(`receiver exited ${code}: ${diagnostics}`)); }); + process.on("message", message => { + const kind = (message as { kind?: string }).kind; + if (kind === "capture-failed") { failed++; lastCaptureError = String((message as { cause?: string }).cause); } + if (kind === "ready") { clearTimeout(timer); resolve(process); } + }); + }); + let requestId = 0; + const request = (target: ChildProcess, value: Record) => new Promise>((resolve, reject) => { + const id = ++requestId; + const timer = setTimeout(() => { target.off("message", listener); reject(new Error("receiver response timeout")); }, 30_000); + const listener = (message: unknown) => { + const result = message as Record; + if (result.requestId !== id) return; + clearTimeout(timer); target.off("message", listener); + if (result.error) reject(new Error(String(result.error))); else resolve(result); + }; + target.on("message", listener); + target.send({ ...value, requestId: id }); + }); + receiver = await startReceiver(); + const firstReceiver = await request(receiver, { kind: "start", connectionString: database.connectionString, directory: receiverA, identity, input }); + const connectUrl = String(firstReceiver.connectUrl), port = Number(new URL(connectUrl).port), ticket = String(firstReceiver.ticket); + child = spawn(resolve(runnerRoot, `target/${fixtureProfile}/examples/recovery-fixture`), ["--fixture-script", scriptFile, "--connect-url", connectUrl, + "--state-dir", resolve(root, "producer"), "--runner-id", identity.runnerInstanceId, "--environment-lease-id", identity.environmentLeaseId, + "--run-id", identity.runId, "--session-id", identity.normalizedSessionId, "--turn-id", identity.turnId, "--item-id", identity.itemId, + "--runner-version", expectedRunnerVersion, "--runner-digest", expectedRunnerDigest, "--max-outbox-bytes", "65536", "--p0-reserve-bytes", "16384", "--reconnect-grace-ms", "120000"], + { env: { ...process.env, PAPERCLIP_RUNNER_BOOTSTRAP_TICKET: ticket }, stdio: ["ignore", "ignore", "pipe"] }); + exit = once(child, "exit"); + await request(receiver, { kind: "command", type: "turn.start", commandId: "start-once" }); + writeFileSync(releaseFile, "produce"); + await vi.waitFor(() => expect(failed).toBeGreaterThan(0), { timeout: 10_000 }); + expect(await receipts()).toHaveLength(0); + const producerState = () => JSON.parse(readFileSync(resolve(root, "producer/runner-state.json"), "utf8")) as { + outbox: Array<{ eventType: string; envelope: { payload: { sourceEventId: string } } }>; + }; + const pendingUsage = producerState().outbox.find(report => report.eventType === "usage.reported"); + expect(pendingUsage).toBeDefined(); + const pendingSourceEventId = pendingUsage!.envelope.payload.sourceEventId; + const stoppedReceiver = await request(receiver, { kind: "stop" }); + rmSync(receiverA, { recursive: true, force: true }); + await db.execute(sql`DROP TRIGGER fail_native_usage ON run_usage_receipts`); + await db.execute(sql`DROP FUNCTION fail_native_usage_receipt()`); + + receiver = await startReceiver(); + await request(receiver, { kind: "start", connectionString: database.connectionString, directory: receiverB, identity, input, port, checkpoint: stoppedReceiver.checkpoint }); + await vi.waitFor(async () => expect((await receipts()).filter(row => row.complete)).toHaveLength(1), { timeout: 15_000 }); + await vi.waitFor(() => expect(producerState().outbox).toEqual([]), { timeout: 10_000 }); + expect((await receipts()).some(row => (row.receiptJson.producerEvent as Record).sourceEventId === pendingSourceEventId)).toBe(true); + expect((await receipts()).filter(row => row.receiptJson.producerEvent && (row.receiptJson.producerEvent as Record).eventType === "usage.reported")).toHaveLength(1); + await db.update(heartbeatRuns).set({ status: "succeeded", finishedAt: new Date() }).where(eq(heartbeatRuns.id, input.runId)); + expect(await accountRunCost(db, input.runId)).toBe(true); + expect(await accountRunCost(db, input.runId)).toBe(false); + const ledger = await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, input.runId)); + expect(ledger).toHaveLength(1); + expect(ledger[0].costCents).toBe(25); + const failedBeforeLateReport = failed; + await request(receiver, { kind: "command", type: "turn.steer", commandId: "release-late-usage" }); + await vi.waitFor(() => expect(failed).toBeGreaterThan(failedBeforeLateReport), { timeout: 10_000 }); + expect(lastCaptureError).toContain("native_usage_after_finalization_requires_reconciliation"); + const retainedLate = producerState().outbox.find(report => report.eventType === "usage.reported"); + expect(retainedLate).toBeDefined(); + expect(retainedLate!.envelope.payload).toMatchObject({ runId: input.runId, sourceInstanceId: input.runnerInstanceId }); + expect((await receipts()).filter(row => (row.receiptJson.producerEvent as Record)?.eventType === "usage.reported")).toHaveLength(1); + expect(await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, input.runId))).toHaveLength(1); + expect(existsSync(usageReceiptSpoolPath())).toBe(false); + } finally { + await db.execute(sql`DROP TRIGGER IF EXISTS fail_native_usage ON run_usage_receipts`); + await db.execute(sql`DROP FUNCTION IF EXISTS fail_native_usage_receipt()`); + if (receiver && receiver.exitCode === null && receiver.signalCode === null) receiver.kill("SIGKILL"); + if (child && child.exitCode === null && child.signalCode === null) child.kill("SIGKILL"); + await exit; + rmSync(root, { force: true, recursive: true }); + } + }, 240_000); + + it("preserves source takeover fencing, budget holds, and missing-usage debt", async () => { + const input = await seed(); + const first = await createNativeUsageDelivery(db, input); + await db.insert(budgetPolicies).values({ companyId: input.companyId, scopeType: "agent", scopeId: input.agentId, + metric: "billed_cents", windowKind: "lifetime", amount: 10, notifyEnabled: false }); + await first.capture(event(input, 1, "usage.reported")); + const [agent] = await db.select().from(agents).where(eq(agents.id, input.agentId)); + expect(agent.lifecycleHolds).toContain("budget"); + const replacement = { ...input, runnerInstanceId: randomUUID() }; + const second = await createNativeUsageDelivery(db, replacement); + await second.capture(event(replacement, 1, "usage.reported", "turn-2", 0.5)); + await first.capture(event(input, 2, "turn.completed")); + const [pending] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, input.runId)); + expect(pending.usageJson).toMatchObject({ costUsd: 0.5, accountingReceiptReady: false }); + await db.update(heartbeatRuns).set({ status: "succeeded", finishedAt: new Date() }).where(eq(heartbeatRuns.id, input.runId)); + expect(await accountRunCost(db, input.runId)).toBe(false); + expect(await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, input.runId))).toHaveLength(0); + await second.capture(event(replacement, 2, "turn.completed", "turn-2")); + expect(await accountRunCost(db, input.runId)).toBe(true); + expect((await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, input.runId)))[0].costCents).toBe(50); + }); + + it.each(["tokens", "cost", "incomplete"])("accepts equal finalized snapshots and rejects changed %s without repricing", async change => { + const input = await seed(); + const delivery = await createNativeUsageDelivery(db, input); + await delivery.capture(event(input, 1, "usage.reported")); + await delivery.capture(event(input, 2, "turn.completed")); + await db.update(heartbeatRuns).set({ status: "succeeded", finishedAt: new Date() }).where(eq(heartbeatRuns.id, input.runId)); + expect(await accountRunCost(db, input.runId)).toBe(true); + await delivery.capture(event(input, 3, "usage.reported")); + const late = event(input, 4, "usage.reported"); + (late.payload as Record).runDelta = { inputTokens: change === "tokens" ? 150 : 120, outputTokens: change === "tokens" ? 15 : 10, providerCostUsd: change === "incomplete" ? 0.25 : 0.5 }; + if (change === "incomplete") (late.payload as Record).runDeltaAvailable = false; + await expect(delivery.capture(late)).rejects.toThrow("native_usage_after_finalization_requires_reconciliation"); + await expect(delivery.capture(late)).rejects.toThrow("native_usage_after_finalization_requires_reconciliation"); + expect((await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, input.runId)))[0].costCents).toBe(25); + }); + + it("accepts equal finalized rate-card reports without requiring terminal-only derived pricing", async () => { + const input = { ...await seed(), provider: { kind: "codex" as const, model: "gpt-6.1-sol" } }; + const delivery = await createNativeUsageDelivery(db, input); + const report = (sequence: number) => { + const reported = event(input, sequence, "usage.reported"); + reported.payload = { runDeltaBasis: "run", runDeltaAvailable: true, runDelta: { inputTokens: 1000, outputTokens: 100000 } }; + return reported; + }; + await delivery.capture(report(1)); + await delivery.capture(event(input, 2, "turn.completed")); + await db.update(heartbeatRuns).set({ status: "succeeded", finishedAt: new Date() }).where(eq(heartbeatRuns.id, input.runId)); + expect(await accountRunCost(db, input.runId)).toBe(true); + await delivery.capture(report(3)); + const [run] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, input.runId)); + expect(run.usageJson).toMatchObject({ pricingProvenance: { source: "rate_card" }, accountingReceiptReady: true }); + expect(usdToUnits(run.usageJson!.costUsdExact as string)).toBe(usdToUnits("1.002")); + const ledger = await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, input.runId)); + expect(ledger).toHaveLength(1); + expect(ledger[0].costCents).toBe(100.2); + const correction = report(4); + (correction.payload as Record).runDelta = { inputTokens: 1000, outputTokens: 100000, providerCostUsd: 2 }; + await expect(delivery.capture(correction)).rejects.toThrow("native_usage_after_finalization_requires_reconciliation"); + }); + + it("keeps successor exposure pending after prior-turn accounting invalidates its live snapshot", async () => { + const input = await seed(); + const delivery = await createNativeUsageDelivery(db, input); + const paid = event(input, 1, "usage.reported"); + paid.payload = { runDeltaBasis: "run", runDeltaAvailable: true, runDelta: { inputTokens: 50, outputTokens: 5, providerCostUsd: 0.5 } }; + await delivery.capture(paid); + const invalidated = event(input, 2, "usage.reported"); + invalidated.payload = { runDeltaBasis: "run", runDeltaAvailable: false, runDelta: {}, reason: "accounting_reconciliation_required", + reconciliation: { receivedTurnId: "old-provider-turn", cumulative: { inputTokens: 120, outputTokens: 12 }, priorOrigin: { runId: "old-run" } } }; + await delivery.capture(invalidated); + await delivery.capture(event(input, 3, "turn.failed")); + await db.update(heartbeatRuns).set({ status: "failed", errorCode: "codex_usage_accounting_integrity", finishedAt: new Date() }).where(eq(heartbeatRuns.id, input.runId)); + const [run] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, input.runId)); + expect(run).toMatchObject({ costAccountingPending: true, costAccountedAt: null, + usageJson: { accountingReceiptReady: false, costStatus: "unpriced" } }); + expect(compareCents((run.usageJson?.budgetExposure as { costCents: string }).costCents, "50")).toBe(0); + const [required] = await db.select().from(runUsageReceipts).where(and(eq(runUsageReceipts.runId, input.runId), eq(runUsageReceipts.sequence, 2))); + expect(required.receiptJson.producerEvent).toMatchObject({ usage: { reconciliation: { receivedTurnId: "old-provider-turn", cumulative: { inputTokens: 120 }, priorOrigin: { runId: "old-run" } } } }); + expect(await accountRunCost(db, input.runId)).toBe(false); + expect(await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, input.runId))).toHaveLength(0); + }); + + it("retains unmarked legacy Codex reports as incomplete unpriced debt", async () => { + const input = { ...await seed(), provider: { kind: "codex" as const, model: "gpt-6.1-sol" } }; + const delivery = await createNativeUsageDelivery(db, input); + const legacy = event(input, 1, "usage.reported"); + delete (legacy.payload as Record).runDeltaBasis; + await delivery.capture(legacy); + await delivery.capture(event(input, 2, "turn.completed")); + await db.update(heartbeatRuns).set({ status: "succeeded", finishedAt: new Date() }).where(eq(heartbeatRuns.id, input.runId)); + expect((await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, input.runId)))[0]).toMatchObject({ + costAccountingPending: true, costAccountedAt: null, usageJson: { accountingReceiptReady: false, costStatus: "unpriced" } }); + expect(await accountRunCost(db, input.runId)).toBe(false); + expect(await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, input.runId))).toHaveLength(0); + }); + + it("replays partial and final usage once after a lost commit response and restores turn aggregation", async () => { + const input = { ...await seed(), provider: { kind: "opencode" as const, model: "test-model" } }; + let loseResponse = false; + const failingDb = new Proxy(db, { get(target, property) { + if (property === "transaction") return async (...args: Parameters) => { + const result = await db.transaction(...args); + if (loseResponse) { loseResponse = false; throw new Error("lost commit response"); } + return result; + }; + const value = Reflect.get(target, property); + return typeof value === "function" ? value.bind(target) : value; + } }) as Db; + let delivery = await createNativeUsageDelivery(failingDb, input); + const first = event(input, 1, "usage.reported"), done = event(input, 2, "turn.completed"); + loseResponse = true; + await expect(delivery.capture(first)).rejects.toThrow("lost commit response"); + await delivery.capture(first); + await delivery.capture(done); + delivery = await createNativeUsageDelivery(db, input); + await delivery.capture(first); + await delivery.capture(done); + const nextTurn = event(input, 3, "turn.started", "turn-1"); + nextTurn.payload = { providerTurnId: "provider-turn-2" }; + await delivery.capture(nextTurn); + const partial = event(input, 4, "usage.reported", "turn-1", 0.5); + (partial.payload as Record).runDeltaAvailable = false; + await delivery.capture(partial); + const final = event(input, 5, "usage.reported", "turn-1", 0.5); + await delivery.capture(final); + const terminal = event(input, 6, "turn.completed", "turn-1"); + terminal.payload = { providerTurnId: "provider-turn-2" }; + await delivery.capture(terminal); + const [run] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, input.runId)); + expect(run.usageJson).toMatchObject({ inputTokens: 240, outputTokens: 20, accountingReceiptReady: true, costUsd: 0.75 }); + expect(run.usageJson?.accountingCaptureFailed).not.toBe(true); + expect(await db.select().from(runUsageReceipts).where(and(eq(runUsageReceipts.runId, input.runId), eq(runUsageReceipts.sequence, 1)))).toHaveLength(1); + await expect(delivery.capture({ ...final, payload: { ...final.payload as object, runDeltaAvailable: false } })).rejects.toThrow("native_usage_source_conflict"); + }); +}); diff --git a/server/src/services/native-runtime/native-usage-delivery.ts b/server/src/services/native-runtime/native-usage-delivery.ts new file mode 100644 index 00000000000..2bbf52d0d1b --- /dev/null +++ b/server/src/services/native-runtime/native-usage-delivery.ts @@ -0,0 +1,109 @@ +import { createHash } from "node:crypto"; +import { and, asc, eq, isNull, sql } from "drizzle-orm"; +import { heartbeatRuns, runUsageReceipts, type Db } from "@paperclipai/db"; +import type { AdapterUsageCheckpoint } from "@paperclipai/adapter-utils"; +import type { NativeExecutionInput, PrpEvent } from "../../vendor/paperclip-runner/index.js"; +import { priceAnthropicReceipt } from "../anthropic-pricing.js"; +import { priceCodexReceipt } from "../codex-pricing.js"; +import { liveRunUsageCostCents } from "../budget-live-usage.js"; +import { receiptFingerprint } from "../receipt-fingerprint.js"; +import { persistUsageReceipt, type UsageReceiptEnvelope } from "../usage-receipts.js"; +import { createNativeTurnAccounting, nativeUsageCostUsd, normalizeNativeUsage } from "./native-usage-accounting.js"; + +const terminal = new Set(["turn.completed", "turn.failed", "turn.cancelled", "turn.interrupted"]); +const uuid = (identity: string) => { + const hex = createHash("sha256").update(identity).digest("hex"); + return `${hex.slice(0, 8)}-${hex.slice(8, 12)}-5${hex.slice(13, 16)}-a${hex.slice(17, 20)}-${hex.slice(20, 32)}`; +}; + +export async function createNativeUsageDelivery(db: Db, input: { + companyId: string; runId: string; runnerInstanceId: string; + provider: NativeExecutionInput["provider"]; + billing: Pick; +}) { + const sourceId = uuid(`${input.runId}:${input.runnerInstanceId}`); + const [bound] = await db.update(heartbeatRuns).set({ usageJson: sql` + coalesce(${heartbeatRuns.usageJson}, '{}'::jsonb) || '{"accountingReceiptOwner":"native_producer"}'::jsonb || + case when ${heartbeatRuns.usageJson}->>'accountingReceiptSourceId' = ${sourceId} + then '{}'::jsonb else ${JSON.stringify({ accountingReceiptSourceId: sourceId, accountingReceiptSequence: 0, accountingReceiptReady: false })}::jsonb end` + }).where(and(eq(heartbeatRuns.companyId, input.companyId), eq(heartbeatRuns.id, input.runId), + isNull(heartbeatRuns.costAccountedAt))).returning({ id: heartbeatRuns.id }); + if (!bound) throw new Error("native_usage_run_not_available"); + const saved = await db.select({ receipt: runUsageReceipts.receiptJson }).from(runUsageReceipts).where(and( + eq(runUsageReceipts.companyId, input.companyId), eq(runUsageReceipts.runId, input.runId), + eq(runUsageReceipts.sourceId, sourceId))).orderBy(asc(runUsageReceipts.sequence)); + const accepted = new Map(); + const turnAccounting = ["opencode", "acpx"].includes(input.provider.kind) ? createNativeTurnAccounting(input.provider) : null; + let observedUsage: Record | null = null; + let observedTurn: string | undefined; + let activeProviderTurn: string | undefined; + const observe = (envelope: UsageReceiptEnvelope) => { + const fact = envelope.producerEvent!; + if (fact.eventType === "turn.started") activeProviderTurn = fact.providerTurnId ?? fact.sourceEventId; + const accountingTurn = fact.providerTurnId ?? activeProviderTurn ?? fact.turnId; + const interpretedUsage = fact.usage ? { ...fact.usage, runDeltaComplete: fact.usage.runDeltaComplete === true + && (input.provider.kind !== "codex" || fact.usage.runDeltaBasis === "run") } : undefined; + const event = { sourceInstanceId: input.runnerInstanceId, sourceSeq: envelope.sequence, + turnId: accountingTurn, eventType: fact.eventType, + payload: interpretedUsage ? { kind: "usage", usage: interpretedUsage } : {} } as PrpEvent; + if (turnAccounting) { + turnAccounting.observe(event); + return turnAccounting.snapshot(); + } + if (fact.eventType === "turn.started") observedTurn = undefined; + if (interpretedUsage) { + observedUsage = interpretedUsage; + observedTurn = normalizeNativeUsage(observedUsage, { inputIncludesCacheReads: input.provider.kind === "codex" }) ? accountingTurn : undefined; + } + return { usage: observedUsage, complete: terminal.has(fact.eventType) && observedTurn !== undefined && observedTurn === accountingTurn }; + }; + for (const row of saved) { + const envelope = row.receipt as UsageReceiptEnvelope; + if (!envelope.producerEvent) throw new Error("native_usage_receipt_missing_producer"); + accepted.set(envelope.producerEvent.sourceEventId, envelope); + observe(envelope); + } + let pending: UsageReceiptEnvelope | undefined; + let chain = Promise.resolve(); + const capture = async (event: PrpEvent) => { + if (event.eventType !== "usage.reported" && event.eventType !== "turn.started" && !terminal.has(event.eventType)) return; + if (event.runId !== input.runId || event.sourceInstanceId !== input.runnerInstanceId) throw new Error("native_usage_source_mismatch"); + const payload = event.payload as Record; + const fact: NonNullable = { + sourceEventId: event.sourceEventId, turnId: event.turnId, eventType: event.eventType, + ...(typeof payload.providerTurnId === "string" ? { providerTurnId: payload.providerTurnId } : {}), + ...(event.eventType === "usage.reported" ? { usage: { runDelta: payload.runDelta, runDeltaComplete: payload.runDeltaAvailable === true, runDeltaBasis: payload.runDeltaBasis, + ...(payload.reconciliation && typeof payload.reconciliation === "object" ? { reconciliation: payload.reconciliation } : {}) } } : {}), + }; + const previous = accepted.get(event.sourceEventId) ?? (pending?.producerEvent?.sourceEventId === event.sourceEventId ? pending : undefined); + if (previous && (previous.sequence !== event.sourceSeq || previous.receivedAt !== event.emittedAt + || receiptFingerprint(previous.producerEvent) !== receiptFingerprint(fact))) throw new Error("native_usage_source_conflict"); + if (accepted.has(event.sourceEventId)) return; + if (pending && pending.producerEvent?.sourceEventId !== event.sourceEventId) throw new Error("native_usage_report_pending"); + if (!pending) { + const envelope: UsageReceiptEnvelope = { schema: "paperclip/accounting-receipt/v1", + id: uuid(`${input.runId}:${input.runnerInstanceId}:${event.sourceEventId}`), companyId: input.companyId, + runId: input.runId, adapterType: "paperclip_runner", sourceId, sequence: event.sourceSeq, + receivedAt: event.emittedAt, producerEvent: fact, receipt: { complete: false } }; + const snapshot = observe(envelope); + const usage = normalizeNativeUsage(snapshot.usage, { inputIncludesCacheReads: input.provider.kind === "codex" }); + envelope.receipt = priceAnthropicReceipt(priceCodexReceipt({ ...input.billing, + model: input.provider.model ?? "unknown", usage, usageBasis: "per_run", complete: snapshot.complete && usage !== undefined, + costUsd: usage ? nativeUsageCostUsd(snapshot.usage, input.provider) ?? null : null, + costUsdExact: typeof snapshot.usage?.accountingCostUsdExact === "string" ? snapshot.usage.accountingCostUsdExact : undefined, + costStatus: usage === undefined || snapshot.usage?.accountingCostIncomplete === true ? "unpriced" + : input.provider.kind === "aws_agentcore" ? "estimated" : undefined, + })); + envelope.liveCostCents = liveRunUsageCostCents(envelope.receipt as AdapterUsageCheckpoint); + pending = envelope; + } + await persistUsageReceipt(db, pending); + accepted.set(event.sourceEventId, pending); + pending = undefined; + }; + return { capture(event: PrpEvent) { + const result = chain.then(() => capture(event)); + chain = result.catch(() => undefined); + return result; + } }; +} diff --git a/server/src/services/usage-receipts.ts b/server/src/services/usage-receipts.ts index 0f99401d9da..74493640746 100644 --- a/server/src/services/usage-receipts.ts +++ b/server/src/services/usage-receipts.ts @@ -40,6 +40,8 @@ const envelopeSchema = z.object({ schema: z.literal("paperclip/accounting-receipt/v1"), id: z.string().uuid(), companyId: z.string().uuid(), runId: z.string().uuid(), sourceId: z.string().uuid(), sequence: z.number().int().positive(), receivedAt: z.iso.datetime(), adapterType: z.string().max(100), receipt: checkpointSchema, + producerEvent: z.object({ sourceEventId: z.string(), turnId: z.string().optional(), providerTurnId: z.string().optional(), + eventType: z.string(), usage: z.record(z.string(), z.unknown()).optional() }).optional(), // Derived by the recorder, not a provider's final charge. Keeping it in the // fsynced envelope preserves known partial attempts through database replay. liveCostCents: z.string().max(160).refine(value => { @@ -75,6 +77,27 @@ export async function persistUsageReceipt(db: Db, raw: UsageReceiptEnvelope) { if (!run) throw notFound("Accounting run not found"); const [existing] = await tx.select().from(runUsageReceipts).where(and(eq(runUsageReceipts.companyId, envelope.companyId), eq(runUsageReceipts.runId, envelope.runId), eq(runUsageReceipts.sourceId, envelope.sourceId), eq(runUsageReceipts.sequence, envelope.sequence))); if (existing && existing.receiptHash !== hash) throw conflict("Conflicting usage checkpoint replay"); + if (!existing && run.costAccountedAt && envelope.producerEvent) { + const previous = run.usageJson ?? {}; + const [saved] = await tx.select({ receiptJson: runUsageReceipts.receiptJson }).from(runUsageReceipts).where(and( + eq(runUsageReceipts.companyId, envelope.companyId), eq(runUsageReceipts.runId, envelope.runId), + sql`${runUsageReceipts.id}::text = ${previous.accountingReceiptId ?? null}`)); + const accepted = saved ? envelopeSchema.parse(saved.receiptJson).receipt : undefined; + const monetaryAmount = (receipt: UsageReceiptEnvelope["receipt"] | undefined) => { + const value = receipt?.cacheAdjustedCostUsd ?? receipt?.costUsdExact ?? receipt?.costUsd; + return value == null ? null : usdToUnits(value); + }; + const incomingMoney = monetaryAmount(envelope.receipt); + const authoritativeMoney = incomingMoney !== null && envelope.receipt.pricingProvenance?.source !== "rate_card"; + const authoritativeProvenance = envelope.receipt.pricingProvenance + && !["rate_card", "unknown"].includes(envelope.receipt.pricingProvenance.source); + if ((envelope.producerEvent.eventType === "usage.reported" && (!envelope.receipt.usage || !accepted)) + || Object.entries(envelope.receipt.usage ?? {}).some(([key, value]) => previous[key] !== value) + || (authoritativeMoney && incomingMoney !== monetaryAmount(accepted)) + || (authoritativeProvenance && receiptFingerprint(envelope.receipt.pricingProvenance) !== receiptFingerprint(accepted?.pricingProvenance ?? null))) { + throw conflict("native_usage_after_finalization_requires_reconciliation"); + } + } if (!existing) await tx.insert(runUsageReceipts).values({ id: envelope.id, companyId: envelope.companyId, runId: envelope.runId, sourceId: envelope.sourceId, sequence: envelope.sequence, receiptHash: hash, receiptJson: envelope, complete: envelope.receipt.complete, receivedAt: new Date(envelope.receivedAt), @@ -367,3 +390,33 @@ export async function createRunUsageRecorder(db: Db, input: { companyId: string; }), }; } + +export async function readAcceptedRunUsageCheckpoint(db: Db, input: { companyId: string; runId: string }): Promise { + const [run] = await db.select({ usageJson: heartbeatRuns.usageJson }).from(heartbeatRuns).where(and( + eq(heartbeatRuns.companyId, input.companyId), eq(heartbeatRuns.id, input.runId))); + const state = run?.usageJson; + if (typeof state?.accountingReceiptId !== "string") return undefined; + const [saved] = await db.select({ receiptJson: runUsageReceipts.receiptJson }).from(runUsageReceipts).where(and( + eq(runUsageReceipts.companyId, input.companyId), eq(runUsageReceipts.runId, input.runId), + sql`${runUsageReceipts.id}::text = ${state.accountingReceiptId}`)); + if (!saved) return undefined; + const receipt = envelopeSchema.parse(saved.receiptJson); + if (receipt.sourceId !== state.accountingReceiptSourceId || receipt.sequence !== state.accountingReceiptSequence) return undefined; + return { ...receipt.receipt, complete: receipt.receipt.complete && state.accountingReceiptReady === true } as AdapterUsageCheckpoint; +} + +const producerAccountingProjectionFields = [ + "accountingReceiptOwner", "accountingReceiptSourceId", "accountingReceiptSequence", "accountingReceiptReady", + "accountingReceiptId", "accountingReceiptReceivedAt", "accountingCaptureFailed", + "inputTokens", "outputTokens", "cachedInputTokens", "cacheWriteTokens", + "provider", "biller", "model", "billingType", "usageSource", "providerRequestId", "usageByModel", + "costUsd", "costUsdExact", "cacheAdjustedCostUsd", "costStatus", "pricingProvenance", "budgetExposure", +]; + +export function preserveAcceptedRunUsageProjectionSql(patch: Record) { + const fields = sql.join(producerAccountingProjectionFields.map(field => sql`${field}`), sql`, `); + return sql`case when ${heartbeatRuns.usageJson}->>'accountingReceiptOwner' = 'native_producer' + then ${JSON.stringify(patch)}::jsonb || (select coalesce(jsonb_object_agg(key, value), '{}'::jsonb) + from jsonb_each(coalesce(${heartbeatRuns.usageJson}, '{}'::jsonb)) where key in (${fields})) + else ${JSON.stringify(patch)}::jsonb end`; +}