huskies: merge 839
This commit is contained in:
dave
@@ -0,0 +1,482 @@
|
||||
//! Tests for the agent_log module.
|
||||
use super::*;
|
||||
use crate::agents::AgentEvent;
|
||||
use tempfile::tempdir;
|
||||
|
||||
#[test]
|
||||
fn test_log_writer_creates_directory_and_file() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let root = tmp.path();
|
||||
|
||||
let _writer = AgentLogWriter::new(root, "42_story_foo", "coder-1", "sess-abc123").unwrap();
|
||||
|
||||
let expected_path = root
|
||||
.join(".huskies")
|
||||
.join("logs")
|
||||
.join("42_story_foo")
|
||||
.join("coder-1-sess-abc123.log");
|
||||
assert!(expected_path.exists(), "Log file should exist");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn numeric_id_log_dir_uses_number_only() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let root = tmp.path();
|
||||
|
||||
let _writer = AgentLogWriter::new(root, "664", "coder-1", "sess-xyz").unwrap();
|
||||
|
||||
let expected_path = root
|
||||
.join(".huskies")
|
||||
.join("logs")
|
||||
.join("664")
|
||||
.join("coder-1-sess-xyz.log");
|
||||
assert!(
|
||||
expected_path.exists(),
|
||||
"Log file for numeric ID should be at .huskies/logs/664/..."
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_log_writer_writes_jsonl_with_timestamps() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let root = tmp.path();
|
||||
|
||||
let mut writer = AgentLogWriter::new(root, "42_story_foo", "coder-1", "sess-001").unwrap();
|
||||
|
||||
let event = AgentEvent::Status {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
status: "running".to_string(),
|
||||
};
|
||||
writer.write_event(&event).unwrap();
|
||||
|
||||
let event2 = AgentEvent::Output {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
text: "Hello world".to_string(),
|
||||
};
|
||||
writer.write_event(&event2).unwrap();
|
||||
|
||||
// Read the file and verify
|
||||
let path = log_file_path(root, "42_story_foo", "coder-1", "sess-001");
|
||||
let content = std::fs::read_to_string(&path).unwrap();
|
||||
let lines: Vec<&str> = content.lines().collect();
|
||||
assert_eq!(lines.len(), 2, "Should have 2 log lines");
|
||||
|
||||
// Parse each line as valid JSON with a timestamp
|
||||
for line in &lines {
|
||||
let entry: LogEntry = serde_json::from_str(line).unwrap();
|
||||
assert!(!entry.timestamp.is_empty(), "Timestamp should be present");
|
||||
// Verify it's a valid ISO 8601 timestamp
|
||||
chrono::DateTime::parse_from_rfc3339(&entry.timestamp)
|
||||
.expect("Timestamp should be valid RFC3339");
|
||||
}
|
||||
|
||||
// Verify the first entry is a status event
|
||||
let entry1: LogEntry = serde_json::from_str(lines[0]).unwrap();
|
||||
assert_eq!(entry1.event["type"], "status");
|
||||
assert_eq!(entry1.event["status"], "running");
|
||||
|
||||
// Verify the second entry is an output event
|
||||
let entry2: LogEntry = serde_json::from_str(lines[1]).unwrap();
|
||||
assert_eq!(entry2.event["type"], "output");
|
||||
assert_eq!(entry2.event["text"], "Hello world");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_read_log_parses_written_events() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let root = tmp.path();
|
||||
|
||||
let mut writer = AgentLogWriter::new(root, "42_story_foo", "coder-1", "sess-002").unwrap();
|
||||
|
||||
let events = vec![
|
||||
AgentEvent::Status {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
status: "running".to_string(),
|
||||
},
|
||||
AgentEvent::Output {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
text: "Processing...".to_string(),
|
||||
},
|
||||
AgentEvent::AgentJson {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
data: serde_json::json!({"type": "tool_use", "name": "read_file"}),
|
||||
},
|
||||
AgentEvent::Done {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
session_id: Some("sess-002".to_string()),
|
||||
},
|
||||
];
|
||||
|
||||
for event in &events {
|
||||
writer.write_event(event).unwrap();
|
||||
}
|
||||
|
||||
let path = log_file_path(root, "42_story_foo", "coder-1", "sess-002");
|
||||
let entries = read_log(&path).unwrap();
|
||||
assert_eq!(entries.len(), 4, "Should read back all 4 events");
|
||||
|
||||
// Verify event types round-trip correctly
|
||||
assert_eq!(entries[0].event["type"], "status");
|
||||
assert_eq!(entries[1].event["type"], "output");
|
||||
assert_eq!(entries[2].event["type"], "agent_json");
|
||||
assert_eq!(entries[3].event["type"], "done");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_separate_sessions_produce_separate_files() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let root = tmp.path();
|
||||
|
||||
let mut writer1 = AgentLogWriter::new(root, "42_story_foo", "coder-1", "sess-aaa").unwrap();
|
||||
let mut writer2 = AgentLogWriter::new(root, "42_story_foo", "coder-1", "sess-bbb").unwrap();
|
||||
|
||||
writer1
|
||||
.write_event(&AgentEvent::Output {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
text: "from session aaa".to_string(),
|
||||
})
|
||||
.unwrap();
|
||||
|
||||
writer2
|
||||
.write_event(&AgentEvent::Output {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
text: "from session bbb".to_string(),
|
||||
})
|
||||
.unwrap();
|
||||
|
||||
let path1 = log_file_path(root, "42_story_foo", "coder-1", "sess-aaa");
|
||||
let path2 = log_file_path(root, "42_story_foo", "coder-1", "sess-bbb");
|
||||
|
||||
assert_ne!(
|
||||
path1, path2,
|
||||
"Different sessions should use different files"
|
||||
);
|
||||
|
||||
let entries1 = read_log(&path1).unwrap();
|
||||
let entries2 = read_log(&path2).unwrap();
|
||||
|
||||
assert_eq!(entries1.len(), 1);
|
||||
assert_eq!(entries2.len(), 1);
|
||||
assert_eq!(entries1[0].event["text"], "from session aaa");
|
||||
assert_eq!(entries2[0].event["text"], "from session bbb");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_find_latest_log_returns_most_recent() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let root = tmp.path();
|
||||
|
||||
// Create two log files with a small delay
|
||||
let mut writer1 = AgentLogWriter::new(root, "42_story_foo", "coder-1", "sess-old").unwrap();
|
||||
writer1
|
||||
.write_event(&AgentEvent::Output {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
text: "old".to_string(),
|
||||
})
|
||||
.unwrap();
|
||||
drop(writer1);
|
||||
|
||||
// Touch the second file to ensure it's newer
|
||||
std::thread::sleep(std::time::Duration::from_millis(50));
|
||||
|
||||
let mut writer2 = AgentLogWriter::new(root, "42_story_foo", "coder-1", "sess-new").unwrap();
|
||||
writer2
|
||||
.write_event(&AgentEvent::Output {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
text: "new".to_string(),
|
||||
})
|
||||
.unwrap();
|
||||
drop(writer2);
|
||||
|
||||
let latest = find_latest_log(root, "42_story_foo", "coder-1").unwrap();
|
||||
assert!(
|
||||
latest.to_string_lossy().contains("sess-new"),
|
||||
"Should find the newest log file, got: {}",
|
||||
latest.display()
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_list_story_log_files_returns_empty_for_missing_dir() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let files = list_story_log_files(tmp.path(), "nonexistent", None);
|
||||
assert!(files.is_empty());
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_list_story_log_files_no_filter_returns_all_logs() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let root = tmp.path();
|
||||
|
||||
let mut w1 = AgentLogWriter::new(root, "42_story_foo", "coder-1", "sess-aaa").unwrap();
|
||||
w1.write_event(&AgentEvent::Output {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
text: "from coder-1".to_string(),
|
||||
})
|
||||
.unwrap();
|
||||
drop(w1);
|
||||
std::thread::sleep(std::time::Duration::from_millis(10));
|
||||
|
||||
let mut w2 = AgentLogWriter::new(root, "42_story_foo", "mergemaster", "sess-bbb").unwrap();
|
||||
w2.write_event(&AgentEvent::Output {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "mergemaster".to_string(),
|
||||
text: "from mergemaster".to_string(),
|
||||
})
|
||||
.unwrap();
|
||||
drop(w2);
|
||||
|
||||
let files = list_story_log_files(root, "42_story_foo", None);
|
||||
assert_eq!(files.len(), 2, "Should find both log files");
|
||||
// Oldest first
|
||||
assert!(
|
||||
files[0].to_string_lossy().contains("coder-1"),
|
||||
"coder-1 should be first (older)"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_list_story_log_files_with_agent_filter() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let root = tmp.path();
|
||||
|
||||
let mut w1 = AgentLogWriter::new(root, "42_story_foo", "coder-1", "sess-a").unwrap();
|
||||
w1.write_event(&AgentEvent::Output {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
text: "from coder-1".to_string(),
|
||||
})
|
||||
.unwrap();
|
||||
drop(w1);
|
||||
|
||||
let mut w2 = AgentLogWriter::new(root, "42_story_foo", "mergemaster", "sess-b").unwrap();
|
||||
w2.write_event(&AgentEvent::Output {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "mergemaster".to_string(),
|
||||
text: "from mergemaster".to_string(),
|
||||
})
|
||||
.unwrap();
|
||||
drop(w2);
|
||||
|
||||
let files = list_story_log_files(root, "42_story_foo", Some("coder-1"));
|
||||
assert_eq!(files.len(), 1, "Should find only coder-1 log");
|
||||
assert!(files[0].to_string_lossy().contains("coder-1"));
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_format_log_entry_output_event() {
|
||||
let ts = "2026-04-10T12:48:02.123456789+00:00";
|
||||
let event = serde_json::json!({
|
||||
"type": "output",
|
||||
"story_id": "42_story",
|
||||
"agent_name": "coder-1",
|
||||
"text": "Hello world"
|
||||
});
|
||||
let result = format_log_entry_as_text(ts, &event).unwrap();
|
||||
assert!(result.contains("12:48:02"), "should include timestamp");
|
||||
assert!(result.contains("coder-1"), "should include agent name");
|
||||
assert!(result.contains("Hello world"), "should include text");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_format_log_entry_skips_empty_output() {
|
||||
let ts = "2026-04-10T12:48:02.123456789+00:00";
|
||||
let event = serde_json::json!({
|
||||
"type": "output",
|
||||
"story_id": "42_story",
|
||||
"agent_name": "coder-1",
|
||||
"text": " "
|
||||
});
|
||||
assert!(format_log_entry_as_text(ts, &event).is_none());
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_format_log_entry_error_event() {
|
||||
let ts = "2026-04-10T12:48:02.123+00:00";
|
||||
let event = serde_json::json!({
|
||||
"type": "error",
|
||||
"story_id": "42_story",
|
||||
"agent_name": "coder-1",
|
||||
"message": "Something went wrong"
|
||||
});
|
||||
let result = format_log_entry_as_text(ts, &event).unwrap();
|
||||
assert!(result.contains("ERROR"));
|
||||
assert!(result.contains("Something went wrong"));
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_format_log_entry_done_event() {
|
||||
let ts = "2026-04-10T12:48:02.123+00:00";
|
||||
let event = serde_json::json!({
|
||||
"type": "done",
|
||||
"story_id": "42_story",
|
||||
"agent_name": "coder-1",
|
||||
"session_id": null
|
||||
});
|
||||
let result = format_log_entry_as_text(ts, &event).unwrap();
|
||||
assert!(result.contains("DONE"));
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_format_log_entry_skips_running_status() {
|
||||
let ts = "2026-04-10T12:48:02.123+00:00";
|
||||
let event = serde_json::json!({
|
||||
"type": "status",
|
||||
"story_id": "42_story",
|
||||
"agent_name": "coder-1",
|
||||
"status": "running"
|
||||
});
|
||||
assert!(format_log_entry_as_text(ts, &event).is_none());
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_format_log_entry_agent_json_tool_use() {
|
||||
let ts = "2026-04-10T12:48:03.000+00:00";
|
||||
let event = serde_json::json!({
|
||||
"type": "agent_json",
|
||||
"story_id": "42_story",
|
||||
"agent_name": "coder-1",
|
||||
"data": {
|
||||
"type": "assistant",
|
||||
"message": {
|
||||
"content": [
|
||||
{
|
||||
"type": "tool_use",
|
||||
"id": "tool-1",
|
||||
"name": "Read",
|
||||
"input": {"file_path": "/some/file.rs"}
|
||||
}
|
||||
]
|
||||
}
|
||||
}
|
||||
});
|
||||
let result = format_log_entry_as_text(ts, &event).unwrap();
|
||||
assert!(
|
||||
result.contains("TOOL: Read"),
|
||||
"should show tool call: {result}"
|
||||
);
|
||||
assert!(result.contains("file_path"), "should show input: {result}");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_format_log_entry_agent_json_text() {
|
||||
let ts = "2026-04-10T12:48:04.000+00:00";
|
||||
let event = serde_json::json!({
|
||||
"type": "agent_json",
|
||||
"story_id": "42_story",
|
||||
"agent_name": "coder-1",
|
||||
"data": {
|
||||
"type": "assistant",
|
||||
"message": {
|
||||
"content": [
|
||||
{
|
||||
"type": "text",
|
||||
"text": "Now I will read the file."
|
||||
}
|
||||
]
|
||||
}
|
||||
}
|
||||
});
|
||||
let result = format_log_entry_as_text(ts, &event).unwrap();
|
||||
assert!(
|
||||
result.contains("Now I will read the file."),
|
||||
"should show text: {result}"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_format_log_entry_skips_stream_events() {
|
||||
let ts = "2026-04-10T12:48:04.000+00:00";
|
||||
let event = serde_json::json!({
|
||||
"type": "agent_json",
|
||||
"story_id": "42_story",
|
||||
"agent_name": "coder-1",
|
||||
"data": {
|
||||
"type": "stream_event",
|
||||
"event": {"type": "content_block_delta", "delta": {"type": "text_delta", "text": "chunk"}}
|
||||
}
|
||||
});
|
||||
assert!(
|
||||
format_log_entry_as_text(ts, &event).is_none(),
|
||||
"stream events should be skipped"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_read_log_as_readable_lines_produces_formatted_output() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let root = tmp.path();
|
||||
|
||||
let mut writer = AgentLogWriter::new(root, "42_story_foo", "coder-1", "sess-readable").unwrap();
|
||||
writer
|
||||
.write_event(&AgentEvent::Output {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
text: "Let me read the file".to_string(),
|
||||
})
|
||||
.unwrap();
|
||||
writer
|
||||
.write_event(&AgentEvent::Done {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
session_id: Some("sess-readable".to_string()),
|
||||
})
|
||||
.unwrap();
|
||||
|
||||
let path = log_file_path(root, "42_story_foo", "coder-1", "sess-readable");
|
||||
let lines = read_log_as_readable_lines(&path).unwrap();
|
||||
assert_eq!(lines.len(), 2, "Should produce 2 readable lines");
|
||||
assert!(
|
||||
lines[0].contains("Let me read the file"),
|
||||
"first line: {}",
|
||||
lines[0]
|
||||
);
|
||||
assert!(lines[1].contains("DONE"), "second line: {}", lines[1]);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_find_latest_log_returns_none_for_missing_dir() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let result = find_latest_log(tmp.path(), "nonexistent", "coder-1");
|
||||
assert!(result.is_none());
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_log_files_persist_on_disk() {
|
||||
let tmp = tempdir().unwrap();
|
||||
let root = tmp.path();
|
||||
|
||||
let path = {
|
||||
let mut writer =
|
||||
AgentLogWriter::new(root, "42_story_foo", "coder-1", "sess-persist").unwrap();
|
||||
writer
|
||||
.write_event(&AgentEvent::Status {
|
||||
story_id: "42_story_foo".to_string(),
|
||||
agent_name: "coder-1".to_string(),
|
||||
status: "running".to_string(),
|
||||
})
|
||||
.unwrap();
|
||||
log_file_path(root, "42_story_foo", "coder-1", "sess-persist")
|
||||
// writer is dropped here
|
||||
};
|
||||
|
||||
// File should still exist and be readable
|
||||
assert!(
|
||||
path.exists(),
|
||||
"Log file should persist after writer is dropped"
|
||||
);
|
||||
let entries = read_log(&path).unwrap();
|
||||
assert_eq!(entries.len(), 1);
|
||||
assert_eq!(entries[0].event["type"], "status");
|
||||
}
|
||||
Reference in New Issue
Block a user