Root-cause the backend's non-durable shard writes (source of #139) instead of relying on reconciliation

[tkuhn]

The shard-consistency sweep (#140, #141) is a safety net, not a fix: the underlying defect is that the RDF4J/LMDB backend sometimes acknowledges a per-repo write transaction (2xx on commit) that never becomes durable/visible — or answers a repo-status query with a false "already loaded" row. Either way the loader is told the shard is fine when it isn't. This issue tracks fixing that at the source.

Evidence so far

#139 (2026-07-27, query.knowledgepixels.com): nanopub RAHokSK… present in text/full/pubkey/type_ListView/meta (all six stamps within ~150 ms of a clean first load attempt; meta committed, which requires every shard task to have reported success), yet zero durable trace in type_ec6722… (ResourceView) — no stamp, no content, count/checksum internally consistent without it. Ruled out client-side: repo recreation, thread-unsafe hash → wrong repo name, type computation, LMDB tail loss, transaction-atomicity break, coordination logic.

Recurrence 2026-07-29, ~09:20 and ~09:28 UTC: two freshly published ResourceView nanopubs dropped from the same type repo, now across instances — RA9WoVD9… missing on knowledgepixels and petapico (both ingested it within ~3 s of each other), RAZzhA4a… missing on knowledgepixels and nanodash.net. Same nanopub dropped on two instances at the same wall-clock moment ⇒ the trigger is load-correlated at ingest time (all instances replay the same registry stream on the same schedule), and it keeps hitting the hottest type repo — the same type_ec6722… that has the documented repo-wedge/outage history (see the TripleStore pinning rationale and deferred-shutdown comments around the MMapIndexInput – Already closed failure mode).

Related: the 2026-06-29 meta-behind-full divergence (4,763 nanopubs in full/pubkey/type but absent from meta after a resync) has the same "shard reported success without a durable write" signature.

What would discriminate the mechanism

1. RDF4J server logs at incident time — the key missing evidence. The reconciler now gives precise detection (registry_reconciler_shards_repaired_total > 0, WARN log with nanopub + repo + timestamp), so on the next occurrence, capture the server-side log around the original load window before rotation. Known windows: 2026-07-27T06:48:05Z (kpxl), 2026-07-29T09:20:08–11Z (kpxl + petapico), 2026-07-29T09:28:52Z (kpxl + nanodash.net), all on type_ec6722efa3….
2. Client-side skip logs — since feat(loader): periodic shard-consistency sweep to detect and repair missing shard writes #140, the "Skipping already-loaded nanopub" line is INFO. If a drop coincides with such a line for the affected repo, the mechanism is a false read (store answered "already loaded" for a nanopub it doesn't hold); if there's no skip line, the commit ack itself was non-durable.

Candidate directions once discriminated

• LMDB store durability settings (e.g. lmdb:forceSync, currently at RDF4J defaults in the repo-creation config in TripleStore).
• The known store-wedge mode on hot repos (shutdown-during-use / env lifecycle) — possibly an upstream RDF4J LmdbStore bug worth reporting with the captured evidence; we already run 5.3.1 with a patched-workbench history.
• Load-correlation: incidents cluster at ingest bursts on the most-queried type repo, suggesting write-under-concurrent-read-pressure; a reproducer hammering an LmdbStore with concurrent federation reads + serializable writes might trigger it in isolation.

Until this is fixed, the reconciler keeps the damage bounded (detection ≤ ~5 min for completed loads), but every non-zero shards_repaired_total is a reminder that the store is acking writes it doesn't keep.

🤖 Generated with Claude Code

[tkuhn]

Evidence update (2026-07-29): onset is abrupt and recent, pattern points at read-concurrency pressure

A full-vs-type-repo diff across four hot type repos on query.knowledgepixels.com (membership by npa:hasLoadNumber stamp, verified against direct triple counts):

type repo	missing shards	dropped at (full-repo load time, UTC)
grlc-query	0	—
ListView	0	—
ViewDisplay	5	Jul 28 11:47 (×4), Jul 29 10:15
ResourceView	14	Jul 27 06:48 (#139), Jul 27 15:11–15:18 (×7), Jul 28 12:32, Jul 29 09:20/09:28/09:37/10:14/10:17

Observations:

1. Zero drops in all prior history, nineteen since July 27, still ongoing — three more ResourceViews dropped the morning of Jul 29 (09:37, 10:14, 10:17) after the two already reported. Whatever triggers this started 2–3 days ago.
2. Confined to ResourceView and ViewDisplay — exactly the two hottest, view-UI-facing repos (the ones pinned in TripleStore for their wedge history). grlc-query shares the same write path and is untouched, so this is not a general loader problem; it looks like write loss under concurrent read pressure on specific LMDB stores.
3. The Jul 27 15:11–15:18 burst (7 drops in 7 minutes) coincides with an active view-publishing session — write bursts under simultaneous read load.
4. Cross-instance correlation reported earlier (same nanopub dropped on two instances within the same ingest moment) fits the same mechanism: all instances replay the same registry stream under the same external read load.

Two configuration changes bracket the onset:

• limit_conn uri 1 on the nginx /repo location — which serialized external SPARQL reads per repository, exactly the Nanodash view-chooser/federation traffic hitting these two repos — was deactivated on the live servers ~2 weeks before onset. Years of operation with it active show zero drops; publishing on Jul 16–18 (after deactivation, before onset) survived, so it may not be the sole trigger.
• 1.20.0 raised the federation HTTP pool limits (internal read concurrency against the same backend). If its deployment landed around Jul 26–27, the combination would explain the abrupt onset precisely.

Mitigations being applied:

• Re-activating limit_conn uri 1 (or a bounded limit_conn uri 3) on the live servers.
• Deploying the reconciliation sweep (feat(loader): periodic shard-consistency sweep to detect and repair missing shard writes #140/feat(reconciler): meta-stamp completion gate and 5-minute sweep cadence #141); on query.knowledgepixels.com, setting npa:hasReconciliationCheckpoint to 86293 after deploy heals all 19 currently-missing shards. Other instances need their own diff + checkpoint once updated.

For the root cause, the log-capture windows are now plentiful: any of the drop timestamps above on type_ec6722… (ResourceView) or type_11daee… (ViewDisplay), RDF4J server side. The 15:11–15:18 Jul 27 burst is probably the richest window.

Missing nanopubs for the record:
ResourceView: RAHokSK-M65X…, RAG-J3Oa…, RAxp92GW…, RAS6B6wH…, RA7WlFOv…, RAFSAWMv…, RAbhvVL0…, RAEHjDgt…, RAJg_xJf…, RA9WoVD9…, RAZzhA4a…, RAUqJMjX…, RAQY6LMx…, RAw4gGU6…
ViewDisplay: RAILkx4Z…, RAGI1ANX…, RAfU2Ebc…, RAl5Tb_T…, RAiiPvWi…

🤖 Generated with Claude Code

[tkuhn]

2026-07-29 afternoon: first confirmed verified-then-lost capture, full causal chain, counter-measures

The incident

Nanopub RAdtjqGM_dd98dt0Q_W7fhLCmdL1di3VpkitO28OIMe3g (a ResourceView, ingested fleet-wide ~12:08:27Z) is in full/meta on all three instances but missing from type_ec6722… on all three — and on every instance the reconciliation checkpoint had advanced past its load number (kpxl 86512>86497, petapico 86500>86492, nanodash 86515>86500). The sweep only passes a nanopub after a membership read confirms every expected shard. So the shard write was acknowledged and readable at sweep time, and vanished afterwards. The empty result of grepping nanodash's app log for the IRI is consistent with the sweep having seen the original write as present (clean verifications log nothing at INFO).

Supporting state: later writes persisted around the hole (nanodash's ec6722 took writes at 12:14/12:34/12:36; count/stamps internally consistent), and every shard the sweep had repaired earlier that day survived — the loss was surgical, one committed transaction evaporating from the middle of the lineage.

The causal chain (each link evidenced)

1. limit_conn uri 1 re-activated while kpxl still routed federation through the public edge (pre-feat(api): route federated SERVICE traffic in-cluster via NANOPUB_QUERY_INTERNAL_URL #143 deploy) → SERVICE calls 503/aborted en masse → mass query interruptions (kpxl's localhost.2026-07-29.log shows a continuous SEVERE/Broken-pipe abort storm, e.g. 12:05–12:06).
2. Interrupted/timed-out queries leak LMDB read handles (rdf4j#5807, fixed in 5.3.2) → hottest env (type_ec6722…) wedges — kpxl's copy stalled at 10:51:46Z and was later fully unreachable (nginx 502) while its other repos kept taking writes.
3. Wedged env → federation healthcheck probe fails → pkill -15; sleep 10; pkill -9 — ten seconds is never enough for dozens of LMDB repos, so effectively a hard kill. /var/info/restart shows ~21 restarts on 2026-07-29 vs a 2–5/day background rate.
4. Writes acknowledged into the wedged/re-initializing store die with the JVM: the 12:08:28 load is bracketed by restarts at 12:07:06 and 12:11:56 — a one-cycle-wide loss window. kpxl lost everything acked into ec6722 between 10:52 and the upgrade.

Forensics gap and runbook

A month of the volume-mounted Tomcat logs (catalina/localhost/…) contains zero MDB_/maxreaders lines — those files only capture servlet-layer errors. RDF4J's own logging goes to container stdout, and docker logs rdf4j died with the 5.3.2 container recreation on all instances. Runbook for the next occurrence (the retro pass announces it): capture docker logs rdf4j before any restart or recreate; that's where the store-level error (MDB_READERS_FULL or otherwise) will finally be visible.

Remediations now in place

• rdf4j 5.3.2 (rdf4j#5807 read-handle leak fix) + in-cluster federation (feat(api): route federated SERVICE traffic in-cluster via NANOPUB_QUERY_INTERNAL_URL #143) + limit_conn restored for external traffic only — the trigger chain is dismantled link by link.
• Checkpoints re-lowered on all three instances; sweeps re-healed today's holes.
• PR feat(reconciler): retro pass for verified-then-lost shards + healthcheck restart softening #144: (a) a stateless retro pass re-verifying the trailing 24 h below the checkpoint each tick, so verified-then-lost cannot escape again — with a dedicated gauge registry_reconciler_shards_relost_total that, unlike shards_repaired_total, can only count revoked-after-readable losses; (b) healthcheck softening: 60 s graceful stop before kill -9 and a 10-minute restart backoff, removing the loss amplifier.

Remaining open question

Whether the wedge is fully explained by rdf4j#5807 or something deeper in LmdbStore's env lifecycle. Discriminator: after 5.3.2, shards_relost_total staying at 0 across the fleet closes this issue's acute half; any non-zero reading comes with a same-tick WARN and an intact docker logs rdf4j to finally name the store-level failure.

🤖 Generated with Claude Code

[tkuhn]

Server-log evidence: commit reversion WITHOUT restart, and the store-level defect named

Follow-up to the previous comment — the retro-pass counter-measures (#144, merged) were built for exactly what the logs now prove.

Petapico: the decisive capture

App log (nanopub-query, 1.22.0):

13:43:58.001 WARN ShardReconciler - Nanopub <…RAdtjqGM…> is missing from shard repo(s) [type_ec6722…]; re-loading
13:43:58.049 WARN ShardReconciler - Repaired: nanopub <…RAdtjqGM…> re-loaded into shard repo 'type_ec6722…'

The "Repaired" line means the post-repair verification read the stamp back successfully. By ~13:52 the nanopub was absent again (confirmed via four independent query patterns) — and petapico's rdf4j log shows no webapp stop in the entire window: no restart occurred. A committed, acknowledged, read-back-verified write to an LMDB repo reverted in-flight on a running rdf4j 5.3.2 server. Restarts (the earlier working theory) amplify the loss but are not required for it.

kpxl: the defect visible at webapp stop

kpxl restarted again at 13:51:19 (discarding its 13:45:21 sweep repairs — the healthcheck softening was not yet active on the running container). At that stop, Tomcat's leak checker reported dozens of:

SEVERE … The web application [rdf4j-server] created a ThreadLocal … and a value of type
[org.eclipse.rdf4j.sail.lmdb.ValueStore$ReadTxn] … but failed to remove it when the web application was stopped.

plus leaked org.lwjgl.system.MemoryStack native allocations. The LMDB read-transaction leak class (rdf4j#5807) is demonstrably still present in 5.3.2 on Tomcat worker threads.

Working mechanism theory

A wedge-scarred env (stale/corrupt reader-lock state accumulated during the abort storms and kill-loop) can break LMDB's writer serialization: a second writer commits from a stale root and last-committer-wins silently orphans the earlier commit. This fits every observation — surgical mid-lineage loss while later writes persist, internally consistent counts/checksums, loss with and without restarts, and the fact that repairs stick on nanodash (unscarred env) but keep evaporating on kpxl/petapico.

Consequences

• Repos on the affected hosts are damaged goods; repairing into them is Sisyphus work. Decision: fresh full resyncs from the registry for kpxl and petapico (one at a time, after deploying the retro-pass release), followed by a full-history verification sweep (set-reconciliation-checkpoint.sh -1, ~7–8 h) whose end state shards_repaired_total == 0 certifies the store clean. nanodash stays as fleet anchor.
• registry_reconciler_shards_relost_total (new in feat(reconciler): retro pass for verified-then-lost shards + healthcheck restart softening #144) is from now on the direct alarm for in-flight reversions.
• Next step for the root cause: an upstream RDF4J issue with this evidence package — ReadTxn ThreadLocal leaks at webapp stop on 5.3.2, timestamped commit reversion without restart, the #5807 relationship, and the abort-storm trigger conditions.

🤖 Generated with Claude Code