Add temporary undo-span tracing for the mid-drain Ctrl-Z bug

One switch (REASAMPLER_UNDO_TRACE) gates every line. Traces span open/close
reasons, FX writes, UndoBlock depth, timer standoffs, and load-state hooks.

src/app/CMakeLists.txt

@@ -39,6 +39,7 @@ add_library(reaper_reasampler MODULE
     ${LICE_SRC}
     ${REASAMPLER_SRC_DIR}/shell/capture/insert.cpp
     ${REASAMPLER_SRC_DIR}/shell/undo/undo_block.cpp
+    ${REASAMPLER_SRC_DIR}/shell/undo/undo_trace.cpp
     ${REASAMPLER_SRC_DIR}/shell/view/view.cpp
     ${REASAMPLER_SRC_DIR}/shell/view/fx_reclaim.cpp
     ${REASAMPLER_SRC_DIR}/shell/view/view_lanes.cpp

src/app/main.cpp

@@ -38,6 +38,7 @@
 #include "shell/panel/panel_input.h"             // bankPanelRefresh / bankPanelNotifyProjectLoaded
 #include "shell/panel/panel_window.h"            // panel lifecycle (init/toggle/open-query/shutdown)
 #include "shell/persist/session.h"               // ReaSamplerSession
+#include "shell/undo/undo_trace.h"               // TEMPORARY — see undo_trace.h; revert together
 #include "shell/view/fx_reclaim.h"               // the FX reclaimer's tick
 #include "shell/view/view.h"                     // applyMode
 #include "shell/view/view_lanes.h"               // reconcileManagedLanes
@@ -183,6 +184,12 @@ static void OnTimer()
     // the idle fast-path is a SINGLE POINTER TEST — drive only when a capture is live.
     if (capture::g_rtCapture) capture::DriveRealtimeCapture(g_session);
 
+    // TEMPORARY: captured in a local (rather than calling GetCurrentProjectInLoadSave()
+    // twice) so the trace can report the value on every tick, standoff or not, with no
+    // change to the call below. See undo_trace.h.
+    ReaProject* const loadSaveProj = GetCurrentProjectInLoadSave();
+    REASAMPLER_TRACE("[Timer] loadSaveProj=%p", (void*)loadSaveProj);
+
     // A project load or save is IN FLIGHT, so this tick is running inside its own message
     // pump — a restore brings plugins online and a plugin load pumps. Everything below
     // would then act on a half-restored project: poll() reads the pre-load <EXTSTATE> that
@@ -192,7 +199,10 @@ static void OnTimer()
     // the first tick after the load runs as if this one had never been due. Self-lowering
     // (reaper_plugin_functions.h:1584-1587), and placed after the realtime drive so that
     // fast path keeps its single-pointer-test shape. See src/shell/view/CLAUDE.md.
-    if (GetCurrentProjectInLoadSave()) return;
+    if (loadSaveProj) {
+        REASAMPLER_TRACE("[Timer] STANDOFF guard=loadSaveProj");
+        return;
+    }
 
     // poll()'s undo/redo-reload and project-switch Load branches call
     // loadFromProject, replacing g_session.view() wholesale — deferred here while
@@ -202,8 +212,13 @@ static void OnTimer()
     // cheap to skip for one tick and resumes correctly, unlatched, on the next.
     // The reclaim drain is latched for the same reason and is the same window: it
     // holds that view model for the length of a plugin unload, which pumps.
-    if (!reasampler::modeApplyInProgress() && !reasampler::fxReclaimDrainInProgress())
+    if (!reasampler::modeApplyInProgress() && !reasampler::fxReclaimDrainInProgress()) {
         g_session.poll();
+    } else {
+        REASAMPLER_TRACE("[Timer] SKIP-POLL modeApply=%d drain=%d",
+                          reasampler::modeApplyInProgress() ? 1 : 0,
+                          reasampler::fxReclaimDrainInProgress() ? 1 : 0);
+    }
 
     // persist stays MODEL-ONLY (loads the saved view model but does not apply
     // visibility, to avoid coupling persist to the view shell); poll() raises a
@@ -216,8 +231,15 @@ static void OnTimer()
     // signal is one-shot, a re-entered applyMode fails closed, and a reapply dropped here
     // is the saved mode never applied at all. Holding the whole block back one tick also
     // keeps the panel re-arm ahead of the reapply.
-    if (!reasampler::modeApplyInProgress() && !reasampler::fxReclaimDrainInProgress() &&
+    // TEMPORARY: split into locals + if/else-if so the skip can be traced without
-        g_session.consumeLoadSignal()) {
+    // calling consumeLoadSignal() (which has a side effect) a second time — same
+    // short-circuit semantics as the original single `if`. See undo_trace.h.
+    const bool loadGateModeApply = reasampler::modeApplyInProgress();
+    const bool loadGateDraining  = reasampler::fxReclaimDrainInProgress();
+    if (loadGateModeApply || loadGateDraining) {
+        REASAMPLER_TRACE("[Timer] SKIP-LOAD modeApply=%d drain=%d", loadGateModeApply ? 1 : 0,
+                          loadGateDraining ? 1 : 0);
+    } else if (g_session.consumeLoadSignal()) {
         reasampler::bankPanelNotifyProjectLoaded();
         // Reconcile lane ownership against the live project's lanes (P_LANENAME,
         // the cross-session source of truth) BEFORE reapplying visibility. Never
@@ -257,6 +279,8 @@ static void OnTimer()
 // forked-sibling re-GUID branch requesting a reload here would bypass.
 static void OnBeginLoadProjectState(bool isUndo, project_config_extension_t* /*reg*/)
 {
+    REASAMPLER_TRACE("[Load] BeginLoadProjectState isUndo=%d", isUndo ? 1 : 0);
+
     // UNBRANCHED, and the reason the terminator is a hook at all: this is REAPER's one
     // entry for a state load — "project load/undo", plus a new project
     // (reaper_plugin.h:1203-1205) — and the last moment before the restore. Why that
@@ -343,7 +367,7 @@ extern "C" REAPER_PLUGIN_DLL_EXPORT int REAPER_PLUGIN_ENTRYPOINT(
 
             // Same reason, for the reclaimer's undo span: a block left open here has no
             // owner left to close it and would swallow every edit the user makes after.
-            reasampler::fxReclaimEndUndoSpan();
+            reasampler::fxReclaimEndUndoSpan("extension unload");
 
             g_rec->Register("-timer", (void*)&OnTimer);
             g_rec->Register("-projectconfig", (void*)&g_projectConfig);

src/shell/undo/undo_block.cpp

@@ -5,6 +5,7 @@
 
 #include <utility>
 
+#include "shell/undo/undo_trace.h"  // TEMPORARY — see undo_trace.h; revert together
 #include "shell/view/fx_reclaim.h"  // fxReclaimEndUndoSpan — the span this must not nest over
 
 #define REAPERAPI_MINIMAL
@@ -40,12 +41,13 @@ UndoBlock::UndoBlock(ReaProject* proj) : project_(proj) {
     // outermost. Roll the depth back on any throw so the type degrades to "this one
     // block failed to open," not "every block after it is now poisoned."
     try {
-        if (g_depth++ == 0) fxReclaimEndUndoSpan();
+        if (g_depth++ == 0) fxReclaimEndUndoSpan("UndoBlock ctor");
         Undo_BeginBlock2(proj);
     } catch (...) {
         --g_depth;
         throw;
     }
+    REASAMPLER_TRACE("[UndoBlock] CTOR proj=%s depth=%d", proj ? "real" : "active", g_depth);
 }
 
 UndoBlock::~UndoBlock() {
@@ -63,6 +65,8 @@ UndoBlock::~UndoBlock() {
     if (!project_ || ValidatePtr2(nullptr, project_, "ReaProject*"))
         Undo_EndBlock2(project_, label_.c_str(), mask_);
     --g_depth;
+    REASAMPLER_TRACE("[UndoBlock] DTOR label=\"%s\" mask=%d depth=%d",
+                      label_.empty() ? "(discard)" : label_.c_str(), mask_, g_depth);
 }
 
 void UndoBlock::recordPoint(std::string label, int mask) {

src/shell/undo/undo_trace.cpp

@@ -0,0 +1,54 @@
+// See undo_trace.h. Compiled into the reaper_reasampler module; includes
+// reaper_plugin_functions.h without REAPERAPI_IMPLEMENT (main.cpp owns that). Isolated
+// in its own TU so every call site needs only the trace-only header, not the REAPER
+// ShowConsoleMsg want-define.
+
+#include "shell/undo/undo_trace.h"
+
+#if REASAMPLER_UNDO_TRACE
+
+#include <chrono>
+#include <cstdarg>
+#include <cstdio>
+
+#define REAPERAPI_MINIMAL
+#define REAPERAPI_WANT_ShowConsoleMsg
+#include "reaper_plugin_functions.h"
+
+namespace reasampler {
+
+namespace {
+
+unsigned long long g_seq = 0;
+
+double startMs() {
+    static const double t0 = std::chrono::duration<double, std::milli>(
+                                  std::chrono::steady_clock::now().time_since_epoch())
+                                  .count();
+    return t0;
+}
+
+double nowMs() {
+    return std::chrono::duration<double, std::milli>(
+               std::chrono::steady_clock::now().time_since_epoch())
+               .count() -
+           startMs();
+}
+
+}  // namespace
+
+void undoTrace(const char* fmt, ...) {
+    char body[256];
+    va_list args;
+    va_start(args, fmt);
+    std::vsnprintf(body, sizeof(body), fmt, args);
+    va_end(args);
+
+    char line[320];
+    std::snprintf(line, sizeof(line), "!SHOW:#%llu %.0fms %s\n", ++g_seq, nowMs(), body);
+    ShowConsoleMsg(line);
+}
+
+}  // namespace reasampler
+
+#endif  // REASAMPLER_UNDO_TRACE

src/shell/undo/undo_trace.h

@@ -0,0 +1,29 @@
+#pragma once
+// TEMPORARY diagnostic tracing for the Design-View undo-span bug (many-undo-entries-on-
+// Ctrl-Z-mid-drain). NOT for shipping. ONE switch below gates every trace line in the
+// tree; flip REASAMPLER_UNDO_TRACE to 0, or delete this file pair plus the call sites
+// that include it, to revert.
+#define REASAMPLER_UNDO_TRACE 1
+
+#if REASAMPLER_UNDO_TRACE
+
+namespace reasampler {
+
+// Emits one line via ShowConsoleMsg: "UT#<seq> <ms>ms <fmt...>\n", "!SHOW:"-prefixed so
+// a trace point on a background tick never forces the console open. printf-style;
+// sequence number and a monotonic millisecond timestamp are stamped here so lines sort
+// and date themselves even pasted back out of order. Keep each `fmt` short — this has to
+// read at a glance in REAPER's console.
+void undoTrace(const char* fmt, ...);
+
+}  // namespace reasampler
+
+#define REASAMPLER_TRACE(...) ::reasampler::undoTrace(__VA_ARGS__)
+
+#else
+
+#define REASAMPLER_TRACE(...) \
+    do {                      \
+    } while (0)
+
+#endif

src/shell/view/fx_reclaim.cpp

@@ -12,6 +12,7 @@
 
 #include "shell/persist/session.h"  // flushViewState — the release's durable half
 #include "shell/undo/undo_block.h"  // undoBlockOpen — the reverse of the nesting rule
+#include "shell/undo/undo_trace.h"  // TEMPORARY — see undo_trace.h; revert together
 #include "shell/view/view.h"        // modeApplyInProgress, transportBlocksModeSwitch
 #include "shell/view/view_park.h"   // fxGuidString — the one FX-identity read
 #include "shell/view/view_tracks.h"
@@ -46,11 +47,17 @@ UndoSpan g_span;
 // unconditionally; the close reads the span's values before clearing it, because the
 // clear has to precede the SDK call — nothing re-entered through Undo_EndBlock2 may
 // find a span it could close a second time.
-void openSpan(ReaProject* proj, const char* label, int mask) {
+//
-    if (g_span.begin(proj, label, mask)) Undo_BeginBlock2(proj);
+// `caller`/`reason` are TEMPORARY tracing plumbing only (see shell/undo/undo_trace.h) —
+// they select nothing and gate nothing.
+void openSpan(ReaProject* proj, const char* label, int mask, const char* caller) {
+    if (g_span.begin(proj, label, mask)) {
+        Undo_BeginBlock2(proj);
+        REASAMPLER_TRACE("[UndoSpan] OPEN caller=%s label=\"%s\" mask=%d", caller, label, mask);
+    }
 }
 
-void closeSpan() {
+void closeSpan(const char* reason) {
     if (!g_span.open()) return;
     ReaProject* const proj  = g_span.project();
     const std::string label = g_span.label();
@@ -59,6 +66,8 @@ void closeSpan() {
     // The span outlives its opener, so by here the project may be the one that just
     // closed — its undo history went with it and there is no block left to end.
     if (ValidatePtr2(nullptr, proj, "ReaProject*")) Undo_EndBlock2(proj, label.c_str(), mask);
+    REASAMPLER_TRACE("[UndoSpan] CLOSE reason=%s label=\"%s\" mask=%d",
+                      reason, label.empty() ? "(discard)" : label.c_str(), mask);
 }
 
 // Monotonic and sub-millisecond: the drain's budget discriminates at 30ms, which
@@ -171,9 +180,12 @@ struct ReclaimHost {
         // no-op under a switch's span, which is why the FX bit is added separately —
         // here, at the first real write, so a switch whose parking never matured closes
         // on the flags-and-items mask it opened with and serializes no FX state.
-        openSpan(project, kReclaimUndoLabel, UNDO_STATE_FX);
+        const bool spanWasOpenBeforeWrite = g_span.open();
+        openSpan(project, kReclaimUndoLabel, UNDO_STATE_FX, "drain");
         g_span.widen(UNDO_STATE_FX);
         TrackFX_SetOffline(tr, fxIndex, offline);
+        REASAMPLER_TRACE("[writeOffline] track=%s fx=%d offline=%d spanWasOpen=%d",
+                          guid.c_str(), fxIndex, offline ? 1 : 0, spanWasOpenBeforeWrite ? 1 : 0);
         return true;
     }
 
@@ -241,10 +253,16 @@ bool fxReclaimDrainInProgress() { return g_draining; }
 void fxReclaimTick(ReaSamplerSession& session, ReaProject* proj) {
     // NO guard here may close the span: each names a caller that is still on the stack and
     // still owns it — the outer drain, or the applyMode that opened it. All re-tick.
-    if (g_draining) return;
+    if (g_draining) {
+        REASAMPLER_TRACE("[Tick] STANDOFF guard=g_draining");
+        return;
+    }
     // The model is mid-rewrite and its records are being consumed out from under any
     // plan derived from it. The apply invalidates on its way out, so nothing is lost.
-    if (modeApplyInProgress()) return;
+    if (modeApplyInProgress()) {
+        REASAMPLER_TRACE("[Tick] STANDOFF guard=modeApplyInProgress");
+        return;
+    }
     // The MIRROR of the rule that no block may open over the span: an extension undo
     // block is open — a capture, a bank verb, an ingest — and its own message pump is how
     // this tick arrived. openSpan from in there would begin at depth 2, and that block's
@@ -256,7 +274,10 @@ void fxReclaimTick(ReaSamplerSession& session, ReaProject* proj) {
     // claim is this function's own control-flow order — this TU is REAPER-linked, off the
     // pure fx_reclaim_tests target, so unlike the queue/span state machine above it, the
     // ordering is DAW-verified, not unit-tested.
-    if (undoBlockOpen()) return;
+    if (undoBlockOpen()) {
+        REASAMPLER_TRACE("[Tick] STANDOFF guard=undoBlockOpen");
+        return;
+    }
     DrainLatch latch;
 
     // beginTick owns what a pin/project mismatch means. What is local to here: the model
@@ -270,7 +291,8 @@ void fxReclaimTick(ReaSamplerSession& session, ReaProject* proj) {
     // rather than the queue's pin, which moves independently: a tab switch, a closed
     // project, or no active project at all ends it where it stands rather than carrying
     // it into another project's history — and the no-project arm below returns.
-    if (g_span.open() && g_span.project() != project) closeSpan();
+    if (g_span.open() && g_span.project() != project)
+        closeSpan(project ? "project retarget" : "no active project");
     if (!g_queue.beginTick(project)) return;
 
     // DERIVED, never persisted: recomputed from view state every time the queue was
@@ -284,19 +306,26 @@ void fxReclaimTick(ReaSamplerSession& session, ReaProject* proj) {
     ReclaimHost host{project, &session};
     const ReclaimRunResult run = g_queue.run(host);
     reportDrops(project, run.drops);
-    if (spanEndsAfter(run)) closeSpan();
+    if (spanEndsAfter(run)) {
+        // Priority order for the trace label only, when more than one is true at once —
+        // does not affect which branch runs; spanEndsAfter already decided that.
+        const char* reason = run.aborted            ? "drain aborted"
+                              : run.transportDeferred ? "transport-deferred"
+                                                       : "drain settled";
+        closeSpan(reason);
+    }
     if (!run.aborted && run.settled) g_queue.goIdle();
 }
 
 void fxReclaimBeginUndoSpan(ReaProject* proj) {
-    openSpan(proj, "", 0);
+    openSpan(proj, "", 0, "action");
 }
 
 void fxReclaimLabelUndoSpan(const char* label, int mask) {
     g_span.relabel(label ? label : "", mask);
 }
 
-void fxReclaimEndUndoSpan() { closeSpan(); }
+void fxReclaimEndUndoSpan(const char* reason) { closeSpan(reason); }
 
 void fxReclaimAbandonForStateLoad() {
     // Close FIRST and unconditionally. The abandon below stops the drain and puts the loop
@@ -306,7 +335,8 @@ void fxReclaimAbandonForStateLoad() {
     // confirmed case of that shape on the save side) — the span can never be open at depth
     // > 0 in the first place: src/shell/view/CLAUDE.md's "NOTHING MAY OPEN AN UNDO BLOCK
     // WHILE THE SPAN IS OPEN" invariant. closeSpan() just finds nothing to close there.
-    closeSpan();
+    REASAMPLER_TRACE("[abandon] spanOpen=%d", g_span.open() ? 1 : 0);
+    closeSpan("state load");
     g_queue.abandon();
 }
 
@@ -322,7 +352,7 @@ void fxReclaimFlushRelease(ReaSamplerSession& session) {
     // absorb, and the arm is not what decides whether one is open. Same "depth > 0 never
     // holds an open span" invariant as fxReclaimAbandonForStateLoad above makes this safe
     // even when the save itself is issued from inside an extension UndoBlock.
-    closeSpan();
+    closeSpan("project save");
     if (!g_releaseFlush.pendingFor(saving)) return;
     // Promptless, unlike design_view_actions' persistViewState, which can open a modal
     // Save-As. [verify — DAW] whether this write reaches the <EXTSTATE> block of the

src/shell/view/fx_reclaim.h

@@ -698,7 +698,11 @@ void fxReclaimLabelUndoSpan(const char* label, int mask);
 // unload; and shell/undo's UndoBlock, at its OUTERMOST open. A leaked open block would
 // swallow everything the user does afterwards, so nothing may return past a terminating
 // condition without calling this.
-void fxReclaimEndUndoSpan();
+//
+// `reason` is TEMPORARY tracing plumbing (see shell/undo/undo_trace.h) naming which
+// terminating path called — it has no effect on behavior. Revert together with the rest
+// of the undo-span tracing pass.
+void fxReclaimEndUndoSpan(const char* reason);
 
 // EVERY project-state load, undo-driven or not — Ctrl-Z, Ctrl-Shift-Z, a project open, a
 // File > Revert, a new project. Ends the span, stops any drain on the stack, drops the

src/shell/view/view.cpp

@@ -126,7 +126,7 @@ ModeApplyResult applyModeImpl(ViewModeModel& model, const std::string& targetMod
     // opens a block ends the span itself, first, at depth 0 — see this directory's
     // CLAUDE.md. Both calls are idempotent; do not reintroduce either unconditionally.
     if (realSwitch) {
-        fxReclaimEndUndoSpan();
+        fxReclaimEndUndoSpan("next apply supersedes");
         // BEFORE the open, never after this function returns. The wakeup is what
         // guarantees a tick, and a tick is the only thing that can close this span; a
         // throw anywhere below would otherwise leave the block open with the reclaimer