Skip to content

Commit 9cbf0e7

Browse files
authored
Add Solr write-health checks (closed IndexWriter / NFS EIO) (#1)
The 2026-06-08 vfb_json outage was invisible to the status page: a closed Lucene IndexWriter (EIO on write.lock when the soft NFS mount dropped) made every /update return 500 while /select and /admin/system stayed 200, and the liveness probe is a /select. Add two detectors across every solr_services core: - Passive, read-only: flag a write outage when UPDATE serverErrors (5xx only) rises between checks; baseline taken from history before the new row lands, so a post-restart counter reset never false-alarms. - Active, opt-in (write_probe): empty commit forces IndexWriter.ensureOpen(), catching a closed writer with no other traffic. Off by default (it is a write request, though an empty commit changes no documents). A write failure marks the container not-ok and shows a 'writes failing' badge. Adds solr_history.u_server_errors (migrated via ADD COLUMN) and exposes u_server_errors / write_ok / write_detail on /api/solr.
1 parent f8e9647 commit 9cbf0e7

4 files changed

Lines changed: 176 additions & 6 deletions

File tree

CHANGELOG.md

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,16 @@
22

33
All notable changes to vfb-status are recorded here. The format is loosely based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/) and the project follows [Semantic Versioning](https://semver.org/spec/v2.0.0.html).
44

5+
## [0.12.0] — 2026-06-08
6+
7+
### Added
8+
9+
- **Solr write-health checks.** Catches the failure mode that took out `vfb_json` on 2026-06-08: a closed Lucene `IndexWriter` (an `EIO` on `write.lock` when the soft NFSv3 mount backing `/var/solr` dropped) turns every `/update` into an HTTP 500 while `/select` and `/admin/system` keep returning 200. The existing liveness probe is a `/select`, so the page stayed green throughout the outage. Two detectors now run against **every** core in `solr_services`:
10+
- **Passive (always on, read-only).** Tracks the `UPDATE./update.serverErrors.count` counter (5xx only — client 4xx can't trip it) and flags a write outage when it climbs between checks. Computed from history before the new row is written, so each check seeds the next baseline. A post-restart counter reset reads as a negative delta and never false-alarms. No writes against prod.
11+
- **Active (opt-in, `write_probe: true` per service).** Issues an empty commit — the only request that reliably forces `IndexWriter.ensureOpen()` — so it detects a closed writer even with no other traffic. An empty commit changes no documents, but it is a write request, so it is **off by default**; enable per service where a periodic empty commit is acceptable.
12+
- A container failing writes is marked not-ok (so it counts against uptime and surfaces in the cluster-degraded table) and the Solr card shows a `writes failing ⚠` badge. New fields `u_server_errors`, `write_ok`, `write_detail` on `/api/solr`.
13+
- `solr_history.u_server_errors` column, added to existing databases via the standard `_migrate()` ADD COLUMN path.
14+
515
## [0.11.4] — 2026-06-05
616

717
### Fixed

app/main.py

Lines changed: 149 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -212,6 +212,13 @@ class SolrServiceSpec:
212212
fronts: str | None = None
213213
timeout: float = 12.0
214214
verify_tls: bool = True
215+
# Active write-liveness probe. When true, each check issues an empty
216+
# commit to /update — the only request that reliably forces Lucene to
217+
# call IndexWriter.ensureOpen(), so it returns 500 the moment the writer
218+
# is closed (e.g. an EIO on write.lock from a soft NFS mount dropping).
219+
# It is a write request, so it's OFF by default and must be opted into
220+
# per service in services.yml. An empty commit adds/changes no documents.
221+
write_probe: bool = False
215222
rancher: "RancherEnumeration | None" = None
216223

217224

@@ -249,6 +256,17 @@ class SolrCheck:
249256
u_requests: int | None = None
250257
u_mean_rate: float | None = None
251258
u_errors: int | None = None
259+
# 5xx-only update errors (UPDATE./update.serverErrors.count). A closed
260+
# IndexWriter turns every /update into an HTTP 500, so this counter
261+
# climbing between checks is the signal that writes are failing while
262+
# reads (and /admin/system) stay green. Tracked separately from u_errors
263+
# so a burst of client 4xx can't masquerade as a write outage.
264+
u_server_errors: int | None = None
265+
# Write-path verdict. None = not assessed this cycle; True = writes ok;
266+
# False = writes failing (set by the active probe or by a rising
267+
# serverErrors delta). When False the check is also marked not-ok.
268+
write_ok: bool | None = None
269+
write_detail: str | None = None
252270

253271

254272
@dataclass
@@ -440,6 +458,7 @@ def load_solr_services(path: Path) -> list[SolrServiceSpec]:
440458
fronts=svc.get("fronts"),
441459
timeout=float(svc.get("timeout", 12.0)),
442460
verify_tls=bool(svc.get("verify_tls", True)),
461+
write_probe=bool(svc.get("write_probe", False)),
443462
rancher=ranch,
444463
)
445464
)
@@ -1151,6 +1170,42 @@ async def probe_all_neo4j(services: Iterable[Neo4jServiceSpec]) -> list[Neo4jChe
11511170
# ----- Solr probing ---------------------------------------------------------
11521171

11531172

1173+
async def _solr_write_probe(
1174+
client: httpx.AsyncClient,
1175+
base_url: str,
1176+
svc: SolrServiceSpec,
1177+
headers: dict[str, str],
1178+
) -> tuple[bool, str | None]:
1179+
"""Issue an empty commit against /update and report whether the write
1180+
path is alive. Returns (ok, detail).
1181+
1182+
An empty commit (`{"commit":{}}`) adds, deletes, and changes nothing, but
1183+
it forces DirectUpdateHandler2 → IndexWriter.ensureOpen(). When the writer
1184+
has been closed by a storage fault (the classic case: an EIO on
1185+
write.lock when a soft NFS mount drops), Solr answers 500 with
1186+
"this IndexWriter is closed". A healthy core answers 200. This is the only
1187+
probe that catches the failure mode where reads stay green but writes are
1188+
dead, which a plain /select can't see.
1189+
"""
1190+
url = f"{base_url}/solr/{svc.core}/update?commit=true"
1191+
try:
1192+
resp = await client.post(
1193+
url, timeout=svc.timeout,
1194+
headers={**headers, "Content-Type": "application/json"},
1195+
content=b'{"commit":{}}', follow_redirects=True,
1196+
)
1197+
except httpx.TimeoutException:
1198+
return False, f"timeout after {svc.timeout}s"
1199+
except Exception as exc: # noqa: BLE001
1200+
return False, f"{type(exc).__name__}: {exc}"
1201+
if resp.status_code == 200:
1202+
return True, None
1203+
detail = f"HTTP {resp.status_code}"
1204+
if "IndexWriter is closed" in resp.text:
1205+
detail += " (IndexWriter closed — check storage/NFS mount)"
1206+
return False, detail
1207+
1208+
11541209
async def _probe_solr_at(
11551210
client: httpx.AsyncClient,
11561211
svc: SolrServiceSpec,
@@ -1199,7 +1254,7 @@ async def _get(url: str) -> tuple[bool, dict[str, Any] | None, str | None]:
11991254

12001255
mb_ok, mb_body, mb_err = await _get(mbeans_url)
12011256
q_requests = q_mean = q_errors = q_timeouts = q_total = None
1202-
u_requests = u_mean = u_errors = None
1257+
u_requests = u_mean = u_errors = u_server_errors = None
12031258
if mb_ok and mb_body is not None:
12041259
beans = mb_body.get("solr-mbeans") or []
12051260
# beans alternates [cat_name, handlers_dict, ...]
@@ -1220,14 +1275,31 @@ async def _get(url: str) -> tuple[bool, dict[str, Any] | None, str | None]:
12201275
elif cat == "UPDATE" and hname == "/update":
12211276
u_requests = _to_int(stats.get("UPDATE./update.requests"))
12221277
u_errors = _to_int(stats.get("UPDATE./update.errors.count"))
1278+
u_server_errors = _to_int(stats.get("UPDATE./update.serverErrors.count"))
12231279
mr = stats.get("UPDATE./update.requestTimes.meanRate")
12241280
u_mean = float(mr) if mr is not None else None
12251281

1282+
# Active write-liveness probe (opt-in). An empty commit is the only
1283+
# request that reliably exercises IndexWriter.ensureOpen(); a closed
1284+
# writer answers it with HTTP 500 while /select and /admin/system stay
1285+
# green. Skipped unless write_probe is set on the service.
1286+
write_ok: bool | None = None
1287+
write_detail: str | None = None
1288+
if svc.write_probe:
1289+
write_ok, write_detail = await _solr_write_probe(client, base_url, svc, headers)
1290+
12261291
latency_ms = int((datetime.now(timezone.utc) - started).total_seconds() * 1000)
1292+
err = (f"mbeans: {mb_err}" if (not mb_ok and mb_err) else None)
1293+
ok = True
1294+
if write_ok is False:
1295+
ok = False
1296+
wmsg = f"write probe failed: {write_detail}"
1297+
err = f"{err} | {wmsg}" if err else wmsg
12271298
return SolrCheck(
1228-
name=svc.name, base_url=base_url, core=svc.core, ok=True,
1299+
name=svc.name, base_url=base_url, core=svc.core, ok=ok,
12291300
checked_at=iso_started, container=container, latency_ms=latency_ms,
1230-
error=(f"mbeans: {mb_err}" if (not mb_ok and mb_err) else None),
1301+
error=err,
1302+
write_ok=write_ok, write_detail=write_detail,
12311303
jvm_mem_used=_to_int(mem_raw.get("used")),
12321304
jvm_mem_free=_to_int(mem_raw.get("free")),
12331305
jvm_mem_total=_to_int(mem_raw.get("total")),
@@ -1247,6 +1319,7 @@ async def _get(url: str) -> tuple[bool, dict[str, Any] | None, str | None]:
12471319
q_requests=q_requests, q_mean_rate=q_mean, q_errors=q_errors,
12481320
q_timeouts=q_timeouts, q_total_time_ns=q_total,
12491321
u_requests=u_requests, u_mean_rate=u_mean, u_errors=u_errors,
1322+
u_server_errors=u_server_errors,
12501323
)
12511324

12521325

@@ -1614,7 +1687,8 @@ class History:
16141687
q_total_time_ns INTEGER,
16151688
u_requests INTEGER,
16161689
u_mean_rate REAL,
1617-
u_errors INTEGER
1690+
u_errors INTEGER,
1691+
u_server_errors INTEGER
16181692
);
16191693
CREATE INDEX IF NOT EXISTS idx_solr_service_ts ON solr_history (service, ts);
16201694
CREATE INDEX IF NOT EXISTS idx_solr_service_container_ts ON solr_history (service, container, ts);
@@ -1731,6 +1805,37 @@ def _migrate(self) -> None:
17311805
"CREATE INDEX IF NOT EXISTS idx_neo4j_service_container_ts "
17321806
"ON neo4j_history (service, container, ts)"
17331807
)
1808+
# solr_history.u_server_errors (added in v0.12.0 for write-health)
1809+
solr_cols = {r[1] for r in self._conn.execute("PRAGMA table_info(solr_history)")}
1810+
if solr_cols and "u_server_errors" not in solr_cols:
1811+
self._conn.execute("ALTER TABLE solr_history ADD COLUMN u_server_errors INTEGER")
1812+
log.info("history: added u_server_errors column to solr_history")
1813+
1814+
def last_solr_server_errors(self, service: str, container: str | None) -> int | None:
1815+
"""Most recent stored UPDATE serverErrors count for one (service,
1816+
container), or None if unknown. Used to compute the per-check delta
1817+
that flags a write outage. Returns None when history is disabled so
1818+
the caller treats it as "no baseline yet" rather than zero.
1819+
"""
1820+
if self._conn is None:
1821+
return None
1822+
if container is None:
1823+
row = self._conn.execute(
1824+
"SELECT u_server_errors FROM solr_history "
1825+
"WHERE service = ? AND container IS NULL "
1826+
"ORDER BY ts DESC LIMIT 1",
1827+
(service,),
1828+
).fetchone()
1829+
else:
1830+
row = self._conn.execute(
1831+
"SELECT u_server_errors FROM solr_history "
1832+
"WHERE service = ? AND container = ? "
1833+
"ORDER BY ts DESC LIMIT 1",
1834+
(service, container),
1835+
).fetchone()
1836+
if row is None or row[0] is None:
1837+
return None
1838+
return int(row[0])
17341839

17351840
def record(self, results: Iterable[CheckResult]) -> None:
17361841
if self._conn is None:
@@ -1800,6 +1905,7 @@ def record_solr(self, results: Iterable[SolrCheck]) -> None:
18001905
r.host_mem_total, r.host_mem_free, r.solr_version,
18011906
r.q_requests, r.q_mean_rate, r.q_errors, r.q_timeouts,
18021907
r.q_total_time_ns, r.u_requests, r.u_mean_rate, r.u_errors,
1908+
r.u_server_errors,
18031909
)
18041910
for r in results
18051911
]
@@ -1813,8 +1919,8 @@ def record_solr(self, results: Iterable[SolrCheck]) -> None:
18131919
" jvm_mem_used_pct, system_load, open_fds, max_fds, "
18141920
" host_mem_total, host_mem_free, solr_version, "
18151921
" q_requests, q_mean_rate, q_errors, q_timeouts, q_total_time_ns, "
1816-
" u_requests, u_mean_rate, u_errors) "
1817-
"VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)",
1922+
" u_requests, u_mean_rate, u_errors, u_server_errors) "
1923+
"VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)",
18181924
rows,
18191925
)
18201926
cur.execute("COMMIT")
@@ -2384,6 +2490,35 @@ async def run_checks(self) -> None:
23842490
self.solr_results = {}
23852491
for sr in solr_results:
23862492
self.solr_results.setdefault(sr.name, []).append(sr)
2493+
# Passive write-health detector (read-only). A closed
2494+
# IndexWriter turns every /update into an HTTP 500, so the
2495+
# UPDATE serverErrors counter climbs while /select and
2496+
# /admin/system stay green — invisible to the liveness probe.
2497+
# Compare each container's counter against its previous stored
2498+
# value; a rise means writes are failing right now. Computed
2499+
# before record_solr() so this cycle's value becomes the next
2500+
# baseline. Only 5xx are counted, so client 4xx can't trip it.
2501+
# The active write_probe (opt-in) is more direct; this catches
2502+
# the same failure with zero writes against prod.
2503+
if self.history.enabled:
2504+
for sr in solr_results:
2505+
if sr.write_ok is False or sr.u_server_errors is None:
2506+
continue
2507+
baseline = self.history.last_solr_server_errors(sr.name, sr.container)
2508+
if baseline is not None and sr.u_server_errors > baseline:
2509+
delta = sr.u_server_errors - baseline
2510+
sr.write_ok = False
2511+
sr.write_detail = (
2512+
f"{delta} new update 5xx since last check "
2513+
"(IndexWriter likely closed — reads ok, writes failing; "
2514+
"check storage/NFS mount)"
2515+
)
2516+
sr.ok = False
2517+
sr.error = (
2518+
f"{sr.error} | {sr.write_detail}" if sr.error else sr.write_detail
2519+
)
2520+
elif sr.write_ok is None:
2521+
sr.write_ok = True
23872522
self.cluster_result = cluster_result
23882523
self.last_run = datetime.now(timezone.utc).isoformat(timespec="seconds")
23892524
self.persist()
@@ -2625,6 +2760,11 @@ def _max(attr: str) -> int | None:
26252760
"u_mean_rate_sum": (sum(c.u_mean_rate for c in ok_containers if c.u_mean_rate is not None)
26262761
if any(c.u_mean_rate is not None for c in ok_containers) else None),
26272762
"first_err": next((c.error for c in containers if not c.ok and c.error), None),
2763+
# Write-path rollup: how many containers are failing writes, and the
2764+
# first explanation, so the card can flag a write outage even though
2765+
# /select stays green.
2766+
"write_failing": sum(1 for c in containers if c.write_ok is False),
2767+
"write_detail": next((c.write_detail for c in containers if c.write_ok is False and c.write_detail), None),
26282768
}
26292769
series = state.history.solr_series(
26302770
svc.name, _cache_chart_window_seconds(), max_points=120
@@ -3030,6 +3170,9 @@ async def api_solr(request: Request) -> JSONResponse:
30303170
"u_requests": c.u_requests,
30313171
"u_mean_rate": c.u_mean_rate,
30323172
"u_errors": c.u_errors,
3173+
"u_server_errors": c.u_server_errors,
3174+
"write_ok": c.write_ok,
3175+
"write_detail": c.write_detail,
30333176
}
30343177
for c in containers
30353178
]

app/templates/index.html

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -523,6 +523,9 @@ <h2>Solr — load over time</h2>
523523
{{ s.container_count }} container{{ '' if s.container_count == 1 else 's' }} ({{ s.ok_count }} ok)
524524
</div>
525525
</div>
526+
{% if s.write_failing and s.write_failing > 0 %}
527+
<span class="badge badge-down" title="{{ s.write_detail or 'update path failing' }}">writes failing ⚠</span>
528+
{% endif %}
526529
{% if s.container_count > 0 and s.ok_count == s.container_count %}
527530
<span class="pill up">ok</span>
528531
{% elif s.container_count == 0 %}

config/services.yml

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -238,6 +238,20 @@ neo4j_services:
238238
# and /solr/<core>/admin/mbeans?stats=true for /select and /update handler
239239
# stats (cumulative requests + meanRate). Per-container probing via Rancher
240240
# v1 API; fallback to LB-fronted probe.
241+
#
242+
# Write-health (added v0.12.0): a closed IndexWriter — e.g. an EIO on
243+
# write.lock when the soft NFS mount backing /var/solr drops — turns every
244+
# /update into an HTTP 500 while /select and /admin/system stay green, so a
245+
# plain liveness check misses it. Two detectors, both applied to EVERY core
246+
# below:
247+
# 1. Passive (always on, read-only): the UPDATE serverErrors counter rising
248+
# between checks flags a live write outage. No prod writes.
249+
# 2. Active (opt-in per service: `write_probe: true`): issues an empty
250+
# commit, the only request that forces IndexWriter.ensureOpen(), so it
251+
# detects a closed writer even with no other traffic. It IS a write
252+
# request (an empty commit changes no documents), so it's off by default
253+
# — enable only where issuing a periodic empty commit against the core is
254+
# acceptable.
241255
solr_services:
242256
- name: SOLR (solr.virtualflybrain.org)
243257
base_url: https://solr.virtualflybrain.org

0 commit comments

Comments
 (0)