2 commits

Author	SHA1	Message	Date
Gergő Magyar	c4b69402e1	feat(workers): self-healing worker pool + deferred-resolution observability (#1741) (#1947) ... * fix(workers): fail fast instead of silently degrading on worker-pool startup failure (#1741) When an explicitly-sized worker pool (--workers <N>) fails to start because every worker crashes during top-of-script init, the parse phase used to log a swallowed `logger.warn` and silently fall back to the ~10x slower sequential parser. In #1741 (rc99) that turned a worker-startup regression into a 123-minute "stuck" parse with no explanation. This change: - Surfaces the real crash: the pool now spawns workers with `{ stderr: true }`, tees + captures each worker's stderr, and attaches the tail to its readiness-failure messages (propagated via WorkerPoolInitializationError.readinessFailures). "did not report ready" now carries the underlying native-binding/import error. - Gates the fallback: when --workers was explicit and fallback was not opted into, a total startup failure throws an actionable error instead of degrading. Auto-sized pools still fall back, but loudly (logger.error + progress warning). New --allow-sequential-fallback flag (+ i18n) opts back in. - Adds env-gated worker bootstrap-stage logging (GITNEXUS_WORKER_BOOTSTRAP / --verbose): imports+grammars loaded -> ready sent -> first task received, so a slow/crashing startup is diagnosable. Tests: all-workers-failed gating (fatal vs loud degrade), stderr surfacing, and the updated lazy-cache fallback contract (opt-in flag + fail-fast). Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * feat(ingestion): always-on slow-file watchdog for deferred call resolution (#1741) The original #1741 symptom is a run that appears stuck at "Resolving calls (all chunks)... (9000/18066 files)" — the progress bar freezes inside a single file's call resolution and nothing reaches the log. Rich per-file deferred diagnostics already exist, but only behind --verbose / GITNEXUS_PROFILE_DEFERRED, so a plain `analyze` run gives the user a frozen bar and silence. Add an always-on (not verbose-gated) per-file watchdog in processCallsFromExtracted: when a single file's call resolution exceeds alwaysOnSlowFileWarnMs() (default 15s, override GITNEXUS_SLOW_FILE_WARN_MS, 0 disables) it emits a throttled logger.warn naming the culprit file and the files-resolved-so-far — turning the silent stall into one actionable line. Throttled (>=30s between warnings) so a genuinely slow repo can't storm the log. The watchdog is observation-only; resolution behavior is unchanged. Note: deliberately did NOT add a heritage child x parent product cap — the name lookups are O(1) (type-registry Map.get) and the product is bounded, so the heritage build is not the bottleneck; a cap would risk dropping real edges for no measured gain. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * test(ingestion): worker-vs-sequential parity guard for binding/edge collapse (#1741) rc99 produced almost no bindings/edges (13 bindings vs rc91's 106,305) because a worker-path failure left extracted results unmerged while the run still reported success. Rather than an arbitrary "implausibly low" runtime threshold (which false-positives on legitimately low-binding repos/languages), pin the invariant directly: for the same repo, worker mode and sequential mode must produce the same graph. The test runs the ts-simple cross-file fixture through worker mode (workerPoolSize + lowered threshold) and sequential mode (skipWorkers), and asserts: usedWorkerPool is true/false respectively (guards the test itself against a silent fallback masking divergence), identical CALLS/IMPORTS/DEFINES/ HAS_METHOD edge sets and Class/Function/Method defs, and non-zero CALLS/IMPORTS (the rc99 collapse signature). Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * fix(workers): arm fail-fast for env-sized pools + fix watchdog /0 denominator (#1741) Addresses two review findings on the #1741 worker-startup PR: - Fail-fast gate missed the env channel. `explicitWorkers` keyed only off the `--workers` flag, so a pool sized via `GITNEXUS_WORKER_POOL_SIZE` (with no `--workers`) silently degraded to sequential on a total worker-startup crash — reproducing the original #1741 symptom for env-channel operators. The gate now arms on a non-zero size from either channel, via a single-source `envWorkerPoolSize()` helper exported from worker-pool.ts (also rewired through resolveAutoPoolSize). The fatal message now names the channel actually used instead of "--workers undefined". - Always-on slow-file watchdog printed "Resolved N/0 files". `resolvedTotal` was pre-counted only on the profile path, but the watchdog reads it on every run, so a plain `analyze` showed a bogus /0 denominator on exactly the unprofiled hang the watchdog exists to explain. Pre-count now runs whenever its result is read (profile path OR watchdog active). Tests: strengthened the watchdog test to assert "1/1" (not "/0"); added env-channel fail-fast/degrade cases and made the gating suite hermetic against an ambient GITNEXUS_WORKER_POOL_SIZE. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * feat(workers): self-healing worker pool replaces the fail-fast flag (#1741) Replaces the interim --allow-sequential-fallback flag with automatic, bounded self-healing in the worker pool — industry-standard supervision (OTP restart-intensity, systemd StartLimit, circuit-breaker, AWS jittered backoff) translated to the Node worker_threads pool. worker-pool.ts — bounded startup self-heal (the missing layer): - A worker that crashes during top-of-script init is now RETRIED with capped, full-jitter backoff (BASE 250ms, CAP 2s) up to a small per-slot budget, so a transient blip heals itself with no operator action. The prior code dropped an unready initial slot on its first crash. - A DETERMINISTIC crash-loop (>=2 fresh workers crash with the same normalized signature before any reaches ready — the #1741 missing native-binding case) is detected and short-circuited, so the pool gives up in ~1s instead of burning every slot's budget. Correctness rests on the STRUCTURAL signal (zero workers ever ready + budget exhausted), so a missed signature only costs a few seconds, never a misfire; even a stderr-less crash groups via its normalized "exited with code N" message. - Backoff sleeps are cancellable (unref'd timer + abort on terminate), so terminate() can't be wedged for the backoff duration. - WorkerPoolInitializationError now carries a crashClass for an accurate, flag-free message. The runtime respawn/breaker path is unchanged. parse-impl.ts — collapse to automatic fail-fast: - handleWorkerStartupFailure always logs the real cause then THROWS with the captured crash + `--workers 0` as the explicit sequential escape. No more degrade branch; no dependence on how the pool was sized. This is reached only after the bounded self-heal is exhausted, so it can't resurrect the #1741 silent 123-minute sequential grind. Construction failure (broken install) also fails fast instead of degrading silently. Removed --allow-sequential-fallback end to end (CLI, run-analyze, pipeline, i18n). --workers 0 remains the explicit "parse sequentially" path; one flag removed, none added. Grounded in a research+critique pass; the critique's hazards (N-parallel race, empty-stderr timing, non-cancellable sleep, runtime-breaker regression) are addressed or scoped out by design. Tests: startup self-heal (transient recovers; deterministic fails fast without burning the budget); gating test rewritten to the fail-fast-always contract; obsolete degrade test removed. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * fix(workers): ref + cancel startup backoff so transient retries aren't dropped (#1741 U1) abortableSleep unref'd its backoff timer, so a transient startup retry could be silently dropped if that timer was the last ref'd handle on the event loop — the process could exit mid-recovery. Keep the timer ref'd (a pending retry is necessary work) and register a cancel fn in a pool-scoped set; terminate() now clears pending backoffs so it can't be wedged for the backoff cap. A normally fired timer self-deregisters (clear-on-settle), so no timer lingers after a slot's retry loop exits. Exposes pendingStartupTimers in getStats. Tests: terminate-during-backoff cancels + spawns nothing after (R2); the recovery test now asserts no startup timer lingers after settle (R1). Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * fix(workers): route GITNEXUS_WORKER_POOL_SIZE=0 to sequential, not a phantom fail-fast (#1741 U2) env=0 (no --workers) built a size-0 pool that threw a fabricated "retry budget exhausted / native binding" crash. The shouldUseWorkers gate now routes env=0 to the sequential path before pool construction — but only when no explicit --workers <N> was given, so an explicit positive size wins over an ambient env=0. The route emits one log line so the undocumented (possibly accidental) env=0 case is observable instead of a silent degrade. envWorkerPoolSize is un-exported (module-internal sizing reader); a new workerPoolDisabledByEnv() predicate serves the gate. Empty/whitespace env is now treated as unset (auto formula), not 0 — an empty assignment is an accident, not a request for zero workers. Reattached the detached resolveAutoPoolSize JSDoc and corrected the stale docstring. Tests: env=0 → sequential (no spawn); explicit --workers wins over env=0; workerPoolDisabledByEnv unit (0=true, positive/empty/invalid=false); getStats shape updated for pendingStartupTimers. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * fix(workers): make deterministic crash-loop detection conservative (#1741 U3) The old tally counted crash EVENTS in a shared signature->count map, so a simultaneous transient crash storm (e.g. spawn EAGAIN under fork pressure) or a single slot crashing identically twice falsely tripped "deterministic" and hard-aborted work that would have self-healed. Replace it: a crash counts toward deterministic only after its signature REPRODUCES across a respawn on the same slot, and the short-circuit fires once >=2 distinct slots reproduced (or 1 for a size-1 pool). Every slot now gets >=1 self-heal attempt before any short-circuit; the structural budget floor still bounds the worst case. crashSignature now also collapses Windows backslash paths and bare (no-0x) hex runs so the fast-path fires on those platforms; exported for unit testing. Tests: simultaneous storm self-heals (the discriminator vs an attempt-0 rule); distinct-per-attempt crashes classify transient-exhausted; single-slot reproduction classifies deterministic; crashSignature normalization unit. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * fix(workers): class-aware startup failure hint + reattach detached JSDoc (#1741 U4) The "often a missing/broken native binding" hint was appended to every failure class, including a pool *construction* failure where no worker ever ran (a missing build / bad worker path). Make the hint class-aware: keep it for the readiness/init classes, use a construction-specific hint otherwise, and surface the construction error (e.g. "Worker script not found: …") verbatim. Reattach the waitForWorkerReady JSDoc that the stderr-capture block had detached from its function. (The abortableSleep docstring was already corrected in U1.) Tests: construction message surfaces the real error + drops the native-binding guess; deterministic/transient messages keep the hint (regression guard). Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> --------- Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>	2026-05-31 13:52:04 +01:00
Gergő Magyar	d15f8bef54	feat(ingestion): log deferred resolution progress when verbose (#1741) (#1773) ... * feat(ingestion): log deferred resolution progress when verbose Add [deferred-profile] timing logs for post-chunk import, heritage, heritage-map, and legacy call resolution. Enabled on GITNEXUS_VERBOSE / analyze -v (and optionally GITNEXUS_PROFILE_DEFERRED) to diagnose analyze stalls on large repos (issue #1741). Co-authored-by: Cursor <cursoragent@cursor.com> * chore(autofix): apply prettier + eslint fixes via /autofix command * fix(ingestion): address PR #1773 production-readiness review Move deferred call progress logs after the registry-primary skip so sites= counts match files actually resolved. Only time buildHeritageMap when heritage records exist; otherwise log an explicit skip. Add wiring tests that assert [deferred-profile] emission from buildHeritageMap and processCallsFromExtracted. Snapshot GITNEXUS_PROFILE_DEFERRED env vars in analyze CLI isolation. Co-authored-by: Cursor <cursoragent@cursor.com> * fix(ingestion): address PR #1773 code-review findings P0 - Replace forbidden toBeGreaterThanOrEqual/toBeLessThan in profileElapsedMs test with exact-arithmetic vi.spyOn(hrtime.bigint) asserting .toBe(2.5) and .toBe(0). DoD §2.7 compliance. P2 - Use Number() (not parseInt) when parsing GITNEXUS_PROFILE_DEFERRED_SLOW_MS so scientific notation like '1e9' doesn't silently parse to 1 and turn the slow-file log into a per-file log storm. - Introduce startTimer(enabled): bigint | null and endTimer(start, format) helpers in deferred-resolution-profile.ts; refactor 6+ timing blocks in parse-impl.ts and call-processor.ts to use them. Removes the 0n sentinel that conflated 'disabled' with 'zero elapsed time' and let TS narrow correctly. - Split the call-processor file counter: filesProcessed (all iterated) vs resolvedFiles (post registry-primary skip). Key the every-N progress log and the start-of-phase log on resolvedFiles so mixed Python+JVM repos where the skipped language sorts first still emit 'calls 1/1 file=...' on the first non-skipped file. Adds a wiring test for the mixed-language ordering case. P3 - Restore the original isDev '🔗 E1: Seeded ...' logger.info line so log scrapers keyed on the emoji marker still match; emit the [deferred-profile] variant only when deferredProfile && !isDev. - Move tFile = startTimer(profileCalls) below the registry-primary skip so skipped files don't trigger an hrtime.bigint() call. - Document GITNEXUS_PROFILE_DEFERRED and GITNEXUS_PROFILE_DEFERRED_SLOW_MS in the README env-var table. * refactor(ingestion): extract parseTruthyEnv to shared utils (U5) Three narrow-form env-var truthy checkers (verbose.ts, registry-primary-flag.ts, deferred-resolution-profile.ts) each had their own `'1' | 'true' | 'yes'` parser with subtle divergences (trim or no trim, set vs disjunction). Consolidate on a single `parseTruthyEnv(raw)` helper in utils/env.ts — the module already serves as the centralization point for shared ingestion env constants. logger.ts's broader `isTruthyEnv` (negative-list, pino-debug convention) stays untouched — different intent, different semantics. New table-driven test at test/unit/env.test.ts covers case variants, whitespace, and rejection of falsy / unknown tokens. * refactor(ingestion): named constants for deferred-profile log gates (U6) Replace magic literals 10 / 100 / 3_000 / 5_000 in deferred-resolution-profile.ts with module-private named constants LOG_EVERY_N_VERBOSE, LOG_EVERY_N_PROFILE, DEFAULT_SLOW_MS_VERBOSE, DEFAULT_SLOW_MS. Not exported — internal tuning knobs. Pure refactor; existing tests assert the exact values and still pass unchanged. * fix(ingestion): pre-pass denominator for deferred call progress (U1, A1) The live per-file denominator in processCallsFromExtracted previously read `totalFiles - skippedRegistryPrimaryFiles` at log time. On mixed Python+JVM repos where the skipped language interleaves with the resolved one, the denominator drifts upward as the loop iterates — files iterated before later skips have been seen carry an inflated denominator. The live ratio only self-corrects after the final file has been classified. Fix: one-pass pre-count over byFile.keys() before the work loop computes resolvedTotal once. The denominator is then stable from the first emission onward. The pre-pass runs only on the enabled path (profileCalls=true) so the disabled path keeps zero extra work. Adds a wiring test exercising the alternating [ts, py, ts, py, ...] order that triggered the drift, asserting every emitted line uses `/4` and no other denominator slips through. * fix(ingestion): E1 enrichment log emits on both dev and profile flags (U2, A2) The post-chunk E1 enrichment log used `if (isDev) {...} else if (deferredProfile) {...}` which is mutually exclusive. On combined runs (NODE_ENV=development + GITNEXUS_PROFILE_DEFERRED=1) the [deferred- profile] line was silently swallowed — operators grepping that prefix saw a gap between wildcard-synth and heritage timings, while the inline comment promised dual emission. Fix: two independent `if` statements so both branches fire when both flags are set. The original emoji-prefixed `🔗 E1: Seeded` line keeps its phrasing for any dev-mode log scrapers that depend on the marker. Pinning test (parse-impl-e1-emission-shape.test.ts) reads the source and asserts (a) both branches exist as standalone `if` statements and (b) the closing `}` of the isDev branch is followed by `if`, not `else if`. Source-shape pins are the right test scope for a purely structural change — the regression we are guarding against is exactly how a future reader greps for it. * feat(ingestion): unresolved-side counters in heritage-map profile (U7) The existing maxNameCartesian / ambiguousHeritageRecords counters in buildHeritageMap only observed records where BOTH the child and parent name lookups resolved. On JVM monorepos the actual pathological case is one side empty (typically an unresolved external supertype with many same-named children, or vice versa) — those records were silently dropped from the metric. Add `unresolvedChildLookups` and `unresolvedParentLookups` in a separate `if (profileHeritage)` block placed immediately after the two `lookupClassByName` calls (so it observes the unresolved cases the length-guarded ambiguity block below cannot see). Both counters reuse the existing childDefs / parentDefs values — no additional lookups. Done-summary log extended to include the two new counters. Wiring test covers both directions (unresolved parent, unresolved child) plus the existing "both resolved" baseline now asserts the new counters report zero for that case. * fix(ingestion): endTimer formatter exception safety (U3) Wrap the format callback in endTimer in a try/catch so a throwing formatter (custom toString, JSON.stringify on a circular object, future heavier serializers) cannot abort the deferred resolution band. Observability code must never escalate to a load-bearing failure mode. On catch we emit a single `[deferred-profile] formatter error: …` line via logDeferredProfile and return; the caller's stage continues as if profiling had no-op'd for this timer. DoD §2.8 is satisfied — the failure is surfaced, not silently swallowed. Tests cover the four cases: happy path emits the formatted line, null start no-ops without invoking the formatter, throwing formatter is caught and surfaces one error line, non-Error throws are coerced via String() in the message. * fix(ingestion): defensive wrap + dropped-line counter for logDeferredProfile (U4) Wrap logger.info inside logDeferredProfile in a try/catch so a throwing underlying logger cannot abort the deferred resolution band. Pino with sync:false (the current SonicBoom destination) does not throw synchronously for `info(string)` calls, but first-use construction paths (pino-pretty resolve, level validation) and any future transport reconfiguration could. The wrap is belt-and-suspenders coverage; the counter makes silent failures visible. A module-private droppedLogLines counter accumulates dropped lines. Two helpers — getDeferredProfileDroppedCount() and resetDeferredProfileDroppedCount() — expose the counter. The handler deliberately does NOT call the failing logger; that would risk an infinite loop if the failure is steady-state. processCallsFromExtracted resets the counter at entry (so each analyze run gets a fresh count rather than accumulating across the process lifetime — relevant for the MCP server, eval harness, integration tests), and surfaces the count in the done-summary as `note: N profile log lines dropped (logger errors)` when greater than zero. DoD §2.8 (no silent diagnostic catches) is satisfied. Tests cover the helper API (zero at entry, idempotent reset) and the happy path; the catch arm is pinned via source-shape assertion since the logger Proxy can't be vi.spyOn'd directly (lazy `get` trap, no own-property to wrap). * docs(readme): clarify GITNEXUS_PROFILE_DEFERRED_SLOW_MS coercion (U8) The env-var row mentioned integer / scientific notation only, but the underlying parser (`Number(raw)` since the U2 fix in PR #1773) also accepts decimals like `.5` and hex like `0x10`. Document the actual acceptance set plus the non-finite / non-positive fallback so operators setting unusual values know what to expect. --------- Co-authored-by: Test <test@example.com> Co-authored-by: Cursor <cursoragent@cursor.com> Co-authored-by: github-actions[bot] <41898282+github-actions[bot]@users.noreply.github.com>	2026-05-22 12:37:30 +01:00