1use crate::reducer::event::PipelinePhase;
2use crate::workspace::Workspace;
3use std::path::Path;
4
5pub struct LogEffectParams<'a> {
6 pub workspace: &'a dyn Workspace,
7 pub log_path: &'a Path,
8 pub phase: PipelinePhase,
9 pub effect: &'a str,
10 pub primary_event: &'a str,
11 pub extra_events: &'a [String],
12 pub duration_ms: u64,
13 pub context: &'a [(&'a str, &'a str)],
14 pub timestamp: &'a str,
15}
16
17fn format_log_line_content(seq: u64, params: &LogEffectParams<'_>) -> String {
18 let extra = if params.extra_events.is_empty() {
19 String::new()
20 } else {
21 format!(" extra=[{}]", params.extra_events.join(","))
22 };
23
24 let ctx = if params.context.is_empty() {
25 String::new()
26 } else {
27 let pairs: Vec<String> = params
28 .context
29 .iter()
30 .map(|(k, v)| format!("{k}={v}"))
31 .collect();
32 format!(" ctx={}", pairs.join(","))
33 };
34
35 format!(
36 "{} ts={} phase={} effect={} event={}{}{} ms={}\n",
37 seq,
38 params.timestamp,
39 params.phase,
40 params.effect,
41 params.primary_event,
42 extra,
43 ctx,
44 params.duration_ms
45 )
46}
47
48#[derive(Clone)]
49pub struct EventLoopLogger {
50 seq: u64,
51}
52
53impl EventLoopLogger {
54 #[must_use]
55 pub const fn new() -> Self {
56 Self { seq: 1 }
57 }
58
59 #[must_use]
60 pub const fn seq(&self) -> u64 {
61 self.seq
62 }
63
64 pub fn from_existing_log(
65 workspace: &dyn crate::workspace::Workspace,
66 log_path: &Path,
67 ) -> Result<Self, std::io::Error> {
68 if !workspace.exists(log_path) {
69 return Ok(Self { seq: 1 });
70 }
71
72 let content = workspace.read(log_path)?;
73 if content.is_empty() {
74 return Ok(Self { seq: 1 });
75 }
76
77 let last_seq = content
78 .lines()
79 .rev()
80 .find(|line| !line.trim().is_empty())
81 .and_then(|line| line.split_whitespace().next()?.parse::<u64>().ok())
82 .unwrap_or(0);
83
84 Ok(Self { seq: last_seq + 1 })
85 }
86
87 pub fn log_effect(self, params: &LogEffectParams<'_>) -> Result<(Self, u64), std::io::Error> {
88 let line = format_log_line_content(self.seq, params);
89
90 params
91 .workspace
92 .append_bytes(params.log_path, line.as_bytes())?;
93
94 let next_seq = self.seq.saturating_add(1);
95 let updated_logger = Self { seq: next_seq };
96 Ok((updated_logger, next_seq))
97 }
98}
99
100impl Default for EventLoopLogger {
101 fn default() -> Self {
102 Self::new()
103 }
104}
105
106#[cfg(test)]
107mod tests {
108 use super::*;
109 use crate::workspace::WorkspaceFs;
110
111 const TEST_TIMESTAMP: &str = "2026-01-01T00:00:00Z";
112
113 #[test]
114 fn test_event_loop_logger_basic() {
115 let tempdir = tempfile::tempdir().unwrap();
116 let workspace = WorkspaceFs::new(tempdir.path().to_path_buf());
117
118 let log_path = std::path::Path::new("event_loop.log");
119 let logger = EventLoopLogger::new();
120
121 let (logger, _) = logger
122 .log_effect(&LogEffectParams {
123 workspace: &workspace,
124 log_path,
125 phase: PipelinePhase::Development,
126 effect: "InvokePrompt",
127 primary_event: "PromptCompleted",
128 extra_events: &[],
129 duration_ms: 1234,
130 context: &[("iteration", "1")],
131 timestamp: TEST_TIMESTAMP,
132 })
133 .unwrap();
134
135 let (_, _) = logger
136 .log_effect(&LogEffectParams {
137 workspace: &workspace,
138 log_path,
139 phase: PipelinePhase::Development,
140 effect: "WriteFile",
141 primary_event: "FileWritten",
142 extra_events: &["CheckpointSaved".to_string()],
143 duration_ms: 12,
144 context: &[],
145 timestamp: TEST_TIMESTAMP,
146 })
147 .unwrap();
148
149 assert!(workspace.exists(log_path));
150
151 let content = workspace.read(log_path).unwrap();
152 assert!(content.contains("1 ts="));
153 assert!(content.contains("phase=Development"));
154 assert!(content.contains("effect=InvokePrompt"));
155 assert!(content.contains("event=PromptCompleted"));
156 assert!(content.contains("ms=1234"));
157 assert!(content.contains("ctx=iteration=1"));
158
159 assert!(content.contains("2 ts="));
160 assert!(content.contains("effect=WriteFile"));
161 assert!(content.contains("event=FileWritten"));
162 assert!(content.contains("extra=[CheckpointSaved]"));
163 assert!(content.contains("ms=12"));
164 }
165
166 #[test]
167 fn test_event_loop_logger_sequence_increment() {
168 let tempdir = tempfile::tempdir().unwrap();
169 let workspace = WorkspaceFs::new(tempdir.path().to_path_buf());
170
171 let log_path = std::path::Path::new("event_loop.log");
172
173 let _ = (0..5).fold(EventLoopLogger::new(), |logger, i| {
174 let (updated_logger, _) = logger
175 .log_effect(&LogEffectParams {
176 workspace: &workspace,
177 log_path,
178 phase: PipelinePhase::Planning,
179 effect: "TestEffect",
180 primary_event: "TestEvent",
181 extra_events: &[],
182 duration_ms: 10 * i,
183 context: &[],
184 timestamp: TEST_TIMESTAMP,
185 })
186 .unwrap();
187 updated_logger
188 });
189
190 let content = workspace.read(log_path).unwrap();
191 (1..=5).for_each(|i| {
192 assert!(
193 content.contains(&format!("{i} ts=")),
194 "Should contain sequence number {i}"
195 );
196 });
197 }
198
199 #[test]
200 fn test_event_loop_logger_context_formatting() {
201 let tempdir = tempfile::tempdir().unwrap();
202 let workspace = WorkspaceFs::new(tempdir.path().to_path_buf());
203
204 let log_path = std::path::Path::new("event_loop.log");
205 let logger = EventLoopLogger::new();
206
207 let (_, _) = logger
208 .log_effect(&LogEffectParams {
209 workspace: &workspace,
210 log_path,
211 phase: PipelinePhase::Review,
212 effect: "InvokeReviewer",
213 primary_event: "ReviewCompleted",
214 extra_events: &[],
215 duration_ms: 5000,
216 context: &[
217 ("reviewer_pass", "2"),
218 ("agent_index", "3"),
219 ("retry_cycle", "1"),
220 ],
221 timestamp: TEST_TIMESTAMP,
222 })
223 .unwrap();
224
225 let content = workspace.read(log_path).unwrap();
226 assert!(content.contains("ctx=reviewer_pass=2,agent_index=3,retry_cycle=1"));
227 }
228
229 #[test]
230 fn test_event_loop_logger_empty_context() {
231 let tempdir = tempfile::tempdir().unwrap();
232 let workspace = WorkspaceFs::new(tempdir.path().to_path_buf());
233
234 let log_path = std::path::Path::new("event_loop.log");
235 let logger = EventLoopLogger::new();
236
237 let (_, _) = logger
238 .log_effect(&LogEffectParams {
239 workspace: &workspace,
240 log_path,
241 phase: PipelinePhase::CommitMessage,
242 effect: "GenerateCommit",
243 primary_event: "CommitGenerated",
244 extra_events: &[],
245 duration_ms: 100,
246 context: &[],
247 timestamp: TEST_TIMESTAMP,
248 })
249 .unwrap();
250
251 let content = workspace.read(log_path).unwrap();
252 assert!(!content.contains("ctx="));
253 assert!(!content.contains("extra="));
254 }
255
256 #[test]
257 fn test_event_loop_logger_from_existing_log() {
258 let tempdir = tempfile::tempdir().unwrap();
259 let workspace = WorkspaceFs::new(tempdir.path().to_path_buf());
260
261 let log_path = std::path::Path::new("event_loop.log");
262
263 {
264 let _ = (0..3).fold(EventLoopLogger::new(), |logger, i| {
265 let (updated_logger, _) = logger
266 .log_effect(&LogEffectParams {
267 workspace: &workspace,
268 log_path,
269 phase: PipelinePhase::Development,
270 effect: "TestEffect",
271 primary_event: "TestEvent",
272 extra_events: &[],
273 duration_ms: 10 * i,
274 context: &[],
275 timestamp: TEST_TIMESTAMP,
276 })
277 .unwrap();
278 updated_logger
279 });
280 }
281
282 let logger = EventLoopLogger::from_existing_log(&workspace, log_path).unwrap();
283
284 let (_, _) = logger
285 .log_effect(&LogEffectParams {
286 workspace: &workspace,
287 log_path,
288 phase: PipelinePhase::Review,
289 effect: "ResumeEffect",
290 primary_event: "ResumeEvent",
291 extra_events: &[],
292 duration_ms: 100,
293 context: &[],
294 timestamp: TEST_TIMESTAMP,
295 })
296 .unwrap();
297
298 let content = workspace.read(log_path).unwrap();
299 assert!(content.contains("1 ts="));
300 assert!(content.contains("2 ts="));
301 assert!(content.contains("3 ts="));
302 assert!(content.contains("4 ts="));
303 let seq1_count = content.matches("1 ts=").count();
304 assert_eq!(seq1_count, 1, "Should only have one '1 ts=' entry");
305 }
306
307 #[test]
308 fn test_event_loop_logger_from_nonexistent_log() {
309 let tempdir = tempfile::tempdir().unwrap();
310 let workspace = WorkspaceFs::new(tempdir.path().to_path_buf());
311
312 let log_path = std::path::Path::new("event_loop.log");
313
314 let logger = EventLoopLogger::from_existing_log(&workspace, log_path).unwrap();
315
316 let (_, _) = logger
317 .log_effect(&LogEffectParams {
318 workspace: &workspace,
319 log_path,
320 phase: PipelinePhase::Development,
321 effect: "TestEffect",
322 primary_event: "TestEvent",
323 extra_events: &[],
324 duration_ms: 10,
325 context: &[],
326 timestamp: TEST_TIMESTAMP,
327 })
328 .unwrap();
329
330 let content = workspace.read(log_path).unwrap();
331 assert!(content.contains("1 ts="));
332 }
333
334 #[test]
335 fn test_event_loop_logger_from_empty_log() {
336 let tempdir = tempfile::tempdir().unwrap();
337 let workspace = WorkspaceFs::new(tempdir.path().to_path_buf());
338
339 let log_path = std::path::Path::new("event_loop.log");
340
341 workspace.write(log_path, "").unwrap();
342
343 let logger = EventLoopLogger::from_existing_log(&workspace, log_path).unwrap();
344
345 let (_, _) = logger
346 .log_effect(&LogEffectParams {
347 workspace: &workspace,
348 log_path,
349 phase: PipelinePhase::Development,
350 effect: "TestEffect",
351 primary_event: "TestEvent",
352 extra_events: &[],
353 duration_ms: 10,
354 context: &[],
355 timestamp: TEST_TIMESTAMP,
356 })
357 .unwrap();
358
359 let content = workspace.read(log_path).unwrap();
360 assert!(content.contains("1 ts="));
361 }
362}