xil/cmd/
stem_log.rs

1//! `xil stem-log` — daily logs → stem generation chronology CSV. Port of
2//! `XILU008_stem_log_report.py`.
3//!
4//! This one talks on stderr and stdout directly (the Python never calls the
5//! logger), but the dispatcher still configures logging, so the day's log
6//! file exists — empty — after a run.
7
8use std::ffi::OsString;
9use std::fs;
10use std::io::Write;
11use std::path::{Path, PathBuf};
12use std::sync::LazyLock;
13
14use clap::Parser;
15use regex::Regex;
16use serde_json::{Map, Value};
17use xil_core::fsutil::{basename, glob_children};
18use xil_core::log;
19use xil_core::pycsv;
20use xil_core::workspace::workspace_root;
21
22static RE_ELEVEN: LazyLock<Regex> = LazyLock::new(|| {
23    Regex::new(r"^\s*>\s*\[(\d+)\]\s+(\S+)\s+with\s+(eleven_\S+)\s+\((\d+)\s+chars\)").unwrap()
24});
25static RE_GTTS: LazyLock<Regex> = LazyLock::new(|| {
26    Regex::new(r"^\s*>\s*\[(\d+)\]\s+(\S+)\s+via\s+gTTS\s+\((\d+)\s+chars\)").unwrap()
27});
28static RE_CHATTERBOX_TURBO: LazyLock<Regex> = LazyLock::new(|| {
29    Regex::new(r"(?i)^\s*>\s*\[(\d+)\]\s+(\S+)\s+via\s+Chatterbox\s+Turbo\s+\((\d+)\s+chars\)")
30        .unwrap()
31});
32static RE_CHATTERBOX: LazyLock<Regex> = LazyLock::new(|| {
33    Regex::new(r"(?i)^\s*>\s*\[(\d+)\]\s+(\S+)\s+via\s+Chatterbox\s+\((\d+)\s+chars\)").unwrap()
34});
35static RE_SAVED: LazyLock<Regex> = LazyLock::new(|| Regex::new(r"^\s*Saved:\s+(\S+)").unwrap());
36static RE_SHA256: LazyLock<Regex> =
37    LazyLock::new(|| Regex::new(r"^\s*SHA256:\s+([0-9a-fA-F]+)").unwrap());
38static RE_PHASE1: LazyLock<Regex> =
39    LazyLock::new(|| Regex::new(r"^---\s*Phase 1:\s*Generating").unwrap());
40static RE_V2_PREFIX: LazyLock<Regex> = LazyLock::new(|| {
41    Regex::new(r"^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}[^|]*\|[A-Z]+\|[^|]*\|[^|]*\|").unwrap()
42});
43static RE_RUN_BEGIN: LazyLock<Regex> = LazyLock::new(|| Regex::new(r"^BEGIN\b").unwrap());
44static RE_DATE: LazyLock<Regex> = LazyLock::new(|| Regex::new(r"(\d{4}-\d{2}-\d{2})").unwrap());
45
46const FIELDNAMES: [&str; 11] = [
47    "log_date",
48    "log_file",
49    "run_index",
50    "log_line",
51    "seq",
52    "speaker",
53    "backend",
54    "char_count",
55    "stem_path",
56    "stem_filename",
57    "sha256",
58];
59
60#[derive(Parser)]
61#[command(
62    name = "xil-stem-log",
63    about = "Parse xil-pipeline logs into a stem generation chronology CSV."
64)]
65struct Args {
66    /// Directory containing xil_YYYY-MM-DD.log files (default: <workspace>/logs/)
67    #[arg(long, value_name = "DIR")]
68    logs_dir: Option<PathBuf>,
69    /// Output CSV path (default: stem_log_report.csv); use - for stdout
70    #[arg(
71        long,
72        short = 'o',
73        value_name = "PATH",
74        default_value = "stem_log_report.csv"
75    )]
76    output: String,
77    /// Only include log files on or after this date
78    #[arg(long, value_name = "YYYY-MM-DD")]
79    since: Option<String>,
80    /// Filter records to a specific episode tag (e.g. S03E03)
81    #[arg(long, visible_alias = "tag", value_name = "TAG")]
82    episode: Option<String>,
83    /// Filter records to a specific show slug (e.g. the413)
84    #[arg(long, value_name = "SLUG")]
85    slug: Option<String>,
86    /// Print CSV to stdout (equivalent to --output -)
87    #[arg(long)]
88    show: bool,
89    /// Instead of writing CSV: compare logged char_counts against the given parsed script JSON and flag stems whose audio may not match current text.
90    #[arg(long, value_name = "PARSED_JSON")]
91    audit: Option<PathBuf>,
92    /// Char-count delta threshold for --audit flagging (default: 20)
93    #[arg(long, value_name = "N", default_value_t = 20)]
94    audit_threshold: i64,
95}
96
97/// One generated stem, as recorded in a log.
98#[derive(Clone, Debug, PartialEq)]
99pub struct Record {
100    pub log_date: String,
101    pub log_file: String,
102    pub run_index: u64,
103    pub log_line: Option<u64>,
104    pub seq: i64,
105    pub speaker: String,
106    pub backend: String,
107    pub char_count: i64,
108    pub stem_path: Option<String>,
109    pub stem_filename: Option<String>,
110    pub sha256: Option<String>,
111}
112
113fn strip_v2_prefix(line: &str) -> &str {
114    match RE_V2_PREFIX.find(line) {
115        Some(m) => &line[m.end()..],
116        None => line,
117    }
118}
119
120/// `YYYY-MM-DD` from a log filename, else today.
121pub fn date_from_filename(name: &str) -> String {
122    RE_DATE
123        .captures(name)
124        .map(|c| c[1].to_string())
125        .unwrap_or_else(|| chrono::Local::now().format("%Y-%m-%d").to_string())
126}
127
128pub fn parse_log(log_path: &Path) -> Vec<Record> {
129    let name = basename(log_path);
130    let log_date = date_from_filename(&name);
131    let bytes = fs::read(log_path).unwrap_or_default();
132    let text = String::from_utf8_lossy(&bytes);
133
134    let mut records = Vec::new();
135    let mut run_index = 0u64;
136    let mut pending: Option<Record> = None;
137
138    for (i, raw) in text.split_inclusive('\n').enumerate() {
139        let lineno = (i + 1) as u64;
140        let stripped = raw.strip_suffix('\n').unwrap_or(raw);
141        let is_v2 = RE_V2_PREFIX.is_match(stripped);
142        let line = strip_v2_prefix(stripped);
143
144        let boundary = if is_v2 {
145            RE_RUN_BEGIN.is_match(line)
146        } else {
147            RE_PHASE1.is_match(line)
148        };
149        if boundary {
150            run_index += 1;
151            pending = None;
152            continue;
153        }
154
155        let hit = RE_ELEVEN
156            .captures(line)
157            .map(|c| {
158                (
159                    c[1].to_string(),
160                    c[2].to_string(),
161                    c[3].to_string(),
162                    c[4].to_string(),
163                )
164            })
165            .or_else(|| {
166                RE_GTTS.captures(line).map(|c| {
167                    (
168                        c[1].to_string(),
169                        c[2].to_string(),
170                        "gtts".into(),
171                        c[3].to_string(),
172                    )
173                })
174            })
175            .or_else(|| {
176                RE_CHATTERBOX_TURBO.captures(line).map(|c| {
177                    (
178                        c[1].to_string(),
179                        c[2].to_string(),
180                        "chatterbox-turbo".into(),
181                        c[3].to_string(),
182                    )
183                })
184            })
185            .or_else(|| {
186                RE_CHATTERBOX.captures(line).map(|c| {
187                    (
188                        c[1].to_string(),
189                        c[2].to_string(),
190                        "chatterbox".into(),
191                        c[3].to_string(),
192                    )
193                })
194            });
195        if let Some((seq, speaker, backend, chars)) = hit {
196            pending = Some(Record {
197                log_date: log_date.clone(),
198                log_file: name.clone(),
199                run_index,
200                log_line: None,
201                seq: seq.parse().unwrap_or(0),
202                speaker,
203                backend,
204                char_count: chars.parse().unwrap_or(0),
205                stem_path: None,
206                stem_filename: None,
207                sha256: None,
208            });
209        }
210
211        let Some(p) = pending.as_mut() else { continue };
212
213        if let Some(m) = RE_SAVED.captures(line) {
214            if p.stem_path.is_none() {
215                let path = m[1].to_string();
216                p.stem_filename = Some(basename(Path::new(&path)));
217                p.stem_path = Some(path);
218                p.log_line = Some(lineno);
219                continue;
220            }
221        }
222        if let Some(m) = RE_SHA256.captures(line) {
223            if p.stem_path.is_some() && p.sha256.is_none() {
224                p.sha256 = Some(m[1].to_string());
225                records.push(p.clone());
226                pending = None;
227            }
228        }
229    }
230    records
231}
232
233fn to_row(r: &Record) -> Map<String, Value> {
234    let opt = |s: &Option<String>| s.clone().map(Value::String).unwrap_or(Value::Null);
235    let mut m = Map::new();
236    m.insert("log_date".into(), Value::String(r.log_date.clone()));
237    m.insert("log_file".into(), Value::String(r.log_file.clone()));
238    m.insert("run_index".into(), Value::from(r.run_index));
239    m.insert(
240        "log_line".into(),
241        r.log_line.map(Value::from).unwrap_or(Value::Null),
242    );
243    m.insert("seq".into(), Value::from(r.seq));
244    m.insert("speaker".into(), Value::String(r.speaker.clone()));
245    m.insert("backend".into(), Value::String(r.backend.clone()));
246    m.insert("char_count".into(), Value::from(r.char_count));
247    m.insert("stem_path".into(), opt(&r.stem_path));
248    m.insert("stem_filename".into(), opt(&r.stem_filename));
249    m.insert("sha256".into(), opt(&r.sha256));
250    m
251}
252
253fn audit(records: &[Record], parsed_json: &Path, threshold: i64) -> anyhow::Result<()> {
254    let text = fs::read_to_string(parsed_json)?;
255    let parsed: Value = serde_json::from_str(&text)?;
256    let mut by_seq_spk = std::collections::HashMap::new();
257    for e in parsed
258        .get("entries")
259        .and_then(Value::as_array)
260        .cloned()
261        .unwrap_or_default()
262    {
263        if e.get("type").and_then(Value::as_str) == Some("dialogue") {
264            let seq = e.get("seq").and_then(Value::as_i64).unwrap_or(0);
265            let spk = e
266                .get("speaker")
267                .and_then(Value::as_str)
268                .unwrap_or("")
269                .to_string();
270            let txt = e
271                .get("text")
272                .and_then(Value::as_str)
273                .unwrap_or("")
274                .chars()
275                .count() as i64;
276            by_seq_spk.insert((seq, spk), txt);
277        }
278    }
279    let mut out = std::io::stdout().lock();
280    writeln!(
281        out,
282        "{:>4}  {:<14} {:>9}  {:>10}  {:>6}  status",
283        "seq", "speaker", "log_chars", "json_chars", "delta"
284    )?;
285    writeln!(out, "{}", "-".repeat(65))?;
286    let (mut ok, mut flagged, mut unmatched) = (0, 0, 0);
287    for rec in records {
288        let Some(json_len) = by_seq_spk.get(&(rec.seq, rec.speaker.clone())) else {
289            unmatched += 1;
290            continue;
291        };
292        let delta = (json_len - rec.char_count).abs();
293        if delta > threshold {
294            flagged += 1;
295            writeln!(
296                out,
297                "{:>4}  {:<14} {:>9}  {:>10}  {:>6}  ⚠ MISMATCH",
298                rec.seq, rec.speaker, rec.char_count, json_len, delta
299            )?;
300        } else {
301            ok += 1;
302        }
303    }
304    writeln!(out, "{}", "-".repeat(65))?;
305    writeln!(
306        out,
307        "  {ok} OK, {flagged} flagged (delta > {threshold}), {unmatched} not in current JSON"
308    )?;
309    Ok(())
310}
311
312pub fn run(args: &[OsString]) -> anyhow::Result<i32> {
313    log::init("stem-log");
314    let a: Args = match super::parse_or_exit("xil-stem-log", args) {
315        Ok(a) => a,
316        Err(code) => return Ok(code),
317    };
318    let logs_dir = a
319        .logs_dir
320        .clone()
321        .unwrap_or_else(|| workspace_root().join("logs"));
322    if !logs_dir.is_dir() {
323        eprintln!("[ERROR] Logs directory not found: {}", logs_dir.display());
324        return Ok(1);
325    }
326
327    let mut log_files = glob_children(&logs_dir, "xil_", ".log");
328    log_files.sort_by_key(|p| (date_from_filename(&basename(p)), basename(p)));
329    if let Some(since) = &a.since {
330        log_files.retain(|p| date_from_filename(&basename(p)).as_str() >= since.as_str());
331    }
332    if log_files.is_empty() {
333        eprintln!("[!] No matching log files found.");
334        return Ok(0);
335    }
336
337    let mut all = Vec::new();
338    for lf in &log_files {
339        let recs = parse_log(lf);
340        eprintln!("  {}: {} stems", basename(lf), recs.len());
341        all.extend(recs);
342    }
343    if let Some(tag) = &a.episode {
344        let tag = tag.to_uppercase();
345        all.retain(|r| {
346            r.stem_path
347                .as_ref()
348                .map(|p| p.to_uppercase().contains(&tag))
349                .unwrap_or(false)
350        });
351    }
352    if let Some(slug) = &a.slug {
353        let slug = slug.to_lowercase();
354        all.retain(|r| {
355            r.stem_path
356                .as_ref()
357                .map(|p| p.to_lowercase().contains(&slug))
358                .unwrap_or(false)
359        });
360    }
361    eprintln!("Total: {} stem records", all.len());
362
363    if let Some(pj) = &a.audit {
364        audit(&all, pj, a.audit_threshold)?;
365        return Ok(0);
366    }
367
368    let rows: Vec<_> = all.iter().map(to_row).collect();
369    if a.show || a.output == "-" {
370        let mut so = std::io::stdout().lock();
371        pycsv::write_dicts(&mut so, &FIELDNAMES, &rows)?;
372        so.flush()?;
373    } else {
374        let mut f = fs::File::create(&a.output)?;
375        pycsv::write_dicts(&mut f, &FIELDNAMES, &rows)?;
376        eprintln!("Written: {}", a.output);
377    }
378    Ok(0)
379}
380
381/// The clap definition behind `--help`, for man pages.
382pub fn command() -> clap::Command {
383    <Args as clap::CommandFactory>::command()
384}
385
386#[cfg(test)]
387mod tests {
388    use super::*;
389
390    const V2: &str = "\
3912026-08-01T10:00:00-0400|RUN|h|produce|BEGIN argv=\"xil produce\" pid=1 ver=0.3.2 cwd=/x
3922026-08-01T10:00:01-0400|INFO|h|produce|  > [006] adam via Chatterbox Turbo (282 chars)...
3932026-08-01T10:00:05-0400|INFO|h|produce|   Saved: stems/the413/S01E01/006_act1_adam.mp3
3942026-08-01T10:00:05-0400|INFO|h|produce|   SHA256: abc123
3952026-08-01T10:00:06-0400|INFO|h|produce|  > [007] sarah with eleven_v3 (120 chars)...
3962026-08-01T10:00:09-0400|INFO|h|produce|   Saved: stems/the413/S01E01/007_act1_sarah.mp3
3972026-08-01T10:00:09-0400|INFO|h|produce|   SHA256: def456
3982026-08-01T11:00:00-0400|RUN|h|produce|BEGIN argv=\"xil produce\" pid=2 ver=0.3.2 cwd=/x
3992026-08-01T11:00:03-0400|INFO|h|produce|  > [004] maya via chatterbox (50 chars)...
4002026-08-01T11:00:04-0400|INFO|h|produce|   Saved: stems/nightowls/S01E02/004_cold-open_maya.mp3
401";
402
403    #[test]
404    fn v2_state_machine_and_run_index() {
405        let tmp = tempfile::tempdir().unwrap();
406        let p = tmp.path().join("xil_v2_2026-08-01_h.log");
407        fs::write(&p, V2).unwrap();
408        let recs = parse_log(&p);
409        assert_eq!(recs.len(), 2, "record without SHA256 is dropped");
410        assert_eq!(recs[0].backend, "chatterbox-turbo");
411        assert_eq!(
412            (
413                recs[0].seq,
414                recs[0].char_count,
415                recs[0].run_index,
416                recs[0].log_line
417            ),
418            (6, 282, 1, Some(3))
419        );
420        assert_eq!(recs[0].stem_filename.as_deref(), Some("006_act1_adam.mp3"));
421        assert_eq!(recs[1].backend, "eleven_v3");
422        assert_eq!(recs[1].log_date, "2026-08-01");
423    }
424
425    #[test]
426    fn v1_uses_phase1_header_as_boundary() {
427        let tmp = tempfile::tempdir().unwrap();
428        let p = tmp.path().join("xil_2026-07-10.log");
429        fs::write(
430            &p,
431            "--- Phase 1: Generating voices ---\n  > [001] adam with eleven_v3 (10 chars)...\n   Saved: s/001.mp3\n   SHA256: aa\n\
432             --- Phase 1: Generating voices ---\n  > [002] maya via gTTS (5 chars)...\n   Saved: s/002.mp3\n   SHA256: bb\n",
433        )
434        .unwrap();
435        let recs = parse_log(&p);
436        assert_eq!(
437            recs.iter().map(|r| r.run_index).collect::<Vec<_>>(),
438            vec![1, 2]
439        );
440        assert_eq!(recs[1].backend, "gtts");
441    }
442
443    #[test]
444    fn date_from_filename_or_today() {
445        assert_eq!(date_from_filename("xil_v1_2026-07-15.log"), "2026-07-15");
446        assert_eq!(date_from_filename("nodate.log").len(), 10);
447    }
448}
xil/cmd/stem_log.rs

xil/cmd/
stem_log.rs
