Skip to main content

forge_sandbox/
audit.rs

1//! Audit logging for sandbox executions.
2//!
3//! Every sandbox execution emits an [`AuditEntry`] containing:
4//! - Execution ID (UUID)
5//! - SHA-256 hash of the code (never raw code in logs)
6//! - A preview of the first 500 chars of code
7//! - Tool calls made (with hashed args, not raw)
8//! - Duration and outcome
9//!
10//! The [`AuditLogger`] trait allows pluggable backends.
11//! [`JsonLinesAuditLogger`] writes newline-delimited JSON to any `AsyncWrite`.
12
13use chrono::{DateTime, Utc};
14use serde::Serialize;
15use sha2::{Digest, Sha256};
16use std::sync::Arc;
17use std::time::Instant;
18use tokio::io::{AsyncWrite, AsyncWriteExt};
19use tokio::sync::Mutex;
20use uuid::Uuid;
21
22/// Maximum length of the code preview in audit entries.
23const CODE_PREVIEW_MAX: usize = 500;
24
25/// A complete audit record for a single sandbox execution.
26#[derive(Debug, Clone, Serialize)]
27pub struct AuditEntry {
28    /// Unique execution identifier.
29    pub execution_id: String,
30    /// ISO-8601 timestamp of when execution started.
31    pub timestamp: DateTime<Utc>,
32    /// SHA-256 hash of the submitted code.
33    pub code_hash: String,
34    /// First N characters of the code (for human review).
35    pub code_preview: String,
36    /// Whether this was a search or execute call.
37    pub operation: AuditOperation,
38    /// Tool calls made during execution.
39    pub tool_calls: Vec<ToolCallAudit>,
40    /// Resource reads made during execution.
41    pub resource_reads: Vec<ResourceReadAudit>,
42    /// Stash operations made during execution (SR-ST9).
43    #[serde(default, skip_serializing_if = "Vec::is_empty")]
44    pub stash_operations: Vec<StashOperationAudit>,
45    /// Total execution duration in milliseconds.
46    pub duration_ms: u64,
47    /// Size of the result in bytes.
48    pub result_size_bytes: usize,
49    /// Final outcome.
50    pub outcome: AuditOutcome,
51    /// Whether a pooled worker was reused (vs. cold start).
52    #[serde(default, skip_serializing_if = "std::ops::Not::not")]
53    pub worker_reused: bool,
54    /// Pool size when this execution acquired a worker. None if no pool.
55    #[serde(default, skip_serializing_if = "Option::is_none")]
56    pub pool_size_at_acquire: Option<usize>,
57}
58
59/// The type of sandbox operation.
60#[derive(Debug, Clone, Serialize)]
61#[serde(rename_all = "snake_case")]
62#[non_exhaustive]
63pub enum AuditOperation {
64    /// A manifest search operation.
65    Search,
66    /// A code execution operation with tool access.
67    Execute,
68}
69
70/// Audit record for a single tool call within an execution.
71#[derive(Debug, Clone, Serialize)]
72pub struct ToolCallAudit {
73    /// Target server name.
74    pub server: String,
75    /// Tool identifier.
76    pub tool: String,
77    /// SHA-256 hash of the serialized arguments (args never stored raw).
78    pub args_hash: String,
79    /// Duration of this tool call in milliseconds.
80    pub duration_ms: u64,
81    /// Whether the tool call succeeded.
82    pub success: bool,
83}
84
85/// Audit record for a single resource read within an execution.
86#[derive(Debug, Clone, Serialize)]
87pub struct ResourceReadAudit {
88    /// Target server name.
89    pub server: String,
90    /// SHA-256 hash of the resource URI (URIs never stored raw in audit logs).
91    pub uri_hash: String,
92    /// Size of the resource content in bytes.
93    pub size_bytes: usize,
94    /// Duration of this resource read in milliseconds.
95    pub duration_ms: u64,
96    /// Whether the resource read succeeded.
97    pub success: bool,
98}
99
100/// Type of stash operation for audit logging.
101#[derive(Debug, Clone, Serialize)]
102#[serde(rename_all = "snake_case")]
103#[non_exhaustive]
104pub enum StashOpType {
105    /// Store a value.
106    Put,
107    /// Retrieve a value.
108    Get,
109    /// Delete an entry.
110    Delete,
111    /// List visible keys.
112    Keys,
113}
114
115/// Audit record for a single stash operation within an execution.
116///
117/// Per SR-ST9: key name is logged but value content is NOT — only `size_bytes`.
118#[derive(Debug, Clone, Serialize)]
119pub struct StashOperationAudit {
120    /// Type of stash operation.
121    pub op_type: StashOpType,
122    /// The stash key (name only, never the value).
123    pub key: String,
124    /// Size of the value in bytes (for put), 0 for other operations.
125    pub size_bytes: usize,
126    /// Duration of this operation in milliseconds.
127    pub duration_ms: u64,
128    /// Whether the operation succeeded.
129    pub success: bool,
130}
131
132/// The outcome of a sandbox execution.
133#[derive(Debug, Clone, Serialize)]
134#[serde(rename_all = "snake_case")]
135#[non_exhaustive]
136pub enum AuditOutcome {
137    /// Execution completed successfully.
138    Success,
139    /// Execution failed with an error.
140    Error {
141        /// The error message.
142        message: String,
143    },
144    /// Execution was terminated due to timeout.
145    Timeout,
146}
147
148/// Trait for audit log backends.
149#[async_trait::async_trait]
150pub trait AuditLogger: Send + Sync {
151    /// Write an audit entry.
152    async fn log(&self, entry: &AuditEntry);
153}
154
155/// Writes audit entries as newline-delimited JSON to an `AsyncWrite` sink.
156pub struct JsonLinesAuditLogger<W: AsyncWrite + Unpin + Send> {
157    writer: Mutex<W>,
158}
159
160impl<W: AsyncWrite + Unpin + Send> JsonLinesAuditLogger<W> {
161    /// Create a new JSON lines audit logger writing to the given sink.
162    pub fn new(writer: W) -> Self {
163        Self {
164            writer: Mutex::new(writer),
165        }
166    }
167}
168
169#[async_trait::async_trait]
170impl<W: AsyncWrite + Unpin + Send + 'static> AuditLogger for JsonLinesAuditLogger<W> {
171    async fn log(&self, entry: &AuditEntry) {
172        let mut line = match serde_json::to_string(entry) {
173            Ok(json) => json,
174            Err(e) => {
175                tracing::warn!(error = %e, "failed to serialize audit entry");
176                return;
177            }
178        };
179        line.push('\n');
180
181        let mut writer = self.writer.lock().await;
182        if let Err(e) = writer.write_all(line.as_bytes()).await {
183            tracing::warn!(error = %e, "failed to write audit entry");
184        }
185        let _ = writer.flush().await;
186    }
187}
188
189/// Compute the SHA-256 hash of a string, returned as a hex string.
190pub fn sha256_hex(data: &str) -> String {
191    let mut hasher = Sha256::new();
192    hasher.update(data.as_bytes());
193    let result = hasher.finalize();
194    hex_encode(&result)
195}
196
197/// Encode bytes as a hex string.
198fn hex_encode(bytes: &[u8]) -> String {
199    let mut s = String::with_capacity(bytes.len() * 2);
200    for b in bytes {
201        s.push_str(&format!("{:02x}", b));
202    }
203    s
204}
205
206/// Create a code preview (first N bytes, with ellipsis if truncated).
207///
208/// Truncates at a valid UTF-8 char boundary to avoid panics on multibyte characters.
209pub fn code_preview(code: &str) -> String {
210    if code.len() <= CODE_PREVIEW_MAX {
211        code.to_string()
212    } else {
213        let mut end = CODE_PREVIEW_MAX;
214        while !code.is_char_boundary(end) {
215            end -= 1;
216        }
217        let mut preview = code[..end].to_string();
218        preview.push_str("...");
219        preview
220    }
221}
222
223/// Builder for constructing audit entries during execution.
224pub struct AuditEntryBuilder {
225    execution_id: String,
226    timestamp: DateTime<Utc>,
227    code_hash: String,
228    code_preview: String,
229    operation: AuditOperation,
230    tool_calls: Vec<ToolCallAudit>,
231    resource_reads: Vec<ResourceReadAudit>,
232    stash_operations: Vec<StashOperationAudit>,
233    start: Instant,
234    worker_reused: bool,
235    pool_size_at_acquire: Option<usize>,
236}
237
238impl AuditEntryBuilder {
239    /// Start building an audit entry for an execution.
240    pub fn new(code: &str, operation: AuditOperation) -> Self {
241        Self {
242            execution_id: Uuid::new_v4().to_string(),
243            timestamp: Utc::now(),
244            code_hash: sha256_hex(code),
245            code_preview: crate::redact::redact_error_message(&code_preview(code)),
246            operation,
247            tool_calls: Vec::new(),
248            resource_reads: Vec::new(),
249            stash_operations: Vec::new(),
250            start: Instant::now(),
251            worker_reused: false,
252            pool_size_at_acquire: None,
253        }
254    }
255
256    /// Record a tool call.
257    pub fn record_tool_call(&mut self, audit: ToolCallAudit) {
258        self.tool_calls.push(audit);
259    }
260
261    /// Record a resource read.
262    pub fn record_resource_read(&mut self, audit: ResourceReadAudit) {
263        self.resource_reads.push(audit);
264    }
265
266    /// Record a stash operation.
267    pub fn record_stash_op(&mut self, audit: StashOperationAudit) {
268        self.stash_operations.push(audit);
269    }
270
271    /// Mark that a pooled worker was reused for this execution.
272    pub fn worker_reused(&mut self, reused: bool) {
273        self.worker_reused = reused;
274    }
275
276    /// Record the pool size when the worker was acquired.
277    pub fn pool_size_at_acquire(&mut self, size: usize) {
278        self.pool_size_at_acquire = Some(size);
279    }
280
281    /// Finalize the audit entry with the execution result.
282    pub fn finish(self, result: &Result<serde_json::Value, crate::SandboxError>) -> AuditEntry {
283        let duration_ms = self.start.elapsed().as_millis() as u64;
284        let (result_size_bytes, outcome) = match result {
285            Ok(value) => {
286                let size = serde_json::to_string(value).map(|s| s.len()).unwrap_or(0);
287                (size, AuditOutcome::Success)
288            }
289            Err(crate::SandboxError::Timeout { .. }) => (0, AuditOutcome::Timeout),
290            Err(e) => (
291                0,
292                AuditOutcome::Error {
293                    message: e.to_string(),
294                },
295            ),
296        };
297
298        AuditEntry {
299            execution_id: self.execution_id,
300            timestamp: self.timestamp,
301            code_hash: self.code_hash,
302            code_preview: self.code_preview,
303            operation: self.operation,
304            tool_calls: self.tool_calls,
305            resource_reads: self.resource_reads,
306            stash_operations: self.stash_operations,
307            duration_ms,
308            result_size_bytes,
309            outcome,
310            worker_reused: self.worker_reused,
311            pool_size_at_acquire: self.pool_size_at_acquire,
312        }
313    }
314}
315
316/// A no-op audit logger for when auditing is not needed.
317pub struct NoopAuditLogger;
318
319#[async_trait::async_trait]
320impl AuditLogger for NoopAuditLogger {
321    async fn log(&self, _entry: &AuditEntry) {}
322}
323
324/// An audit logger that emits structured events via the [`tracing`] framework.
325///
326/// Audit entries are logged at `INFO` level with `audit = true` for easy
327/// filtering. The entry's tool calls, resource reads, and stash operations
328/// are summarised as counts to keep log lines concise.
329///
330/// Use `RUST_LOG=forge=info` to capture all audit events.
331pub struct TracingAuditLogger;
332
333#[async_trait::async_trait]
334impl AuditLogger for TracingAuditLogger {
335    async fn log(&self, entry: &AuditEntry) {
336        let outcome = match &entry.outcome {
337            AuditOutcome::Success => "success",
338            AuditOutcome::Error { .. } => "error",
339            AuditOutcome::Timeout => "timeout",
340        };
341        tracing::info!(
342            audit = true,
343            execution_id = %entry.execution_id,
344            operation = ?entry.operation,
345            code_hash = %entry.code_hash,
346            duration_ms = entry.duration_ms,
347            result_size_bytes = entry.result_size_bytes,
348            tool_calls = entry.tool_calls.len(),
349            resource_reads = entry.resource_reads.len(),
350            stash_ops = entry.stash_operations.len(),
351            outcome = outcome,
352            "audit"
353        );
354    }
355}
356
357/// An audit-logging wrapper around a [`ToolDispatcher`] that records tool call metrics.
358pub struct AuditingDispatcher {
359    inner: Arc<dyn crate::ToolDispatcher>,
360    audit_tx: tokio::sync::mpsc::UnboundedSender<ToolCallAudit>,
361}
362
363impl AuditingDispatcher {
364    /// Wrap a dispatcher with audit recording.
365    pub fn new(
366        inner: Arc<dyn crate::ToolDispatcher>,
367        audit_tx: tokio::sync::mpsc::UnboundedSender<ToolCallAudit>,
368    ) -> Self {
369        Self { inner, audit_tx }
370    }
371}
372
373#[async_trait::async_trait]
374impl crate::ToolDispatcher for AuditingDispatcher {
375    async fn call_tool(
376        &self,
377        server: &str,
378        tool: &str,
379        args: serde_json::Value,
380    ) -> Result<serde_json::Value, forge_error::DispatchError> {
381        let args_hash = sha256_hex(&serde_json::to_string(&args).unwrap_or_default());
382        let start = Instant::now();
383
384        let result = self.inner.call_tool(server, tool, args).await;
385
386        let audit = ToolCallAudit {
387            server: server.to_string(),
388            tool: tool.to_string(),
389            args_hash,
390            duration_ms: start.elapsed().as_millis() as u64,
391            success: result.is_ok(),
392        };
393        let _ = self.audit_tx.send(audit);
394
395        result
396    }
397}
398
399/// An audit-logging wrapper around a [`ResourceDispatcher`] that records resource read metrics.
400pub struct AuditingResourceDispatcher {
401    inner: Arc<dyn crate::ResourceDispatcher>,
402    audit_tx: tokio::sync::mpsc::UnboundedSender<ResourceReadAudit>,
403}
404
405impl AuditingResourceDispatcher {
406    /// Wrap a resource dispatcher with audit recording.
407    pub fn new(
408        inner: Arc<dyn crate::ResourceDispatcher>,
409        audit_tx: tokio::sync::mpsc::UnboundedSender<ResourceReadAudit>,
410    ) -> Self {
411        Self { inner, audit_tx }
412    }
413}
414
415#[async_trait::async_trait]
416impl crate::ResourceDispatcher for AuditingResourceDispatcher {
417    async fn read_resource(
418        &self,
419        server: &str,
420        uri: &str,
421    ) -> Result<serde_json::Value, forge_error::DispatchError> {
422        let uri_hash = sha256_hex(uri);
423        let start = Instant::now();
424
425        let result = self.inner.read_resource(server, uri).await;
426
427        let size_bytes = result
428            .as_ref()
429            .ok()
430            .and_then(|v| serde_json::to_string(v).ok())
431            .map(|s| s.len())
432            .unwrap_or(0);
433
434        let audit = ResourceReadAudit {
435            server: server.to_string(),
436            uri_hash,
437            size_bytes,
438            duration_ms: start.elapsed().as_millis() as u64,
439            success: result.is_ok(),
440        };
441        let _ = self.audit_tx.send(audit);
442
443        result
444    }
445}
446
447/// An audit-logging wrapper around a [`StashDispatcher`] that records stash operation metrics.
448///
449/// Per SR-ST9: logs key name and value size, never the value content itself.
450pub struct AuditingStashDispatcher {
451    inner: Arc<dyn crate::StashDispatcher>,
452    audit_tx: tokio::sync::mpsc::UnboundedSender<StashOperationAudit>,
453}
454
455impl AuditingStashDispatcher {
456    /// Wrap a stash dispatcher with audit recording.
457    pub fn new(
458        inner: Arc<dyn crate::StashDispatcher>,
459        audit_tx: tokio::sync::mpsc::UnboundedSender<StashOperationAudit>,
460    ) -> Self {
461        Self { inner, audit_tx }
462    }
463}
464
465#[async_trait::async_trait]
466impl crate::StashDispatcher for AuditingStashDispatcher {
467    async fn put(
468        &self,
469        key: &str,
470        value: serde_json::Value,
471        ttl_secs: Option<u32>,
472        current_group: Option<String>,
473    ) -> Result<serde_json::Value, forge_error::DispatchError> {
474        let size_bytes = serde_json::to_string(&value).map(|s| s.len()).unwrap_or(0);
475        let start = Instant::now();
476
477        let result = self.inner.put(key, value, ttl_secs, current_group).await;
478
479        let audit = StashOperationAudit {
480            op_type: StashOpType::Put,
481            key: key.to_string(),
482            size_bytes,
483            duration_ms: start.elapsed().as_millis() as u64,
484            success: result.is_ok(),
485        };
486        let _ = self.audit_tx.send(audit);
487
488        result
489    }
490
491    async fn get(
492        &self,
493        key: &str,
494        current_group: Option<String>,
495    ) -> Result<serde_json::Value, forge_error::DispatchError> {
496        let start = Instant::now();
497
498        let result = self.inner.get(key, current_group).await;
499
500        let audit = StashOperationAudit {
501            op_type: StashOpType::Get,
502            key: key.to_string(),
503            size_bytes: 0,
504            duration_ms: start.elapsed().as_millis() as u64,
505            success: result.is_ok(),
506        };
507        let _ = self.audit_tx.send(audit);
508
509        result
510    }
511
512    async fn delete(
513        &self,
514        key: &str,
515        current_group: Option<String>,
516    ) -> Result<serde_json::Value, forge_error::DispatchError> {
517        let start = Instant::now();
518
519        let result = self.inner.delete(key, current_group).await;
520
521        let audit = StashOperationAudit {
522            op_type: StashOpType::Delete,
523            key: key.to_string(),
524            size_bytes: 0,
525            duration_ms: start.elapsed().as_millis() as u64,
526            success: result.is_ok(),
527        };
528        let _ = self.audit_tx.send(audit);
529
530        result
531    }
532
533    async fn keys(
534        &self,
535        current_group: Option<String>,
536    ) -> Result<serde_json::Value, forge_error::DispatchError> {
537        let start = Instant::now();
538
539        let result = self.inner.keys(current_group).await;
540
541        let audit = StashOperationAudit {
542            op_type: StashOpType::Keys,
543            key: String::new(),
544            size_bytes: 0,
545            duration_ms: start.elapsed().as_millis() as u64,
546            success: result.is_ok(),
547        };
548        let _ = self.audit_tx.send(audit);
549
550        result
551    }
552}
553
554#[cfg(test)]
555mod tests {
556    use super::*;
557    use crate::StashDispatcher;
558
559    #[test]
560    fn sha256_hex_produces_correct_hash() {
561        // Known SHA-256 of "hello"
562        let hash = sha256_hex("hello");
563        assert_eq!(
564            hash,
565            "2cf24dba5fb0a30e26e83b2ac5b9e29e1b161e5c1fa7425e73043362938b9824"
566        );
567    }
568
569    #[test]
570    fn code_preview_short_code_unchanged() {
571        let code = "async () => { return 42; }";
572        assert_eq!(code_preview(code), code);
573    }
574
575    #[test]
576    fn code_preview_long_code_truncated() {
577        let code = "x".repeat(1000);
578        let preview = code_preview(&code);
579        assert_eq!(preview.len(), 503); // 500 + "..."
580        assert!(preview.ends_with("..."));
581    }
582
583    #[test]
584    fn code_preview_multibyte_emoji_boundary() {
585        // 499 ASCII bytes + U+1F600 (4 bytes) = 503 total, crosses the 500 boundary
586        let mut code = "a".repeat(499);
587        code.push('\u{1F600}'); // 😀 — 4 bytes
588        code.push_str(&"b".repeat(100));
589        let preview = code_preview(&code);
590        assert!(preview.ends_with("..."));
591        // Should truncate before the emoji since byte 500 is mid-char
592        assert!(preview.starts_with(&"a".repeat(499)));
593    }
594
595    #[test]
596    fn code_preview_all_emoji() {
597        // 200 × U+1F600 (4 bytes each) = 800 bytes
598        let code: String = "\u{1F600}".repeat(200);
599        let preview = code_preview(&code);
600        assert!(preview.ends_with("..."));
601        // Verify valid UTF-8 (would panic on invalid)
602        let _ = preview.chars().count();
603    }
604
605    #[test]
606    fn code_preview_exact_500_ascii() {
607        let code = "a".repeat(500);
608        let preview = code_preview(&code);
609        assert_eq!(preview, code); // no truncation, no "..."
610    }
611
612    #[test]
613    fn code_preview_cjk_boundary() {
614        // CJK chars are 3 bytes each: 167 × 3 = 501 bytes, crosses 500
615        let code: String = "\u{4E00}".repeat(200); // 600 bytes
616        let preview = code_preview(&code);
617        assert!(preview.ends_with("..."));
618        // Verify valid UTF-8
619        let _ = preview.chars().count();
620    }
621
622    #[test]
623    fn audit_entry_builder_success() {
624        let code = "async () => { return 1; }";
625        let builder = AuditEntryBuilder::new(code, AuditOperation::Execute);
626        let result: Result<serde_json::Value, crate::SandboxError> = Ok(serde_json::json!(1));
627        let entry = builder.finish(&result);
628
629        assert!(!entry.execution_id.is_empty());
630        assert_eq!(entry.code_preview, code);
631        assert!(matches!(entry.outcome, AuditOutcome::Success));
632        assert_eq!(entry.result_size_bytes, 1); // "1" = 1 byte
633    }
634
635    #[test]
636    fn audit_entry_builder_error() {
637        let code = "async () => { throw new Error('test'); }";
638        let builder = AuditEntryBuilder::new(code, AuditOperation::Search);
639        let result: Result<serde_json::Value, crate::SandboxError> =
640            Err(crate::SandboxError::JsError {
641                message: "test error".into(),
642            });
643        let entry = builder.finish(&result);
644
645        assert!(matches!(entry.outcome, AuditOutcome::Error { .. }));
646        if let AuditOutcome::Error { message } = &entry.outcome {
647            assert!(message.contains("test error"));
648        }
649    }
650
651    #[test]
652    fn audit_entry_builder_timeout() {
653        let code = "async () => { while(true) {} }";
654        let builder = AuditEntryBuilder::new(code, AuditOperation::Execute);
655        let result: Result<serde_json::Value, crate::SandboxError> =
656            Err(crate::SandboxError::Timeout { timeout_ms: 5000 });
657        let entry = builder.finish(&result);
658
659        assert!(matches!(entry.outcome, AuditOutcome::Timeout));
660    }
661
662    #[tokio::test]
663    async fn json_lines_logger_writes_valid_json() {
664        let buf: Vec<u8> = Vec::new();
665        let logger = JsonLinesAuditLogger::new(buf);
666
667        let entry = AuditEntry {
668            execution_id: "test-id".into(),
669            timestamp: Utc::now(),
670            code_hash: "abc123".into(),
671            code_preview: "async () => {}".into(),
672            operation: AuditOperation::Execute,
673            tool_calls: vec![],
674            resource_reads: vec![],
675            stash_operations: vec![],
676            duration_ms: 42,
677            result_size_bytes: 10,
678            outcome: AuditOutcome::Success,
679            worker_reused: false,
680            pool_size_at_acquire: None,
681        };
682
683        logger.log(&entry).await;
684
685        let writer = logger.writer.lock().await;
686        let output = String::from_utf8(writer.clone()).unwrap();
687        assert!(output.ends_with('\n'));
688
689        let parsed: serde_json::Value = serde_json::from_str(output.trim()).unwrap();
690        assert_eq!(parsed["execution_id"], "test-id");
691        assert_eq!(parsed["duration_ms"], 42);
692        assert_eq!(parsed["outcome"], "success");
693    }
694
695    #[tokio::test]
696    async fn json_lines_logger_with_tool_calls() {
697        let buf: Vec<u8> = Vec::new();
698        let logger = JsonLinesAuditLogger::new(buf);
699
700        let entry = AuditEntry {
701            execution_id: "test-id-2".into(),
702            timestamp: Utc::now(),
703            code_hash: "def456".into(),
704            code_preview: "async () => { await forge.callTool(...); }".into(),
705            operation: AuditOperation::Execute,
706            tool_calls: vec![
707                ToolCallAudit {
708                    server: "narsil".into(),
709                    tool: "ast.parse".into(),
710                    args_hash: "hash1".into(),
711                    duration_ms: 10,
712                    success: true,
713                },
714                ToolCallAudit {
715                    server: "github".into(),
716                    tool: "issues.list".into(),
717                    args_hash: "hash2".into(),
718                    duration_ms: 25,
719                    success: false,
720                },
721            ],
722            resource_reads: vec![],
723            stash_operations: vec![],
724            duration_ms: 100,
725            result_size_bytes: 500,
726            outcome: AuditOutcome::Success,
727            worker_reused: false,
728            pool_size_at_acquire: None,
729        };
730
731        logger.log(&entry).await;
732
733        let writer = logger.writer.lock().await;
734        let output = String::from_utf8(writer.clone()).unwrap();
735        let parsed: serde_json::Value = serde_json::from_str(output.trim()).unwrap();
736        let calls = parsed["tool_calls"].as_array().unwrap();
737        assert_eq!(calls.len(), 2);
738        assert_eq!(calls[0]["server"], "narsil");
739        assert_eq!(calls[1]["success"], false);
740    }
741
742    #[test]
743    fn audit_entry_serializes_no_raw_credentials() {
744        let entry = AuditEntry {
745            execution_id: "id".into(),
746            timestamp: Utc::now(),
747            code_hash: "hash".into(),
748            code_preview: "preview".into(),
749            operation: AuditOperation::Execute,
750            tool_calls: vec![ToolCallAudit {
751                server: "s".into(),
752                tool: "t".into(),
753                args_hash: "args_are_hashed".into(),
754                duration_ms: 1,
755                success: true,
756            }],
757            resource_reads: vec![],
758            stash_operations: vec![],
759            duration_ms: 1,
760            result_size_bytes: 0,
761            outcome: AuditOutcome::Success,
762            worker_reused: false,
763            pool_size_at_acquire: None,
764        };
765
766        let json = serde_json::to_string(&entry).unwrap();
767        // Verify that the JSON contains "args_hash" field, not "args"
768        assert!(json.contains("args_hash"));
769        assert!(!json.contains("\"args\""));
770    }
771
772    #[test]
773    fn stash_operations_omitted_when_empty() {
774        let entry = AuditEntry {
775            execution_id: "id".into(),
776            timestamp: Utc::now(),
777            code_hash: "hash".into(),
778            code_preview: "preview".into(),
779            operation: AuditOperation::Execute,
780            tool_calls: vec![],
781            resource_reads: vec![],
782            stash_operations: vec![],
783            duration_ms: 1,
784            result_size_bytes: 0,
785            outcome: AuditOutcome::Success,
786            worker_reused: false,
787            pool_size_at_acquire: None,
788        };
789        let json = serde_json::to_string(&entry).unwrap();
790        assert!(
791            !json.contains("stash_operations"),
792            "stash_operations should be omitted when empty"
793        );
794    }
795
796    #[test]
797    fn stash_operations_included_when_present() {
798        let entry = AuditEntry {
799            execution_id: "id".into(),
800            timestamp: Utc::now(),
801            code_hash: "hash".into(),
802            code_preview: "preview".into(),
803            operation: AuditOperation::Execute,
804            tool_calls: vec![],
805            resource_reads: vec![],
806            stash_operations: vec![StashOperationAudit {
807                op_type: StashOpType::Put,
808                key: "mykey".into(),
809                size_bytes: 42,
810                duration_ms: 1,
811                success: true,
812            }],
813            duration_ms: 1,
814            result_size_bytes: 0,
815            outcome: AuditOutcome::Success,
816            worker_reused: false,
817            pool_size_at_acquire: None,
818        };
819        let json = serde_json::to_string(&entry).unwrap();
820        assert!(json.contains("stash_operations"));
821        assert!(json.contains("mykey"));
822        assert!(json.contains("\"size_bytes\":42"));
823        // Value content must NOT appear in audit
824        assert!(!json.contains("\"value\""));
825    }
826
827    #[tokio::test]
828    async fn auditing_stash_dispatcher_records_operations() {
829        use tokio::sync::mpsc;
830
831        /// Minimal stash dispatcher that records nothing.
832        struct NoopStash;
833
834        #[async_trait::async_trait]
835        impl crate::StashDispatcher for NoopStash {
836            async fn put(
837                &self,
838                _key: &str,
839                _value: serde_json::Value,
840                _ttl_secs: Option<u32>,
841                _current_group: Option<String>,
842            ) -> Result<serde_json::Value, forge_error::DispatchError> {
843                Ok(serde_json::json!({"ok": true}))
844            }
845            async fn get(
846                &self,
847                _key: &str,
848                _current_group: Option<String>,
849            ) -> Result<serde_json::Value, forge_error::DispatchError> {
850                Ok(serde_json::Value::Null)
851            }
852            async fn delete(
853                &self,
854                _key: &str,
855                _current_group: Option<String>,
856            ) -> Result<serde_json::Value, forge_error::DispatchError> {
857                Ok(serde_json::json!({"deleted": false}))
858            }
859            async fn keys(
860                &self,
861                _current_group: Option<String>,
862            ) -> Result<serde_json::Value, forge_error::DispatchError> {
863                Ok(serde_json::json!([]))
864            }
865        }
866
867        let (tx, mut rx) = mpsc::unbounded_channel();
868        let dispatcher = AuditingStashDispatcher::new(Arc::new(NoopStash), tx);
869
870        // Exercise all four operations
871        dispatcher
872            .put("k1", serde_json::json!("hello"), None, None)
873            .await
874            .unwrap();
875        dispatcher.get("k1", None).await.unwrap();
876        dispatcher.delete("k1", None).await.unwrap();
877        dispatcher.keys(None).await.unwrap();
878
879        let mut audits = Vec::new();
880        while let Ok(a) = rx.try_recv() {
881            audits.push(a);
882        }
883
884        assert_eq!(audits.len(), 4, "should have 4 audit entries");
885        assert!(matches!(audits[0].op_type, StashOpType::Put));
886        assert_eq!(audits[0].key, "k1");
887        assert!(audits[0].size_bytes > 0, "put should record value size");
888        assert!(matches!(audits[1].op_type, StashOpType::Get));
889        assert!(matches!(audits[2].op_type, StashOpType::Delete));
890        assert!(matches!(audits[3].op_type, StashOpType::Keys));
891        assert_eq!(audits[3].key, "", "keys op should have empty key");
892        assert!(audits.iter().all(|a| a.success));
893    }
894
895    // --- Phase 7: TracingAuditLogger tests ---
896
897    #[tokio::test]
898    async fn ob_01_tracing_audit_logger_does_not_panic() {
899        // TracingAuditLogger should handle any valid AuditEntry without panic.
900        // We can't easily capture tracing output in tests, but we verify no panic.
901        let logger = TracingAuditLogger;
902        let entry = AuditEntry {
903            execution_id: "trace-test".into(),
904            timestamp: Utc::now(),
905            code_hash: "abc".into(),
906            code_preview: "async () => {}".into(),
907            operation: AuditOperation::Execute,
908            tool_calls: vec![ToolCallAudit {
909                server: "s".into(),
910                tool: "t".into(),
911                args_hash: "h".into(),
912                duration_ms: 5,
913                success: true,
914            }],
915            resource_reads: vec![],
916            stash_operations: vec![],
917            duration_ms: 10,
918            result_size_bytes: 100,
919            outcome: AuditOutcome::Success,
920            worker_reused: false,
921            pool_size_at_acquire: None,
922        };
923        logger.log(&entry).await;
924    }
925
926    #[tokio::test]
927    async fn ob_02_tracing_audit_logger_handles_error_outcome() {
928        let logger = TracingAuditLogger;
929        let entry = AuditEntry {
930            execution_id: "err-test".into(),
931            timestamp: Utc::now(),
932            code_hash: "def".into(),
933            code_preview: "async () => { throw new Error('x'); }".into(),
934            operation: AuditOperation::Execute,
935            tool_calls: vec![],
936            resource_reads: vec![],
937            stash_operations: vec![],
938            duration_ms: 3,
939            result_size_bytes: 0,
940            outcome: AuditOutcome::Error {
941                message: "test error".into(),
942            },
943            worker_reused: false,
944            pool_size_at_acquire: None,
945        };
946        logger.log(&entry).await;
947    }
948
949    #[tokio::test]
950    async fn ob_03_tracing_audit_logger_handles_timeout_outcome() {
951        let logger = TracingAuditLogger;
952        let entry = AuditEntry {
953            execution_id: "timeout-test".into(),
954            timestamp: Utc::now(),
955            code_hash: "ghi".into(),
956            code_preview: "async () => { while(true) {} }".into(),
957            operation: AuditOperation::Search,
958            tool_calls: vec![],
959            resource_reads: vec![],
960            stash_operations: vec![],
961            duration_ms: 5000,
962            result_size_bytes: 0,
963            outcome: AuditOutcome::Timeout,
964            worker_reused: false,
965            pool_size_at_acquire: None,
966        };
967        logger.log(&entry).await;
968    }
969
970    #[tokio::test]
971    async fn ob_04_audit_entry_never_contains_raw_code() {
972        // Security: the audit entry must never contain the raw submitted code.
973        // It should only store a SHA-256 hash and a truncated preview.
974        let secret_code = "async () => { const API_KEY = 'sk-secret-12345'; return API_KEY; }";
975        let builder = AuditEntryBuilder::new(secret_code, AuditOperation::Execute);
976        let entry = builder.finish(&Ok(serde_json::json!("ok")));
977
978        // The serialized entry should not have a raw "code" field — only code_hash and code_preview.
979        let json = serde_json::to_string(&entry).expect("serialize");
980        let parsed: serde_json::Value = serde_json::from_str(&json).expect("parse");
981        assert!(
982            parsed.get("code").is_none(),
983            "serialized entry must not have a raw 'code' field"
984        );
985        assert!(
986            parsed.get("code_hash").is_some(),
987            "serialized entry must include code_hash"
988        );
989        // code_preview IS included (it's the first 500 chars) — that's by design
990        // But the full code should not appear as a separate field
991        assert_eq!(entry.code_hash, sha256_hex(secret_code));
992        assert!(!entry.code_hash.contains("sk-secret"));
993        // Verify the hash is a valid 64-char hex string (SHA-256)
994        assert_eq!(entry.code_hash.len(), 64);
995        assert!(entry.code_hash.chars().all(|c| c.is_ascii_hexdigit()));
996    }
997
998    #[tokio::test]
999    async fn ob_05_audit_entry_code_preview_truncated() {
1000        let long_code = "x".repeat(1000);
1001        let builder = AuditEntryBuilder::new(&long_code, AuditOperation::Execute);
1002        let entry = builder.finish(&Ok(serde_json::json!(null)));
1003
1004        // Preview should be truncated + "..."
1005        assert!(entry.code_preview.len() <= CODE_PREVIEW_MAX + 3); // +3 for "..."
1006        assert!(entry.code_preview.ends_with("..."));
1007    }
1008
1009    #[tokio::test]
1010    async fn ob_06_audit_entry_serializes_all_fields() {
1011        // Verify the full audit entry serializes correctly with all field types populated.
1012        let entry = AuditEntry {
1013            execution_id: "test-id".into(),
1014            timestamp: Utc::now(),
1015            code_hash: sha256_hex("code"),
1016            code_preview: "code".into(),
1017            operation: AuditOperation::Execute,
1018            tool_calls: vec![ToolCallAudit {
1019                server: "srv".into(),
1020                tool: "t".into(),
1021                args_hash: "h".into(),
1022                duration_ms: 1,
1023                success: true,
1024            }],
1025            resource_reads: vec![ResourceReadAudit {
1026                server: "srv".into(),
1027                uri_hash: "uri_h".into(),
1028                size_bytes: 1024,
1029                duration_ms: 2,
1030                success: true,
1031            }],
1032            stash_operations: vec![StashOperationAudit {
1033                op_type: StashOpType::Put,
1034                key: "k".into(),
1035                size_bytes: 100,
1036                duration_ms: 1,
1037                success: true,
1038            }],
1039            duration_ms: 50,
1040            result_size_bytes: 200,
1041            outcome: AuditOutcome::Success,
1042            worker_reused: false,
1043            pool_size_at_acquire: None,
1044        };
1045
1046        let json = serde_json::to_string(&entry).expect("serialize");
1047        let parsed: serde_json::Value = serde_json::from_str(&json).expect("parse");
1048
1049        assert_eq!(parsed["execution_id"], "test-id");
1050        assert_eq!(parsed["tool_calls"][0]["server"], "srv");
1051        assert_eq!(parsed["resource_reads"][0]["size_bytes"], 1024);
1052        assert_eq!(parsed["stash_operations"][0]["op_type"], "put");
1053        assert_eq!(parsed["outcome"], "success");
1054    }
1055
1056    #[tokio::test]
1057    async fn ob_07_tracing_audit_logger_with_all_fields() {
1058        // TracingAuditLogger should handle entries with tool_calls, resource_reads,
1059        // and stash_operations without panic, summarised as counts.
1060        let logger = TracingAuditLogger;
1061        let entry = AuditEntry {
1062            execution_id: "full-test".into(),
1063            timestamp: Utc::now(),
1064            code_hash: sha256_hex("test"),
1065            code_preview: "test".into(),
1066            operation: AuditOperation::Execute,
1067            tool_calls: vec![
1068                ToolCallAudit {
1069                    server: "s1".into(),
1070                    tool: "t1".into(),
1071                    args_hash: "h1".into(),
1072                    duration_ms: 5,
1073                    success: true,
1074                },
1075                ToolCallAudit {
1076                    server: "s2".into(),
1077                    tool: "t2".into(),
1078                    args_hash: "h2".into(),
1079                    duration_ms: 10,
1080                    success: false,
1081                },
1082            ],
1083            resource_reads: vec![ResourceReadAudit {
1084                server: "s1".into(),
1085                uri_hash: "uh".into(),
1086                size_bytes: 512,
1087                duration_ms: 3,
1088                success: true,
1089            }],
1090            stash_operations: vec![
1091                StashOperationAudit {
1092                    op_type: StashOpType::Put,
1093                    key: "k1".into(),
1094                    size_bytes: 50,
1095                    duration_ms: 1,
1096                    success: true,
1097                },
1098                StashOperationAudit {
1099                    op_type: StashOpType::Get,
1100                    key: "k1".into(),
1101                    size_bytes: 0,
1102                    duration_ms: 1,
1103                    success: true,
1104                },
1105            ],
1106            duration_ms: 100,
1107            result_size_bytes: 500,
1108            outcome: AuditOutcome::Success,
1109            worker_reused: false,
1110            pool_size_at_acquire: None,
1111        };
1112        // Should not panic with multiple tool_calls, resource_reads, stash_ops
1113        logger.log(&entry).await;
1114    }
1115
1116    #[tokio::test]
1117    async fn ob_08_audit_entry_builder_execution_id_is_uuid() {
1118        let builder = AuditEntryBuilder::new("code", AuditOperation::Execute);
1119        let entry = builder.finish(&Ok(serde_json::json!(null)));
1120        // Execution ID should be a valid UUID v4
1121        assert!(
1122            uuid::Uuid::parse_str(&entry.execution_id).is_ok(),
1123            "execution_id should be a valid UUID: {}",
1124            entry.execution_id
1125        );
1126    }
1127
1128    #[tokio::test]
1129    async fn ob_09_audit_outcome_error_redaction() {
1130        // Error messages in audit should not contain raw internal paths or stack traces
1131        // beyond what the error itself provides. Verify the mapping works correctly.
1132        let err = crate::SandboxError::Timeout { timeout_ms: 5000 };
1133        let builder = AuditEntryBuilder::new("code", AuditOperation::Execute);
1134        let entry = builder.finish(&Err(err));
1135        assert!(matches!(entry.outcome, AuditOutcome::Timeout));
1136
1137        let err2 = crate::SandboxError::JsError {
1138            message: "ReferenceError: x is not defined".into(),
1139        };
1140        let builder2 = AuditEntryBuilder::new("code", AuditOperation::Execute);
1141        let entry2 = builder2.finish(&Err(err2));
1142        match &entry2.outcome {
1143            AuditOutcome::Error { message } => {
1144                assert!(message.contains("ReferenceError"));
1145            }
1146            other => panic!("expected Error outcome, got {:?}", other),
1147        }
1148    }
1149
1150    // --- Phase R6: AuditEntry new fields ---
1151
1152    #[tokio::test]
1153    async fn ae_01_audit_entry_worker_reused_defaults_false() {
1154        let builder = AuditEntryBuilder::new("code", AuditOperation::Execute);
1155        let entry = builder.finish(&Ok(serde_json::json!(null)));
1156        assert!(!entry.worker_reused);
1157    }
1158
1159    #[tokio::test]
1160    async fn ae_02_audit_entry_pool_size_defaults_none() {
1161        let builder = AuditEntryBuilder::new("code", AuditOperation::Execute);
1162        let entry = builder.finish(&Ok(serde_json::json!(null)));
1163        assert!(entry.pool_size_at_acquire.is_none());
1164    }
1165
1166    #[tokio::test]
1167    async fn ae_03_builder_sets_worker_reused() {
1168        let mut builder = AuditEntryBuilder::new("code", AuditOperation::Execute);
1169        builder.worker_reused(true);
1170        let entry = builder.finish(&Ok(serde_json::json!(null)));
1171        assert!(entry.worker_reused);
1172    }
1173
1174    #[tokio::test]
1175    async fn ae_04_builder_sets_pool_size() {
1176        let mut builder = AuditEntryBuilder::new("code", AuditOperation::Execute);
1177        builder.pool_size_at_acquire(4);
1178        let entry = builder.finish(&Ok(serde_json::json!(null)));
1179        assert_eq!(entry.pool_size_at_acquire, Some(4));
1180    }
1181
1182    #[tokio::test]
1183    async fn ae_05_new_fields_serialize_correctly() {
1184        let mut builder = AuditEntryBuilder::new("code", AuditOperation::Execute);
1185        builder.worker_reused(true);
1186        builder.pool_size_at_acquire(3);
1187        let entry = builder.finish(&Ok(serde_json::json!(null)));
1188
1189        let json = serde_json::to_string(&entry).expect("serialize");
1190        let parsed: serde_json::Value = serde_json::from_str(&json).expect("parse");
1191        assert_eq!(parsed["worker_reused"], true);
1192        assert_eq!(parsed["pool_size_at_acquire"], 3);
1193
1194        // When defaults: worker_reused should be skipped, pool_size_at_acquire should be skipped
1195        let builder2 = AuditEntryBuilder::new("code", AuditOperation::Execute);
1196        let entry2 = builder2.finish(&Ok(serde_json::json!(null)));
1197        let json2 = serde_json::to_string(&entry2).expect("serialize");
1198        let parsed2: serde_json::Value = serde_json::from_str(&json2).expect("parse");
1199        assert!(
1200            parsed2.get("worker_reused").is_none(),
1201            "worker_reused=false should be skipped"
1202        );
1203        assert!(
1204            parsed2.get("pool_size_at_acquire").is_none(),
1205            "pool_size_at_acquire=None should be skipped"
1206        );
1207    }
1208
1209    // --- Phase 7 Gap #16: Audit code_preview redaction ---
1210
1211    #[test]
1212    fn audit_l2_01_code_preview_redacts_api_keys() {
1213        // API keys in code_preview must be redacted before storage
1214        let code = "async () => { const key = 'Bearer sk-1234567890abcdef'; return key; }";
1215        let builder = AuditEntryBuilder::new(code, AuditOperation::Execute);
1216        let entry = builder.finish(&Ok(serde_json::json!("ok")));
1217
1218        // The code_preview should have been redacted
1219        assert!(
1220            !entry.code_preview.contains("sk-1234567890abcdef"),
1221            "code_preview should not contain raw API key: {}",
1222            entry.code_preview
1223        );
1224        assert!(
1225            entry.code_preview.contains("[REDACTED]"),
1226            "code_preview should contain redaction marker: {}",
1227            entry.code_preview
1228        );
1229    }
1230
1231    #[test]
1232    fn audit_l2_02_code_preview_preserves_safe_code() {
1233        // Safe code without credentials should pass through unchanged
1234        let code = "async () => { return 42; }";
1235        let builder = AuditEntryBuilder::new(code, AuditOperation::Execute);
1236        let entry = builder.finish(&Ok(serde_json::json!(42)));
1237
1238        assert_eq!(
1239            entry.code_preview, code,
1240            "safe code_preview should be unchanged"
1241        );
1242    }
1243}