Skip to content

Commit c204856

Browse files
dwertheimerclaude
andcommitted
nplog 1.3.0: make --plugin startup navigable; fix two hidden-boundary bugs
Reported: load --plugin, wait, trigger a command, press an arrow -- "no run boundaries". Reproduced, and it was two separate bugs plus a missing affordance. 1. Idle gaps were measured against stamps[i-1] strictly. nplog's own notices carry no timestamp, and NaN on either side of the subtraction makes the delta NaN -- so the lull SPANNING a notice was invisible. That killed precisely the boundary that matters: the reset notice sits between the old run's last line and the new run's first, so the gap separating them never registered. Now measured against the nearest real timestamp via prevFiniteStamp(), which walks past stampless entries (bounded, so it can't go quadratic). 2. buildRows()'s anti-stacking guard suppressed any rule sitting directly below another. That was correct when only run/idle rules were `sep` rows, but 1.1.2 made notices rules too -- so the reset notice silently swallowed the idle rule for the gap right after it. They now merge into one navigable rule carrying both facts: "_MCP-console.log was reset by NotePlan (new run) ... 1h40m idle". 3. Whatever is already in _MCP-console.log at startup is the tail of a run that began before nplog did. That's now book-ended: a rule for where retained output starts (nothing earlier survives NotePlan's overwrite) and one for "nplog started watching here -- <clock>". The latter is a navigable boundary, so the arrows have somewhere useful to land even before the first reset. pushNotice() gained a boundary flag, carried in the line text alongside the existing sentinel rather than in a parallel array -- same reasoning as before (see the ^L desync in 1.1.1). Verified in pty tests: the reported scenario now yields run 2/2 (the merged reset+idle rule) and run 1/2 (watch start); the pre-existing 4-run idle navigation still steps correctly in both directions; main-log --json output is unchanged. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
1 parent 51e27b7 commit c204856

4 files changed

Lines changed: 144 additions & 26 deletions

File tree

‎scripts/nplog/AGENTS.md‎

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -246,6 +246,20 @@ timestamps, suspect a stamps/lines desync before suspecting `separatorForRange()
246246
misleading. If you add another notice type, leave `boundary` off it unless it genuinely
247247
marks the start of a run.
248248

249+
Two traps that both hid boundaries, worth knowing because neither looks like a boundary bug:
250+
251+
- **Gaps must be measured against the nearest *real* timestamp, not `stamps[i-1]`.** Notices
252+
carry no timestamp (`NaN`), and `NaN` on either side of a subtraction makes the delta `NaN`,
253+
so the lull *spanning* a notice vanished. That killed exactly the boundary you most want: the
254+
one between the pre-reset run and the post-reset run, with the reset notice sitting in the
255+
middle. `prevFiniteStamp()` walks back past stampless entries (capped, so it can't go
256+
quadratic).
257+
- **The anti-stacking guard in `buildRows()` must not suppress a boundary behind a notice.** It
258+
originally read `if (sep && !(prevRow && prevRow.sep))`, which was right when only run/idle
259+
rules were `sep` rows — but notices became `sep` rows too, so a reset notice silently ate the
260+
idle rule for the gap right after it. They now merge: the notice row is upgraded to
261+
`boundary: true` and the idle/clock detail is appended to its label.
262+
249263
`jumpToBoundary()` keeps its own `lastBoundaryRow` rather than reading `state.scroll` back,
250264
because a boundary inside the final page can't reach the top -- render clamps scroll to
251265
`maxScroll`. Measuring the next jump from the clamped position would silently skip that

‎scripts/nplog/CHANGELOG.md‎

Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,30 @@ All notable changes to `nplog` are documented here. Versions follow
44
[Semantic Versioning](https://semver.org/): MAJOR for breaking CLI/output changes, MINOR for
55
new features, PATCH for fixes. Check the current version with `nplog --version`.
66

7+
## [1.3.0] - 2026-07-30
8+
9+
Startup in `--plugin` mode is a common case that read badly: the file already contains the tail
10+
of a run that began before nplog did, and `←`/`→` reported no boundaries even after triggering a
11+
command. Three fixes, two of them real bugs:
12+
13+
- **`--plugin` now book-ends the seeded history.** A rule marks where the retained output starts
14+
(NotePlan overwrites the file each run, so nothing earlier survives) and another marks
15+
`nplog started watching here -- <clock>`. The second is a navigable boundary, so `←` has
16+
somewhere useful to land immediately — "show me only what I actually watched" — rather than
17+
reporting nothing at all.
18+
- **Fixed: a lull spanning an entry with no timestamp went undetected.** Idle gaps compared
19+
strictly against the immediately-preceding entry, so a `NaN` stamp on either side produced a
20+
`NaN` delta. nplog's own notices carry no timestamp, which meant the notice sitting between a
21+
`--plugin` reset and the new run's first line hid the single most useful boundary in the
22+
buffer. Gaps are now measured against the nearest real timestamp, walking past stampless
23+
entries.
24+
- **Fixed: a notice rule swallowed the boundary immediately after it.** The anti-stacking guard
25+
in `buildRows()` suppressed a rule whenever one already sat directly above — correct for two
26+
run/idle rules, but since 1.1.2 notices are rules too, so the reset notice silently ate the
27+
idle rule for the very gap that separates the old run from the new one. They now **merge**
28+
into one navigable rule carrying both facts:
29+
`─── _MCP-console.log was reset by NotePlan (new run) 2026-07-30 17:40:36 1h40m idle ───`
30+
731
## [1.2.0] - 2026-07-30
832

933
- **`←` / `→` jump between run boundaries**, scrolling the previous/next one to the top of the

‎scripts/nplog/README.md‎

Lines changed: 23 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -274,12 +274,16 @@ The footer shows where you landed:
274274

275275
`←` goes back in time, `→` forward. Both stop at the ends rather than wrapping, and say so.
276276

277-
Only the [run and idle rules](#run-separators) count as boundaries. The `--plugin` mode
278-
[reset notice](#--plugin-fastest-data-for-one-plugin) deliberately does **not** — NotePlan
279-
rewriting `_MCP-console.log` is a file-truncation artifact, and it doesn't reliably line up
280-
with a new run, so jumping to one would land you somewhere misleading. In `--plugin` mode that
281-
leaves idle lulls as the only boundaries, since
282-
[named-run rules never appear there](#--plugin-fastest-data-for-one-plugin).
277+
Only the [run and idle rules](#run-separators) count as boundaries — plus the
278+
`nplog started watching here` rule in `--plugin` mode, so there's always somewhere to land even
279+
before the first reset. A bare `--plugin` reset notice deliberately does **not** count on its
280+
own: NotePlan rewriting `_MCP-console.log` is a file-truncation artifact that doesn't reliably
281+
line up with a new run. When a reset *does* coincide with a real idle gap — which is the normal
282+
case when you trigger a command — the two merge into one navigable rule carrying both facts:
283+
284+
```
285+
───── _MCP-console.log was reset by NotePlan (new run) 2026-07-30 17:40:36 1h40m idle ─────
286+
```
283287

284288
A boundary inside the final page can't literally reach the top — there aren't enough rows below
285289
it — so the view stops at the bottom while the footer still names the boundary you asked for.
@@ -499,6 +503,19 @@ or asks once if it can't tell, and remembers the answer in `~/.config/nplog/conf
499503
`NPLOG_APP_SUPPORT_DIR` yourself to override it (or skip `install.sh` and let auto-detection
500504
run every time).
501505

506+
**What you see on startup.** The file already holds the tail of a run that began before nplog
507+
did, so that seeded content is book-ended to make it legible rather than looking like a normal
508+
complete run:
509+
510+
```
511+
───── start of retained output -- NotePlan overwrites this file each run, so nothing earlier survives ─────
512+
… whatever was already in the file …
513+
───── nplog started watching here -- 2026-07-30 17:40:31 ─────
514+
```
515+
516+
The second rule is a [jump target](#jumping-between-runs), so `←` gets you to "only what I
517+
actually watched" straight away.
518+
502519
If the plugin hasn't logged anything yet this session, `nplog` warns rather than erroring,
503520
and keeps watching for the file to appear:
504521

‎scripts/nplog/nplog‎

Lines changed: 83 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -87,7 +87,7 @@ const PLUGINS_DIR = path.join(CONTAINER_DIR, 'Plugins')
8787
// there and missing here. The main log is a strict superset and the only ground truth.
8888

8989
// Bump this and add a matching entry to CHANGELOG.md for any user-visible change.
90-
const VERSION = '1.2.0'
90+
const VERSION = '1.3.0'
9191

9292
const MAX_LINES = 50000 // ring-buffer cap; ~50k lines keeps memory modest
9393
const CONTEXT_MODES = [0, 1, 5, 10] // 0 == matched lines only
@@ -342,17 +342,29 @@ function pushLine(text, stampMs) {
342342
// array, deliberately: a second index-parallel array is exactly the shape
343343
// that produced the ^L stamps/lines desync bug (see AGENTS.md), and text
344344
// can't drift out of sync with itself. NUL never appears in log output, so
345-
// it's safe as a sentinel; strip it with noticeLabel() anywhere the text
345+
// it's safe as a sentinel; strip it with parseNotice() anywhere the text
346346
// escapes to a consumer (JSON, etc).
347347
const NOTICE_PREFIX = '\u0000notice\u0000'
348348

349-
function pushNotice(label) {
350-
pushLine(NOTICE_PREFIX + label)
349+
// Layout after the sentinel: one flag char ('B' = navigable boundary, '-' =
350+
// not) then the label. The flag rides along in the text for the same reason
351+
// the sentinel does -- no parallel array to fall out of sync.
352+
//
353+
// boundary=true only for notices that genuinely mark "a new stretch of work
354+
// starts here" and so are worth landing on with the arrow keys. A
355+
// _MCP-console.log reset is NOT one: it's a NotePlan file-rewrite artifact
356+
// that doesn't reliably coincide with a run.
357+
function pushNotice(label, boundary) {
358+
pushLine(NOTICE_PREFIX + (boundary ? 'B' : '-') + label)
351359
}
352360

353-
// Returns the human-readable label if `text` is a notice, else null.
354-
function noticeLabel(text) {
355-
return text.startsWith(NOTICE_PREFIX) ? text.slice(NOTICE_PREFIX.length) : null
361+
// Returns {label, boundary} if `text` is one of nplog's notices, else null.
362+
function parseNotice(text) {
363+
if (!text.startsWith(NOTICE_PREFIX)) return null
364+
return {
365+
boundary: text.charAt(NOTICE_PREFIX.length) === 'B',
366+
label: text.slice(NOTICE_PREFIX.length + 1),
367+
}
356368
}
357369

358370
const INDENT_UNIT = 2 // spaces per nesting level
@@ -567,6 +579,28 @@ function separatorClock(ms) {
567579
return `${d.getFullYear()}-${p(d.getMonth() + 1)}-${p(d.getDate())} ${p(d.getHours())}:${p(d.getMinutes())}:${p(d.getSeconds())}`
568580
}
569581

582+
// Not every entry has a parseable timestamp -- nplog's own notices carry
583+
// none, and neither does anything logged before the first timestamped line.
584+
// Comparing strictly against stamps[i-1] made a NaN on either side produce a
585+
// NaN delta, so a real lull *spanning* such an entry went undetected. That
586+
// bit hardest exactly where it mattered most: across a --plugin reset the
587+
// notice sits between the old run's last line and the new run's first, which
588+
// hid the single most useful boundary in the buffer. Walk back to the nearest
589+
// real stamp instead, so the gap is measured across the gap-less entry.
590+
//
591+
// Bounded because the scan is per-entry: a long stretch of stampless lines
592+
// would otherwise make this quadratic. Past the cap there is no usable
593+
// reference anyway, so reporting "no gap" is the honest answer.
594+
const MAX_STAMP_BACKSCAN = 50
595+
596+
function prevFiniteStamp(i) {
597+
const floor = Math.max(0, i - MAX_STAMP_BACKSCAN)
598+
for (let k = i; k >= floor; k--) {
599+
if (Number.isFinite(stamps[k])) return stamps[k]
600+
}
601+
return NaN
602+
}
603+
570604
// What run/idle boundary falls in buffer entries [from..to], or null.
571605
//
572606
// A range rather than a single entry, because with a filter applied the run
@@ -591,7 +625,7 @@ function separatorForRange(from, to) {
591625
runIndex = i
592626
}
593627
if (state.idleGapMs > 0 && i > 0) {
594-
const delta = stamps[i] - stamps[i - 1]
628+
const delta = stamps[i] - prevFiniteStamp(i - 1)
595629
// widest lull in the range, so a filtered view reports the real one
596630
if (Number.isFinite(delta) && delta >= state.idleGapMs && delta > idleMs) idleMs = delta
597631
}
@@ -669,24 +703,38 @@ function buildRows() {
669703
}
670704
const sep = seps[i]
671705
const prevRow = rows.length > 0 ? rows[rows.length - 1] : null
672-
if (sep && !(prevRow && prevRow.sep)) {
673-
// A labelled rule says everything the anonymous skipped-lines rule does
674-
// and more, so replace rather than stack the two.
675-
if (prevRow && prevRow.gap) rows.pop()
706+
if (sep) {
676707
// `boundary` marks the rules that represent a real break in the work --
677708
// an idle lull or an "Executing function" run start. That's what ←/→
678-
// navigate between. Deliberately NOT set on the notice rows below: an
709+
// navigate between. Notice rows (below) don't get it on their own: an
679710
// _MCP-console.log reset is a NotePlan file-rewrite artifact, not a
680-
// reliable indicator that a new run began, so jumping to one would land
681-
// you somewhere misleading.
682-
rows.push({ sep: true, boundary: true, label: [sep.clock, sep.idle, sep.runText].filter(Boolean).join(' ') })
711+
// reliable indicator that a new run began.
712+
const label = [sep.clock, sep.idle, sep.runText].filter(Boolean).join(' ')
713+
if (prevRow && prevRow.sep) {
714+
// A rule already sits here, so don't stack a second one -- but don't
715+
// silently drop this boundary either. That combination is exactly
716+
// what a --plugin reset produces: the reset notice lands first and
717+
// used to swallow the idle rule for the very gap that separates the
718+
// old run from the new one, leaving the most useful boundary in the
719+
// buffer unreachable with ←/→. Fold the detail into the existing rule
720+
// and let it become navigable instead.
721+
if (!prevRow.boundary) {
722+
prevRow.boundary = true
723+
if (label) prevRow.label = prevRow.label ? `${prevRow.label} ${label}` : label
724+
}
725+
} else {
726+
// A labelled rule says everything the anonymous skipped-lines rule
727+
// does and more, so replace rather than stack the two.
728+
if (prevRow && prevRow.gap) rows.pop()
729+
rows.push({ sep: true, boundary: true, label })
730+
}
683731
}
684732
// The rule already displays this entry's text, so don't repeat it below.
685733
if (sep && sep.runIndex === item.index) continue
686734
// nplog's own stream-boundary notices render as rules, not as log text.
687-
const notice = noticeLabel(item.text)
735+
const notice = parseNotice(item.text)
688736
if (notice !== null) {
689-
rows.push({ sep: true, label: notice })
737+
rows.push({ sep: true, boundary: notice.boundary, label: notice.label })
690738
continue
691739
}
692740
if (item.text.indexOf('\n') === -1) {
@@ -1472,7 +1520,7 @@ function streamPending(flush) {
14721520
run: streamRun || null,
14731521
// notice lines are nplog's own, not the plugin's -- emit the label
14741522
// without the internal sentinel so consumers never see it
1475-
text: noticeLabel(text) ?? text,
1523+
text: (parseNotice(text) || {}).label ?? text,
14761524
})}\n`,
14771525
)
14781526
}
@@ -1545,7 +1593,7 @@ function emitJson(file, waitInfo) {
15451593
source: /^\[WebView/.test(e.text) ? 'webview' : 'plugin',
15461594
run: e.run || null,
15471595
// see streamPending: strip the internal notice sentinel before emitting
1548-
text: noticeLabel(e.text) ?? e.text,
1596+
text: (parseNotice(e.text) || {}).label ?? e.text,
15491597
}
15501598
process.stdout.write(`${JSON.stringify(rec)}\n`)
15511599
}
@@ -1663,13 +1711,15 @@ function main() {
16631711
process.exit(1)
16641712
}
16651713

1714+
let pluginHadHistory = false
16661715
if (opts.pluginMode) {
16671716
let st = null
16681717
try {
16691718
st = fs.statSync(file)
16701719
} catch (err) {
16711720
// doesn't exist -- st stays null
16721721
}
1722+
pluginHadHistory = Boolean(st && st.size > 0)
16731723
if (!st || st.size === 0) {
16741724
console.error(`nplog: ${file}`)
16751725
console.error(st ? ' exists but is empty.' : " doesn't exist yet.")
@@ -1692,7 +1742,20 @@ function main() {
16921742
process.exit(1)
16931743
}
16941744

1745+
// Whatever is already in a plugin's _MCP-console.log at startup is the tail
1746+
// of a run that was underway before nplog existed -- NotePlan overwrote
1747+
// anything earlier. Book-ending the seeded content makes that legible
1748+
// instead of looking like a normal, complete run: one notice for where the
1749+
// retained data starts, one for where live capture began. The second is a
1750+
// navigable boundary, so ← always has something to land on even before the
1751+
// first reset -- "show me only what I actually watched".
1752+
if (opts.pluginMode && pluginHadHistory) {
1753+
pushNotice('start of retained output -- NotePlan overwrites this file each run, so nothing earlier survives', false)
1754+
}
16951755
openFile(file, true)
1756+
if (opts.pluginMode) {
1757+
pushNotice(`nplog started watching here -- ${separatorClock(Date.now())}`, true)
1758+
}
16961759

16971760
out.write(`${ESC}[?1049h${ESC}[2J`) // alternate screen keeps the real scrollback clean
16981761
process.stdin.setRawMode(true)

0 commit comments

Comments
 (0)