v1.20: per-invocation logging + re-assert clipboard before each paste

Diagnosing the user-reported "right-click → Paste does nothing for
image-paste, Ctrl+V works" required two things this commit ships:

1. Per-invocation log in flashpaste-trigger
   Every call appends one line to
   ~/.local/state/flashpaste-trigger.log (override with
   FLASHPASTE_TRIGGER_LOG). Records timestamp, pid, op (paste or
   stage-text), pane, phase (start / handled / exec-bash / exit), and
   the daemon outcome. Combined with the daemon's journalctl
   (also bumped to INFO for the punt reasons below), you can answer
   "what happened when I clicked Paste at 13:47:22?" without strace.

   tmux.conf.snippet now sets TMUX_PASTE_TRIGGER=right-click-menu on
   the right-click path so the log distinguishes it from the
   ctrl-v path the C-v binding tags. Users with their own
   MouseUp3Pane menu should do the same in their Paste item.

   Suppress with FLASHPASTE_QUIET=1 (matches the bash dispatcher's
   FLASHPASTE_QUIET semantics).

2. Re-assert clipboard ownership before each paste (paste.rs)
   Root cause of the user's symptom: between two pastes the user can
   copy text. The v1.19 OSC 52 path makes kitty the live Wayland
   owner with text/plain. The daemon's `latest_image` is still cached
   in memory but the *live* clipboard owner has changed. When the
   daemon dispatches send-text \026 and Claude calls
   `wl-paste -t image/png`, kitty serves the (text) selection and
   Claude reads 0 image bytes — silent no-op.

   Fix: bump the stage_notifier and sleep 40 ms before dispatch. That
   wakes the Wayland + X11 owner tasks; they re-claim the selection
   with the staged image bytes before the kitty send-text fires. On
   mutter (where wl-clipboard-rs's wlr-data-control claim is rejected
   outright — separate ext-data-control TODO), the X11 re-claim still
   succeeds and the wl-paste shim's xclip fallback delivers the
   image to Claude.

3. Bumped DEBUG → INFO for the daemon's paste lifecycle events
   `paste: request received`, `paste: dedupe …`, `paste: no staged
   image`, `paste: staged image too old` are now visible at the
   default RUST_LOG=info level via journalctl --user -fu flashpasted.
   That was the actual show-stopper for v1.19 debugging: the user's
   journalctl was silent because everything interesting was at debug.

Verified locally:
- `cargo build --release` clean (only pre-existing dead-code warnings)
- Smoke test: `flashpaste-trigger %1` writes a `start` then either
  `handled :: daemon` or `exec-bash :: daemon-declined` line to
  ~/.local/state/flashpaste-trigger.log; journalctl shows the
  matching `paste: request received` + decision.
- Daemon restarted on dev box; logs flowing as expected.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

Author: NagyVikt

examples/tmux.conf.snippet

@@ -42,10 +42,15 @@ bind -n C-v run-shell -b "TMUX_PASTE_TRIGGER=ctrl-v flashpaste-trigger '#{pane_i
 bind -n MouseDown2Pane run-shell -b "buf=$(sh -c '#{@paste}'); if [ -n \"$buf\" ]; then printf '%s' \"$buf\" | tmux load-buffer -b mid_paste - 2>/dev/null && tmux paste-buffer -d -p -b mid_paste -t '#{pane_id}' 2>/dev/null; fi"
 
 # Right-click pane menu with Paste item — same tier-3 trigger path.
+# Note: many tmux configs override this with `MouseUp3Pane`. If you
+# already have a custom right-click menu, just make sure its Paste item
+# invokes `flashpaste-trigger '#{pane_id}'` with the TMUX_PASTE_TRIGGER
+# env var so ~/.local/state/flashpaste-trigger.log can distinguish the
+# right-click path from the C-v path during debugging.
 bind -n MouseDown3Pane display-menu -O -x M -y M \
   -T "#[align=centre,fg=#FFFFFF,bold] pane #{pane_index} " \
   "#[fg=#34C759]↳ Paste" p \
-    "run-shell -b \"flashpaste-trigger '#{pane_id}' 2>/dev/null || /home/$USER/.local/bin/tmux-paste-dispatch.sh '#{pane_id}'\""
+    "run-shell -b \"TMUX_PASTE_TRIGGER=right-click-menu flashpaste-trigger '#{pane_id}' 2>/dev/null || TMUX_PASTE_TRIGGER=right-click-menu /home/$USER/.local/bin/tmux-paste-dispatch.sh '#{pane_id}'\""
 
 # Recursion-guard note: the C-v binding above intentionally re-invokes
 # the dispatcher when kitty `send-text` injects a \026 byte. The

rs/flashpaste-trigger/src/main.rs

@@ -98,7 +98,10 @@ fn main() -> ! {
     if args.stage_text {
         // Decoupled path — no pane needed, no bash fallback. The caller
         // (clipboard-set.sh) handles its own fallback if we exit non-zero.
-        std::process::exit(stage_text_main());
+        trigger_log("stage-text", "-", "start", "reading stdin");
+        let code = stage_text_main();
+        trigger_log("stage-text", "-", "exit", &format!("code={code}"));
+        std::process::exit(code);
     }
 
     let pane = match &args.pane {
@@ -109,16 +112,75 @@ fn main() -> ! {
         }
     };
 
+    let trigger_source = std::env::var("TMUX_PASTE_TRIGGER")
+        .unwrap_or_else(|_| "unset".to_string());
+    trigger_log("paste", &pane, "start", &format!("trigger={trigger_source}"));
+
     if args.force_fallback {
+        trigger_log("paste", &pane, "exec-bash", "force-fallback");
         exec_bash_fallback(&pane);
     }
 
     let paste_args = PasteArgs { pane: pane.clone(), op: args.op };
     match try_daemon(&paste_args) {
-        Ok(DaemonOutcome::Handled) => std::process::exit(0),
-        Ok(DaemonOutcome::FallbackRequested) => exec_bash_fallback(&pane),
-        Err(_) => exec_bash_fallback(&pane),
+        Ok(DaemonOutcome::Handled) => {
+            trigger_log("paste", &pane, "handled", "daemon");
+            std::process::exit(0);
+        }
+        Ok(DaemonOutcome::FallbackRequested) => {
+            trigger_log("paste", &pane, "exec-bash", "daemon-declined");
+            exec_bash_fallback(&pane);
+        }
+        Err(e) => {
+            trigger_log("paste", &pane, "exec-bash", &format!("daemon-error: {e}"));
+            exec_bash_fallback(&pane);
+        }
+    }
+}
+
+/// Per-invocation log written to `$FLASHPASTE_TRIGGER_LOG` or
+/// `~/.local/state/flashpaste-trigger.log`. The whole point of this log
+/// is debugging "right-click Paste doesn't paste but Ctrl+V does":
+/// every invocation appends one line so you can see when each handler
+/// fires, what the trigger source was, and which path the daemon chose.
+///
+/// Suppress with `FLASHPASTE_QUIET=1`.
+fn trigger_log(op: &str, pane: &str, phase: &str, detail: &str) {
+    if std::env::var_os("FLASHPASTE_QUIET").is_some() {
+        return;
+    }
+    let path = log_path();
+    if let Some(parent) = path.parent() {
+        let _ = std::fs::create_dir_all(parent);
+    }
+    let Ok(mut f) = std::fs::OpenOptions::new()
+        .create(true)
+        .append(true)
+        .open(&path)
+    else {
+        return;
+    };
+    let ts = iso8601_utc_now();
+    let pid = std::process::id();
+    let _ = writeln!(
+        f,
+        "{ts} pid={pid} op={op} pane={pane} phase={phase} :: {detail}"
+    );
+}
+
+fn log_path() -> PathBuf {
+    if let Ok(p) = std::env::var("FLASHPASTE_TRIGGER_LOG") {
+        if !p.is_empty() {
+            return PathBuf::from(p);
+        }
+    }
+    if let Ok(home) = std::env::var("HOME") {
+        return PathBuf::from(home)
+            .join(".local")
+            .join("state")
+            .join("flashpaste-trigger.log");
     }
+    PathBuf::from("/tmp/flashpaste-trigger.log")
 }
 
 struct PasteArgs {

rs/flashpasted/src/ipc.rs

@@ -157,16 +157,22 @@ async fn write_response(stream: &mut UnixStream, value: &Value) -> Result<()> {
 }
 
 async fn handle_paste(state: &Arc<SharedState>, pane: &str, started: Instant) -> Value {
+    info!(pane, "paste: request received");
+
     // ─── Recursion guard ─────────────────────────────────────────────
     // Fact #2 from the spec: tmux's `bind -n C-v` re-fires when the kitty
     // `send_text \026` byte reaches tmux. The trigger binary calls us
     // again; we dedupe based on the last-paste timestamp.
     let now = now_unix_ms();
     let last = state.last_paste_ms.load(Ordering::Relaxed);
     if now.saturating_sub(last) < RECURSION_DEDUPE_MS {
-        debug!(
+        // INFO not DEBUG: this fires every paste (the recursive C-v echo
+        // is normal) and v1.20 user-reported "right-click Paste does
+        // nothing" debugging needs this visible in journalctl.
+        info!(
+            pane,
             delta_ms = now - last,
-            "paste dedupe — within recursion window"
+            "paste: dedupe — within recursion window (this is normal for the C-v echo back from kitty send-text)"
         );
         return json!({ "ok": true, "deduped": true });
     }
@@ -181,15 +187,18 @@ async fn handle_paste(state: &Arc<SharedState>, pane: &str, started: Instant) ->
     let staged = match state.staged_image().await {
         Some(img) if img.is_fresh() => img,
         Some(_) => {
-            warn!("staged image too old; daemon punting to bash");
+            warn!(pane, "paste: staged image too old; punting to bash");
             return json!({
                 "ok": false,
                 "reason": "stale-image",
                 "fallback": "bash",
             });
         }
         None => {
-            debug!("no staged image (clipboard is empty or holds text); daemon punting to bash");
+            info!(
+                pane,
+                "paste: no staged image (clipboard empty or holds text); punting to bash"
+            );
             return json!({
                 "ok": false,
                 "reason": "no-image",

rs/flashpasted/src/paste.rs

@@ -21,7 +21,7 @@ use anyhow::{Context, Result};
 use tracing::{debug, info, warn};
 
 use crate::kitty;
-use crate::state::{SharedState, StagedImage};
+use crate::state::{now_unix_ms, SharedState, StagedImage};
 use crate::tmux;
 
 /// How long to wait before re-binding `C-v` in tmux. The bash dispatcher
@@ -54,6 +54,27 @@ pub async fn dispatch_image_paste(
     };
     debug!(kitty_sock = %kitty_sock.display(), "resolved kitty socket");
 
+    // Step 0: re-assert clipboard ownership.
+    //
+    // Why: between two pastes, the user can have copied text (the v1.19
+    // OSC 52 path makes kitty the live Wayland selection owner with
+    // text/plain bytes). The daemon's `latest_image` is still cached in
+    // memory, but the *live* clipboard owner has changed. When we
+    // send-text \026 and Claude calls `wl-paste -t image/png`, kitty
+    // serves the (text) selection — Claude reads 0 image bytes and
+    // silently does nothing. Symptom: "right-click → Paste doesn't
+    // paste the image; Ctrl+V right after a screenshot does."
+    //
+    // Bumping the stage notifier wakes the wayland.rs + x11.rs owner
+    // tasks, which re-claim the selection with the staged image bytes.
+    // The brief sleep lets the round-trip land before we send-text.
+    // On mutter where the Wayland claim is rejected outright (no
+    // ext-data-control / wlr-data-control), the X11 re-claim still
+    // succeeds and the wl-paste shim's xclip fallback picks it up.
+    info!(pane, "paste: re-asserting clipboard ownership before dispatch");
+    let _ = state.stage_notifier_tx.send(now_unix_ms());
+    tokio::time::sleep(Duration::from_millis(40)).await;
+
     // Step 1: select pane. Best-effort.
     tmux::select_pane(&pane).await;