fix(rewrite): preserve newline separators in compound commands

README.md

@@ -2175,6 +2175,42 @@ tokf completions nushell | save -f ~/.config/nushell/tokf.nu
 source ~/.config/nushell/tokf.nu
 ```
 
+## Logging hook activity (`TOKF_HOOK_LOG`)
+
+When chasing a rewrite bug that only manifests during a live AI-tool session, set the `TOKF_HOOK_LOG` environment variable to a writable file path. Every `tokf hook handle` invocation then appends a YAML record covering the BEFORE / AFTER command strings and the resulting outcome. Activate it in the same process group as Claude Code (or whichever tool is running the hook) — for Claude Code, that means setting it in your shell profile (`.zshrc`/`.bashrc`) before launching the agent.
+
+```sh
+export TOKF_HOOK_LOG=$HOME/.cache/tokf/hook.log
+```
+
+Each record looks like:
+
+```yaml
+---
+ts: 1714408876
+tool: Bash
+format: claude-code
+outcome: Allow
+before: |-
+  cargo test
+  ls | head -1
+  echo hi
+after: |-
+  tokf run cargo test
+  tokf run --baseline-pipe 'head -1' ls
+  echo hi
+```
+
+- `ts` is Unix epoch seconds (use `date -r <ts>` on macOS / `date -d @<ts>` on Linux to humanise).
+- `tool` is the AI tool's tool-name (`Bash`, `run_shell_command`, etc.).
+- `format` is `claude-code` / `gemini` / `cursor`.
+- `outcome` is one of `Allow`, `Ask`, `Deny`, `PassThrough`.
+- `after: ~` (YAML null) means the hook chose not to rewrite — the agent ran the original command verbatim.
+
+Records are appended; nothing rotates or trims the file, so prune it yourself if it grows large. When the variable is unset (the default), nothing is written and the hook has zero filesystem overhead.
+
+This was added in response to issue #355, where stray `1echo` files in the agent's cwd turned out to come from a multi-line rewrite collapsing newlines into adjacent tokens — the kind of bug that's invisible in `tokf rewrite "..."` runs but obvious in a hook log.
+
 ---
 
 

crates/tokf-cli/src/hook/debug_log.rs

@@ -0,0 +1,201 @@
+//! Append-only diagnostic log for hook invocations. Activated by setting
+//! the `TOKF_HOOK_LOG` env var to a writable file path. Each invocation
+//! writes one YAML record covering the BEFORE / AFTER command strings and
+//! the outcome. Best-effort: any I/O error is silently dropped so a
+//! missing/unwritable log path never blocks the hook (#355).
+
+use std::fs::OpenOptions;
+use std::io::Write;
+use std::path::PathBuf;
+use std::time::{SystemTime, UNIX_EPOCH};
+
+use tokf_hook_types::HookFormat;
+
+use super::HookOutcome;
+
+const ENV_VAR: &str = "TOKF_HOOK_LOG";
+
+/// Write a single hook-event record to the path in `TOKF_HOOK_LOG`, if set.
+///
+/// `after` is the rewritten command string when the rewrite changed the
+/// input; pass `None` when the hook passed the command through unchanged.
+pub(super) fn log_event(
+    tool: &str,
+    format: HookFormat,
+    before: &str,
+    after: Option<&str>,
+    outcome: HookOutcome,
+) {
+    let Some(path) = log_path() else {
+        return;
+    };
+    let record = format_record(&Record {
+        tool,
+        format,
+        before,
+        after,
+        outcome,
+        now: SystemTime::now(),
+    });
+    let _ = OpenOptions::new()
+        .create(true)
+        .append(true)
+        .open(&path)
+        .and_then(|mut f| f.write_all(record.as_bytes()));
+}
+
+fn log_path() -> Option<PathBuf> {
+    let raw = std::env::var_os(ENV_VAR)?;
+    if raw.is_empty() {
+        return None;
+    }
+    Some(PathBuf::from(raw))
+}
+
+struct Record<'a> {
+    tool: &'a str,
+    format: HookFormat,
+    before: &'a str,
+    after: Option<&'a str>,
+    outcome: HookOutcome,
+    now: SystemTime,
+}
+
+fn format_record(rec: &Record<'_>) -> String {
+    let ts = rec
+        .now
+        .duration_since(UNIX_EPOCH)
+        .map(|d| d.as_secs())
+        .unwrap_or(0);
+    let outcome_str = match rec.outcome {
+        HookOutcome::Allow => "Allow",
+        HookOutcome::Ask => "Ask",
+        HookOutcome::Deny => "Deny",
+        HookOutcome::PassThrough => "PassThrough",
+    };
+    let after_block = rec.after.map_or_else(
+        || "after: ~\n".to_string(),
+        |s| format!("after: |-\n{}\n", indent(s, "  ")),
+    );
+    format!(
+        "---\nts: {ts}\ntool: {tool}\nformat: {format}\noutcome: {outcome}\nbefore: |-\n{before}\n{after_block}",
+        tool = rec.tool,
+        format = rec.format.as_str(),
+        outcome = outcome_str,
+        before = indent(rec.before, "  "),
+    )
+}
+
+fn indent(s: &str, prefix: &str) -> String {
+    if s.is_empty() {
+        return prefix.to_string();
+    }
+    s.lines()
+        .map(|line| format!("{prefix}{line}"))
+        .collect::<Vec<_>>()
+        .join("\n")
+}
+
+#[cfg(test)]
+#[allow(clippy::unwrap_used)]
+mod tests {
+    use std::time::Duration;
+
+    use super::*;
+
+    fn at_epoch(secs: u64) -> SystemTime {
+        UNIX_EPOCH + Duration::from_secs(secs)
+    }
+
+    #[test]
+    fn record_with_rewrite() {
+        let r = format_record(&Record {
+            tool: "Bash",
+            format: HookFormat::ClaudeCode,
+            before: "git status",
+            after: Some("tokf run git status"),
+            outcome: HookOutcome::Allow,
+            now: at_epoch(1_700_000_000),
+        });
+        assert!(r.starts_with("---\nts: 1700000000\n"));
+        assert!(r.contains("tool: Bash\n"));
+        assert!(r.contains("format: claude-code\n"));
+        assert!(r.contains("outcome: Allow\n"));
+        assert!(r.contains("before: |-\n  git status\n"));
+        assert!(r.contains("after: |-\n  tokf run git status\n"));
+    }
+
+    #[test]
+    fn record_passthrough_has_null_after() {
+        let r = format_record(&Record {
+            tool: "Bash",
+            format: HookFormat::ClaudeCode,
+            before: "ls",
+            after: None,
+            outcome: HookOutcome::PassThrough,
+            now: at_epoch(1_700_000_000),
+        });
+        assert!(r.contains("outcome: PassThrough\n"));
+        assert!(r.contains("after: ~\n"));
+    }
+
+    #[test]
+    fn multiline_before_indented_under_block_scalar() {
+        // The most useful diagnostic case (#355): newline-bearing BEFORE
+        // blocks must be indented so the YAML block scalar parses cleanly.
+        let r = format_record(&Record {
+            tool: "Bash",
+            format: HookFormat::ClaudeCode,
+            before: "cargo test\nls | head -1\necho hi",
+            after: Some("tokf run cargo test\ntokf run --baseline-pipe 'head -1' ls\necho hi"),
+            outcome: HookOutcome::Allow,
+            now: at_epoch(0),
+        });
+        assert!(
+            r.contains("before: |-\n  cargo test\n  ls | head -1\n  echo hi\n"),
+            "BEFORE block not indented as expected: {r}"
+        );
+        assert!(
+            r.contains(
+                "after: |-\n  tokf run cargo test\n  tokf run --baseline-pipe 'head -1' ls\n  echo hi\n"
+            ),
+            "AFTER block not indented as expected: {r}"
+        );
+    }
+
+    #[test]
+    fn empty_input_does_not_panic() {
+        let r = format_record(&Record {
+            tool: "Bash",
+            format: HookFormat::ClaudeCode,
+            before: "",
+            after: None,
+            outcome: HookOutcome::PassThrough,
+            now: at_epoch(0),
+        });
+        // Block scalar with empty body indents to a single prefix-only line.
+        assert!(r.contains("before: |-\n  \n"));
+    }
+
+    #[test]
+    fn gemini_and_cursor_format_strings() {
+        let r_g = format_record(&Record {
+            tool: "run_shell_command",
+            format: HookFormat::Gemini,
+            before: "ls",
+            after: None,
+            outcome: HookOutcome::PassThrough,
+            now: at_epoch(0),
+        });
+        assert!(r_g.contains("format: gemini\n"));
+        let r_c = format_record(&Record {
+            tool: "Shell",
+            format: HookFormat::Cursor,
+            before: "ls",
+            after: None,
+            outcome: HookOutcome::PassThrough,
+            now: at_epoch(0),
+        });
+        assert!(r_c.contains("format: cursor\n"));
+    }
+}

crates/tokf-cli/src/hook/mod.rs

@@ -3,6 +3,7 @@ pub mod cline;
 pub mod codex;
 pub mod copilot;
 pub mod cursor;
+mod debug_log;
 pub mod gemini;
 pub mod instructions;
 pub mod opencode;
@@ -199,7 +200,8 @@ fn handle_cursor_json_inner(
     };
 
     process_command(
-        command,
+        &command,
+        "shell",
         json,
         HookFormat::Cursor,
         user_config,
@@ -273,7 +275,8 @@ fn handle_generic<R: serde::Serialize>(
     };
 
     process_command(
-        command,
+        &command,
+        expected_tool,
         json,
         format,
         user_config,
@@ -287,10 +290,12 @@ fn handle_generic<R: serde::Serialize>(
 /// Shared post-deserialization logic for all hook formats.
 ///
 /// Handles both the external-engine path (verdict on every command) and
-/// the no-engine path (rewrite-only, auto-allow).
+/// the no-engine path (rewrite-only, auto-allow). When `TOKF_HOOK_LOG`
+/// is set in the env, every invocation appends one diagnostic record.
 #[allow(clippy::too_many_arguments)]
 fn process_command<R: serde::Serialize>(
-    command: String,
+    command: &str,
+    tool_name: &str,
     json: &str,
     format: HookFormat,
     user_config: &RewriteConfig,
@@ -299,42 +304,73 @@ fn process_command<R: serde::Serialize>(
     build_ask: impl FnOnce(String, Option<String>) -> R,
     build_deny: impl FnOnce(String, Option<String>) -> R,
 ) -> HookOutcome {
+    let (outcome, after) = decide(
+        command,
+        json,
+        format,
+        user_config,
+        search_dirs,
+        build_allow,
+        build_ask,
+        build_deny,
+    );
+    debug_log::log_event(tool_name, format, command, after.as_deref(), outcome);
+    outcome
+}
+
+/// Compute the hook decision and emit the response for it. Returns the
+/// outcome plus the rewritten command string when one was emitted (for
+/// the diagnostic log; `None` means no rewrite was sent to the agent).
+#[allow(clippy::too_many_arguments)]
+fn decide<R: serde::Serialize>(
+    command: &str,
+    json: &str,
+    format: HookFormat,
+    user_config: &RewriteConfig,
+    search_dirs: &[PathBuf],
+    build_allow: impl FnOnce(String, Option<String>) -> R,
+    build_ask: impl FnOnce(String, Option<String>) -> R,
+    build_deny: impl FnOnce(String, Option<String>) -> R,
+) -> (HookOutcome, Option<String>) {
     // When an external permission engine is configured, consult it on every
     // command — even ones tokf has no filter for.
-    if let Some(verdict) = query_external_engine(&command, json, format, user_config) {
+    if let Some(verdict) = query_external_engine(command, json, format, user_config) {
         // Deny doesn't need a rewrite — the command won't execute.
         if verdict.decision == PermissionDecision::Deny {
-            if emit_response(&build_deny(command, verdict.reason)) {
-                return HookOutcome::Deny;
+            if emit_response(&build_deny(command.to_string(), verdict.reason)) {
+                return (HookOutcome::Deny, None);
             }
-            return HookOutcome::PassThrough;
+            return (HookOutcome::PassThrough, None);
         }
-        let rewritten = rewrite::rewrite_with_config(&command, user_config, search_dirs, false);
-        let output_cmd = if rewritten == command {
-            command
-        } else {
+        let rewritten = rewrite::rewrite_with_config(command, user_config, search_dirs, false);
+        let rewrite_changed = rewritten != command;
+        let output_cmd = if rewrite_changed {
             rewritten
+        } else {
+            command.to_string()
         };
+        let logged_after = rewrite_changed.then(|| output_cmd.clone());
         let (response, outcome) = match verdict.decision {
             PermissionDecision::Ask => (build_ask(output_cmd, verdict.reason), HookOutcome::Ask),
             _ => (build_allow(output_cmd, verdict.reason), HookOutcome::Allow),
         };
         if emit_response(&response) {
-            return outcome;
+            return (outcome, logged_after);
         }
-        return HookOutcome::PassThrough;
+        return (HookOutcome::PassThrough, logged_after);
     }
 
     // No external engine — only act when tokf has a matching filter.
-    let rewritten = rewrite::rewrite_with_config(&command, user_config, search_dirs, false);
+    let rewritten = rewrite::rewrite_with_config(command, user_config, search_dirs, false);
     if rewritten == command {
-        return HookOutcome::PassThrough;
+        return (HookOutcome::PassThrough, None);
     }
 
+    let logged_after = Some(rewritten.clone());
     if emit_response(&build_allow(rewritten, None)) {
-        HookOutcome::Allow
+        (HookOutcome::Allow, logged_after)
     } else {
-        HookOutcome::PassThrough
+        (HookOutcome::PassThrough, logged_after)
     }
 }