From b782fb2731c55bac3e121be996d4296b7090c367 Mon Sep 17 00:00:00 2001 From: daniel-c-harvey Date: Sun, 9 Aug 2026 12:28:50 -0400 Subject: [PATCH] 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 | 1 + src/app/main.cpp | 34 +++++++++++++++++---- src/shell/undo/undo_block.cpp | 6 +++- src/shell/undo/undo_trace.cpp | 54 +++++++++++++++++++++++++++++++++ src/shell/undo/undo_trace.h | 29 ++++++++++++++++++ src/shell/view/fx_reclaim.cpp | 56 +++++++++++++++++++++++++++-------- src/shell/view/fx_reclaim.h | 6 +++- src/shell/view/view.cpp | 2 +- 8 files changed, 167 insertions(+), 21 deletions(-) create mode 100644 src/shell/undo/undo_trace.cpp create mode 100644 src/shell/undo/undo_trace.h diff --git a/src/app/CMakeLists.txt b/src/app/CMakeLists.txt index b340903..79ec27f 100644 --- a/src/app/CMakeLists.txt +++ b/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 diff --git a/src/app/main.cpp b/src/app/main.cpp index ef62f3a..3c6de88 100644 --- a/src/app/main.cpp +++ b/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 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() && - g_session.consumeLoadSignal()) { + // TEMPORARY: split into locals + if/else-if so the skip can be traced without + // 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); diff --git a/src/shell/undo/undo_block.cpp b/src/shell/undo/undo_block.cpp index 9f10d76..f7ab4b7 100644 --- a/src/shell/undo/undo_block.cpp +++ b/src/shell/undo/undo_block.cpp @@ -5,6 +5,7 @@ #include +#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) { diff --git a/src/shell/undo/undo_trace.cpp b/src/shell/undo/undo_trace.cpp new file mode 100644 index 0000000..59b2156 --- /dev/null +++ b/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 +#include +#include + +#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( + std::chrono::steady_clock::now().time_since_epoch()) + .count(); + return t0; +} + +double nowMs() { + return std::chrono::duration( + 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 diff --git a/src/shell/undo/undo_trace.h b/src/shell/undo/undo_trace.h new file mode 100644 index 0000000..844db35 --- /dev/null +++ b/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# ms \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 diff --git a/src/shell/view/fx_reclaim.cpp b/src/shell/view/fx_reclaim.cpp index fc6979c..6c14e4c 100644 --- a/src/shell/view/fx_reclaim.cpp +++ b/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 block of the diff --git a/src/shell/view/fx_reclaim.h b/src/shell/view/fx_reclaim.h index e131fea..f7fc070 100644 --- a/src/shell/view/fx_reclaim.h +++ b/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 diff --git a/src/shell/view/view.cpp b/src/shell/view/view.cpp index 7a2fe9a..48300cc 100644 --- a/src/shell/view/view.cpp +++ b/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