HarperFast / HarperFast/harper-pro
'indexing-finished' signal has no receiver: worker threads latch isIndexing=true permanently, 503 on every search of a completed index
- Dominant language
- JavaScript
- Stars
- 3
- Forks
- 0
- Avg merge
- 1d 21h
- Merged PRs (30d)
- 80
Description
> **Suggested priority: P2** — permanent per-thread 503s on a healthy index after any rolling
> restart, invisible to `describe_table` and load-balanced into "intermittent". A live workaround
> exists (set the flag via inspector), and the fix is small: the `'indexing-finished'` signal at
> `databases.js:2140` just needs a receiver.
## Summary
The `'indexing-finished'` schema event is **broadcast but never consumed**. Any worker thread that opens an index dbi while `indexingPID` is still present in the attribute descriptor latches `dbi.isIndexing = true` and has **no path back to `false`** for the life of the thread. Every `search()` on that attribute from that thread then throws `IndexRebuildingError` (503) forever, even though the backfill completed cleanly and the index on disk is complete.
Observed on **harper-pro 5.2.1**, Node v24.19.0, a 4-node cluster, on a newly-added `Int @indexed` attribute. 12 of 64 worker threads across 3 nodes were permanently stuck; the 4th node was entirely clean.
## The defect
`databases.js:2140` — on clean completion, the backfilling thread clears its own flags and signals siblings:
```js
attribute.dbi.isIndexing = false;
const activeDbi = Table.indices[attribute.name];
if (activeDbi) activeDbi.isIndexing = false;
...
await signalling.signalSchemaChange(
new SchemaEventMsg(process.pid, 'indexing-finished', Table.databaseName, Table.tableName));
```
`grep -rn "indexing-finished" dist/` returns **exactly one hit — that send.** Nothing subscribes to it. So the clearing is purely thread-local to whichever thread ran the backfill.
Meanwhile `databases.js:1871` latches the flag on any *other* thread that opens the dbi during the backfill window:
```js
// If a migration is in progress (indexingPID set), any newly opened dbi must also
// reflect isIndexing = true.
if (attributeDescriptor?.indexingPID) dbi.isIndexing = true;
```
That set is correct in isolation, but it is one-way: the only code that clears `isIndexing` is inside `runIndexing()`'s completion path, which runs in a single thread. A thread that opens the dbi inside the window and is not the backfilling thread keeps `true` permanently.
`search.js:284` then resolves exactly that object, and `search.js:407-413` rejects:
```js
const index = isPrimaryKey ? Table.primaryStore : Table.indices[attribute_name];
...
if (!index || index.isIndexing || needFullScan || ...) {
if (index?.isIndexing)
throw new IndexRebuildingError(`"${attribute_name}" is not indexed yet, can not search for this attribute`);
```
## Evidence that the index was complete and the flag was purely stale
Probed every worker thread (ports 9229–9245) on all 4 nodes via CDP.
**Persisted descriptor** (`Table.dbisDB.get("/")`) — identical on all nodes, i.e. Harper's own on-disk record says the backfill finished cleanly:
```json
{"indexingPID": null, "indexingFailed": null, "lastIndexedKey": null, "restartNumber": null}
```
**Raw index audit, read from the stuck threads themselves** — the index dbi is complete and exactly matches the primary store:
```
port 9238: {wi:8, isIndexing:true, idxEntries:8, rows:8, match:true, persistedPID:null, persistedFailed:null}
port 9233: {wi:3, isIndexing:true, idxEntries:8, rows:8, match:true, persistedPID:null, persistedFailed:null}
port 9242: {wi:12, isIndexing:true, idxEntries:8, rows:8, match:true, persistedPID:null, persistedFailed:null}
```
Indexed search vs full scan on a *healthy* thread of the same node returned identical results (8/8 rows, same values).
**Distribution** — same table, same data, same version; only the in-memory boolean differs:
| Node | Stuck worker threads |
|---|---|
| A | wi 3, 4, 5, 8, 12, 14 (6 of 16) |
| B | wi 0, 1, 7, 10 (4 of 16) |
| C | wi 12, 13 (2 of 16) |
| D | **none** |
Log attribution matched the probe 1:1 (`http/N` == `wi N-1`), and error volume tracked per-thread traffic (one thread produced 683 errors in 20 min).
## Secondary symptom: leaked read snapshots
Each rejected search leaks a read snapshot that is only reclaimed when the open-transaction limit trips, producing a matching warn per error:
```
[warn]: Read iterators held a committed transaction's snapshot past the open-transaction limit; releasing it, from table: /
```
Counts tracked the errors ~1:1 per thread over 20 min (683/663, 343/338, 260/262, 247/240, 192/185). Combined, the two streams produced ~520 MB of logs in 3 h on one node.
## Why it is not self-healing
- `indexingPID`/`indexingFailed` are absent from the persisted descriptor, so the crash-recovery / retry triggers in `databases.js` do **not** re-fire — Harper correctly believes indexing is done.
- Nothing consumes `'indexing-finished'`.
- The flag is per-thread in-memory state, so it survives until that worker generation is replaced.
A restart is not a reliable remedy: it re-runs the same race. In this incident the stuck state was *created* by a rolling restart, and the one node that restarted outside the window was the clean one.
## Impact
Any consumer searching that attribute gets a permanent 503 on a subset of threads — load-balanced, so it presents as intermittent. In our case the caller degraded fail-safe (feature held at its default), but a caller that treats 503 as fatal, or one whose correctness depends on the query, would see a partial outage that no metric attributes to an index problem. `describe_table` reports the attribute as normally `indexed` and gives no hint.
## Workaround
Setting the flag to match the already-correct persisted state clears it with no restart:
```js
databases...indices..isIndexing = false;
```
Applied to all 12 threads; both log streams went to zero immediately and indexed search returned correct results on every thread.
## Suggested fix
1. Add a receiver for `'indexing-finished'` that re-reads the descriptor and clears `isIndexing` on `attribute.dbi` and `Table.indices[name]` — the send at `databases.js:2140` currently has no counterpart.
2. Consider deriving `isIndexing` from the persisted descriptor at query time (or re-validating on miss) rather than caching a one-way per-thread boolean, so a missed signal cannot strand a thread permanently.
3. Optionally, rate-limit / dedupe the `IndexRebuildingError` log so a stuck thread cannot emit hundreds of MB of logs.
Contributor guide
Research direction
Start in databases.js around lines 1871 and 2140, then trace the schema-event handling and the isIndexing checks in search.js around lines 284 and 407-413. Verify the indexing-finished event reaches every worker and that completed indexes no longer leave stale flags or produce 503 searches; the persisted descriptor should remain the source of completion state.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- javascript, node.js
- Domain
- backend, databases
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Quiet
- Clarity
- Clearly specified
- Newbie friendliness
- 68/100