soul.demarkus.io:6309/debugging.md/v17 draft reader meta

Debugging

Lessons learned from bugs, investigations, and things that went wrong.

General Principles

  • Read the error message. The whole error message.
  • Reproduce before fixing. If you can't trigger it, you don't understand it.
  • Don't brute force. If something is blocked, step back and think about why.
  • When a test fails, read the test first — the test might be wrong.

Known Gotchas

YAML Auto-Typing

YAML will silently convert strings like yes, no, on, off to booleans. This is why frontmatter is parsed as map[string]string — we control the type conversion ourselves.

Symlink Resolution in Tests

When testing the versioned store, be careful with os.ReadFile vs following symlinks. The store creates doc.md -> versions/doc.md.v3 — some operations need the symlink target, others need the symlink itself.

Path Traversal

filepath.Clean handles most cases but you still need an explicit .. check after cleaning. A path like /../../../etc/passwd cleans to /etc/passwd which looks valid but is outside the content root. The check is: clean the path, then verify it doesn't escape the root.

QUIC Stream Lifecycle

Streams must be closed properly. If a handler panics or returns without closing the stream, the client hangs waiting for data. Always defer stream close.

Debugging Approach for This Project

  1. Write a failing test that reproduces the issue
  2. Fix the code
  3. Verify the test passes
  4. Check if the fix breaks anything else (make test)
  5. Run bash pre-commit.sh

The test-first approach isn't dogma here — it's practical. A test that reproduces the bug proves you understand the bug, and it prevents regression.

QUIC UDP Buffer Size Warning

When running demarkus in CI or containerized environments, quic-go logs this warning:

failed to sufficiently increase receive buffer size (was: 1024 kiB, wanted: 7168 kiB, got: 2048 kiB)

Not a failure. quic-go tries to increase the UDP receive buffer to 7168 kiB for optimal performance. In environments with restricted sysctl limits, it can only get partway there. The connection still works — everything publishes fine.

Fix (if needed): Increase the system limit with sysctl -w net.core.rmem_max=7168000. Not necessary for correctness, only for optimal throughput under heavy load.

First seen: CI publishing content to demarkus-hub (hub.demarkus.io).

OnNode Callback Concurrency

graph.Crawl invokes OnNode from multiple worker goroutines. Any mutable state captured by the callback must use sync/atomic or a mutex. The CrawlAndPersist MaxNodes counter uses atomic.Int32 for this reason. Always run go test -race on packages that use OnNode.

Glamour WithAutoStyle() Blocks TUI Rendering

Symptom: TUI shows "Loading..." for up to 60 seconds after fetch completes. Server logs confirm the FETCH is handled immediately. CLI works fine. A mouse scroll "unsticks" the display.

Root cause: glamour.WithAutoStyle() calls termenv.HasDarkBackground(), which sends an OSC 11 escape sequence to the terminal and reads the response from stdin. But Bubbletea is also reading stdin for input events. This causes two problems:

  1. Stdin contention — Bubbletea's input goroutine may consume the OSC 11 response, so termenv never sees it and blocks for the full 5-second timeout.
  2. Render corruption — The stdin race breaks Bubbletea's render cycle, leaving the view stuck on "Loading..." even though the model state has been updated. A mouse event forces a fresh render, which is why scrolling "fixes" it.

The TUI recreated the glamour renderer on every window resize (to update word wrap width), re-triggering the query each time. Multiple resize events at startup compounded into 30-60 seconds of blocking.

Fix: Detect dark/light background once in main() before tea.NewProgram().Run() takes over stdin. Pass the resolved style name ("dark" or "light") into the model. Use glamour.WithStandardStyle(styleName) instead of glamour.WithAutoStyle() — this hits the DefaultStyles map lookup directly, bypassing the terminal query entirely. Also added a -style flag so users can skip detection.

Guard: Both stdin and stdout must be terminals before attempting detection. If either is piped, fall back to dark.

Key insight: Never do terminal escape sequence queries inside a Bubbletea event loop. Bubbletea owns stdin once it starts. Any library that reads stdin for terminal responses will race with Bubbletea's input goroutine.

TUI Link Highlighting: Marker Injection and the Glamour Black Box

Context: The TUI needs to highlight the selected link in the rendered markdown and support clickable links. But glamour's API is Render(string) → string — a black box. It doesn't expose the goldmark AST it builds internally, and the rendered ANSI output doesn't preserve link structure. Link URLs are stripped from the output; only styled text remains.

Problem: We parse the markdown twice with goldmark. Once in links.ExtractWithPositions to get link destinations and their byte offsets in the source, and again inside glamour to render. If glamour exposed its pre-parsed AST (or accepted one), we could do a single parse, extract link positions, and annotate nodes directly for highlighting.

Workaround: Marker injection. Before passing markdown to glamour, we inject Unicode private-use-area codepoints (U+F0000 range) around each link's text inside the [...] brackets. Glamour treats them as literal characters and passes them through to the rendered output. After rendering, processMarkers scans the ANSI output, finds the markers, records their screen coordinates as linkRegion entries, and strips them (or replaces with ANSI reverse-video for highlighted links).

Goldmark AST quirks for link positions:

  • ast.Link nodes don't expose the byte offset of [ or ] directly. You have to walk the link's child ast.Text nodes to get their Segment.Start and Segment.Stop, then scan backward/forward in the source to find the brackets.
  • Links with inline formatting (e.g., [hello **world**](url)) have multiple child nodes. The ** markers sit between text segments but aren't text nodes themselves, so Segment.Stop of one child doesn't equal Segment.Start of the next.
  • link.Text(source) is deprecated in newer goldmark versions. Use the child text segments directly and build the text yourself.
  • Links with no text nodes (e.g., [](url)) produce no text segments. ExtractWithPositions handles this by emitting a LinkInfo with OpenBracket: -1 so the link is still in the navigation list but skipped during marker injection.

Region extension for clickable URLs: Glamour renders links as bold text followed by an underlined URL. The end marker sits after the text but before the URL. processMarkers extends each region past the end marker to also cover the URL portion, scanning forward through the space and URL characters and stopping at the next space. This makes both the text and URL clickable.

Marker limit: Start markers use U+F0000+i, end markers use U+F1000+i. Maximum 4096 links per document before the ranges overlap. injectLinkMarkers caps at maxMarkedLinks; excess links render normally but without highlighting or click detection.

Mouse mode: tea.WithMouseCellMotion() only delivers motion events when a button is held. Hover requires tea.WithMouseAllMotion().

Argo CD selfHeal Reverts Broker Writes to the World Tokens Secret

Context: demarkus-broker mints a token by appending a [tokens.usr_xxx] section to the world's tokens.toml Secret (the same Secret the chart created with the admin token at install time). When the world is deployed via Argo CD with syncPolicy.automated.selfHeal: true (the default for an "auto-sync" GitOps shape), Argo's reconciler treats the broker's appended sections as drift from the chart-rendered manifest and reverts them on the next sync pass.

Symptom:

  • POST /auth/callback returns 200 with a tokens array. Broker logs mint succeeded.
  • The broker-namespace issuances Secret has the new entry — broker side is fine.
  • The world's tokens.toml Secret only contains the original admin entry. kubectl get secret -o yaml | grep resourceVersion shows a high number (e.g. 1705 after a few minutes) — the Secret has been updated repeatedly, but every update is immediately overwritten by Argo's selfHeal cycle.
  • demarkus-server returns "unauthorized" for every minted token because they never make it to the file the server reads.

Why selfHeal does this: Argo's drift detector compares the live Secret's data against the rendered manifest. The Helm chart only renders data.tokens\.toml with the admin entry. Anything else — including the broker's runtime-appended [tokens.usr_xxx] blocks — is "extra content" that selfHeal removes to bring the Secret back into compliance with the chart-defined source of truth. There's no warning. The mint API call succeeds because the broker's Secret-update API call returned 200; the revert happens milliseconds later.

Fix: add ignoreDifferences to the Application (or ApplicationSet template) so Argo stops reconciling /data of the per-world tokens Secret:

spec:
  ignoreDifferences:
    - kind: Secret
      name: "<release>-demarkus-server-tokens"
      jsonPointers:
        - /data

This leaves the chart in charge of the Secret's existence + initial admin entry while letting the broker own its runtime mutations from then on. The narrower /data/tokens.toml jsonPointer also works but /data covers the case where the chart later adds another data field.

Key insight: Argo CD treats every Helm-rendered manifest as the desired state. Any resource whose contents are mutated at runtime by another controller (or by the broker, in our case) needs an ignoreDifferences carve-out for the field being mutated, OR the Argo Application needs selfHeal: false. Pick one — selfHeal=true with no ignoreDifferences is a silent data-loss machine.

Detection: how to spot this fast. When a runtime mutation against an Argo-managed resource appears to have no effect, check kubectl get <kind> <name> -o yaml | grep resourceVersion. If the version is climbing every few seconds without obvious cause, selfHeal is the cause.

Where this bites in production: any Helm-rendered Secret/ConfigMap/CRD that another component mutates at runtime. demarkus-broker writes to the world tokens Secret. cert-manager writes to TLS Secrets. external-secrets-operator writes to Secrets. Any operator that owns a CR's .spec may hit the inverse pattern (Argo trying to reset spec back to the rendered shape). The ignoreDifferences carve-out is the durable answer in every case.

First seen: Stage 4 of the kind harness (PR #134), 2026-05-14. Mint API returned 200 with valid tokens; the world Secrets stayed at the chart-default admin-only contents. Took ~30 minutes of broker-side debugging (logs, code-reading, RBAC checks) before checking the Argo CD Application diff revealed the selfHeal cycle. Now load-bearing knowledge for any production broker deployment with Argo CD.

Agents improvise body frontmatter that demarkus never interprets (2026-06-10)

Symptom. Browsing a new project's index doc in the TUI showed garbled output — a stray ## name: setext heading followed by loose description: / type: lines. The doc had been authored by a claude-code agent against an org knowledge system.

Root cause — doubled frontmatter. demarkus carries metadata out of band: the publisher passes a metadata object on PUBLISH, the store prepends its own version envelope (buildVersionFile, protocol/store/store.go), and on FETCH the server strips exactly one leading ------ block (stripFrontmatter, server/internal/handler/handler.go). The agent additionally hand-wrote a second frontmatter block into the document body:

---            ← store envelope (version/archived/meta.*), stripped on fetch
version: 1
meta.agent: claude-code
---
---            ← agent's own block, survives into Response.Body
name: ...
description: ...
type: reference
---
# real content

The server strips only the first block, so the agent's block reaches the TUI as literal body. glamour renders name: ...\n--- as a setext H2, hence ## name:. The block is also invisible to LOOKUP (which reads only tags/importance/title).

Why the agent did it. Two reinforcing causes. (1) The session guidance told it to set tags/importance via the metadata object but never mentioned title — so "record a name" had no documented home and it reached for the Hugo/Obsidian frontmatter reflex. (2) name/description/type is ubiquitous in LLM training data. Provenance check came back negative: nothing in the repo prescribes that block, the org template was the stock deploy default (unchanged), and docs/site/reference/markdown.md already warns against body ---. Pure improvisation.

Fix. Guidance, not code. Added "all metadata travels in the metadata object, never the body; recognized keys are title/tags/importance; map name→H1/title, kind→a type: tag, description→first sentence under the H1" to both context/session-guidance.md files and skills/soul-memory/SKILL.md. Naming title is the gap-closer. Deliberately did not add defensive frontmatter stripping to the TUI — Fritz wants the raw render to stay a faithful knowledge-document debugger (it's exactly what surfaced this). Open follow-up: a write-side guard in publish-gate.sh to warn when a body opens with ---.

Managed soul server didn't restart onto an upgraded binary (2026-06-10)

Symptom. After a plugin update, the local demarkus-server stayed on the old version ("server binary behind").

Root cause. Two-stage propagation, only one stage existed. ensure_binaries (plugins/claude-code/scripts/lib.sh) compares a .versions sentinel against the pinned SERVER_VERSION and re-downloads the binary file on drift at session start — that worked. But ensure_managed_server reused any live PID unconditionally (kill -0 only), so the already-running server kept serving the old binary from memory until the process died (reboot / manual kill). The on-disk upgrade never reached the running process.

Fix. Version-stamp the managed server and restart on mismatch. On spawn, write SERVER_VERSION to ${soul_dir}/.server-version next to .pid. New predicate managed_server_current PID_FILE VERSION_FILE reuses only when the PID is alive AND the stamp equals the current pin; a live-but-stale (or unstamped, from an older plugin) server is killed (SIGTERM, bounded ~3s wait, SIGKILL fallback) and respawned on the new binary. Safe: soul is on-disk + versioned, and demarkus is QUIC/UDP so the port frees on exit with no TIME_WAIT. Restart only happens in managed default/isolated modes — reuse mode (user's own server) never calls this. Propagates automatically on next session start and on /soul-init. demarkus-server has no --version flag, which is why the stamp file (not a process query) is the source of truth. Branch fix/server-auto-upgrade-on-drift, demarkus-memory 0.5.1→0.5.2.

Test gotcha found along the way. pid="$(helper)" where helper does sleep 30 & echo $! does not reliably leave the process alive in the caller (command-substitution subshell ownership + the inherited-fd pipe trap). Start background test processes directly in the test function with fds redirected: sleep 30 >/dev/null 2>&1 & local pid=$!. The bug hid because "not-current" assertions pass for a dead process too — only the positive "reuse a live current server" case caught it.

Release binaries shipped version="dev" — goreleaser ldflags lacked -X main.version (2026-06-10)

Finding (while adding --version). The Makefile injects -ldflags "-X main.version=$(VERSION)", but the goreleaser configs (server/.goreleaser.yml, client/.goreleaser.yml, tools/.goreleaser.yml) had ldflags: -s -w only. Releases go through goreleaser, so every released binary reported main.version = "dev" (the package default). Local make builds looked correct; the gap was invisible unless you ran a released binary. Fix: add -X main.version={{ .Version }} to each released build's ldflags. goreleaser runs per-module with the module tag, so {{ .Version }} resolves to the real release version (e.g. server/v0.17.x → 0.17.x).

--version added to demarkus-server, demarkus-mcp, demarkus-token. Each prints the bare version to stdout and returns before any side effects (no config load / no server start / no token file). server & mcp use a -version bool flag (Go's flag pkg accepts -version and --version); token is subcommand-style so it takes a version subcommand plus --version/-version cases. Output is bare (just the version, node-style) so ver=$("$bin" --version) needs no parsing — that's the ops use case.

Design constraint (carried from the auto-upgrade work): --version reports the on-disk binary's version, not a running process's. So it can feed ensure_binaries' installed-version detection and /soul-status diagnostics, but it does not replace the .server-version launch-stamp used to decide whether to restart a live server. Two different questions.

Sequencing gotcha for adoption: the plugin can't call --version on its managed binaries until the pinned release actually includes it — old binaries error on the unknown flag/subcommand. So: land this → release server/client/tools → bump plugin pins → only then wire --version into ensure_binaries//soul-status. Test approach: each binary's version_test.go builds itself with -ldflags -X main.version=9.9.9-test and asserts --version echoes it, which also catches a mistargeted -X package path (would silently stay "dev"). Branch feat/binary-version-flag.

Plugin adopted --version for binary drift detection; dropped the .versions sidecar (2026-06-10)

Follow-on to the --version work, now that server 0.17.15 / client 0.12.39 / tools 0.1.32 ship the flag. The demarkus-memory plugin's ensure_binaries (plugins/claude-code/scripts/lib.sh) used a .versions sidecar file recording what it last installed. Replaced that with a live query: _binary_version BIN --version plus _installed_versions running each binary's --version, compared against the pinned _desired_versions. The binaries are now the source of truth — the sidecar could drift from reality (binary swapped out of band, sidecar deleted, partial install), and a live query also catches a corrupt or wrong-arch binary (fails to run → empty field → mismatch → re-download). Removed PLUGIN_VERSION_FILE, the end-of-install sidecar write, and the failure-path rm; a failed/partial install simply reads as a mismatch next session. demarkus-token accepts --version as well as its version subcommand, so one flag form (--version) covers all three. Pre-0.17.15 binaries error on the unknown flag → empty field → upgraded on next session start (the desired transition). /soul-status now queries --version per binary instead of cat .versions. Tested via stub scripts (working / old-erroring / missing / non-executable) and verified end-to-end against the real released binaries. Branch feat/plugin-adopt-version-flag, demarkus-memory 0.5.2→0.5.3. Pins bumped to 0.17.15 / 0.12.39 / 0.1.32.

pi slash commands registered but never executed — sendMessage without triggerTurn (2026-06-25)

Symptom. In the pi-agent ports (plugins/pi-memory, plugins/pi-knowledge, #211), every slash command (/soul-*, /promote, /knowledge-*) appeared to do nothing. The command was recognized — no "unknown command" error — but the agent never acted on it.

Root cause. The command handlers inject the bundled skill body into the session with pi.sendMessage({ customType, content, display: false }) and no options. Pi's sendCustomMessage (@earendil-works/pi-coding-agent dist/core/agent-session.js) branches three ways: streaming → steer/followUp; not-streaming + triggerTurn_runAgentPrompt (starts a turn); not-streaming + no trigger → just append to state + emit message_start/message_end, no LLM turn. Typing a slash command happens while the session is idle (not streaming), so it hit the third branch: the skill instructions landed in history and the agent was never prompted to run them. display: false made it invisible too, so it looked like a complete no-op.

Fix. Pass { triggerTurn: true } in the command handler's sendMessage (both plugins/pi-memory/src/index.ts and plugins/pi-knowledge/src/index.ts). Idle → starts a turn; mid-stream → pi ignores triggerTurn and steers, which is the desired behavior anyway. The nudge/gate sendMessage calls elsewhere correctly pass { triggerTurn: false } (fire-and-forget reminders) — only the user-invoked command path needs a turn.

Key insight. In pi, sendMessage is not a request to act — it's an entry append that only starts a turn when triggerTurn: true (or when streaming, via steer/followUp). sendUserMessage always triggers a turn. For a user-invoked command whose whole job is "make the agent do X now," you must trigger the turn explicitly; the claude-code mental model (inject prompt → it runs) does not carry over. No test caught this because the handlers were never exercised end-to-end against a live pi session — type-checking passes regardless.

Ignoring the lock-PID write creates a poison lock (2026-06-25)

Context. The demarkus-plugin (tools/demarkus-plugin) guards provisioning and registry writes with an atomic mkdir-mutex: os.Mkdir(lockDir) acquires, and the holder stamps its PID into lockDir/pid so stale-lock recovery can reclaim a lock whose owner died. Two sites: internal/provision/provision.go (withProvisionLock) and internal/registry/lock.go (withLock).

Bug (caught in PR #218 review). Both did _ = os.WriteFile(lockPid, …) — swallowing the error — then ran the critical section anyway. If that write fails, the lock dir exists with no PID file. Stale-lock recovery reads lockPid to check whether the recorded owner is still alive; with no file the read fails and the recovery path falls through to sleep-and-retry, never reclaiming. Result: an unowned poison lock that wedges every future writer for the full bounded wait (~180s for provision, ~2s for registry) and then errors — with no owner to blame and nothing to clean it up.

Fix. Treat the PID stamp as part of acquisition: on write failure, os.RemoveAll the lock dir and return the error (fail closed) instead of entering the critical section. Don't hold a lock you can't prove ownership of.

Lesson / sweep. A _ = on a write that another code path later reads to make a decision is not a benign ignore — it silently breaks the reader's invariant. When auditing, separate "best-effort writes nobody depends on" (e.g. the guidance.go one-time-offer sentinels — a lost write just re-offers, fine to ignore) from "writes that establish state a recovery/cleanup path relies on" (lock PID stamps — must be checked). Grep for the lock acquisition primitive (os.Mkdir( mutexes), not just os.WriteFile, to enumerate every site: there were exactly two module-wide.

gh pr view <branch> resolves CLOSED PRs — automation edited a dead PR for 10 days

The plugin-pin-bump workflow's "open or update PR" step used gh pr view "$branch" to decide between gh pr edit and gh pr create. gh pr view (and gh pr edit) resolve a branch name to the most recent PR for that branch, including closed ones. After bump PR #210 was closed unmerged (2026-06-24), every daily run force-pushed auto/plugin-pin-bump and "successfully" edited the closed PR's title/body — no new PR, no failure, pins silently drifting behind releases for 10 days. The tell: #210's title named server 0.19.0, a version released a week after the PR was closed, and updatedAt kept moving.

Rule: in automation, branch→PR resolution must be gh pr list --head "$branch" --state open --json number and then operate on the PR number. Never gh pr view/edit <branch> when a closed PR for that branch may exist. Fixed in plugin-pin-bump.yml (2026-07-05).

General shape of the bug: an "upsert" whose existence check matches dead records. Same family as matching stale locks or tombstoned rows — the check must filter by liveness, not just identity.

Mirrored code without a fidelity test absorbs every fix twice

PR #230 (broker ergonomics parity): changedNote/seenDoc were copy-pasted between client cmd and broker as a "deliberate mirror". Two consecutive review rounds found wording bugs that had to be fixed in both places, and a later round found a guard present in one flow but not the other. Hoisting into a shared package (client/fetchdedup) ended it.

Rule of thumb: a deliberate mirror is only safe when a byte-for-byte fidelity TEST enforces it (as formatResult/formatToolResult has — that mirror has never drifted). A mirror kept in sync by reviewer vigilance will drift; hoist to a shared package at the SECOND two-place fix. The tools module imports the client module, so client-side shared packages (mdoutline, fetchdedup) are always available to the broker.

A gateway behavior change needs a consumer census, not just agent acceptance

Broker 0.5.0's mark_fetch ergonomics (outline mode >8KB, session unchanged-dedup) were verified against LLM agents on both MCP surfaces — but the demarkus-library is a THIRD consumer of the same gateway (broker mode reads every document through mark_fetch, one pooled MCP session per reader), and it broke two ways, silently:

  1. graph.md (74KB) returned an outline → the floor's hub-topology parser found no Edges table → federation portals (soul.demarkus.io) vanished. The library's designed degradation ("any read/parse failure yields an empty topology") masked it — degradation paths hide regressions.
  2. Re-opening an already-opened document returned status: unchanged with no body → parseToolResult's default branch → "unreachable" in the UI. unchanged was a NEW status value in a response contract that programmatic consumers parse by exact status.

Fix: the library's gateway Fetch passes force=true — a programmatic renderer always wants the real body; force bypasses both behaviors by design (library fix/gateway-force-fetch). Diagnosis pattern that worked: walk the data pipeline producer→consumer (root hub row → federated- systems.md → agent graph.md → floor parser) — the break is at the first hop where healthy data stops being consumed correctly.

Rules of thumb:

  • Changing a shared surface's RESPONSE SHAPE (new status values, new body modes) is a breaking change for every parser of that surface; census the consumers (agents, library, plugins, smoke scripts) before shipping.
  • A consumer with graceful degradation needs a canary assertion somewhere (e.g. the floor should alert when the hub topology parses to zero edges but the doc fetch succeeded), or regressions land as quiet emptiness.

Deleting old versions broke a hidden v1-existence assumption (#236)

Version retention (prune oldest, keep last N) looked structurally safe: numbering derives from max-on-disk, VerifyChain checks consecutive present pairs. The store tests caught what analysis missed — migrateFlatFile detected "flat file needing migration" by checking whether v1 exists. After pruning v1, the next write misclassified the versioned document as a flat file and "migrated" the current symlink's raw bytes into a resurrected v1: doubled store frontmatter, broken hash chain, a version listing showing deleted versions back from the dead. Fixed by detecting any per-doc version history instead of v1 specifically.

Rules of thumb:

  • Before adding deletion to an append-only store, grep for existence checks on specific low versions (v1, version==1 special cases) — append-only code is full of "oldest version always exists" assumptions that deletion invalidates.
  • Destructive filesystem ops in the store go through os.OpenRoot (Go 1.24+): paths resolve inside the root at operation time, so planted or raced symlinks error instead of redirecting the delete outside the store, and a final-element symlink is unlinked, never followed. Retention's pruneVersions is the reference example; reuse the pattern for any future delete/rename in protocol/store.
  • The debug loop that found it: identical logic passed in a scratch test but failed in the suite → diff the sequence, not the assertion — the extra later write was the trigger, and find on the versions dir between steps showed v1 reappearing with double frontmatter.
trail
  1. soul.demarkus.io:6309 v17