已合并
Implement bounded runtime metrics and execution health for #175 #168
urandon创建于 24 天前
Implement bounded runtime metrics and execution health for #175 #168
已合并
共 93 个文件变更+12059-193
| @@ -100,3 +100,14 @@ When cache identity evidence conflicts, the text and JSON diagnostics expose onl | |||
| 100 | The registry and bounded job history survive daemon restart. Active jobs restored after a crash become `interrupted`; the next reconciliation validates the cache again and safely reschedules incomplete work. Identity replacement, unreadable caches, sync failures, and index failures become explicit degraded states. Startup validates registered caches through a fixed four-worker pool behind one global one-second inspection budget; filesystem canonicalization and SQLite inspection are both inside that boundary. Registry size therefore cannot grow pre-listener latency or permanently blocked inspection workers without bound. An OS or host-policy filesystem operation that does not observe context cancellation disables the affected and not-yet-inspected registrations as `cache_inspection_timeout`; the control socket still becomes available. Durable sync-stage recovery begins only after the control endpoint is published, and affected cache writer authorities remain fenced until recovery finishes or its terminal failure is durably recorded. If either recovery or that persistence fails, the interrupted job and writer fence remain in place for a later restart. A blocked recovery stays visible as an interrupted job without preventing cached status and diagnostic reads. The diagnostic tells operators to grant the installed service access to the cache location or use foreground service mode, without returning the private path. A later successful daemon restart restores the prior enabled state through normal identity validation. A persisted enrollment whose configuration snapshot hash or cache authority no longer matches its registration is disabled as `config_snapshot_invalid`; reconciliation remains blocked until the snapshot is repaired and revalidated. | 100 | The registry and bounded job history survive daemon restart. Active jobs restored after a crash become `interrupted`; the next reconciliation validates the cache again and safely reschedules incomplete work. Identity replacement, unreadable caches, sync failures, and index failures become explicit degraded states. Startup validates registered caches through a fixed four-worker pool behind one global one-second inspection budget; filesystem canonicalization and SQLite inspection are both inside that boundary. Registry size therefore cannot grow pre-listener latency or permanently blocked inspection workers without bound. An OS or host-policy filesystem operation that does not observe context cancellation disables the affected and not-yet-inspected registrations as `cache_inspection_timeout`; the control socket still becomes available. Durable sync-stage recovery begins only after the control endpoint is published, and affected cache writer authorities remain fenced until recovery finishes or its terminal failure is durably recorded. If either recovery or that persistence fails, the interrupted job and writer fence remain in place for a later restart. A blocked recovery stays visible as an interrupted job without preventing cached status and diagnostic reads. The diagnostic tells operators to grant the installed service access to the cache location or use foreground service mode, without returning the private path. A later successful daemon restart restores the prior enabled state through normal identity validation. A persisted enrollment whose configuration snapshot hash or cache authority no longer matches its registration is disabled as `config_snapshot_invalid`; reconciliation remains blocked until the snapshot is repaired and revalidated. |
| 101 | 101 | ||
| 102 | Sync and RAG failures are tracked independently. Each failed stage keeps a sanitized error class and uses persisted exponential retry backoff from one minute up to 64 minutes; success of that same stage clears its failure state. A backed-off stage does not prevent healthy work in the other stage. Disabling a registration is reversible and does not mutate cache content. | 102 | Sync and RAG failures are tracked independently. Each failed stage keeps a sanitized error class and uses persisted exponential retry backoff from one minute up to 64 minutes; success of that same stage clears its failure state. A backed-off stage does not prevent healthy work in the other stage. Disabling a registration is reversible and does not mutate cache content. |
| 103 | + | ||
| 104 | +Repository-document Git/policy/revision-set inspection is also independent of | ||
| 105 | +indexing. Its fixed-size result and retained failure episode live on the | ||
| 106 | +existing source registration and use actual inspection-completion timestamps. | ||
| 107 | +A successful inspection can leave the source `not_indexed`; conversely, an old | ||
| 108 | +successful index cannot prove that its Git source is currently available. | ||
| 109 | +Observability health distinguishes `inspection` from `indexing`, marks legacy | ||
| 110 | +or inconsistent inspection history partial/unknown, and never reads Git or | ||
| 111 | +starts maintenance while answering a health query. This backend evidence is | ||
| 112 | +not the complete observation UI/CLI/MCP feature; transport and UI rollout have | ||
| 113 | +their own qualification gates. | ||
| @@ -91,6 +91,7 @@ flowchart TD | |||
| 91 | | Repository documentation RAG | `internal/repositorydocs/`, metadata tables in `internal/cache/` | Resolves committed corpus policy, reads exact local Git objects, chunks in memory, publishes immutable revision sets/vectors, and hydrates verified citations. | Git is the only document-byte authority; aliases canonicalize before writes; no fetch and no persistent source/chunk text. | | 91 | | Repository documentation RAG | `internal/repositorydocs/`, metadata tables in `internal/cache/` | Resolves committed corpus policy, reads exact local Git objects, chunks in memory, publishes immutable revision sets/vectors, and hydrates verified citations. | Git is the only document-byte authority; aliases canonicalize before writes; no fetch and no persistent source/chunk text. | |
| 92 | | Maintenance identity resolution | `internal/servicectl/maintenance.go`, `maintenance_conflicts.go`, Admin controls | Canonicalizes aliases, preserves lossless conflict candidates, renders a generation-fenced selection plan, then atomically promotes one repository authority or one complete physical clone-path cohort behind a cache-writer admission fence. | Distinct repositories never merge across a clone; public surfaces receive paired hashes/fingerprints only; cache paths, repository paths, and config snapshots remain daemon-private. | | 92 | | Maintenance identity resolution | `internal/servicectl/maintenance.go`, `maintenance_conflicts.go`, Admin controls | Canonicalizes aliases, preserves lossless conflict candidates, renders a generation-fenced selection plan, then atomically promotes one repository authority or one complete physical clone-path cohort behind a cache-writer admission fence. | Distinct repositories never merge across a clone; public surfaces receive paired hashes/fingerprints only; cache paths, repository paths, and config snapshots remain daemon-private. | |
| 93 | | Maintenance coordinator | `internal/servicectl/` | Owns the per-user managed-cache registry, identity validation, head/tail scheduling, job coalescing, and sanitized lifecycle status. | Raw cache paths stay daemon-local; scheduling keys include durable cache UUID and repository. | | 93 | | Maintenance coordinator | `internal/servicectl/` | Owns the per-user managed-cache registry, identity validation, head/tail scheduling, job coalescing, and sanitized lifecycle status. | Raw cache paths stay daemon-local; scheduling keys include durable cache UUID and repository. | |
| 94 | +| Bounded observation foundations | `internal/observability/` | Keeps catalog-only events and volatile fixed-cardinality metric samples separate from execution authority. | Recording never waits for disk, network, a probe or a telemetry reader; loss and unavailable probes remain explicit. Full transport/UI rollout is a separate cohort. | | ||
| 94 | | Indexer | `internal/index/` | Parses markdown, headings, stable ids, links, anchors, chunks, and freshness state. | Indexed chunks carry provenance and citations needed by CLI/MCP reads and snapshots. | | 95 | | Indexer | `internal/index/` | Parses markdown, headings, stable ids, links, anchors, chunks, and freshness state. | Indexed chunks carry provenance and citations needed by CLI/MCP reads and snapshots. | |
| 95 | | GitCode provider boundary | `internal/gitcode/` | Defines provider interfaces, fixture behavior, live HTTP adapter, API models, route matrix, pagination, and write confirmation. | Live API shape decisions stay behind this adapter. Fixture mode remains deterministic and network-free. | | 96 | | GitCode provider boundary | `internal/gitcode/` | Defines provider interfaces, fixture behavior, live HTTP adapter, API models, route matrix, pagination, and write confirmation. | Live API shape decisions stay behind this adapter. Fixture mode remains deterministic and network-free. | |
| 96 | | Route schema matrix | `internal/gitcode/route_schema_matrix.go` | Declares supported, deferred, and unsupported route families by product area. | Unsupported or deferred capabilities return explicit diagnostics instead of empty success. | | 97 | | Route schema matrix | `internal/gitcode/route_schema_matrix.go` | Declares supported, deferred, and unsupported route families by product area. | Unsupported or deferred capabilities return explicit diagnostics instead of empty success. | |
| @@ -150,6 +151,424 @@ flowchart TD | |||
| 150 | 151 | ||
| 151 | ## Related Docs | 152 | ## Related Docs |
| 152 | 153 | ||
| 154 | +### Event admission isolation | ||
| 155 | + | ||
| 156 | +Validated catalog events enter the bounded queue through `TryLock` admission. | ||
| 157 | +An observation reader or writer holding the collector mutex cannot delay an | ||
| 158 | +execution producer: rejected admission increments one atomic pending-loss scalar | ||
| 159 | +without retaining the rejected event. Observation snapshots and asynchronous | ||
| 160 | +checkpoints fold that scalar into dropped-event coverage and the cursor loss | ||
| 161 | +epoch. A previously issued cursor therefore requires a new snapshot after loss; | ||
| 162 | +checkpointed loss survives restart. Production instrumentation never retries | ||
| 163 | +rejected events, and invalid codes or untrusted references do not manufacture | ||
| 164 | +an execution-loss boundary. Close atomically seals and folds pending losses | ||
| 165 | +before shutdown persistence; rejections and delayed producer increments after | ||
| 166 | +that seal cannot alter published coverage or invalidate clean cursors. This | ||
| 167 | +best-effort evidence is not execution authority | ||
| 168 | +and does not promise crash durability before its asynchronous checkpoint. | ||
| 169 | + | ||
| 170 | +Execution events use additive schema-1 `phase`, `collection`, `outcome`, | ||
| 171 | +`failure_class`, optional `attempt`, and writer-only `work_kind` fields. Their closed, code-specific | ||
| 172 | +compatibility table is checked before admission and again during replay. Job | ||
| 173 | +admission/terminal, provider-attempt, sync-commit, and retry-admission codes | ||
| 174 | +require resolved opaque correlation; job, commit, and retry codes also require | ||
| 175 | +an opaque job ref. | ||
| 176 | +Terminal outcomes include succeeded, failed, cancelled, interrupted, and | ||
| 177 | +superseded; cancellation, interruption, and supersession carry the matching | ||
| 178 | +finite class rather than an arbitrary owner error string. | ||
| 179 | +Attempt ordinals are bounded to 1024; absent means unknown, not an invented | ||
| 180 | +first attempt. Existing lifecycle records remain valid without these fields, | ||
| 181 | +but cannot carry execution dimensions. Legacy text cannot establish an | ||
| 182 | +execution event. A private context carrier copies resolved refs and a concrete | ||
| 183 | +collector without changing deadlines or cancellation; event details are supplied | ||
| 184 | +at the actual boundary. Daemon construction attaches the collector to the job | ||
| 185 | +owner. Confirmed admission and active-to-terminal transitions copy primitive | ||
| 186 | +identity under the existing job lock; opaque hashing and admission run after | ||
| 187 | +unlocking. Newly dispatched and resumed workers inherit boot/job correlation | ||
| 188 | +from the returned authority value, without another instrumentation job read. | ||
| 189 | +Coalesced admission, failed persistence, repeated terminal updates and snapshot | ||
| 190 | +projection are not new execution events. | ||
| 191 | +If a failed snapshot retains a terminal mutation in memory, its unconfirmed | ||
| 192 | +boundary records ledger loss with `execution_boundary_unconfirmed`; a later | ||
| 193 | +repeat or unrelated snapshot does not invent a confirmed event. A rolled-back | ||
| 194 | +terminal attempt records no ledger loss and a confirmed retry emits normally. | ||
| 195 | +This bounded atomic loss participates in the ledger seal/checkpoint, restart | ||
| 196 | +and cursor-loss boundary, but not the admission-rejection `event_drops` metric. | ||
| 197 | + | ||
| 198 | +Actual GitCode and embedding HTTP attempts inherit that context and record one | ||
| 199 | +finite transport outcome after bounded response transfer/body release. This is | ||
| 200 | +not proof of successful JSON decoding or embedding. Pre-transport rejection | ||
| 201 | +records no attempt; ordinals are supplied only by a known policy loop. | ||
| 202 | +Confirmed graph commits mark a concrete one-slot process-local buffer while the | ||
| 203 | +coordinator owns its turn. The service first releases its cache lease; the | ||
| 204 | +coordinator then releases its turn and flushes the buffer exactly once. A scope | ||
| 205 | +mismatch or late confirmation cannot attach to another job or duplicate the | ||
| 206 | +event. Receipt-only recovery emits no new commit. None of this evidence is a | ||
| 207 | +durable execution receipt or a reason to retry work. Observation rejection is | ||
| 208 | +counted as partial coverage and is never retried. These hooks expose no new | ||
| 209 | +transport/UI controls; the full cohort remains gated by remaining O2 hooks, | ||
| 210 | +health qualification and O3-O5 implementation. | ||
| 211 | + | ||
| 212 | +`sync_stage_changed` records only new retained batches and confirmed changes of | ||
| 213 | +phase or the actual commit-retry attempt. Its additive opaque `stage_ref` is | ||
| 214 | +valid only on this code; the closed `staging` outcome is staged, waiting_commit, | ||
| 215 | +committing, committed, rejected or superseded. Validated journal identity must | ||
| 216 | +match the existing job/cache/repository/registration context. Idempotent Create, | ||
| 217 | +timestamp-only writes, failed journal writes and read/UI projections emit no | ||
| 218 | +transition. Create records its fresh-retention decision inside the existing | ||
| 219 | +capacity lock and emits after unlocking. A separate one-slot buffer is installed | ||
| 220 | +before the committing journal write and flushed only after the coordinator turn | ||
| 221 | +and service lease are released; failed writes have no confirmed mark to flush. | ||
| 222 | +The buffer retains only opaque refs and finite fields, never an envelope, | ||
| 223 | +payload, blocker, checkpoint, path or terminal-reason bytes. Actual recovered | ||
| 224 | +commit attempts use the same owners. Receipt-only stage reconstruction remains | ||
| 225 | +unobserved at the journal-transition boundary and never invents a fresh provider | ||
| 226 | +attempt or cache commit. Job recovery owners are distinct, as described below. | ||
| 227 | +An accepted journal attempt outside the diagnostic catalog range is never | ||
| 228 | +clamped or rejected by instrumentation. Its confirmed boundary instead records | ||
| 229 | +scope-matched loss and partial coverage; during a commit turn that omission uses | ||
| 230 | +the same one-slot buffer and becomes visible only after release. Loss survives | ||
| 231 | +diagnostic restart without manufacturing a stage event or execution receipt. | ||
| 232 | + | ||
| 233 | +`job_recovered` records a confirmed recovery-owner decision: resumed, reconciled | ||
| 234 | +or rejected, with job/boot correlation and a closed rejection class. It carries | ||
| 235 | +no collection, stage ref or fabricated attempt and is not a new admission, | ||
| 236 | +provider attempt, terminal execution outcome or cache commit. Actual resume | ||
| 237 | +owners capture identity/status inside their existing lock and emit after a | ||
| 238 | +confirmed save and unlock. A failed save that retains the memory mutation | ||
| 239 | +records loss, not confirmation; rollback paths emit nothing. Receipt/checkpoint | ||
| 240 | +terminal reconciliation uses a private owner-marked persisted-update path; | ||
| 241 | +generic job projections and repeated recovery never invent this event. Group | ||
| 242 | +rejection captures at most 128 identities under its existing authority lock, | ||
| 243 | +then publishes outside it after the single save. Uncaptured overflow and | ||
| 244 | +retained failed-save boundaries use count-only atomic loss accounting, never an | ||
| 245 | +unbounded diagnostic slice, per-job diagnostic save, extra authority lookup or | ||
| 246 | +retry. These backend hooks remain subject to the O3/O4/O5 rollout gates; | ||
| 247 | +conflict maintenance events use their separate persistence owner below. | ||
| 248 | + | ||
| 249 | +`maintenance_state_changed` records a confirmed registration state/class pair | ||
| 250 | +change at enrollment, disable or reconcile persistence owners, not at List, | ||
| 251 | +load, stage projection or timestamp updates. It uses closed before/after enums, | ||
| 252 | +opaque cache/registration/repository refs and collector-owned atomic transition | ||
| 253 | +correlation; it carries no job/stage, attempt, collection, generation, config, | ||
| 254 | +path or error bytes. An operation-local 128-item context buffer captures only | ||
| 255 | +primitive identity and finite fields under the existing registry lock. Nested | ||
| 256 | +owners share it; the outer scheduler/IPC, Admin control receipt or job-action | ||
| 257 | +receipt boundary flushes after all its authority locks unwind. No asynchronous | ||
| 258 | +job retains the buffer. Overflow and retained failed saves record count-only | ||
| 259 | +loss, while rollback and unchanged later replay emit nothing. Existing exact | ||
| 260 | +payload readback confirms an ambiguous atomic write without extra telemetry | ||
| 261 | +I/O. Metrics-only operation counts unconfirmed persistence independently but | ||
| 262 | +does not fabricate overflow for a disabled event sink. | ||
| 263 | + | ||
| 264 | +Repository-document transitions use scope `repository_docs` and an event-owned | ||
| 265 | +opaque `source_ref`, distinct for every durably registered source. Their states | ||
| 266 | +are registered, not_indexed, indexing, disabled, ready and degraded; the same | ||
| 267 | +closed failure map and shared capture cap apply. Actual registration/admission, | ||
| 268 | +rebind reset, reconcile completion and retained failure owners observe only a | ||
| 269 | +changed finite pair at their existing save confirmation, qualified against the | ||
| 270 | +originating registration/cache/repository/path and source-generation authority. | ||
| 271 | +An obsolete owner that retains an execution mutation records count-only | ||
| 272 | +unconfirmed loss rather than certifying the replacement source. This observation | ||
| 273 | +guard does not change existing scheduling, mutation, save or return behavior; | ||
| 274 | +unchanged replay does not retroactively confirm or recount the pair. Generation-only rebind, | ||
| 275 | +source replay and inspection-health projection are not extra transitions. Flush | ||
| 276 | +also follows source-generation fences. Source refs are rejected on other events | ||
| 277 | +and cleared from per-worker context. No source path, Git identity, content or | ||
| 278 | +revision enters diagnostics. These hooks do not complete O2 or its O3-O5 gates. | ||
| 279 | + | ||
| 280 | +Confirmed conflict resolution uses scope `identity_resolution`, not an ordinary | ||
| 281 | +registration projection. Its event-owned `previous_registration_ref` names the | ||
| 282 | +immutable opaque predecessor, even when that registration is later redirected. | ||
| 283 | +Only identity_conflict, cache_clone_conflict and identity_unresolved are valid | ||
| 284 | +predecessors. Results use the actual final registration state/class, including | ||
| 285 | +residual identity conflicts, config_snapshot_invalid and cache_inspection_timeout; | ||
| 286 | +these extra states do not widen the ordinary registration/source catalogs. | ||
| 287 | +Clone resolution captures each final unique result in the existing result | ||
| 288 | +generation loop after canonicalization, never a provisional selected candidate | ||
| 289 | +or a synthetic single repository. Results of one confirmed operation share fresh | ||
| 290 | +opaque correlation; repeated episodes with the same predecessor remain distinct. | ||
| 291 | + | ||
| 292 | +Resolution observations are attempt-local primitive captures sharing the same | ||
| 293 | +128-item logical capacity with earlier registration/source captures. Only the | ||
| 294 | +existing successful save or exact ambiguous-write readback promotes pending | ||
| 295 | +captures and qualified loss to the context carrier. Rollback and panic before | ||
| 296 | +confirmation discard the attempt without erasing earlier evidence. An unchanged | ||
| 297 | +finite pair consumes neither capacity nor loss; unsupported changed results and | ||
| 298 | +over-capacity results report honest count-only loss. Publication follows registry | ||
| 299 | +unlock, job redirect publication and cache mutation fence release. The direct | ||
| 300 | +Admin resolution owner does not introduce an extra control-receipt boundary. | ||
| 301 | +Predecessor refs are forbidden on other events and cleared from worker context; | ||
| 302 | +no candidate, plan, generation, policy, path or source authority enters diagnostics. | ||
| 303 | +Final O2 qualification and the O3-O5 rollout gates remain required. | ||
| 304 | + | ||
| 305 | +### Metric evidence foundation | ||
| 306 | + | ||
| 307 | +The metric catalog is machine-readable and closed: there is no arbitrary | ||
| 308 | +registration or label API. Dimensions are finite product enums for work kind, | ||
| 309 | +collection, outcome and Admin route class; job, request, cache and repository | ||
| 310 | +identities belong in typed event correlation, never in metric labels. | ||
| 311 | +The foundation does not itself expose new CLI/MCP/Admin endpoints or claim that | ||
| 312 | +the complete observability cohort is ready. Execution hooks, incident projection | ||
| 313 | +and the shared transport/UI rollout have independent integration gates. | ||
| 314 | + | ||
| 315 | +Gauges have a 15-second sampling window. Runtime probes report uptime in seconds, | ||
| 316 | +heap allocation in bytes, goroutines as a count and the last observed GC pause | ||
| 317 | +in seconds; no GC observation is unavailable, not a zero pause. Execution probes | ||
| 318 | +supply queued/active jobs, writer waiters, scheduled retries and SSE connections. | ||
| 319 | +Absent, invalid or failed probes produce `value: null` and a fixed reason. | ||
| 320 | +Counters and duration histograms reset at boot and remain unavailable until | ||
| 321 | +their trusted origin is attached. Snapshot `boot_id` and `reset_at` identify | ||
| 322 | +that boundary. Histogram boundaries are 0.01, 0.05, 0.1, 0.5, 1, 5, 15, 60, 300 | ||
| 323 | +and 1800 seconds, plus one overflow cell. Distribution cells are non-cumulative; | ||
| 324 | +`count` and `sum` describe the per-boot duration distribution, not proof of work. | ||
| 325 | + | ||
| 326 | +Job gauges inspect at most 32,768 authority rows and commit-queue headers under | ||
| 327 | +a successfully acquired execution `TryLock`. Nil and terminal rows count toward | ||
| 328 | +that bound; queue membership is not scanned to obtain its length. Larger job | ||
| 329 | +authorities make all three job gauges unavailable rather than returning partial | ||
| 330 | +counts, pruning execution state or holding the mutex for an unbounded traversal. | ||
| 331 | + | ||
| 332 | +The collector attaches a concrete boot-matched atomic origin for `event_drops`. | ||
| 333 | +Current metric snapshots and sampler history read only that scalar, never the | ||
| 334 | +collector mutex or storage. It counts validated admissions rejected by queue | ||
| 335 | +bounds or observation contention; invalid input, post-Close rejection and | ||
| 336 | +replayed prior-boot durable losses are excluded. A storage failure that retains | ||
| 337 | +an event in memory is partial persistence coverage, not an invented admission | ||
| 338 | +drop. Missing attachment stays unavailable. There is no per-entity series or | ||
| 339 | +caller callback, and additive recording cannot overwrite this attached total. | ||
| 340 | +Generic origin registration also cannot make this collector-owned series | ||
| 341 | +available; only the concrete boot-matched attachment supplies its current total. | ||
| 342 | + | ||
| 343 | +History is a fixed ring of 60 UTC one-minute buckets, sampled in distinct UTC | ||
| 344 | +15-second slots. Gauge/counter count, sum and extrema summarize sampled values. | ||
| 345 | +Counter delta sums valid adjacent-sample increments; rate is the latest valid | ||
| 346 | +adjacent-sample increment per second, not a cross-boot or whole-minute rate. | ||
| 347 | +Histogram history aggregates observed duration count/sum/extrema between | ||
| 348 | +adjacent samples, assigned to the ending sample's UTC bucket. A sampling gap | ||
| 349 | +does not attribute an arbitrarily long duration interval to the newest minute. | ||
| 350 | +Current per-boot totals remain available separately. Missing buckets, | ||
| 351 | +pre-boot history, unavailable probes and baseline/reset boundaries remain | ||
| 352 | +explicit, without invented zeros. A complete bucket requires all four distinct | ||
| 353 | +slots and no missing baseline/probe/loss evidence. The current in-progress | ||
| 354 | +bucket may be incomplete without being an execution failure. | ||
| 355 | + | ||
| 356 | +Instrumentation uses bounded `TryLock` recording and never invokes a supplied | ||
| 357 | +callback. Telemetry contention or invalid input increments a loss counter and | ||
| 358 | +makes the snapshot partial; it cannot change execution results. Sampling probes | ||
| 359 | +run only on a separate cancellation-aware worker. A stalled probe does not block | ||
| 360 | +recording or snapshot reads, and shutdown cannot certify that worker as joined | ||
| 361 | +until it actually exits. Returned catalog, labels, buckets and distribution | ||
| 362 | +arrays are independent copies, not mutable references to the live registry. | ||
| 363 | + | ||
| 364 | +The daemon constructs metrics with the collector's immutable boot identity, | ||
| 365 | +attaches the concrete JobManager sink before loading durable jobs, then starts | ||
| 366 | +the sampler after snapshot recovery and before publishing work. Teardown must | ||
| 367 | +join the sampler before the collector can record a clean shutdown. Early | ||
| 368 | +startup failure cannot claim a clean observed boot. | ||
| 369 | + | ||
| 370 | +Job admission counts only a newly created, successfully persisted admission; | ||
| 371 | +coalesced requests and reused recovery identities are not new admissions. | ||
| 372 | +Terminal counters count successfully persisted active-to-terminal transitions, | ||
| 373 | +not each progress update or the number of retained terminal jobs. Snapshot | ||
| 374 | +loading and interrupted-to-terminal recovery projections are not execution | ||
| 375 | +outcomes. A failed terminal persistence boundary marks observation loss without | ||
| 376 | +changing the existing job error/rollback behavior. Recording follows execution | ||
| 377 | +lock release and uses only finite work-kind/outcome enums. Sync/RAG duration | ||
| 378 | +histograms are attached with the job origin independently of the confirmed | ||
| 379 | +record/chunk throughput origins. No-start cancellations have an outcome but no | ||
| 380 | +fabricated execution duration. | ||
| 381 | + | ||
| 382 | +Job gauges use a non-waiting authority probe: queued jobs are counted separately | ||
| 383 | +from running/cancelling jobs. `writer_waiters` counts only entries behind the | ||
| 384 | +current owner in daemon sync-commit FIFOs, not external OS/SQLite waiters or the | ||
| 385 | +active turn itself. A busy JobManager gives null probe values. This remains | ||
| 386 | +distinct from writer-contention attempt instrumentation and durable incident | ||
| 387 | +health; observing a queue does not repair or admit work. | ||
| 388 | + | ||
| 389 | +Collection `retry_admissions` increments on entry into a real re-attempt, not | ||
| 390 | +when its checkpoint is saved, loaded or waiting for a future window. A resumed | ||
| 391 | +retry which actually executes counts in the new boot; receipt-only recovery | ||
| 392 | +does not. Cancellation before admission and failed checkpoint persistence do | ||
| 393 | +not invent retries. Typed writer denials are counted at daemon admission, | ||
| 394 | +sync-commit reservation and execution-result boundaries, after releasing job | ||
| 395 | +locks and commit turns. Normal FIFO queueing, coalescing, identity/recovery | ||
| 396 | +fences and raw error messages are not writer contention. Internal adapter | ||
| 397 | +errors are not also counted at the cache layer. Direct local writers use the | ||
| 398 | +finite `other` work kind, never their operation/id as a label. | ||
| 399 | + | ||
| 400 | +Those same typed-denial owners emit `writer_contended` with `phase: writer`, | ||
| 401 | +`outcome: denied`, `failure_class: writer_busy` and one of `sync`, `rag`, | ||
| 402 | +`repository_docs`, or `other`. Worker events inherit their private job context; | ||
| 403 | +resumed admission copies its validated retained identity under the existing job | ||
| 404 | +lock. Pre-admission/direct denials have no fabricated job ref: they use only | ||
| 405 | +already resolved cache/repository refs and a fixed boot/work-kind correlation | ||
| 406 | +scope, not a request identity. Recording happens outside job locks, commit turns | ||
| 407 | +and cache leases, without new authority lookups. Metrics are optional and loss | ||
| 408 | +is not retried through another collector binding. The closed dimensions are | ||
| 409 | +validated again on replay; typed error bodies and blocker ids never cross this | ||
| 410 | +boundary. | ||
| 411 | + | ||
| 412 | +The same actual retry-entry boundary emits `retry_admitted` with `phase: retry`, | ||
| 413 | +`outcome: admitted`, a known collection and bounded ordinal from 2 through 1024. | ||
| 414 | +It inherits the job's opaque boot correlation even without a metrics sink. | ||
| 415 | +Timers, checkpoint writes, cancelled waits and the first attempt emit no retry | ||
| 416 | +admission. Unknown collections/ordinals cannot become event dimensions; the | ||
| 417 | +existing counter's fixed `other` bucket remains separate diagnostic evidence. | ||
| 418 | +An actual retry outside those catalog bounds, including an accepted retained | ||
| 419 | +ordinal, contributes count-only ledger loss when its inherited worker scope is | ||
| 420 | +valid. It never clamps the execution ordinal or fabricates an event; malformed | ||
| 421 | +or absent scopes, non-attempts and cancelled waits contribute no phantom loss. | ||
| 422 | +Lossy event admission never retries or changes the actual scheduler operation. | ||
| 423 | + | ||
| 424 | +`retry_scheduled` samples durable pending collection/commit waits and enabled | ||
| 425 | +maintenance backoff windows, including due windows not yet admitted. Active | ||
| 426 | +work suppresses its registry's previous backoff projection; a collection and | ||
| 427 | +commit-stage projection for the same waiting collection count once. Canonical | ||
| 428 | +repository-document source windows replace, rather than add to, their legacy | ||
| 429 | +single-source summary. Terminal job snapshots, disabled stages/registrations | ||
| 430 | +and ordinary periodic polls are not scheduled retries. The registry/job probe | ||
| 431 | +uses try-only locks over both authorities and returns null if either is busy; | ||
| 432 | +it never starts work, reads disk or infers retry state from event counts. | ||
| 433 | +Cancelled/superseded maintenance stages and current-authority source admission | ||
| 434 | +tombstones suppress backoff, including the legacy source projection. A current | ||
| 435 | +physical-authority admission takes precedence over a legacy tombstone; another | ||
| 436 | +physical authority's cancellation does not apply. | ||
| 437 | + | ||
| 438 | +Execution health is a separate read-only projection of retained durable jobs, | ||
| 439 | +collection outcomes, maintenance/frontier state and canonical source stages. | ||
| 440 | +It accepts only fixed signal/reason enums and internally resolved opaque refs; | ||
| 441 | +no raw error, progress text, provider payload or counter is evidence of success. | ||
| 442 | +Up to 128 incident cohorts are returned, active first then newest; omitted | ||
| 443 | +cohorts are counted and history becomes partial without hiding the overall | ||
| 444 | +active-failure count. First/last observations, last success and retry deadlines | ||
| 445 | +use authority timestamps, not polling time. A strictly later confirmed success | ||
| 446 | +recovers an incident; equal timestamps do not prove recovery order. Restart and | ||
| 447 | +repeated reads reconstruct the same retained evidence, not new execution. | ||
| 448 | +History explicitly covers retained authority, not pruned jobs or unobserved | ||
| 449 | +work. Busy/missing authority and the 32768-input projection cap produce unknown | ||
| 450 | +health, not healthy empty history. Authority inspection itself uses that same | ||
| 451 | +32768-item work budget, including inactive/empty rows; oversized sources cannot | ||
| 452 | +hold execution locks through an unbounded scan. Grouping/ref construction follows try-only | ||
| 453 | +authority snapshot release. Telemetry/storage readiness remains separate from | ||
| 454 | +execution health; unavailable observation cannot change a durable job outcome. | ||
| 455 | +Collection snapshots cannot hide a later rejected commit stage or whole-job | ||
| 456 | +failure. Retained degraded frontiers contribute their current failure as well | ||
| 457 | +as their preceding success, even when the relevant job has expired. Automatic | ||
| 458 | +configuration/identity blocking remains a fault when it disables admission; | ||
| 459 | +explicit user-disable is not a fault. Missing fault timestamps remain unknown. | ||
| 460 | +Whole-job failure deduplication requires a matching terminal signal, fixed | ||
| 461 | +reason, exact nonempty authority error class and timestamp in the collection | ||
| 462 | +evidence; an older collection problem cannot represent a later checkpoint | ||
| 463 | +rejection. Automatic cache | ||
| 464 | +inspection timeouts and clone conflicts also remain visible admission faults. | ||
| 465 | + | ||
| 466 | +Repository-document source inspection has an independent `inspection` health | ||
| 467 | +cohort; indexing jobs/stages have `indexing` phase and cannot recover that | ||
| 468 | +cohort at any timestamp. The existing source registration retains one | ||
| 469 | +fixed-size inspection episode: last result/attempt/success, first/last failure | ||
| 470 | +and a closed Git-store/policy/revision-set category. The real reconcile owner | ||
| 471 | +records its completion clock and confirms a registry transaction before | ||
| 472 | +downstream admission/indexing. A failed metadata write preserves the last | ||
| 473 | +confirmed episode with `retention_incomplete`; it does not invent recovery or | ||
| 474 | +change scheduling. Later finish snapshots cannot republish discarded evidence, | ||
| 475 | +and a new confirmed inspection clears incomplete coverage. Registration/source | ||
| 476 | +generation and physical authority must still match at publication. A later | ||
| 477 | +admission error cannot discard an independently confirmed inspection; its | ||
| 478 | +indexing fault remains visible instead of being erased as an aggregate duplicate. | ||
| 479 | +No observation reader performs Git/cache I/O or updates this authority. | ||
| 480 | +Successful inspection is not index readiness or embedding success. Only a | ||
| 481 | +strictly later inspection success recovers the retained episode; a new failure | ||
| 482 | +after recovery begins a new episode, not an unbounded history of all failures. | ||
| 483 | +Legacy/unobserved or inconsistent summary state is explicitly partial/unknown; | ||
| 484 | +recognized current legacy inspection faults remain active with partial history. | ||
| 485 | +An older/equal/newer indexing success cannot hide them. Canonical source maps | ||
| 486 | +replace the singleton projection. Current physical-authority cancellation | ||
| 487 | +tombstones and explicit registration/corpus disable suppress intentionally | ||
| 488 | +inactive work; an old cancelled indexing stage alone is not a cancellation of | ||
| 489 | +a new inspection. Source records share the evidence budget and active-first | ||
| 490 | +128-cohort bound. O3 transport selectors and O4 Admin must expose these phases | ||
| 491 | +before the complete observability cohort is released. | ||
| 492 | + | ||
| 493 | +Daemon-owned execution carries the concrete metric sink in a private context | ||
| 494 | +value without changing cancellation or deadlines. GitCode provider attempts | ||
| 495 | +are one actual policy-loop HTTP Client.Do invocation plus its bounded response | ||
| 496 | +transfer, excluding rate-limit waiting, pre-transport validation and sleep | ||
| 497 | +between retries. Each retry is observed separately, including the direct wiki | ||
| 498 | +tree path; a guarded single-attempt request remains single-attempt. This is not | ||
| 499 | +a TCP packet/socket count, redirect-hop count or confirmation of a remote | ||
| 500 | +mutation. Domain JSON decoding after a completed transfer is a separate | ||
| 501 | +execution result. Outcomes use fixed status/typed-error classes: succeeded, | ||
| 502 | +forbidden (including authentication rejection), rate_limited, timeout, | ||
| 503 | +cancelled, invalid transfer/validation or failed. Only the class and duration | ||
| 504 | +cross the observation boundary, never raw request/response data. | ||
| 505 | +Foreground clients without a daemon sink remain unobserved. Incidents and the | ||
| 506 | +remaining execution boundaries retain their own integration gates. | ||
| 507 | + | ||
| 508 | +Ollama HTTP attempts use the same finite transport outcome classes and per-boot | ||
| 509 | +provider series. Model listing, native embedding calls, each actual retry and | ||
| 510 | +each one-input legacy fallback request count separately. A fake provider, | ||
| 511 | +empty input, encoding/request-construction failure or pre-cancelled work does | ||
| 512 | +not invent HTTP traffic. Duration ends when transport/response reading completes, | ||
| 513 | +excluding subsequent JSON/vector validation; recording occurs after response | ||
| 514 | +body release. An HTTP-successful response can therefore still yield an invalid | ||
| 515 | +JSON, missing-model or dimension error at the embedding-operation layer. No | ||
| 516 | +input, endpoint, model, credentials or provider error text enters these metrics. | ||
| 517 | + | ||
| 518 | +Confirmed sync throughput is recorded at the shared atomic commit boundary, | ||
| 519 | +not inferred from a job, a fetched/staged count or a recovery projection. | ||
| 520 | +`sync_committed` counts successfully committed source graphs by fixed collection: | ||
| 521 | +issue/PR/wiki sources or individual comment sources. Completing one issue-comment | ||
| 522 | +parent queue item with two comments therefore counts two records, not one group | ||
| 523 | +or three staged work units. Queue/frontier-only updates count zero. Rewriting an | ||
| 524 | +unchanged graph in a new actual commit still represents committed processing; | ||
| 525 | +the counter does not claim newly inserted records or changed content. Writer | ||
| 526 | +contention, rejected/cancelled transactions and rollback count zero. A newly | ||
| 527 | +committed recovery batch counts in the current boot; reading an existing commit | ||
| 528 | +receipt without another transaction does not. Recording follows cache writer | ||
| 529 | +lease release; no telemetry-driven cache reads or deduplication store are added. | ||
| 530 | + | ||
| 531 | +`rag_embedded` counts only successful vector upserts for missing/stale chunks. | ||
| 532 | +It excludes provider calls, fresh-vector reuse and failed writes. A local scalar | ||
| 533 | +accumulator is flushed after writer lease release on every exit, including | ||
| 534 | +cancellation, a later run/coverage persistence failure or superseded coverage. | ||
| 535 | +Resuming skips already persisted vectors rather than inflating throughput. | ||
| 536 | +These counters remain volatile per-boot evidence; durable receipts and coverage | ||
| 537 | +remain the execution authority. Their availability is attached when the actual | ||
| 538 | +commit/index hook is entered, independently of job admission/duration. | ||
| 539 | + | ||
| 540 | +Admin HTTP hooks classify only registered router patterns into the fixed | ||
| 541 | +`session`, `read`, `control`, `search`, `events`, `assets` and `unknown` classes. | ||
| 542 | +Completed handlers record one request outcome and duration outside handler | ||
| 543 | +execution and session locks. A final 4xx is rejected, a 5xx, panic or response | ||
| 544 | +write failure is failed, and a cancelled request is cancelled unless an observed | ||
| 545 | +failure already takes precedence. Metric loss never changes response behavior. | ||
| 546 | +Queries, request bodies, cookies, raw paths, target identities and error text | ||
| 547 | +are not metric dimensions. Explicit handler work inherits the concrete daemon | ||
| 548 | +metric sink without starting additional provider or maintenance work. | ||
| 549 | + | ||
| 550 | +The same completion owner emits `admin_request_completed` independently of | ||
| 551 | +metrics. Its closed schema carries only `phase=admin`, finite `admin_route` and | ||
| 552 | +outcome plus opaque correlation. No entity, raw status, error, route, request id, | ||
| 553 | +cookie, body or header is accepted. The concrete collector owns an atomic | ||
| 554 | +boot/request sequence shared across HTTP controllers; browser request ids never | ||
| 555 | +participate. Completion runs after handler/session/control locks unwind and | ||
| 556 | +keeps response, panic, flush and cancellation semantics unchanged. A dropped | ||
| 557 | +event is explicit partial evidence and is never retried. The three registered | ||
| 558 | +observability GET patterns are excluded from event emission, preventing | ||
| 559 | +telemetry polling from appending its own timeline; arbitrary prefix-matching | ||
| 560 | +user paths are not excluded. O3 must retain this exclusion when exposing those | ||
| 561 | +endpoints, and O4/O5 remain the UI/integrated rollout gates. | ||
| 562 | + | ||
| 563 | +The SSE connection gauge counts only authenticated, cursor-valid handlers with | ||
| 564 | +actual streaming support. Atomic admission and deferred release cover every | ||
| 565 | +exit, including cancellation and replay recovery. Its request duration is the | ||
| 566 | +stream lifetime, not handshake latency; an open stream has not yet contributed | ||
| 567 | +a completed request. Sampling this gauge invokes no snapshot or provider and | ||
| 568 | +takes no execution/session/event locks. HTTP streaming support and | ||
| 569 | +ResponseController error behavior remain unchanged by the optional wrapper. | ||
| 570 | + | ||
| 571 | + | ||
| 153 | - [Architecture](architecture.md) | 572 | - [Architecture](architecture.md) |
| 154 | - [Cache And Sync Model](cache-and-sync-model.md) | 573 | - [Cache And Sync Model](cache-and-sync-model.md) |
| 155 | - [GitCode API Discovery](gitcode-api-discovery.md) | 574 | - [GitCode API Discovery](gitcode-api-discovery.md) |
| @@ -103,6 +103,102 @@ pressure, and prove that membership, chunks, and vectors have no orphans after | |||
| 103 | GC. Maintenance tests register a private worktree, poll exact HEAD/policy | 103 | GC. Maintenance tests register a private worktree, poll exact HEAD/policy |
| 104 | identity, enqueue only on change, recover the registration after daemon | 104 | identity, enqueue only on change, recover the registration after daemon |
| 105 | restart, and assert that public JSON never contains the filesystem path. | 105 | restart, and assert that public JSON never contains the filesystem path. |
| 106 | +Inspection-health fixtures also force registry write failure, an unrelated | ||
| 107 | +later save/restart and independent provider-boundary admission rejection. | ||
| 108 | +They prove that only confirmed inspection recovers its source cohort and that | ||
| 109 | +generation/path replacement cannot publish a stale observation. Retry event | ||
| 110 | +fixtures exercise the actual scheduler with resume, cancelled waits, failed | ||
| 111 | +checkpoint writes and no metric sink; neither waiting nor replay alone counts | ||
| 112 | +as an actual retry admission. | ||
| 113 | +Durable journal reload followed by actual scheduler execution also covers the | ||
| 114 | +last representable ordinal, an accepted over-catalog ordinal and an unknown | ||
| 115 | +collection. The counter and execution result remain unchanged; qualified | ||
| 116 | +omissions conserve ledger loss, including observation-only execution, without | ||
| 117 | +inventing event rejection or poisoning metrics-only coverage. Context controls | ||
| 118 | +check malformed scopes, nonblocking loss under a held collector lock, sealed | ||
| 119 | +collectors and persisted loss after restart. | ||
| 120 | +Writer-event fixtures exercise actual pre-admission, direct and retained resume | ||
| 121 | +denials, a staged commit's typed lease failure and cancellation of its retry | ||
| 122 | +wait. They assert opaque worker correlation versus fixed pre-job scopes, | ||
| 123 | +optional metrics, no observation lookup of held job authority, wrapped typed | ||
| 124 | +errors versus raw strings/fences, closed work-kind replay and content privacy. | ||
| 125 | +Every actual boundary is retained or explicitly counted as lost; telemetry | ||
| 126 | +rejection cannot retry or revive execution. | ||
| 127 | +Stage-event fixtures exercise actual durable collection transitions and typed | ||
| 128 | +writer denial/cancellation, idempotent retention across journal restart, | ||
| 129 | +timestamp-only updates, failed create/state writes and scope mismatch. Strict | ||
| 130 | +catalog/replay tests enforce stage-only opaque identity and finite outcomes. | ||
| 131 | +One-turn tests hold the observation reader mutex, race Flush with late marks, | ||
| 132 | +and prove a rejected confirmation is counted once without retry. Confirmation | ||
| 133 | +never publishes while the coordinator owns its turn; private envelope bytes | ||
| 134 | +and raw error sentinels must be absent from all retained event JSON. | ||
| 135 | +Actual recovered SQLite commits also cover negative and over-catalog durable | ||
| 136 | +attempts: execution and the original ordinal remain unchanged, no fabricated | ||
| 137 | +stage event is emitted, and each omitted confirmed transition is counted as | ||
| 138 | +partial coverage. Buffered-omission tests reject mismatched scopes, defer loss | ||
| 139 | +until release, race duplicate/late flushes, and verify restart persistence. | ||
| 140 | +Recovery-event fixtures reload real job snapshots and exercise actual sync and | ||
| 141 | +repository-documentation resume, receipt/checkpoint terminal reconciliation and | ||
| 142 | +group rejection. Repeated/missing/stale/fenced decisions and generic projections | ||
| 143 | +emit no new boundary. Failed retained resume records loss while rolled-back | ||
| 144 | +resume/rejection emits nothing. Fixed-cap group capture is qualified using a | ||
| 145 | +supported retention policy larger than 128 jobs and paginated event reads, | ||
| 146 | +conserving retained plus lost boundaries without fabricating admission, | ||
| 147 | +terminal execution, provider or commit counters. Closed replay, reader-lock | ||
| 148 | +contention, count-only metric loss and durable loss-restart tests enforce the | ||
| 149 | +same nonblocking/public-safe contracts independently of optional metrics. | ||
| 150 | +Maintenance registration fixtures use real cache bindings, registry saves and | ||
| 151 | +Admin receipt-wrapped disable, covering new/replayed enrollment, unchanged | ||
| 152 | +reconcile/timestamp projections, schema block/recovery, retained failed save | ||
| 153 | +versus rollback, and rename-success/readback confirmation. A blocked actual | ||
| 154 | +save and nested outer-lock boundary prove no early event. Fixed 128-item capture | ||
| 155 | +conserves overflow using bounded cursor continuation instead of enlarged page | ||
| 156 | +limits; metrics-only mode reports unconfirmed persistence without inventing | ||
| 157 | +disabled event-queue loss. Strict replay rejects raw states/classes and other | ||
| 158 | +execution dimensions; primitive identity, config/key/error sentinels stay out | ||
| 159 | +of diagnostics, and registry restart emits no fresh transition. | ||
| 160 | +Repository-document source fixtures exercise real Git source registration, | ||
| 161 | +replay, distinct sources and generation-only versus degraded-state rebind reset. | ||
| 162 | +Actual inspection failure/recovery and indexing state owners preserve separate | ||
| 163 | +inspection health. Failed registration rolls back without diagnostic loss; | ||
| 164 | +retained failed source writes report count-only loss, and exact atomic readback | ||
| 165 | +confirms rename success without extra I/O. Source identity and finite classes | ||
| 166 | +survive strict replay; paths, source ids, content and raw safe-looking error | ||
| 167 | +classes remain excluded. Registration and source captures share one bounded | ||
| 168 | +operation-local buffer and publication boundary. | ||
| 169 | +Actual queued-job/rebind/fence and reconcile-snapshot/late-scheduling-failure | ||
| 170 | +fixtures pair obsolete owners with current-generation controls. They preserve | ||
| 171 | +existing execution results while requiring exactly one count-only loss for an | ||
| 172 | +obsolete changed pair, one confirmed source capture for a current pair, and no | ||
| 173 | +extra boundary on unchanged replay. The held generation-fence test waits for an | ||
| 174 | +accepted FIFO collector marker after registry save/unlock before asserting no | ||
| 175 | +early maintenance publication; releasing the real fence conserves the transition. | ||
| 176 | +Identity-resolution fixtures apply real legacy registry conflicts and physical | ||
| 177 | +SQLite clones through the existing Plan/Apply owners. They cover enabled/disabled | ||
| 178 | +Admin selection, stale plans, durable replay/restart, rollback/retry, panic before | ||
| 179 | +confirmation and exact atomic readback without additional writes. Earlier actual | ||
| 180 | +registration/source evidence survives a failed attempt. Multi-repository results | ||
| 181 | +are qualified after canonicalization, including residual identity conflicts and | ||
| 182 | +unresolved, timeout or config-snapshot-blocked results. An actual held job-redirect | ||
| 183 | +mutex, active cache mutation fence and persisted FIFO marker prove publication | ||
| 184 | +waits for authority unwind. Mixed-scope fixed capacity conserves qualified loss; | ||
| 185 | +unchanged pairs add none, unsupported changed pairs fabricate no success, and | ||
| 186 | +metrics-only mode invents no disabled event-stream loss. Later confirmed conflict | ||
| 187 | +episodes with the same predecessor receive distinct operation correlations. | ||
| 188 | +Closed replay enforces scope-specific predecessor/result enums and opaque | ||
| 189 | +historical predecessor identity, which never leaks into worker context or other | ||
| 190 | +event codes. Private candidate/plan/key/config/path coordinates stay excluded. | ||
| 191 | +Admin request fixtures use actual mux/authenticated control and SSE paths, with | ||
| 192 | +collector-only and combined metric modes. They conserve retained plus lost | ||
| 193 | +completions, preserve panic/write/short-write/flush/cancellation outcomes and | ||
| 194 | +streaming support, and wait for an active handler to unwind before recording | ||
| 195 | +completion. Strict replay rejects Admin dimensions on other events and every | ||
| 196 | +entity/private field on HTTP completions. Concurrent request correlation is | ||
| 197 | +collector-owned across controllers and never waits for a reader; restart | ||
| 198 | +preserves original events without replaying job/provider/commit throughput. | ||
| 199 | +Registered observability polling emits no self-events; unsupported/user-prefix | ||
| 200 | +paths remain observable ordinary requests. Synthetic control, cookie, body, | ||
| 201 | +header, request-id and URL sentinels must be absent from retained evidence. | ||
| 106 | Maintenance identity tests also enroll canonical and alias repository ids | 202 | Maintenance identity tests also enroll canonical and alias repository ids |
| 107 | concurrently, migrate compatible and conflicting version-1 registry entries, | 203 | concurrently, migrate compatible and conflicting version-1 registry entries, |
| 108 | project legacy registration/job references to the canonical identity, preserve | 204 | project legacy registration/job references to the canonical identity, preserve |
| @@ -0,0 +1,165 @@ | |||
| 1 | +package adminhttp | ||
| 2 | + | ||
| 3 | +import ( | ||
| 4 | + "context" | ||
| 5 | + "net/http" | ||
| 6 | + "strings" | ||
| 7 | + "time" | ||
| 8 | + | ||
| 9 | + "gitcode-mcp/internal/observability" | ||
| 10 | +) | ||
| 11 | + | ||
| 12 | +// Classification uses registered router patterns, never request coordinates. | ||
| 13 | +// Every return is a member of the fixed metric catalog, including fallbacks. | ||
| 14 | +func adminMetricRoute(pattern string, r *http.Request) string { | ||
| 15 | + switch pattern { | ||
| 16 | + case "POST /api/admin/v1/session", "GET /api/admin/v1/session", "DELETE /api/admin/v1/session": | ||
| 17 | + return "session" | ||
| 18 | + case "GET /api/admin/v1/readiness", "GET /api/admin/v1/snapshot", "GET /api/admin/v1/caches", "GET /api/admin/v1/caches/{cache_ref}", | ||
| 19 | + "GET /api/admin/v1/caches/{cache_ref}/repositories/{repo_id...}", "GET /api/admin/v1/jobs", "GET /api/admin/v1/jobs/{job_id}", | ||
| 20 | + "GET /api/admin/v1/maintenance", "GET /api/admin/v1/diagnostics", "GET /api/admin/v1/capabilities", | ||
| 21 | + "GET /api/admin/v1/observability", "GET /api/admin/v1/observability/metrics", "GET /api/admin/v1/observability/events": | ||
| 22 | + return "read" | ||
| 23 | + case "POST /api/admin/v1/search/compare", "POST /api/admin/v1/repository-docs/{registration_id}/search": | ||
| 24 | + return "search" | ||
| 25 | + case "POST /api/admin/v1/jobs/{job_id}/cancel", "POST /api/admin/v1/jobs/{job_id}/retry", "POST /api/admin/v1/maintenance/plan", "POST /api/admin/v1/maintenance/apply", | ||
| 26 | + "POST /api/admin/v1/maintenance/{registration_id}/disable", "POST /api/admin/v1/maintenance/{registration_id}/reconcile", | ||
| 27 | + "POST /api/admin/v1/maintenance/{registration_id}/conflict-resolution/plan", "POST /api/admin/v1/maintenance/{registration_id}/conflict-resolution/apply", | ||
| 28 | + "POST /api/admin/v1/bindings/plan", "POST /api/admin/v1/bindings/apply", "POST /api/admin/v1/feedback/setup/plan", "POST /api/admin/v1/feedback/setup/apply", | ||
| 29 | + "POST /api/admin/v1/repository-docs/{registration_id}/plan", "POST /api/admin/v1/repository-docs/{registration_id}/index", | ||
| 30 | + "POST /api/admin/v1/rag/provider/smoke", "POST /api/admin/v1/rag/repair/plan", "POST /api/admin/v1/rag/repair/apply": | ||
| 31 | + return "control" | ||
| 32 | + case "GET /api/admin/v1/events": | ||
| 33 | + return "events" | ||
| 34 | + case "/": | ||
| 35 | + if !strings.HasPrefix(r.URL.Path, "/api/admin/") { | ||
| 36 | + return "assets" | ||
| 37 | + } | ||
| 38 | + } | ||
| 39 | + return "unknown" | ||
| 40 | +} | ||
| 41 | + | ||
| 42 | +type adminRouteKey struct{} | ||
| 43 | +type adminRouteObservation struct { | ||
| 44 | + class string | ||
| 45 | + observationRead bool | ||
| 46 | +} | ||
| 47 | + | ||
| 48 | +// Only registered observation GET patterns are excluded. A user-entered path | ||
| 49 | +// with this prefix is not a telemetry read until the mux actually registers it. | ||
| 50 | +func adminObservationRead(pattern string) bool { | ||
| 51 | + switch pattern { | ||
| 52 | + case "GET /api/admin/v1/observability", "GET /api/admin/v1/observability/metrics", "GET /api/admin/v1/observability/events": | ||
| 53 | + return true | ||
| 54 | + } | ||
| 55 | + return false | ||
| 56 | +} | ||
| 57 | + | ||
| 58 | +func observeAdminRoute(mux *http.ServeMux, r *http.Request) { | ||
| 59 | + if state, ok := r.Context().Value(adminRouteKey{}).(*adminRouteObservation); ok { | ||
| 60 | + // ServeMux.Handler exposes the registered pattern on the supported Go | ||
| 61 | + // baseline, unlike Request.Pattern (introduced in Go 1.23). Routing and | ||
| 62 | + // PathValue assignment still belong to the unchanged ServeHTTP call. | ||
| 63 | + _, pattern := mux.Handler(r) | ||
| 64 | + state.class = adminMetricRoute(pattern, r) | ||
| 65 | + state.observationRead = adminObservationRead(pattern) | ||
| 66 | + } | ||
| 67 | +} | ||
| 68 | + | ||
| 69 | +type metricResponse struct { | ||
| 70 | + http.ResponseWriter | ||
| 71 | + status int | ||
| 72 | + failed bool | ||
| 73 | +} | ||
| 74 | + | ||
| 75 | +func (w *metricResponse) Unwrap() http.ResponseWriter { return w.ResponseWriter } | ||
| 76 | +func (w *metricResponse) WriteHeader(status int) { | ||
| 77 | + if w.status == 0 && (status >= 200 || status == http.StatusSwitchingProtocols) { | ||
| 78 | + w.status = status | ||
| 79 | + } | ||
| 80 | + w.ResponseWriter.WriteHeader(status) | ||
| 81 | +} | ||
| 82 | +func (w *metricResponse) Write(body []byte) (int, error) { | ||
| 83 | + if w.status == 0 { | ||
| 84 | + w.status = http.StatusOK | ||
| 85 | + } | ||
| 86 | + n, err := w.ResponseWriter.Write(body) | ||
| 87 | + w.failed = w.failed || err != nil || n != len(body) | ||
| 88 | + return n, err | ||
| 89 | +} | ||
| 90 | + | ||
| 91 | +// Preserve optional streaming support: a non-Flusher must remain one. The | ||
| 92 | +// Unwrap chain also preserves ResponseController operations on the writer. | ||
| 93 | +type metricFlusher struct { | ||
| 94 | + *metricResponse | ||
| 95 | +} | ||
| 96 | + | ||
| 97 | +func (w *metricFlusher) Flush() { | ||
| 98 | + // The void Flusher contract still discards its return value, but retain | ||
| 99 | + // any error for the completed handler outcome before cancellation wins. | ||
| 100 | + _ = w.FlushError() | ||
| 101 | +} | ||
| 102 | + | ||
| 103 | +func (w *metricFlusher) FlushError() error { | ||
| 104 | + if w.status == 0 { | ||
| 105 | + w.status = http.StatusOK | ||
| 106 | + } | ||
| 107 | + err := http.NewResponseController(w.ResponseWriter).Flush() | ||
| 108 | + w.failed = w.failed || err != nil | ||
| 109 | + return err | ||
| 110 | +} | ||
| 111 | + | ||
| 112 | +func (c *Controller) observeRequests(next http.Handler) http.Handler { | ||
| 113 | + metrics := c.cfg.Metrics | ||
| 114 | + collector := c.cfg.Observation | ||
| 115 | + if metrics == nil && collector == nil { | ||
| 116 | + return next | ||
| 117 | + } | ||
| 118 | + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { | ||
| 119 | + started := time.Now() | ||
| 120 | + var correlation observability.Ref | ||
| 121 | + if collector != nil { | ||
| 122 | + correlation = collector.AdminRequestCorrelation() | ||
| 123 | + } | ||
| 124 | + routeState := &adminRouteObservation{class: "unknown"} | ||
| 125 | + ctx := observability.WithMetrics(r.Context(), metrics) | ||
| 126 | + r = r.WithContext(context.WithValue(ctx, adminRouteKey{}, routeState)) | ||
| 127 | + observed := &metricResponse{ResponseWriter: w} | ||
| 128 | + var writer http.ResponseWriter = observed | ||
| 129 | + if _, ok := w.(http.Flusher); ok { | ||
| 130 | + writer = &metricFlusher{metricResponse: observed} | ||
| 131 | + } | ||
| 132 | + returned := false | ||
| 133 | + defer func() { | ||
| 134 | + outcome := "succeeded" | ||
| 135 | + switch { | ||
| 136 | + case !returned || observed.failed || observed.status >= 500: | ||
| 137 | + outcome = "failed" | ||
| 138 | + case r.Context().Err() != nil: | ||
| 139 | + outcome = "cancelled" | ||
| 140 | + case observed.status >= 400: | ||
| 141 | + outcome = "rejected" | ||
| 142 | + } | ||
| 143 | + route := routeState.class | ||
| 144 | + if metrics != nil { | ||
| 145 | + metrics.Add("admin_requests", map[string]string{"route": route, "outcome": outcome}, 1) | ||
| 146 | + metrics.Observe("admin_duration", map[string]string{"route": route}, time.Since(started).Seconds()) | ||
| 147 | + } | ||
| 148 | + if collector != nil && !routeState.observationRead { | ||
| 149 | + collector.Emit(observability.AdminRequestCompleted, observability.Context{Correlation: correlation, | ||
| 150 | + ExecutionDetails: observability.ExecutionDetails{Phase: "admin", AdminRoute: route, Outcome: outcome}}) | ||
| 151 | + } | ||
| 152 | + }() | ||
| 153 | + next.ServeHTTP(writer, r) | ||
| 154 | + returned = true | ||
| 155 | + }) | ||
| 156 | +} | ||
| 157 | + | ||
| 158 | +// SSEConnectionsProbe is an atomic in-memory observation. It takes no session, | ||
| 159 | +// event, job or cache locks and never invokes a provider or maintenance action. | ||
| 160 | +func (c *Controller) SSEConnectionsProbe() observability.ProbeValue { | ||
| 161 | + if c == nil { | ||
| 162 | + return observability.Unavailable() | ||
| 163 | + } | ||
| 164 | + return observability.Available(float64(c.sseActive.Load())) | ||
| 165 | +} | ||
| @@ -0,0 +1,336 @@ | |||
| 1 | +package adminhttp | ||
| 2 | + | ||
| 3 | +import ( | ||
| 4 | + "context" | ||
| 5 | + "encoding/json" | ||
| 6 | + "errors" | ||
| 7 | + "net/http" | ||
| 8 | + "net/http/httptest" | ||
| 9 | + "strings" | ||
| 10 | + "sync" | ||
| 11 | + "testing" | ||
| 12 | + "testing/fstest" | ||
| 13 | + "time" | ||
| 14 | + | ||
| 15 | + "gitcode-mcp/internal/observability" | ||
| 16 | + "gitcode-mcp/internal/testnet" | ||
| 17 | +) | ||
| 18 | + | ||
| 19 | +func adminMetric(t *testing.T, metrics *observability.Metrics, name, route, outcome string) observability.MetricSeries { | ||
| 20 | + t.Helper() | ||
| 21 | + for _, series := range metrics.Snapshot().Series { | ||
| 22 | + if series.Name == name && series.Labels["route"] == route && series.Labels["outcome"] == outcome { | ||
| 23 | + return series | ||
| 24 | + } | ||
| 25 | + } | ||
| 26 | + t.Fatalf("missing fixed series %s/%s/%s", name, route, outcome) | ||
| 27 | + return observability.MetricSeries{} | ||
| 28 | +} | ||
| 29 | + | ||
| 30 | +func requireAdminCount(t *testing.T, metrics *observability.Metrics, route, outcome string, count float64) { | ||
| 31 | + t.Helper() | ||
| 32 | + series := adminMetric(t, metrics, "admin_requests", route, outcome) | ||
| 33 | + if series.Value == nil || *series.Value != count { | ||
| 34 | + t.Fatalf("%s/%s count does not match %v", route, outcome, count) | ||
| 35 | + } | ||
| 36 | +} | ||
| 37 | + | ||
| 38 | +func TestAdminMetricsUseActualMuxPatternsAndFiniteOutcomes(t *testing.T) { | ||
| 39 | + metrics := observability.NewMetrics("", time.Now()) | ||
| 40 | + c := New(Config{Metrics: metrics, Assets: fstest.MapFS{"index.html": {Data: []byte("public fixture")}}, | ||
| 41 | + Snapshot: func(ctx context.Context) (ObservationSnapshot, error) { | ||
| 42 | + if observability.MetricsFromContext(ctx) != metrics { | ||
| 43 | + t.Error("explicit handler execution lost its metric sink") | ||
| 44 | + } | ||
| 45 | + return ObservationSnapshot{}, errors.New("synthetic-private-error") | ||
| 46 | + }}) | ||
| 47 | + cookie := authorizeObservationController(c, time.Now().Add(time.Minute)) | ||
| 48 | + handler := c.handler() | ||
| 49 | + for _, tc := range []struct { | ||
| 50 | + method, target, route, outcome string | ||
| 51 | + status int | ||
| 52 | + auth, cancel bool | ||
| 53 | + }{ | ||
| 54 | + {"GET", "/api/admin/v1/readiness", "read", "succeeded", 200, true, false}, | ||
| 55 | + {"GET", "/api/admin/v1/jobs/synthetic-private-job?token=synthetic-private-query", "read", "rejected", 401, false, false}, | ||
| 56 | + {"GET", "/api/admin/v1/snapshot", "read", "failed", 503, true, false}, | ||
| 57 | + {"GET", "/api/admin/v1/readiness", "read", "cancelled", 200, true, true}, | ||
| 58 | + {"POST", "/api/admin/v1/maintenance/synthetic-private-registration/reconcile", "control", "rejected", 401, false, false}, | ||
| 59 | + {"POST", "/api/admin/v1/repository-docs/synthetic-private-registration/search", "search", "rejected", 401, false, false}, | ||
| 60 | + {"GET", "/api/admin/v1/session", "session", "rejected", 401, false, false}, | ||
| 61 | + {"GET", "/api/admin/v1/synthetic-private-route", "unknown", "succeeded", 200, false, false}, | ||
| 62 | + {"GET", "/synthetic-private-spa?query=synthetic-private-query", "assets", "succeeded", 200, false, false}, | ||
| 63 | + } { | ||
| 64 | + req := httptest.NewRequest(tc.method, "http://127.0.0.1:8080"+tc.target, strings.NewReader("synthetic-private-body")) | ||
| 65 | + req.Header.Set("Authorization", "synthetic-private-header") | ||
| 66 | + if tc.auth { | ||
| 67 | + req.AddCookie(cookie) | ||
| 68 | + } | ||
| 69 | + if tc.cancel { | ||
| 70 | + ctx, cancel := context.WithCancel(req.Context()) | ||
| 71 | + cancel() | ||
| 72 | + req = req.WithContext(ctx) | ||
| 73 | + } | ||
| 74 | + res := httptest.NewRecorder() | ||
| 75 | + handler.ServeHTTP(res, req) | ||
| 76 | + if res.Code != tc.status { | ||
| 77 | + t.Fatalf("fixed %s route status=%d, want %d", tc.route, res.Code, tc.status) | ||
| 78 | + } | ||
| 79 | + requireAdminCount(t, metrics, tc.route, tc.outcome, 1) | ||
| 80 | + } | ||
| 81 | + if got := adminMetric(t, metrics, "admin_duration", "read", ""); got.Count != 4 || got.Sum < 0 { | ||
| 82 | + t.Fatal("read duration did not count each completed handler") | ||
| 83 | + } | ||
| 84 | + encoded, err := json.Marshal(metrics.Snapshot()) | ||
| 85 | + if err != nil { | ||
| 86 | + t.Fatal(err) | ||
| 87 | + } | ||
| 88 | + if strings.Contains(string(encoded), "synthetic-private-") || strings.Contains(string(encoded), cookie.Value) { | ||
| 89 | + t.Fatal("request coordinates or session material entered metric evidence") | ||
| 90 | + } | ||
| 91 | +} | ||
| 92 | + | ||
| 93 | +// This writer deliberately has no Flusher; wrapping must not invent support. | ||
| 94 | +type adminPlainWriter struct { | ||
| 95 | + header http.Header | ||
| 96 | + status int | ||
| 97 | + err error | ||
| 98 | +} | ||
| 99 | + | ||
| 100 | +func (w *adminPlainWriter) Header() http.Header { return w.header } | ||
| 101 | +func (w *adminPlainWriter) WriteHeader(status int) { w.status = status } | ||
| 102 | +func (w *adminPlainWriter) Write(body []byte) (int, error) { | ||
| 103 | + if w.err != nil { | ||
| 104 | + return 0, w.err | ||
| 105 | + } | ||
| 106 | + return len(body), nil | ||
| 107 | +} | ||
| 108 | + | ||
| 109 | +func TestAdminMetricWrapperPreservesResponseAndPanicSemantics(t *testing.T) { | ||
| 110 | + for _, tc := range []struct{ name, outcome string }{ | ||
| 111 | + {"informational", "succeeded"}, {"write-failure", "failed"}, {"panic", "failed"}, | ||
| 112 | + } { | ||
| 113 | + t.Run(tc.name, func(t *testing.T) { | ||
| 114 | + metrics := observability.NewMetrics("", time.Now()) | ||
| 115 | + c := New(Config{Metrics: metrics}) | ||
| 116 | + writer := &adminPlainWriter{header: make(http.Header)} | ||
| 117 | + if tc.name == "write-failure" { | ||
| 118 | + writer.err = errors.New("synthetic write failure") | ||
| 119 | + } | ||
| 120 | + panicked := false | ||
| 121 | + func() { | ||
| 122 | + defer func() { panicked = recover() != nil }() | ||
| 123 | + c.observeRequests(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { | ||
| 124 | + if _, ok := w.(http.Flusher); ok { | ||
| 125 | + t.Error("wrapper invented streaming support") | ||
| 126 | + } | ||
| 127 | + if tc.name == "panic" { | ||
| 128 | + panic("synthetic panic") | ||
| 129 | + } | ||
| 130 | + w.WriteHeader(http.StatusEarlyHints) | ||
| 131 | + w.WriteHeader(http.StatusOK) | ||
| 132 | + _, err := w.Write([]byte("public fixture")) | ||
| 133 | + if err != writer.err { | ||
| 134 | + t.Error("writer error changed") | ||
| 135 | + } | ||
| 136 | + })).ServeHTTP(writer, httptest.NewRequest("GET", "http://127.0.0.1/", nil)) | ||
| 137 | + }() | ||
| 138 | + if panicked != (tc.name == "panic") { | ||
| 139 | + t.Fatal("wrapper swallowed or invented a panic") | ||
| 140 | + } | ||
| 141 | + requireAdminCount(t, metrics, "unknown", tc.outcome, 1) | ||
| 142 | + }) | ||
| 143 | + } | ||
| 144 | + plain := &adminPlainWriter{header: make(http.Header)} | ||
| 145 | + untouched := false | ||
| 146 | + New(Config{}).observeRequests(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { | ||
| 147 | + untouched = w == plain && observability.MetricsFromContext(r.Context()) == nil | ||
| 148 | + })).ServeHTTP(plain, httptest.NewRequest("GET", "http://127.0.0.1/", nil)) | ||
| 149 | + if !untouched { | ||
| 150 | + t.Fatal("disabled instrumentation changed transport") | ||
| 151 | + } | ||
| 152 | +} | ||
| 153 | + | ||
| 154 | +type adminErrorFlusher struct { | ||
| 155 | + adminPlainWriter | ||
| 156 | + flushErr error | ||
| 157 | +} | ||
| 158 | + | ||
| 159 | +func (w *adminErrorFlusher) Flush() {} | ||
| 160 | +func (w *adminErrorFlusher) FlushError() error { return w.flushErr } | ||
| 161 | + | ||
| 162 | +func TestAdminMetricWrapperPreservesResponseControllerFlushError(t *testing.T) { | ||
| 163 | + metrics := observability.NewMetrics("", time.Now()) | ||
| 164 | + c := New(Config{Metrics: metrics}) | ||
| 165 | + want := errors.New("synthetic flush failure") | ||
| 166 | + writer := &adminErrorFlusher{adminPlainWriter: adminPlainWriter{header: make(http.Header)}, flushErr: want} | ||
| 167 | + c.observeRequests(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { | ||
| 168 | + if err := http.NewResponseController(w).Flush(); err != want { | ||
| 169 | + t.Error("ResponseController lost the underlying flush error") | ||
| 170 | + } | ||
| 171 | + })).ServeHTTP(writer, httptest.NewRequest("GET", "http://127.0.0.1/", nil)) | ||
| 172 | + requireAdminCount(t, metrics, "unknown", "failed", 1) | ||
| 173 | +} | ||
| 174 | + | ||
| 175 | +func TestSSEActualNetworkFlushFailurePrecedesCancellation(t *testing.T) { | ||
| 176 | + metrics := observability.NewMetrics("", time.Now()) | ||
| 177 | + c := New(Config{Metrics: metrics}) | ||
| 178 | + cookie := authorizeObservationController(c, time.Now().Add(time.Minute)) | ||
| 179 | + completed := make(chan bool, 1) | ||
| 180 | + handler := c.handler() | ||
| 181 | + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { | ||
| 182 | + control := http.NewResponseController(w) | ||
| 183 | + if err := control.SetWriteDeadline(time.Unix(1, 0)); err != nil { | ||
| 184 | + completed <- false | ||
| 185 | + return | ||
| 186 | + } | ||
| 187 | + handler.ServeHTTP(w, r) | ||
| 188 | + completed <- control.Flush() != nil | ||
| 189 | + })) | ||
| 190 | + defer server.Close() | ||
| 191 | + req, err := http.NewRequest("GET", server.URL+"/api/admin/v1/events?after="+encodeEventCursor(999), nil) | ||
| 192 | + if err != nil { | ||
| 193 | + t.Fatal("construct synthetic local request") | ||
| 194 | + } | ||
| 195 | + req.AddCookie(cookie) | ||
| 196 | + client := testnet.NoExternalNetwork(t) | ||
| 197 | + client.Timeout = 2 * time.Second | ||
| 198 | + response, _ := client.Do(req) | ||
| 199 | + if response != nil { | ||
| 200 | + response.Body.Close() | ||
| 201 | + } | ||
| 202 | + select { | ||
| 203 | + case failed := <-completed: | ||
| 204 | + if !failed { | ||
| 205 | + t.Fatal("fixture did not establish an actual response flush failure") | ||
| 206 | + } | ||
| 207 | + case <-time.After(2 * time.Second): | ||
| 208 | + t.Fatal("synthetic local stream did not unwind") | ||
| 209 | + } | ||
| 210 | + requireSSECount(t, c, 0) | ||
| 211 | + requireAdminCount(t, metrics, "events", "failed", 1) | ||
| 212 | + requireAdminCount(t, metrics, "events", "succeeded", 0) | ||
| 213 | + requireAdminCount(t, metrics, "events", "cancelled", 0) | ||
| 214 | +} | ||
| 215 | + | ||
| 216 | +func requireSSECount(t *testing.T, c *Controller, want float64) { | ||
| 217 | + t.Helper() | ||
| 218 | + value := c.SSEConnectionsProbe() | ||
| 219 | + if value.Value == nil || *value.Value != want { | ||
| 220 | + t.Fatalf("active SSE count does not match %v", want) | ||
| 221 | + } | ||
| 222 | +} | ||
| 223 | + | ||
| 224 | +func TestSSEMetricTracksOnlyValidatedStreamsAndUnwinds(t *testing.T) { | ||
| 225 | + metrics := observability.NewMetrics("", time.Now()) | ||
| 226 | + c := New(Config{Metrics: metrics}) | ||
| 227 | + cookie := authorizeObservationController(c, time.Now().Add(time.Minute)) | ||
| 228 | + handler := c.handler() | ||
| 229 | + if res := authorizedRequest(t, handler, cookie, "/api/admin/v1/events?after=invalid"); res.Code != 400 { | ||
| 230 | + t.Fatal("invalid cursor was accepted") | ||
| 231 | + } | ||
| 232 | + requireSSECount(t, c, 0) | ||
| 233 | + req := httptest.NewRequest("GET", "http://127.0.0.1:8080/api/admin/v1/events", nil) | ||
| 234 | + req.AddCookie(cookie) | ||
| 235 | + plain := &adminPlainWriter{header: make(http.Header)} | ||
| 236 | + handler.ServeHTTP(plain, req) | ||
| 237 | + if plain.status != 500 { | ||
| 238 | + t.Fatal("non-streaming writer support changed") | ||
| 239 | + } | ||
| 240 | + requireSSECount(t, c, 0) | ||
| 241 | + unauthorized := request(t, handler, "GET", "/api/admin/v1/events", nil, nil) | ||
| 242 | + if unauthorized.Code != 401 { | ||
| 243 | + t.Fatal("unauthenticated stream accepted") | ||
| 244 | + } | ||
| 245 | + requireSSECount(t, c, 0) | ||
| 246 | + c.events.append(Event{Kind: "snapshot_changed", EntityType: "snapshot", EntityID: "overview"}) | ||
| 247 | + ctx, cancel := context.WithCancel(context.Background()) | ||
| 248 | + req = req.WithContext(ctx) | ||
| 249 | + writer := newFlushRecorder() | ||
| 250 | + done := make(chan struct{}) | ||
| 251 | + go func() { defer close(done); handler.ServeHTTP(writer, req) }() | ||
| 252 | + select { | ||
| 253 | + case <-writer.flushed: | ||
| 254 | + case <-time.After(time.Second): | ||
| 255 | + cancel() | ||
| 256 | + t.Fatal("metric wrapper prevented SSE flushing") | ||
| 257 | + } | ||
| 258 | + requireSSECount(t, c, 1) | ||
| 259 | + // Duration and request count represent a completed stream, not its handshake. | ||
| 260 | + requireAdminCount(t, metrics, "events", "cancelled", 0) | ||
| 261 | + cancel() | ||
| 262 | + select { | ||
| 263 | + case <-done: | ||
| 264 | + case <-time.After(time.Second): | ||
| 265 | + t.Fatal("cancelled stream did not unwind") | ||
| 266 | + } | ||
| 267 | + requireSSECount(t, c, 0) | ||
| 268 | + requireAdminCount(t, metrics, "events", "cancelled", 1) | ||
| 269 | + requireAdminCount(t, metrics, "events", "rejected", 2) | ||
| 270 | + requireAdminCount(t, metrics, "events", "failed", 1) | ||
| 271 | + if got := adminMetric(t, metrics, "admin_duration", "events", ""); got.Count != 4 { | ||
| 272 | + t.Fatal("stream lifetime duration missing") | ||
| 273 | + } | ||
| 274 | + // A valid but unavailable replay cursor is a short successful stream; | ||
| 275 | + // even this early post-admission return must release the gauge. | ||
| 276 | + res := authorizedRequest(t, handler, cookie, "/api/admin/v1/events?after="+encodeEventCursor(999)) | ||
| 277 | + if res.Code != 200 || !strings.Contains(res.Body.String(), "event: snapshot_required") { | ||
| 278 | + t.Fatal("metric wrapper changed cursor recovery") | ||
| 279 | + } | ||
| 280 | + requireSSECount(t, c, 0) | ||
| 281 | + requireAdminCount(t, metrics, "events", "succeeded", 1) | ||
| 282 | + var missing *Controller | ||
| 283 | + if got := missing.SSEConnectionsProbe(); got.Value != nil || got.Reason != "probe_unavailable" { | ||
| 284 | + t.Fatal("missing controller reported a healthy zero") | ||
| 285 | + } | ||
| 286 | +} | ||
| 287 | + | ||
| 288 | +func TestConcurrentAdminMetricProbesDoNotChangeRequests(t *testing.T) { | ||
| 289 | + metrics := observability.NewMetrics("", time.Now()) | ||
| 290 | + c := New(Config{Metrics: metrics}) | ||
| 291 | + cookie := authorizeObservationController(c, time.Now().Add(time.Minute)) | ||
| 292 | + c.events.append(Event{Kind: "snapshot_changed", EntityType: "snapshot", EntityID: "overview"}) | ||
| 293 | + handler := c.handler() | ||
| 294 | + ctx, cancel := context.WithCancel(context.Background()) | ||
| 295 | + defer cancel() | ||
| 296 | + var workers sync.WaitGroup | ||
| 297 | + for i := 0; i < 8; i++ { | ||
| 298 | + writer := newFlushRecorder() | ||
| 299 | + req := httptest.NewRequest("GET", "http://127.0.0.1:8080/api/admin/v1/events", nil).WithContext(ctx) | ||
| 300 | + req.AddCookie(cookie) | ||
| 301 | + workers.Add(1) | ||
| 302 | + go func() { defer workers.Done(); handler.ServeHTTP(writer, req) }() | ||
| 303 | + select { | ||
| 304 | + case <-writer.flushed: | ||
| 305 | + case <-time.After(time.Second): | ||
| 306 | + t.Fatal("concurrent stream did not flush") | ||
| 307 | + } | ||
| 308 | + } | ||
| 309 | + requireSSECount(t, c, 8) | ||
| 310 | + for i := 0; i < 8; i++ { | ||
| 311 | + workers.Add(1) | ||
| 312 | + go func() { | ||
| 313 | + defer workers.Done() | ||
| 314 | + for j := 0; j < 25; j++ { | ||
| 315 | + metrics.SampleAt(time.Now(), map[string]observability.ProbeValue{"sse_connections": c.SSEConnectionsProbe()}) | ||
| 316 | + _ = metrics.Snapshot() | ||
| 317 | + req := httptest.NewRequest("GET", "http://127.0.0.1:8080/api/admin/v1/readiness", nil) | ||
| 318 | + req.AddCookie(cookie) | ||
| 319 | + res := httptest.NewRecorder() | ||
| 320 | + handler.ServeHTTP(res, req) | ||
| 321 | + if res.Code != 200 { | ||
| 322 | + t.Error("telemetry contention changed a read request") | ||
| 323 | + } | ||
| 324 | + } | ||
| 325 | + }() | ||
| 326 | + } | ||
| 327 | + cancel() | ||
| 328 | + done := make(chan struct{}) | ||
| 329 | + go func() { workers.Wait(); close(done) }() | ||
| 330 | + select { | ||
| 331 | + case <-done: | ||
| 332 | + case <-time.After(5 * time.Second): | ||
| 333 | + t.Fatal("concurrent metrics or streams blocked execution") | ||
| 334 | + } | ||
| 335 | + requireSSECount(t, c, 0) | ||
| 336 | +} | ||
| @@ -841,6 +841,8 @@ func (c *Controller) getEvents(w http.ResponseWriter, r *http.Request) { | |||
| 841 | writeAPIError(w, http.StatusInternalServerError, "stream_unavailable", "Event streaming is unavailable.", "Use the snapshot endpoint.") | 841 | writeAPIError(w, http.StatusInternalServerError, "stream_unavailable", "Event streaming is unavailable.", "Use the snapshot endpoint.") |
| 842 | return | 842 | return |
| 843 | } | 843 | } |
| 844 | + c.sseActive.Add(1) | ||
| 845 | + defer c.sseActive.Add(-1) | ||
| 844 | w.Header().Set("Content-Type", "text/event-stream") | 846 | w.Header().Set("Content-Type", "text/event-stream") |
| 845 | w.Header().Set("Cache-Control", "no-store") | 847 | w.Header().Set("Cache-Control", "no-store") |
| 846 | w.Header().Set("Connection", "keep-alive") | 848 | w.Header().Set("Connection", "keep-alive") |
| @@ -0,0 +1,437 @@ | |||
| 1 | +//go:build darwin || linux | ||
| 2 | + | ||
| 3 | +package adminhttp | ||
| 4 | + | ||
| 5 | +import ( | ||
| 6 | + "context" | ||
| 7 | + "encoding/json" | ||
| 8 | + "errors" | ||
| 9 | + "net/http" | ||
| 10 | + "net/http/httptest" | ||
| 11 | + "path/filepath" | ||
| 12 | + "strings" | ||
| 13 | + "sync" | ||
| 14 | + "testing" | ||
| 15 | + "testing/fstest" | ||
| 16 | + "time" | ||
| 17 | + | ||
| 18 | + "gitcode-mcp/internal/observability" | ||
| 19 | + "gitcode-mcp/internal/testnet" | ||
| 20 | +) | ||
| 21 | + | ||
| 22 | +func adminEventCollector(t *testing.T) *observability.Collector { | ||
| 23 | + return adminEventCollectorAt(t, adminEventDirectory(t)) | ||
| 24 | +} | ||
| 25 | + | ||
| 26 | +func adminEventDirectory(t *testing.T) string { | ||
| 27 | + t.Helper() | ||
| 28 | + root, err := filepath.EvalSymlinks(t.TempDir()) | ||
| 29 | + if err != nil { | ||
| 30 | + t.Fatal("resolve synthetic observation root") | ||
| 31 | + } | ||
| 32 | + return filepath.Join(root, "observation") | ||
| 33 | +} | ||
| 34 | + | ||
| 35 | +func adminEventCollectorAt(t *testing.T, dir string) *observability.Collector { | ||
| 36 | + t.Helper() | ||
| 37 | + c := observability.New(observability.Config{Directory: dir, ManagedOutput: true}) | ||
| 38 | + t.Cleanup(func() { closeAdminCollector(t, c) }) | ||
| 39 | + deadline := time.Now().Add(5 * time.Second) | ||
| 40 | + for time.Now().Before(deadline) { | ||
| 41 | + page, err := c.Query(observability.Filter{}, "", 20) | ||
| 42 | + if err == nil && page.Coverage.State != "initializing" { | ||
| 43 | + if page.Coverage.Reason == "storage_unavailable" || page.Coverage.Reason == "storage_failed" { | ||
| 44 | + t.Fatal("synthetic observation fixture did not establish durable storage") | ||
| 45 | + } | ||
| 46 | + return c | ||
| 47 | + } | ||
| 48 | + time.Sleep(time.Millisecond) | ||
| 49 | + } | ||
| 50 | + t.Fatal("observation fixture did not publish its startup snapshot") | ||
| 51 | + return c | ||
| 52 | +} | ||
| 53 | + | ||
| 54 | +func closeAdminCollector(t *testing.T, c *observability.Collector) { | ||
| 55 | + t.Helper() | ||
| 56 | + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) | ||
| 57 | + defer cancel() | ||
| 58 | + if !c.Close(ctx, true) { | ||
| 59 | + t.Error("observation fixture did not finish") | ||
| 60 | + } | ||
| 61 | +} | ||
| 62 | + | ||
| 63 | +func adminCompletedEvents(t *testing.T, c *observability.Collector) []observability.Event { | ||
| 64 | + t.Helper() | ||
| 65 | + page, err := c.Query(observability.Filter{}, "", 200) | ||
| 66 | + if err != nil || page.HasMore { | ||
| 67 | + t.Fatal("small observation fixture did not fit one bounded page") | ||
| 68 | + } | ||
| 69 | + var events []observability.Event | ||
| 70 | + for _, e := range page.Events { | ||
| 71 | + if e.Code == observability.AdminRequestCompleted { | ||
| 72 | + events = append(events, e) | ||
| 73 | + } | ||
| 74 | + } | ||
| 75 | + return events | ||
| 76 | +} | ||
| 77 | + | ||
| 78 | +func TestAdminCompletedRequestCollectorIndependentOfMetrics(t *testing.T) { | ||
| 79 | + collector := adminEventCollector(t) | ||
| 80 | + for i := 0; i < 2; i++ { | ||
| 81 | + // Distinct controllers sharing a boot must not reuse request correlation. | ||
| 82 | + c := New(Config{Observation: collector}) | ||
| 83 | + cookie := authorizeObservationController(c, time.Now().Add(time.Minute)) | ||
| 84 | + r := httptest.NewRequest("GET", "http://127.0.0.1/api/admin/v1/readiness", nil) | ||
| 85 | + r.AddCookie(cookie) | ||
| 86 | + res := httptest.NewRecorder() | ||
| 87 | + c.handler().ServeHTTP(res, r) | ||
| 88 | + if res.Code != 200 { | ||
| 89 | + t.Fatal("observation changed a successful readiness request") | ||
| 90 | + } | ||
| 91 | + } | ||
| 92 | + closeAdminCollector(t, collector) | ||
| 93 | + events := adminCompletedEvents(t, collector) | ||
| 94 | + page, err := collector.Query(observability.Filter{}, "", 200) | ||
| 95 | + if err != nil || uint64(len(events))+page.Coverage.Dropped != 2 { | ||
| 96 | + t.Fatalf("completed requests retained=%d, lost=%d, want total 2", len(events), page.Coverage.Dropped) | ||
| 97 | + } | ||
| 98 | + seen := map[string]bool{} | ||
| 99 | + for _, e := range events { | ||
| 100 | + if e.CorrelationRef == "" || seen[e.CorrelationRef] || e.AdminRoute != "read" || e.Outcome != "succeeded" { | ||
| 101 | + t.Fatal("collector-owned completion/correlation was missing or reused") | ||
| 102 | + } | ||
| 103 | + seen[e.CorrelationRef] = true | ||
| 104 | + } | ||
| 105 | +} | ||
| 106 | + | ||
| 107 | +func TestAdminCompletedRequestRealMuxPrivacyAndOutcomes(t *testing.T) { | ||
| 108 | + collector := adminEventCollector(t) | ||
| 109 | + metrics := observability.NewMetrics(collector.BootID(), time.Now()) | ||
| 110 | + c := New(Config{Observation: collector, Metrics: metrics, | ||
| 111 | + Assets: fstest.MapFS{"index.html": {Data: []byte("public fixture")}}, | ||
| 112 | + Snapshot: func(ctx context.Context) (ObservationSnapshot, error) { | ||
| 113 | + if observability.MetricsFromContext(ctx) != metrics { | ||
| 114 | + t.Error("handler lost its concrete metric sink") | ||
| 115 | + } | ||
| 116 | + return ObservationSnapshot{}, errors.New("synthetic-private-error") | ||
| 117 | + }}) | ||
| 118 | + cookie := authorizeObservationController(c, time.Now().Add(time.Minute)) | ||
| 119 | + handler := c.handler() | ||
| 120 | + want := map[string]int{} | ||
| 121 | + for _, tc := range []struct { | ||
| 122 | + method, target, route, outcome string | ||
| 123 | + status int | ||
| 124 | + auth, cancel bool | ||
| 125 | + }{ | ||
| 126 | + {"GET", "/api/admin/v1/readiness", "read", "succeeded", 200, true, false}, | ||
| 127 | + {"GET", "/api/admin/v1/jobs/synthetic-private-job?token=synthetic-private-query", "read", "rejected", 401, false, false}, | ||
| 128 | + {"GET", "/api/admin/v1/snapshot", "read", "failed", 503, true, false}, | ||
| 129 | + {"GET", "/api/admin/v1/readiness", "read", "cancelled", 200, true, true}, | ||
| 130 | + {"POST", "/api/admin/v1/maintenance/synthetic-private-registration/reconcile", "control", "rejected", 401, false, false}, | ||
| 131 | + {"POST", "/api/admin/v1/repository-docs/synthetic-private-registration/search", "search", "rejected", 401, false, false}, | ||
| 132 | + {"GET", "/api/admin/v1/session", "session", "rejected", 401, false, false}, | ||
| 133 | + // These paths are not registered telemetry endpoints yet; they must | ||
| 134 | + // not be silently excluded based on the user's raw path. | ||
| 135 | + {"GET", "/api/admin/v1/observability/metrics", "unknown", "succeeded", 200, false, false}, | ||
| 136 | + {"GET", "/synthetic-private-spa?token=synthetic-private-query", "assets", "succeeded", 200, false, false}, | ||
| 137 | + } { | ||
| 138 | + r := httptest.NewRequest(tc.method, "http://127.0.0.1:8080"+tc.target, strings.NewReader("synthetic-private-body")) | ||
| 139 | + r.Header.Set("Authorization", "synthetic-private-header") | ||
| 140 | + r.Header.Set("X-Request-Id", "synthetic-private-request") | ||
| 141 | + if tc.auth { | ||
| 142 | + r.AddCookie(cookie) | ||
| 143 | + } | ||
| 144 | + if tc.cancel { | ||
| 145 | + ctx, cancel := context.WithCancel(r.Context()) | ||
| 146 | + cancel() | ||
| 147 | + r = r.WithContext(ctx) | ||
| 148 | + } | ||
| 149 | + res := httptest.NewRecorder() | ||
| 150 | + handler.ServeHTTP(res, r) | ||
| 151 | + if res.Code != tc.status { | ||
| 152 | + t.Fatal("request observation changed HTTP status") | ||
| 153 | + } | ||
| 154 | + requireAdminCount(t, metrics, tc.route, tc.outcome, 1) | ||
| 155 | + want[tc.route+"/"+tc.outcome]++ | ||
| 156 | + } | ||
| 157 | + closeAdminCollector(t, collector) | ||
| 158 | + events := adminCompletedEvents(t, collector) | ||
| 159 | + page, err := collector.Query(observability.Filter{}, "", 200) | ||
| 160 | + if err != nil || uint64(len(events))+page.Coverage.Dropped != 9 { | ||
| 161 | + t.Fatal("completed HTTP boundaries were duplicated or silently lost") | ||
| 162 | + } | ||
| 163 | + seen := map[string]bool{} | ||
| 164 | + for _, e := range events { | ||
| 165 | + key := e.AdminRoute + "/" + e.Outcome | ||
| 166 | + if want[key] == 0 || e.Phase != "admin" || e.CorrelationRef == "" || seen[e.CorrelationRef] || e.JobRef != "" || e.RepoRef != "" || e.CacheRef != "" || e.RegistrationRef != "" || e.StageRef != "" { | ||
| 167 | + t.Fatal("request event invented an outcome, entity or correlation") | ||
| 168 | + } | ||
| 169 | + want[key]-- | ||
| 170 | + seen[e.CorrelationRef] = true | ||
| 171 | + } | ||
| 172 | + data, err := json.Marshal(page) | ||
| 173 | + if err != nil || strings.Contains(string(data), "synthetic-private-") || strings.Contains(string(data), cookie.Value) { | ||
| 174 | + t.Fatal("request/session coordinates entered event evidence") | ||
| 175 | + } | ||
| 176 | +} | ||
| 177 | + | ||
| 178 | +func TestAdminCompletedRequestExcludesOnlyRegisteredObservationReads(t *testing.T) { | ||
| 179 | + collector := adminEventCollector(t) | ||
| 180 | + metrics := observability.NewMetrics(collector.BootID(), time.Now()) | ||
| 181 | + c := New(Config{Observation: collector, Metrics: metrics}) | ||
| 182 | + mux := http.NewServeMux() | ||
| 183 | + for _, pattern := range []string{"GET /api/admin/v1/observability", "GET /api/admin/v1/observability/metrics", "GET /api/admin/v1/observability/events", "GET /api/admin/v1/observability/private-fixture"} { | ||
| 184 | + mux.HandleFunc(pattern, func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(200) }) | ||
| 185 | + } | ||
| 186 | + handler := c.observeRequests(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { | ||
| 187 | + observeAdminRoute(mux, r) | ||
| 188 | + mux.ServeHTTP(w, r) | ||
| 189 | + })) | ||
| 190 | + for _, path := range []string{"/api/admin/v1/observability", "/api/admin/v1/observability/metrics", "/api/admin/v1/observability/events"} { | ||
| 191 | + for i := 0; i < 3; i++ { | ||
| 192 | + handler.ServeHTTP(httptest.NewRecorder(), httptest.NewRequest("GET", "http://127.0.0.1"+path, nil)) | ||
| 193 | + } | ||
| 194 | + } | ||
| 195 | + handler.ServeHTTP(httptest.NewRecorder(), httptest.NewRequest("GET", "http://127.0.0.1/api/admin/v1/observability/private-fixture", nil)) | ||
| 196 | + closeAdminCollector(t, collector) | ||
| 197 | + page, err := collector.Query(observability.Filter{}, "", 200) | ||
| 198 | + if err != nil || uint64(len(adminCompletedEvents(t, collector)))+page.Coverage.Dropped != 1 { | ||
| 199 | + t.Fatal("telemetry polling logged itself or prefix matching suppressed another route") | ||
| 200 | + } | ||
| 201 | + requireAdminCount(t, metrics, "read", "succeeded", 9) | ||
| 202 | + requireAdminCount(t, metrics, "unknown", "succeeded", 1) | ||
| 203 | +} | ||
| 204 | + | ||
| 205 | +func TestAdminCompletedRequestOccursOnlyAfterHandlerUnwinds(t *testing.T) { | ||
| 206 | + collector := adminEventCollector(t) | ||
| 207 | + c := New(Config{Observation: collector}) | ||
| 208 | + entered, release, done := make(chan struct{}), make(chan struct{}), make(chan struct{}) | ||
| 209 | + releaseHandler := sync.OnceFunc(func() { close(release) }) | ||
| 210 | + defer func() { | ||
| 211 | + releaseHandler() | ||
| 212 | + select { | ||
| 213 | + case <-done: | ||
| 214 | + case <-time.After(5 * time.Second): | ||
| 215 | + t.Error("handler cleanup did not finish") | ||
| 216 | + } | ||
| 217 | + }() | ||
| 218 | + handler := c.observeRequests(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { | ||
| 219 | + close(entered) | ||
| 220 | + <-release | ||
| 221 | + w.WriteHeader(200) | ||
| 222 | + })) | ||
| 223 | + go func() { | ||
| 224 | + defer close(done) | ||
| 225 | + handler.ServeHTTP(httptest.NewRecorder(), httptest.NewRequest("GET", "http://127.0.0.1/", nil)) | ||
| 226 | + }() | ||
| 227 | + select { | ||
| 228 | + case <-entered: | ||
| 229 | + case <-time.After(5 * time.Second): | ||
| 230 | + t.Fatal("handler did not enter") | ||
| 231 | + } | ||
| 232 | + before := len(adminCompletedEvents(t, collector)) | ||
| 233 | + releaseHandler() | ||
| 234 | + select { | ||
| 235 | + case <-done: | ||
| 236 | + case <-time.After(5 * time.Second): | ||
| 237 | + t.Fatal("handler did not unwind") | ||
| 238 | + } | ||
| 239 | + closeAdminCollector(t, collector) | ||
| 240 | + page, err := collector.Query(observability.Filter{}, "", 200) | ||
| 241 | + if before != 0 || err != nil || uint64(len(adminCompletedEvents(t, collector)))+page.Coverage.Dropped != 1 { | ||
| 242 | + t.Fatal("active handler was falsely completed or completion was silently lost") | ||
| 243 | + } | ||
| 244 | +} | ||
| 245 | + | ||
| 246 | +type adminShortWriter struct{ adminPlainWriter } | ||
| 247 | + | ||
| 248 | +func (w *adminShortWriter) Write(body []byte) (int, error) { return len(body) - 1, nil } | ||
| 249 | + | ||
| 250 | +func TestAdminCompletedRequestPreservesTransportFailures(t *testing.T) { | ||
| 251 | + for _, tc := range []struct{ name, outcome string }{ | ||
| 252 | + {"informational", "succeeded"}, {"write-failure", "failed"}, {"short-write", "failed"}, | ||
| 253 | + {"flush-failure", "failed"}, {"panic", "failed"}, {"failure-and-cancel", "failed"}, | ||
| 254 | + } { | ||
| 255 | + t.Run(tc.name, func(t *testing.T) { | ||
| 256 | + collector := adminEventCollector(t) | ||
| 257 | + c := New(Config{Observation: collector}) | ||
| 258 | + plain := &adminPlainWriter{header: make(http.Header)} | ||
| 259 | + var writer http.ResponseWriter = plain | ||
| 260 | + switch tc.name { | ||
| 261 | + case "write-failure", "failure-and-cancel": | ||
| 262 | + plain.err = errors.New("synthetic-private-write") | ||
| 263 | + case "short-write": | ||
| 264 | + writer = &adminShortWriter{*plain} | ||
| 265 | + case "flush-failure": | ||
| 266 | + writer = &adminErrorFlusher{adminPlainWriter: *plain, flushErr: errors.New("synthetic-private-flush")} | ||
| 267 | + } | ||
| 268 | + r := httptest.NewRequest("GET", "http://127.0.0.1/", nil) | ||
| 269 | + if tc.name == "failure-and-cancel" { | ||
| 270 | + ctx, cancel := context.WithCancel(r.Context()) | ||
| 271 | + cancel() | ||
| 272 | + r = r.WithContext(ctx) | ||
| 273 | + } | ||
| 274 | + panicked := false | ||
| 275 | + func() { | ||
| 276 | + defer func() { panicked = recover() != nil }() | ||
| 277 | + c.observeRequests(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { | ||
| 278 | + _, flushable := w.(http.Flusher) | ||
| 279 | + if flushable != (tc.name == "flush-failure") { | ||
| 280 | + t.Error("observation changed streaming support") | ||
| 281 | + } | ||
| 282 | + if tc.name == "panic" { | ||
| 283 | + panic("synthetic-private-panic") | ||
| 284 | + } | ||
| 285 | + if tc.name == "flush-failure" { | ||
| 286 | + if http.NewResponseController(w).Flush() == nil { | ||
| 287 | + t.Error("flush error was swallowed") | ||
| 288 | + } | ||
| 289 | + return | ||
| 290 | + } | ||
| 291 | + w.WriteHeader(http.StatusEarlyHints) | ||
| 292 | + w.WriteHeader(http.StatusOK) | ||
| 293 | + n, err := w.Write([]byte("public fixture")) | ||
| 294 | + if err != plain.err || (tc.name == "short-write" && n != len("public fixture")-1) { | ||
| 295 | + t.Error("observation changed response result") | ||
| 296 | + } | ||
| 297 | + })).ServeHTTP(writer, r) | ||
| 298 | + }() | ||
| 299 | + if panicked != (tc.name == "panic") { | ||
| 300 | + t.Fatal("observation swallowed or invented a panic") | ||
| 301 | + } | ||
| 302 | + closeAdminCollector(t, collector) | ||
| 303 | + events := adminCompletedEvents(t, collector) | ||
| 304 | + page, err := collector.Query(observability.Filter{}, "", 200) | ||
| 305 | + if err != nil || uint64(len(events))+page.Coverage.Dropped != 1 { | ||
| 306 | + t.Fatal("transport boundary duplicated or silently lost") | ||
| 307 | + } | ||
| 308 | + for _, e := range events { | ||
| 309 | + if e.AdminRoute != "unknown" || e.Outcome != tc.outcome { | ||
| 310 | + t.Fatal("transport failure precedence changed") | ||
| 311 | + } | ||
| 312 | + } | ||
| 313 | + }) | ||
| 314 | + } | ||
| 315 | +} | ||
| 316 | + | ||
| 317 | +func TestAdminCompletedRequestSSEActualFlushFailure(t *testing.T) { | ||
| 318 | + collector := adminEventCollector(t) | ||
| 319 | + c := New(Config{Observation: collector}) | ||
| 320 | + cookie := authorizeObservationController(c, time.Now().Add(time.Minute)) | ||
| 321 | + completed := make(chan bool, 1) | ||
| 322 | + handler := c.handler() | ||
| 323 | + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { | ||
| 324 | + control := http.NewResponseController(w) | ||
| 325 | + if control.SetWriteDeadline(time.Unix(1, 0)) != nil { | ||
| 326 | + completed <- false | ||
| 327 | + return | ||
| 328 | + } | ||
| 329 | + handler.ServeHTTP(w, r) | ||
| 330 | + completed <- control.Flush() != nil | ||
| 331 | + })) | ||
| 332 | + defer server.Close() | ||
| 333 | + r, err := http.NewRequest("GET", server.URL+"/api/admin/v1/events?after="+encodeEventCursor(999), nil) | ||
| 334 | + if err != nil { | ||
| 335 | + t.Fatal("synthetic SSE request construction failed") | ||
| 336 | + } | ||
| 337 | + r.AddCookie(cookie) | ||
| 338 | + client := testnet.NoExternalNetwork(t) | ||
| 339 | + client.Timeout = 2 * time.Second | ||
| 340 | + res, _ := client.Do(r) | ||
| 341 | + if res != nil { | ||
| 342 | + res.Body.Close() | ||
| 343 | + } | ||
| 344 | + select { | ||
| 345 | + case failed := <-completed: | ||
| 346 | + if !failed { | ||
| 347 | + t.Fatal("actual SSE flush failure was not established") | ||
| 348 | + } | ||
| 349 | + case <-time.After(5 * time.Second): | ||
| 350 | + t.Fatal("SSE handler did not finish") | ||
| 351 | + } | ||
| 352 | + requireSSECount(t, c, 0) | ||
| 353 | + closeAdminCollector(t, collector) | ||
| 354 | + page, err := collector.Query(observability.Filter{}, "", 200) | ||
| 355 | + events := adminCompletedEvents(t, collector) | ||
| 356 | + if err != nil || uint64(len(events))+page.Coverage.Dropped != 1 { | ||
| 357 | + t.Fatal("actual SSE completion duplicated or silently lost") | ||
| 358 | + } | ||
| 359 | + for _, e := range events { | ||
| 360 | + if e.AdminRoute != "events" || e.Outcome != "failed" { | ||
| 361 | + t.Fatal("SSE flush failure lost precedence over cancellation") | ||
| 362 | + } | ||
| 363 | + } | ||
| 364 | +} | ||
| 365 | + | ||
| 366 | +func TestAdminCompletedRequestActualControlFailure(t *testing.T) { | ||
| 367 | + collector := adminEventCollector(t) | ||
| 368 | + metrics := observability.NewMetrics(collector.BootID(), time.Now()) | ||
| 369 | + calls := 0 | ||
| 370 | + c := New(Config{Observation: collector, Metrics: metrics, ReconcileMaintenance: func(ctx context.Context, req RegistrationControlRequest) (any, error) { | ||
| 371 | + calls++ | ||
| 372 | + if req.RegistrationID != "synthetic-private-registration" || observability.MetricsFromContext(ctx) != metrics { | ||
| 373 | + t.Error("explicit control changed its identity or metric sink") | ||
| 374 | + } | ||
| 375 | + return nil, errors.New("synthetic-private-provider") | ||
| 376 | + }}) | ||
| 377 | + cookie := authorizeObservationController(c, time.Now().Add(time.Minute)) | ||
| 378 | + r := httptest.NewRequest("POST", "http://127.0.0.1:8080/api/admin/v1/maintenance/synthetic-private-registration/reconcile", strings.NewReader(`{"idempotency_key":"synthetic-private-key"}`)) | ||
| 379 | + r.AddCookie(cookie) | ||
| 380 | + r.Header.Set("Origin", "http://127.0.0.1:8080") | ||
| 381 | + r.Header.Set("Sec-Fetch-Site", "same-origin") | ||
| 382 | + r.Header.Set("X-CSRF-Token", "csrf") | ||
| 383 | + res := httptest.NewRecorder() | ||
| 384 | + c.handler().ServeHTTP(res, r) | ||
| 385 | + if calls != 1 || res.Code < 500 { | ||
| 386 | + t.Fatal("control failure changed execution or HTTP outcome") | ||
| 387 | + } | ||
| 388 | + closeAdminCollector(t, collector) | ||
| 389 | + page, err := collector.Query(observability.Filter{}, "", 200) | ||
| 390 | + events := adminCompletedEvents(t, collector) | ||
| 391 | + if err != nil || uint64(len(events))+page.Coverage.Dropped != 1 { | ||
| 392 | + t.Fatal("actual control completion duplicated or silently lost") | ||
| 393 | + } | ||
| 394 | + for _, e := range events { | ||
| 395 | + if e.AdminRoute != "control" || e.Outcome != "failed" { | ||
| 396 | + t.Fatal("control failure classification changed") | ||
| 397 | + } | ||
| 398 | + } | ||
| 399 | + data, _ := json.Marshal(page) | ||
| 400 | + if strings.Contains(string(data), "synthetic-private-") || strings.Contains(string(data), cookie.Value) { | ||
| 401 | + t.Fatal("explicit control/session material entered events") | ||
| 402 | + } | ||
| 403 | + requireAdminCount(t, metrics, "control", "failed", 1) | ||
| 404 | +} | ||
| 405 | + | ||
| 406 | +func TestAdminCompletedRequestRestartDoesNotReplayExecution(t *testing.T) { | ||
| 407 | + dir := adminEventDirectory(t) | ||
| 408 | + first := adminEventCollectorAt(t, dir) | ||
| 409 | + c := New(Config{Observation: first}) | ||
| 410 | + request := httptest.NewRequest("GET", "http://127.0.0.1/api/admin/v1/readiness", nil) | ||
| 411 | + request.AddCookie(authorizeObservationController(c, time.Now().Add(time.Minute))) | ||
| 412 | + c.handler().ServeHTTP(httptest.NewRecorder(), request) | ||
| 413 | + closeAdminCollector(t, first) | ||
| 414 | + original := adminCompletedEvents(t, first) | ||
| 415 | + page, err := first.Query(observability.Filter{}, "", 200) | ||
| 416 | + if err != nil || uint64(len(original))+page.Coverage.Dropped != 1 { | ||
| 417 | + t.Fatal("original completion silently lost") | ||
| 418 | + } | ||
| 419 | + restarted := adminEventCollectorAt(t, dir) | ||
| 420 | + closeAdminCollector(t, restarted) | ||
| 421 | + retained := adminCompletedEvents(t, restarted) | ||
| 422 | + if len(retained) != len(original) { | ||
| 423 | + current, _ := restarted.Query(observability.Filter{}, "", 200) | ||
| 424 | + t.Fatalf("restart retained %d original %d; before=%s/%s after=%s/%s", len(retained), len(original), page.Coverage.State, page.Coverage.Reason, current.Coverage.State, current.Coverage.Reason) | ||
| 425 | + } | ||
| 426 | + for i, e := range retained { | ||
| 427 | + if e != original[i] || e.BootID != first.BootID() { | ||
| 428 | + t.Fatal("restart rewrote original request correlation") | ||
| 429 | + } | ||
| 430 | + } | ||
| 431 | + for _, code := range []observability.Code{observability.JobAdmitted, observability.JobTerminal, observability.JobRecovered, observability.ProviderAttempt, observability.SyncCommitted} { | ||
| 432 | + page, err := restarted.Query(observability.Filter{Code: code}, "", 20) | ||
| 433 | + if err != nil || len(page.Events) != 0 { | ||
| 434 | + t.Fatal("HTTP replay invented non-HTTP execution") | ||
| 435 | + } | ||
| 436 | + } | ||
| 437 | +} | ||
| @@ -16,7 +16,10 @@ import ( | |||
| 16 | "path" | 16 | "path" |
| 17 | "strings" | 17 | "strings" |
| 18 | "sync" | 18 | "sync" |
| 19 | + "sync/atomic" | ||
| 19 | "time" | 20 | "time" |
| 21 | + | ||
| 22 | + "gitcode-mcp/internal/observability" | ||
| 20 | ) | 23 | ) |
| 21 | 24 | ||
| 22 | const sessionCookie = "gitcode_mcp_admin_session" | 25 | const sessionCookie = "gitcode_mcp_admin_session" |
| @@ -76,6 +79,8 @@ type Config struct { | |||
| 76 | SmokeProvider ProviderSmokeProvider | 79 | SmokeProvider ProviderSmokeProvider |
| 77 | PlanRAGRepair RAGRepairProvider | 80 | PlanRAGRepair RAGRepairProvider |
| 78 | ApplyRAGRepair RAGRepairProvider | 81 | ApplyRAGRepair RAGRepairProvider |
| 82 | + Metrics *observability.Metrics | ||
| 83 | + Observation *observability.Collector | ||
| 79 | } | 84 | } |
| 80 | 85 | ||
| 81 | type Controller struct { | 86 | type Controller struct { |
| @@ -88,6 +93,7 @@ type Controller struct { | |||
| 88 | launch map[[32]byte]time.Time | 93 | launch map[[32]byte]time.Time |
| 89 | sessions map[[32]byte]session | 94 | sessions map[[32]byte]session |
| 90 | events *eventLog | 95 | events *eventLog |
| 96 | + sseActive atomic.Int64 | ||
| 91 | } | 97 | } |
| 92 | 98 | ||
| 93 | type session struct { | 99 | type session struct { |
| @@ -105,6 +111,9 @@ func New(cfg Config) *Controller { | |||
| 105 | if cfg.EventPollInterval <= 0 { | 111 | if cfg.EventPollInterval <= 0 { |
| 106 | cfg.EventPollInterval = time.Second | 112 | cfg.EventPollInterval = time.Second |
| 107 | } | 113 | } |
| 114 | + if cfg.Metrics != nil { | ||
| 115 | + cfg.Metrics.AttachOrigin("admin") | ||
| 116 | + } | ||
| 108 | return &Controller{cfg: cfg, shutdownDone: make(chan struct{}), launch: map[[32]byte]time.Time{}, sessions: map[[32]byte]session{}, events: newEventLog(cfg.EventCapacity)} | 117 | return &Controller{cfg: cfg, shutdownDone: make(chan struct{}), launch: map[[32]byte]time.Time{}, sessions: map[[32]byte]session{}, events: newEventLog(cfg.EventCapacity)} |
| 109 | } | 118 | } |
| 110 | 119 | ||
| @@ -231,14 +240,15 @@ func (c *Controller) handler() http.Handler { | |||
| 231 | mux.HandleFunc("GET /api/admin/v1/capabilities", c.getCapabilities) | 240 | mux.HandleFunc("GET /api/admin/v1/capabilities", c.getCapabilities) |
| 232 | mux.HandleFunc("GET /api/admin/v1/events", c.getEvents) | 241 | mux.HandleFunc("GET /api/admin/v1/events", c.getEvents) |
| 233 | mux.HandleFunc("/", c.serveAsset) | 242 | mux.HandleFunc("/", c.serveAsset) |
| 234 | - return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { | 243 | + return c.observeRequests(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { |
| 235 | setSecurityHeaders(w) | 244 | setSecurityHeaders(w) |
| 236 | if !c.validHost(r.Host) { | 245 | if !c.validHost(r.Host) { |
| 237 | http.Error(w, "invalid host", http.StatusBadRequest) | 246 | http.Error(w, "invalid host", http.StatusBadRequest) |
| 238 | return | 247 | return |
| 239 | } | 248 | } |
| 249 | + observeAdminRoute(mux, r) | ||
| 240 | mux.ServeHTTP(w, r) | 250 | mux.ServeHTTP(w, r) |
| 241 | - }) | 251 | + })) |
| 242 | } | 252 | } |
| 243 | 253 | ||
| 244 | func (c *Controller) pollObservation(ctx context.Context) { | 254 | func (c *Controller) pollObservation(ctx context.Context) { |
| @@ -21,6 +21,7 @@ import ( | |||
| 21 | "time" | 21 | "time" |
| 22 | 22 | ||
| 23 | "gitcode-mcp/internal/diagnostics" | 23 | "gitcode-mcp/internal/diagnostics" |
| 24 | + "gitcode-mcp/internal/observability" | ||
| 24 | ) | 25 | ) |
| 25 | 26 | ||
| 26 | const defaultMaxResponseSize int64 = 10 << 20 | 27 | const defaultMaxResponseSize int64 = 10 << 20 |
| @@ -1258,13 +1259,17 @@ func (c *HTTPClient) listWikiEntries(ctx context.Context, owner, repo, dir strin | |||
| 1258 | endpoint = wikiContentsPathEndpoint(owner, repo, dir) | 1259 | endpoint = wikiContentsPathEndpoint(owner, repo, dir) |
| 1259 | } | 1260 | } |
| 1260 | 1261 | ||
| 1261 | - resp, err := c.do(ctx, http.MethodGet, endpoint, nil, nil, requestOptions{}) | 1262 | + observation := newProviderMetricAttempt(ctx) |
| 1263 | + observation.ordinal = 1 | ||
| 1264 | + resp, err := c.do(ctx, http.MethodGet, endpoint, nil, nil, requestOptions{metricAttempt: observation}) | ||
| 1262 | if err != nil { | 1265 | if err != nil { |
| 1266 | + observation.finish(0, err) | ||
| 1263 | return nil, ErrNetworkUnavailable{Endpoint: endpoint, Attempts: 1, Cause: err} | 1267 | return nil, ErrNetworkUnavailable{Endpoint: endpoint, Attempts: 1, Cause: err} |
| 1264 | } | 1268 | } |
| 1265 | - defer resp.Body.Close() | ||
| 1266 | 1269 | ||
| 1267 | body, readErr := c.readBounded(resp, endpoint) | 1270 | body, readErr := c.readBounded(resp, endpoint) |
| 1271 | + resp.Body.Close() | ||
| 1272 | + observation.finish(resp.StatusCode, readErr) | ||
| 1268 | if readErr != nil { | 1273 | if readErr != nil { |
| 1269 | return nil, readErr | 1274 | return nil, readErr |
| 1270 | } | 1275 | } |
| @@ -1502,6 +1507,7 @@ func isNotFoundError(err error) bool { | |||
| 1502 | } | 1507 | } |
| 1503 | 1508 | ||
| 1504 | type requestOptions struct { | 1509 | type requestOptions struct { |
| 1510 | + metricAttempt *providerMetricAttempt | ||
| 1505 | contentType string | 1511 | contentType string |
| 1506 | knownRemoteAlias bool | 1512 | knownRemoteAlias bool |
| 1507 | remoteAlias string | 1513 | remoteAlias string |
| @@ -2285,11 +2291,18 @@ func (c *HTTPClient) bytesWithOptions(ctx context.Context, method, endpoint stri | |||
| 2285 | if err := c.waitForRateLimit(ctx, method, endpoint, attempt); err != nil { | 2291 | if err := c.waitForRateLimit(ctx, method, endpoint, attempt); err != nil { |
| 2286 | return nil, nil, ErrNetworkUnavailable{Endpoint: endpoint, Attempts: attempt - 1, Cause: err} | 2292 | return nil, nil, ErrNetworkUnavailable{Endpoint: endpoint, Attempts: attempt - 1, Cause: err} |
| 2287 | } | 2293 | } |
| 2294 | + observation := newProviderMetricAttempt(ctx) | ||
| 2295 | + if attempt <= observability.MaxExecutionAttempt { | ||
| 2296 | + observation.ordinal = uint32(attempt) | ||
| 2297 | + } | ||
| 2298 | + opts.metricAttempt = observation | ||
| 2288 | resp, err := c.do(ctx, method, endpoint, values, bytes.NewReader(requestBody), opts) | 2299 | resp, err := c.do(ctx, method, endpoint, values, bytes.NewReader(requestBody), opts) |
| 2289 | if err != nil { | 2300 | if err != nil { |
| 2290 | if ctx.Err() != nil { | 2301 | if ctx.Err() != nil { |
| 2302 | + observation.finish(0, ctx.Err()) | ||
| 2291 | return nil, nil, ErrNetworkUnavailable{Endpoint: endpoint, Attempts: attempt, Cause: ctx.Err()} | 2303 | return nil, nil, ErrNetworkUnavailable{Endpoint: endpoint, Attempts: attempt, Cause: ctx.Err()} |
| 2292 | } | 2304 | } |
| 2305 | + observation.finish(0, err) | ||
| 2293 | if isRetryableTransport(err) && attempt < attempts { | 2306 | if isRetryableTransport(err) && attempt < attempts { |
| 2294 | continue | 2307 | continue |
| 2295 | } | 2308 | } |
| @@ -2297,11 +2310,13 @@ func (c *HTTPClient) bytesWithOptions(ctx context.Context, method, endpoint stri | |||
| 2297 | } | 2310 | } |
| 2298 | if resp.StatusCode == http.StatusRequestEntityTooLarge { | 2311 | if resp.StatusCode == http.StatusRequestEntityTooLarge { |
| 2299 | resp.Body.Close() | 2312 | resp.Body.Close() |
| 2313 | + observation.finish(resp.StatusCode, nil) | ||
| 2300 | return nil, nil, ErrPayloadTooLarge{Endpoint: endpoint, Limit: c.maxResponseSize, Size: resp.ContentLength, Source: "remote_status"} | 2314 | return nil, nil, ErrPayloadTooLarge{Endpoint: endpoint, Limit: c.maxResponseSize, Size: resp.ContentLength, Source: "remote_status"} |
| 2301 | } | 2315 | } |
| 2302 | body, readErr := c.readBounded(resp, endpoint) | 2316 | body, readErr := c.readBounded(resp, endpoint) |
| 2303 | headers := resp.Header.Clone() | 2317 | headers := resp.Header.Clone() |
| 2304 | resp.Body.Close() | 2318 | resp.Body.Close() |
| 2319 | + observation.finish(resp.StatusCode, readErr) | ||
| 2305 | if readErr != nil { | 2320 | if readErr != nil { |
| 2306 | readErr = withResponseContentType(withResponseAttempt(readErr, attempt), headers.Get("Content-Type")) | 2321 | readErr = withResponseContentType(withResponseAttempt(readErr, attempt), headers.Get("Content-Type")) |
| 2307 | if retryableResponseDecode(readErr) && attempt < attempts { | 2322 | if retryableResponseDecode(readErr) && attempt < attempts { |
| @@ -2441,6 +2456,7 @@ func (c *HTTPClient) do(ctx context.Context, method, endpoint string, values url | |||
| 2441 | if opts.beforeAttempt != nil { | 2456 | if opts.beforeAttempt != nil { |
| 2442 | opts.beforeAttempt() | 2457 | opts.beforeAttempt() |
| 2443 | } | 2458 | } |
| 2459 | + opts.metricAttempt.start() | ||
| 2444 | return c.client.Do(req) | 2460 | return c.client.Do(req) |
| 2445 | } | 2461 | } |
| 2446 | 2462 | ||
| @@ -0,0 +1,81 @@ | |||
| 1 | +package gitcode | ||
| 2 | + | ||
| 3 | +import ( | ||
| 4 | + "context" | ||
| 5 | + "errors" | ||
| 6 | + "net" | ||
| 7 | + "net/http" | ||
| 8 | + "time" | ||
| 9 | + | ||
| 10 | + "gitcode-mcp/internal/observability" | ||
| 11 | +) | ||
| 12 | + | ||
| 13 | +// providerMetricAttempt observes one policy-loop Client.Do invocation and its | ||
| 14 | +// bounded response transfer. It is not a TCP packet count or durable receipt. | ||
| 15 | +// No endpoint, header, coordinate, body, or error string crosses this boundary. | ||
| 16 | +type providerMetricAttempt struct { | ||
| 17 | + ctx context.Context | ||
| 18 | + ordinal uint32 | ||
| 19 | + metrics *observability.Metrics | ||
| 20 | + started time.Time | ||
| 21 | + finished bool | ||
| 22 | +} | ||
| 23 | + | ||
| 24 | +func newProviderMetricAttempt(ctx context.Context) *providerMetricAttempt { | ||
| 25 | + return &providerMetricAttempt{ctx: ctx, metrics: observability.MetricsFromContext(ctx)} | ||
| 26 | +} | ||
| 27 | + | ||
| 28 | +func (a *providerMetricAttempt) start() { | ||
| 29 | + if a == nil || (a.metrics == nil && !observability.HasObservation(a.ctx)) { | ||
| 30 | + return | ||
| 31 | + } | ||
| 32 | + a.started = time.Now() | ||
| 33 | + if a.metrics != nil { | ||
| 34 | + a.metrics.AttachOrigin("provider") | ||
| 35 | + } | ||
| 36 | +} | ||
| 37 | + | ||
| 38 | +func (a *providerMetricAttempt) finish(status int, err error) { | ||
| 39 | + if a == nil || a.started.IsZero() || a.finished { | ||
| 40 | + return | ||
| 41 | + } | ||
| 42 | + a.finished = true | ||
| 43 | + outcome := providerMetricOutcome(status, err) | ||
| 44 | + if a.metrics != nil { | ||
| 45 | + labels := map[string]string{"outcome": outcome} | ||
| 46 | + a.metrics.Add("provider_outcomes", labels, 1) | ||
| 47 | + a.metrics.Observe("provider_duration", labels, time.Since(a.started).Seconds()) | ||
| 48 | + } | ||
| 49 | + details := observability.ExecutionDetails{Phase: "fetch", Outcome: outcome, Attempt: a.ordinal} | ||
| 50 | + if outcome == "failed" { | ||
| 51 | + details.FailureClass = "provider_failed" | ||
| 52 | + } else if outcome != "succeeded" { | ||
| 53 | + details.FailureClass = outcome | ||
| 54 | + } | ||
| 55 | + observability.EmitFromContext(a.ctx, observability.ProviderAttempt, details) | ||
| 56 | +} | ||
| 57 | + | ||
| 58 | +func providerMetricOutcome(status int, err error) string { | ||
| 59 | + if errors.Is(err, context.Canceled) { | ||
| 60 | + return "cancelled" | ||
| 61 | + } | ||
| 62 | + var network net.Error | ||
| 63 | + if errors.Is(err, context.DeadlineExceeded) || errors.As(err, &network) && network.Timeout() { | ||
| 64 | + return "timeout" | ||
| 65 | + } | ||
| 66 | + switch status { | ||
| 67 | + case http.StatusTooManyRequests: | ||
| 68 | + return "rate_limited" | ||
| 69 | + case http.StatusUnauthorized, http.StatusForbidden: | ||
| 70 | + return "forbidden" | ||
| 71 | + case http.StatusBadRequest, http.StatusUnprocessableEntity, http.StatusRequestEntityTooLarge: | ||
| 72 | + return "invalid" | ||
| 73 | + } | ||
| 74 | + if status < 200 || status >= 300 { | ||
| 75 | + return "failed" | ||
| 76 | + } | ||
| 77 | + if err != nil { | ||
| 78 | + return "invalid" | ||
| 79 | + } | ||
| 80 | + return "succeeded" | ||
| 81 | +} | ||
| @@ -0,0 +1,184 @@ | |||
| 1 | +package gitcode | ||
| 2 | + | ||
| 3 | +import ( | ||
| 4 | + "context" | ||
| 5 | + "encoding/json" | ||
| 6 | + "errors" | ||
| 7 | + "io" | ||
| 8 | + "net/http" | ||
| 9 | + "strings" | ||
| 10 | + "testing" | ||
| 11 | + "time" | ||
| 12 | + | ||
| 13 | + "gitcode-mcp/internal/observability" | ||
| 14 | +) | ||
| 15 | + | ||
| 16 | +func observedProviderFixture(t *testing.T, cfg Config, transport roundTripFunc) (*HTTPClient, context.Context, *observability.Metrics) { | ||
| 17 | + t.Helper() | ||
| 18 | + cfg.BaseURL = "https://example.invalid" | ||
| 19 | + client, err := NewHTTPClient(cfg) | ||
| 20 | + if err != nil { | ||
| 21 | + t.Fatal("fixture client construction failed") | ||
| 22 | + } | ||
| 23 | + client.client.Transport = transport | ||
| 24 | + metrics := observability.NewMetrics(strings.Repeat("b", 32), time.Now().UTC()) | ||
| 25 | + return client, observability.WithMetrics(context.Background(), metrics), metrics | ||
| 26 | +} | ||
| 27 | + | ||
| 28 | +func metricProviderSeries(t *testing.T, metrics *observability.Metrics, name, outcome string) observability.MetricSeries { | ||
| 29 | + t.Helper() | ||
| 30 | + for _, s := range metrics.Snapshot().Series { | ||
| 31 | + if s.Name == name && s.Labels["outcome"] == outcome { | ||
| 32 | + return s | ||
| 33 | + } | ||
| 34 | + } | ||
| 35 | + t.Fatal("provider fixed series missing") | ||
| 36 | + return observability.MetricSeries{} | ||
| 37 | +} | ||
| 38 | + | ||
| 39 | +func requireProviderAttempts(t *testing.T, metrics *observability.Metrics, outcome string, want float64) { | ||
| 40 | + t.Helper() | ||
| 41 | + s := metricProviderSeries(t, metrics, "provider_outcomes", outcome) | ||
| 42 | + if s.Value == nil || *s.Value != want { | ||
| 43 | + t.Fatal("provider attempt count differs") | ||
| 44 | + } | ||
| 45 | + h := metricProviderSeries(t, metrics, "provider_duration", outcome) | ||
| 46 | + if h.Count != uint64(want) { | ||
| 47 | + t.Fatal("provider duration counted a different attempt set") | ||
| 48 | + } | ||
| 49 | +} | ||
| 50 | + | ||
| 51 | +func providerFixtureResponse(status int, body string) *http.Response { | ||
| 52 | + return &http.Response{StatusCode: status, Header: make(http.Header), Body: io.NopCloser(strings.NewReader(body)), ContentLength: -1} | ||
| 53 | +} | ||
| 54 | + | ||
| 55 | +func TestProviderMetricsCountActualRetryInvocations(t *testing.T) { | ||
| 56 | + for _, noRetry := range []bool{false, true} { | ||
| 57 | + t.Run(map[bool]string{false: "read-retry", true: "guarded-write-single-attempt"}[noRetry], func(t *testing.T) { | ||
| 58 | + calls := 0 | ||
| 59 | + client, ctx, metrics := observedProviderFixture(t, Config{MaxRetries: 2}, func(*http.Request) (*http.Response, error) { | ||
| 60 | + calls++ | ||
| 61 | + if calls == 1 { | ||
| 62 | + return providerFixtureResponse(http.StatusServiceUnavailable, "synthetic-private-body"), nil | ||
| 63 | + } | ||
| 64 | + return providerFixtureResponse(http.StatusOK, "[]"), nil | ||
| 65 | + }) | ||
| 66 | + _, _, err := client.bytesWithOptions(ctx, http.MethodGet, "/synthetic-private-route", nil, nil, requestOptions{noRetry: noRetry}) | ||
| 67 | + if noRetry { | ||
| 68 | + if err == nil || calls != 1 { | ||
| 69 | + t.Fatal("observation changed guarded retry behavior") | ||
| 70 | + } | ||
| 71 | + requireProviderAttempts(t, metrics, "succeeded", 0) | ||
| 72 | + } else { | ||
| 73 | + if err != nil || calls != 2 { | ||
| 74 | + t.Fatal("observation changed read retry behavior") | ||
| 75 | + } | ||
| 76 | + requireProviderAttempts(t, metrics, "succeeded", 1) | ||
| 77 | + } | ||
| 78 | + requireProviderAttempts(t, metrics, "failed", 1) | ||
| 79 | + }) | ||
| 80 | + } | ||
| 81 | +} | ||
| 82 | + | ||
| 83 | +func TestProviderMetricsPreTransportRejectionDoesNotCount(t *testing.T) { | ||
| 84 | + calls := 0 | ||
| 85 | + client, ctx, metrics := observedProviderFixture(t, Config{}, func(*http.Request) (*http.Response, error) { | ||
| 86 | + calls++ | ||
| 87 | + return providerFixtureResponse(http.StatusOK, "[]"), nil | ||
| 88 | + }) | ||
| 89 | + cancelled, cancel := context.WithCancel(ctx) | ||
| 90 | + cancel() | ||
| 91 | + if _, _, err := client.getBytes(cancelled, "/fixture", nil); err == nil { | ||
| 92 | + t.Fatal("fixture cancelled request accepted") | ||
| 93 | + } | ||
| 94 | + if _, _, err := client.getBytes(ctx, "https://example.invalid/disallowed", nil); err == nil { | ||
| 95 | + t.Fatal("fixture absolute endpoint accepted") | ||
| 96 | + } | ||
| 97 | + if calls != 0 || metricProviderSeries(t, metrics, "provider_outcomes", "succeeded").Value != nil || metrics.Snapshot().Dropped != 0 { | ||
| 98 | + t.Fatal("local rejection fabricated an attempted transport or observation loss") | ||
| 99 | + } | ||
| 100 | +} | ||
| 101 | + | ||
| 102 | +func TestProviderMetricsResponseClassesAndTransferFaults(t *testing.T) { | ||
| 103 | + for _, tc := range []struct { | ||
| 104 | + name, outcome string | ||
| 105 | + status int | ||
| 106 | + transportErr error | ||
| 107 | + shortBody bool | ||
| 108 | + }{ | ||
| 109 | + {name: "success", outcome: "succeeded", status: 200}, | ||
| 110 | + {name: "forbidden", outcome: "forbidden", status: 403}, | ||
| 111 | + {name: "unauthorized", outcome: "forbidden", status: 401}, | ||
| 112 | + {name: "rate-limited", outcome: "rate_limited", status: 429}, | ||
| 113 | + {name: "validation", outcome: "invalid", status: 422}, | ||
| 114 | + {name: "not-found", outcome: "failed", status: 404}, | ||
| 115 | + {name: "oversized-status", outcome: "invalid", status: 413}, | ||
| 116 | + {name: "transport", outcome: "failed", transportErr: errors.New("synthetic-private-transport-error")}, | ||
| 117 | + {name: "cancelled", outcome: "cancelled", transportErr: context.Canceled}, | ||
| 118 | + {name: "timeout", outcome: "timeout", transportErr: context.DeadlineExceeded}, | ||
| 119 | + {name: "truncated-transfer", outcome: "invalid", status: 200, shortBody: true}, | ||
| 120 | + } { | ||
| 121 | + t.Run(tc.name, func(t *testing.T) { | ||
| 122 | + client, ctx, metrics := observedProviderFixture(t, Config{}, func(*http.Request) (*http.Response, error) { | ||
| 123 | + if tc.transportErr != nil { | ||
| 124 | + return nil, tc.transportErr | ||
| 125 | + } | ||
| 126 | + resp := providerFixtureResponse(tc.status, "[]") | ||
| 127 | + if tc.shortBody { | ||
| 128 | + resp.ContentLength = 100 | ||
| 129 | + } | ||
| 130 | + return resp, nil | ||
| 131 | + }) | ||
| 132 | + _, _, err := client.getBytes(ctx, "/fixture", nil) | ||
| 133 | + if tc.outcome == "succeeded" && err != nil || tc.outcome != "succeeded" && err == nil { | ||
| 134 | + t.Fatal("observation changed response outcome") | ||
| 135 | + } | ||
| 136 | + requireProviderAttempts(t, metrics, tc.outcome, 1) | ||
| 137 | + for _, other := range []string{"succeeded", "forbidden", "rate_limited", "failed", "invalid", "timeout", "cancelled"} { | ||
| 138 | + if other != tc.outcome { | ||
| 139 | + requireProviderAttempts(t, metrics, other, 0) | ||
| 140 | + } | ||
| 141 | + } | ||
| 142 | + }) | ||
| 143 | + } | ||
| 144 | +} | ||
| 145 | + | ||
| 146 | +func TestProviderMetricsWikiDirectPathAndNoPrivatePayload(t *testing.T) { | ||
| 147 | + client, ctx, metrics := observedProviderFixture(t, Config{Token: "synthetic-private-token"}, func(*http.Request) (*http.Response, error) { | ||
| 148 | + return providerFixtureResponse(http.StatusOK, "[]"), nil | ||
| 149 | + }) | ||
| 150 | + if _, err := client.listWikiEntries(ctx, "synthetic-private-owner", "synthetic-private-repository", "synthetic-private-directory"); err != nil { | ||
| 151 | + t.Fatal("fixture direct wiki transfer failed") | ||
| 152 | + } | ||
| 153 | + requireProviderAttempts(t, metrics, "succeeded", 1) | ||
| 154 | + data, err := json.Marshal(metrics.Snapshot()) | ||
| 155 | + if err != nil || strings.Contains(string(data), "synthetic-private") || strings.Contains(string(data), "example.invalid") { | ||
| 156 | + t.Fatal("provider metrics leaked private request data") | ||
| 157 | + } | ||
| 158 | +} | ||
| 159 | + | ||
| 160 | +func TestProviderMetricsOmittedOutsideDaemonContext(t *testing.T) { | ||
| 161 | + client, _, metrics := observedProviderFixture(t, Config{}, func(*http.Request) (*http.Response, error) { | ||
| 162 | + return providerFixtureResponse(http.StatusOK, "[]"), nil | ||
| 163 | + }) | ||
| 164 | + if _, _, err := client.getBytes(context.Background(), "/fixture", nil); err != nil { | ||
| 165 | + t.Fatal("fixture unobserved transfer failed") | ||
| 166 | + } | ||
| 167 | + if metricProviderSeries(t, metrics, "provider_outcomes", "succeeded").Value != nil { | ||
| 168 | + t.Fatal("foreground request acquired daemon telemetry implicitly") | ||
| 169 | + } | ||
| 170 | +} | ||
| 171 | + | ||
| 172 | +func TestProviderMetricsAttemptFinalizationIsOnce(t *testing.T) { | ||
| 173 | + metrics := observability.NewMetrics(strings.Repeat("d", 32), time.Now().UTC()) | ||
| 174 | + attempt := newProviderMetricAttempt(observability.WithMetrics(context.Background(), metrics)) | ||
| 175 | + attempt.finish(200, nil) | ||
| 176 | + if metricProviderSeries(t, metrics, "provider_outcomes", "succeeded").Value != nil { | ||
| 177 | + t.Fatal("unstarted attempt was counted") | ||
| 178 | + } | ||
| 179 | + attempt.start() | ||
| 180 | + attempt.finish(200, nil) | ||
| 181 | + attempt.finish(500, errors.New("synthetic-private-error")) | ||
| 182 | + requireProviderAttempts(t, metrics, "succeeded", 1) | ||
| 183 | + requireProviderAttempts(t, metrics, "failed", 0) | ||
| 184 | +} | ||
| @@ -0,0 +1,79 @@ | |||
| 1 | +package gitcode | ||
| 2 | + | ||
| 3 | +import ( | ||
| 4 | + "context" | ||
| 5 | + "encoding/json" | ||
| 6 | + "errors" | ||
| 7 | + "net/http" | ||
| 8 | + "path/filepath" | ||
| 9 | + "strings" | ||
| 10 | + "testing" | ||
| 11 | + "time" | ||
| 12 | + | ||
| 13 | + "gitcode-mcp/internal/observability" | ||
| 14 | +) | ||
| 15 | + | ||
| 16 | +func TestProviderExecutionEventsActualAttemptsWithoutMetrics(t *testing.T) { | ||
| 17 | + for _, tc := range []struct { | ||
| 18 | + name, outcome, class string | ||
| 19 | + status int | ||
| 20 | + err error | ||
| 21 | + }{ | ||
| 22 | + {"success", "succeeded", "", 200, nil}, | ||
| 23 | + {"forbidden", "forbidden", "forbidden", 403, nil}, | ||
| 24 | + {"rate_limit", "rate_limited", "rate_limited", 429, nil}, | ||
| 25 | + {"invalid", "invalid", "invalid", 422, nil}, | ||
| 26 | + {"server", "failed", "provider_failed", 503, nil}, | ||
| 27 | + {"cancel", "cancelled", "cancelled", 0, context.Canceled}, | ||
| 28 | + {"timeout", "timeout", "timeout", 0, context.DeadlineExceeded}, | ||
| 29 | + {"transport", "failed", "provider_failed", 0, errors.New("synthetic-private-error")}, | ||
| 30 | + } { | ||
| 31 | + t.Run(tc.name, func(t *testing.T) { | ||
| 32 | + c := observability.New(observability.Config{Directory: filepath.Join(t.TempDir(), "observation"), ManagedOutput: true}) | ||
| 33 | + deadline := time.Now().Add(5 * time.Second) | ||
| 34 | + for c.Coverage().State == "initializing" { | ||
| 35 | + if time.Now().After(deadline) { | ||
| 36 | + t.Fatal("collector fixture unavailable") | ||
| 37 | + } | ||
| 38 | + time.Sleep(time.Millisecond) | ||
| 39 | + } | ||
| 40 | + if c.Coverage().State != "ready" { | ||
| 41 | + t.Fatal("collector fixture unavailable") | ||
| 42 | + } | ||
| 43 | + calls := 0 | ||
| 44 | + client, _, _ := observedProviderFixture(t, Config{}, func(*http.Request) (*http.Response, error) { | ||
| 45 | + calls++ | ||
| 46 | + if tc.err != nil { | ||
| 47 | + return nil, tc.err | ||
| 48 | + } | ||
| 49 | + return providerFixtureResponse(tc.status, "[]"), nil | ||
| 50 | + }) | ||
| 51 | + ctx := observability.WithObservation(context.Background(), c, observability.Context{Job: observability.KnownRef("job", "fixture"), Correlation: observability.KnownRef("correlation", "fixture")}) | ||
| 52 | + _, _, _ = client.getBytes(ctx, "/synthetic-private-route", nil) | ||
| 53 | + cancelled, cancel := context.WithCancel(ctx) | ||
| 54 | + cancel() | ||
| 55 | + _, _, _ = client.getBytes(cancelled, "/synthetic-private-route", nil) | ||
| 56 | + if calls != 1 { | ||
| 57 | + t.Fatal("pre-transport rejection or telemetry added traffic") | ||
| 58 | + } | ||
| 59 | + closeCtx, closeCancel := context.WithTimeout(context.Background(), 5*time.Second) | ||
| 60 | + defer closeCancel() | ||
| 61 | + if !c.Close(closeCtx, true) { | ||
| 62 | + t.Fatal("collector fixture did not flush") | ||
| 63 | + } | ||
| 64 | + page, err := c.Query(observability.Filter{Code: observability.ProviderAttempt}, "", 20) | ||
| 65 | + if err != nil || uint64(len(page.Events))+page.Coverage.Dropped != 1 { | ||
| 66 | + t.Fatal("provider boundary missing or duplicated") | ||
| 67 | + } | ||
| 68 | + for _, e := range page.Events { | ||
| 69 | + if e.Phase != "fetch" || e.Outcome != tc.outcome || e.FailureClass != tc.class || e.Attempt != 1 || e.JobRef == "" || e.CorrelationRef == "" { | ||
| 70 | + t.Fatal("provider finite execution dimensions changed") | ||
| 71 | + } | ||
| 72 | + } | ||
| 73 | + data, _ := json.Marshal(page) | ||
| 74 | + if strings.Contains(string(data), "synthetic-private") || strings.Contains(string(data), "example.invalid") { | ||
| 75 | + t.Fatal("provider execution captured private request data") | ||
| 76 | + } | ||
| 77 | + }) | ||
| 78 | + } | ||
| 79 | +} | ||
| @@ -0,0 +1,88 @@ | |||
| 1 | +//go:build darwin || linux | ||
| 2 | + | ||
| 3 | +package observability | ||
| 4 | + | ||
| 5 | +import ( | ||
| 6 | + "sync" | ||
| 7 | + "testing" | ||
| 8 | +) | ||
| 9 | + | ||
| 10 | +func TestAdminRequestClosedCatalogReplayAndNonblockingLoss(t *testing.T) { | ||
| 11 | + for _, route := range []string{"session", "read", "control", "search", "events", "assets", "unknown"} { | ||
| 12 | + for _, outcome := range []string{"succeeded", "failed", "rejected", "cancelled"} { | ||
| 13 | + e := executionFixtureEvent(AdminRequestCompleted, ExecutionDetails{Phase: "admin", AdminRoute: route, Outcome: outcome}) | ||
| 14 | + e.JobRef = "" | ||
| 15 | + data, err := marshalEvent(e) | ||
| 16 | + var replay Event | ||
| 17 | + if err != nil || decodeStrict(data, &replay) != nil || replay != e { | ||
| 18 | + t.Fatal("Admin catalog failed strict replay") | ||
| 19 | + } | ||
| 20 | + for _, mutate := range []func(*Event){ | ||
| 21 | + func(e *Event) { e.CorrelationRef = "" }, func(e *Event) { e.JobRef = KnownRef("job", "fixture").value }, | ||
| 22 | + func(e *Event) { e.CacheRef = KnownRef("cache", "fixture").value }, func(e *Event) { e.RepoRef = KnownRef("repo", "fixture").value }, | ||
| 23 | + func(e *Event) { e.RegistrationRef = KnownRef("registration", "fixture").value }, func(e *Event) { e.StageRef = KnownRef("stage", "fixture").value }, | ||
| 24 | + func(e *Event) { e.Phase = "fetch" }, func(e *Event) { e.Collection = "issues" }, func(e *Event) { e.Attempt = 1 }, | ||
| 25 | + func(e *Event) { e.WorkKind = "other" }, func(e *Event) { e.FailureClass = "operation_failed" }, func(e *Event) { e.Legacy = true }, | ||
| 26 | + func(e *Event) { e.AdminRoute = "synthetic-private" }, func(e *Event) { e.Outcome = "synthetic-private" }, | ||
| 27 | + } { | ||
| 28 | + invalid := e | ||
| 29 | + mutate(&invalid) | ||
| 30 | + if invalid.valid() { | ||
| 31 | + t.Fatal("Admin catalog admitted invented execution/private fields") | ||
| 32 | + } | ||
| 33 | + } | ||
| 34 | + } | ||
| 35 | + } | ||
| 36 | + for _, code := range []Code{Boot, JobAdmitted, JobRecovered, ProviderAttempt, WriterContended, SyncCommitted, SyncStageChanged} { | ||
| 37 | + e := executionFixtureEvent(code, ExecutionDetails{AdminRoute: "read"}) | ||
| 38 | + if e.valid() { | ||
| 39 | + t.Fatal("another code admitted Admin-only dimensions") | ||
| 40 | + } | ||
| 41 | + } | ||
| 42 | + c := New(Config{Directory: testDirectory(t), ManagedOutput: true}) | ||
| 43 | + defer flush(t, c, true) | ||
| 44 | + ready(t, c) | ||
| 45 | + before := c.admissionDrops.Load() | ||
| 46 | + c.mu.Lock() | ||
| 47 | + var workers sync.WaitGroup | ||
| 48 | + for i := 0; i < 16; i++ { | ||
| 49 | + workers.Add(1) | ||
| 50 | + go func() { | ||
| 51 | + defer workers.Done() | ||
| 52 | + c.Emit(AdminRequestCompleted, Context{Correlation: c.AdminRequestCorrelation(), ExecutionDetails: ExecutionDetails{Phase: "admin", AdminRoute: "read", Outcome: "succeeded"}}) | ||
| 53 | + }() | ||
| 54 | + } | ||
| 55 | + workers.Wait() | ||
| 56 | + c.mu.Unlock() | ||
| 57 | + if c.admissionDrops.Load()-before != 16 { | ||
| 58 | + t.Fatal("Admin events waited, retried or hid contention") | ||
| 59 | + } | ||
| 60 | + flush(t, c, true) | ||
| 61 | + page, err := c.Query(Filter{Code: AdminRequestCompleted}, "", 20) | ||
| 62 | + if err != nil || len(page.Events) != 0 || page.Coverage.Dropped != 16 || page.Coverage.State != "partial" { | ||
| 63 | + t.Fatal("Admin contention invented retained requests") | ||
| 64 | + } | ||
| 65 | +} | ||
| 66 | + | ||
| 67 | +func TestAdminRequestCorrelationAtomicAcrossControllersAndReaders(t *testing.T) { | ||
| 68 | + c := New(Config{Directory: testDirectory(t), ManagedOutput: true}) | ||
| 69 | + defer flush(t, c, true) | ||
| 70 | + ready(t, c) | ||
| 71 | + var workers sync.WaitGroup | ||
| 72 | + refs := make(chan Ref, 128) | ||
| 73 | + c.mu.Lock() | ||
| 74 | + for i := 0; i < 128; i++ { | ||
| 75 | + workers.Add(1) | ||
| 76 | + go func() { defer workers.Done(); refs <- c.AdminRequestCorrelation() }() | ||
| 77 | + } | ||
| 78 | + workers.Wait() | ||
| 79 | + c.mu.Unlock() | ||
| 80 | + close(refs) | ||
| 81 | + seen := map[string]bool{} | ||
| 82 | + for ref := range refs { | ||
| 83 | + if ref.value == "" || !validRef(ref.value, "correlation") || seen[ref.value] { | ||
| 84 | + t.Fatal("atomic request correlation missing/reused") | ||
| 85 | + } | ||
| 86 | + seen[ref.value] = true | ||
| 87 | + } | ||
| 88 | +} | ||
| @@ -0,0 +1,137 @@ | |||
| 1 | +//go:build darwin || linux | ||
| 2 | + | ||
| 3 | +package observability | ||
| 4 | + | ||
| 5 | +import ( | ||
| 6 | + "context" | ||
| 7 | + "sync" | ||
| 8 | + "sync/atomic" | ||
| 9 | + "testing" | ||
| 10 | + "time" | ||
| 11 | +) | ||
| 12 | + | ||
| 13 | +func TestUnconfirmedExecutionLossSealRestartAndCursor(t *testing.T) { | ||
| 14 | + path := testDirectory(t) | ||
| 15 | + c := New(Config{Directory: path, ManagedOutput: true}) | ||
| 16 | + defer flush(t, c, true) | ||
| 17 | + ready(t, c) | ||
| 18 | + admitFixture(t, c, RecoveryFinished, Context{}) | ||
| 19 | + await(t, func() bool { | ||
| 20 | + c.mu.Lock() | ||
| 21 | + defer c.mu.Unlock() | ||
| 22 | + return len(c.events) > 0 | ||
| 23 | + }) | ||
| 24 | + before, err := c.Query(Filter{}, "", 100) | ||
| 25 | + if err != nil { | ||
| 26 | + t.Fatal("fixture cursor unavailable") | ||
| 27 | + } | ||
| 28 | + admissionDrops := c.admissionDrops.Load() | ||
| 29 | + c.mu.Lock() | ||
| 30 | + done := make(chan struct{}) | ||
| 31 | + go func() { | ||
| 32 | + c.UnconfirmedExecutions(0) | ||
| 33 | + c.UnconfirmedExecutions(7) | ||
| 34 | + close(done) | ||
| 35 | + }() | ||
| 36 | + select { | ||
| 37 | + case <-done: | ||
| 38 | + case <-time.After(time.Second): | ||
| 39 | + c.mu.Unlock() | ||
| 40 | + t.Fatal("boundary loss waited on observation lock") | ||
| 41 | + } | ||
| 42 | + c.mu.Unlock() | ||
| 43 | + if c.admissionDrops.Load() != admissionDrops { | ||
| 44 | + t.Fatal("unconfirmed boundary counted as rejected admission") | ||
| 45 | + } | ||
| 46 | + if _, err := c.Query(Filter{}, before.Cursor, 100); err == nil { | ||
| 47 | + t.Fatal("loss did not invalidate the previous cursor") | ||
| 48 | + } | ||
| 49 | + flush(t, c, true) | ||
| 50 | + baseline := c.Coverage() | ||
| 51 | + if baseline.State != "partial" || baseline.Reason != "execution_boundary_unconfirmed" || baseline.Dropped != before.Coverage.Dropped+7 || baseline.LossEpoch != before.Coverage.LossEpoch+7 { | ||
| 52 | + t.Fatal("unconfirmed boundary loss not folded exactly once") | ||
| 53 | + } | ||
| 54 | + c.UnconfirmedExecution() | ||
| 55 | + // A producer paused between the seal check and Add cannot publish a | ||
| 56 | + // post-seal loss, even when it resumes after shutdown persistence. | ||
| 57 | + c.pendingBoundaryLoss.Add(3) | ||
| 58 | + if c.Coverage() != baseline { | ||
| 59 | + t.Fatal("post-seal loss changed published coverage") | ||
| 60 | + } | ||
| 61 | + restarted := New(Config{Directory: path, ManagedOutput: true}) | ||
| 62 | + defer flush(t, restarted, true) | ||
| 63 | + ready(t, restarted) | ||
| 64 | + flush(t, restarted, true) | ||
| 65 | + got := restarted.Coverage() | ||
| 66 | + if got.Dropped != baseline.Dropped || got.LossEpoch != baseline.LossEpoch { | ||
| 67 | + t.Fatal("restart lost or recounted sealed boundary loss") | ||
| 68 | + } | ||
| 69 | +} | ||
| 70 | + | ||
| 71 | +func TestCloseSealsBoundaryLossBeforeShutdownPersistence(t *testing.T) { | ||
| 72 | + path := testDirectory(t) | ||
| 73 | + var pause atomic.Bool | ||
| 74 | + entered, release := make(chan struct{}), make(chan struct{}) | ||
| 75 | + var enteredOnce, releaseOnce sync.Once | ||
| 76 | + c := newCollector(Config{Directory: path, ManagedOutput: true}, func(path string) (*storage, []Event, bool, error) { | ||
| 77 | + s, events, unclean, err := openStorage(path) | ||
| 78 | + if err == nil { | ||
| 79 | + s.appendFault = func() error { | ||
| 80 | + if pause.Load() { | ||
| 81 | + enteredOnce.Do(func() { close(entered) }) | ||
| 82 | + <-release | ||
| 83 | + } | ||
| 84 | + return nil | ||
| 85 | + } | ||
| 86 | + } | ||
| 87 | + return s, events, unclean, err | ||
| 88 | + }) | ||
| 89 | + defer flush(t, c, true) | ||
| 90 | + defer releaseOnce.Do(func() { close(release) }) | ||
| 91 | + ready(t, c) | ||
| 92 | + admitFixture(t, c, RecoveryFinished, Context{}) | ||
| 93 | + await(t, func() bool { | ||
| 94 | + c.mu.Lock() | ||
| 95 | + defer c.mu.Unlock() | ||
| 96 | + return len(c.events) > 0 | ||
| 97 | + }) | ||
| 98 | + prior := c.Coverage() | ||
| 99 | + c.UnconfirmedExecution() | ||
| 100 | + pause.Store(true) | ||
| 101 | + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) | ||
| 102 | + defer cancel() | ||
| 103 | + done := make(chan bool, 1) | ||
| 104 | + go func() { done <- c.Close(ctx, true) }() | ||
| 105 | + select { | ||
| 106 | + case <-entered: | ||
| 107 | + case <-ctx.Done(): | ||
| 108 | + t.Fatal("shutdown persistence barrier unavailable") | ||
| 109 | + } | ||
| 110 | + // The append barrier may catch a queued event before Close acquires the | ||
| 111 | + // mutex. Observe the actual seal before injecting a post-seal increment. | ||
| 112 | + await(t, func() bool { | ||
| 113 | + c.mu.Lock() | ||
| 114 | + defer c.mu.Unlock() | ||
| 115 | + return c.closing && c.pendingBoundaryLoss.Load()&admissionClosed != 0 | ||
| 116 | + }) | ||
| 117 | + baseline := c.Coverage() | ||
| 118 | + if baseline.Dropped != prior.Dropped+1 || baseline.LossEpoch != prior.LossEpoch+1 { | ||
| 119 | + t.Fatal("pre-seal boundary loss was not folded exactly once") | ||
| 120 | + } | ||
| 121 | + c.UnconfirmedExecution() | ||
| 122 | + c.pendingBoundaryLoss.Add(3) | ||
| 123 | + if c.Coverage() != baseline { | ||
| 124 | + t.Fatal("shutdown rejection changed sealed boundary loss") | ||
| 125 | + } | ||
| 126 | + releaseOnce.Do(func() { close(release) }) | ||
| 127 | + if !<-done { | ||
| 128 | + t.Fatal("shutdown did not finish after releasing persistence") | ||
| 129 | + } | ||
| 130 | + restarted := New(Config{Directory: path, ManagedOutput: true}) | ||
| 131 | + defer flush(t, restarted, true) | ||
| 132 | + ready(t, restarted) | ||
| 133 | + flush(t, restarted, true) | ||
| 134 | + if got := restarted.Coverage(); got.Dropped != baseline.Dropped || got.LossEpoch != baseline.LossEpoch { | ||
| 135 | + t.Fatal("checkpoint lost or recounted sealed boundary loss") | ||
| 136 | + } | ||
| 137 | +} | ||
| @@ -26,27 +26,47 @@ const ( | |||
| 26 | type Code string | 26 | type Code string |
| 27 | 27 | ||
| 28 | const ( | 28 | const ( |
| 29 | - Boot Code = "daemon_boot" | 29 | + Boot Code = "daemon_boot" |
| 30 | - RecoveryStarted Code = "recovery_started" | 30 | + RecoveryStarted Code = "recovery_started" |
| 31 | - RecoveryFinished Code = "recovery_finished" | 31 | + RecoveryFinished Code = "recovery_finished" |
| 32 | - RecoveryFailed Code = "recovery_failed" | 32 | + RecoveryFailed Code = "recovery_failed" |
| 33 | - Shutdown Code = "daemon_shutdown" | 33 | + Shutdown Code = "daemon_shutdown" |
| 34 | - ShutdownIncomplete Code = "shutdown_incomplete" | 34 | + ShutdownIncomplete Code = "shutdown_incomplete" |
| 35 | - PriorBootUnclean Code = "prior_boot_unclean" | 35 | + PriorBootUnclean Code = "prior_boot_unclean" |
| 36 | - LegacyOmitted Code = "legacy_text_omitted" | 36 | + LegacyOmitted Code = "legacy_text_omitted" |
| 37 | + JobAdmitted Code = "job_admitted" | ||
| 38 | + JobTerminal Code = "job_terminal" | ||
| 39 | + JobRecovered Code = "job_recovered" | ||
| 40 | + ProviderAttempt Code = "provider_attempt" | ||
| 41 | + SyncCommitted Code = "sync_committed" | ||
| 42 | + RetryAdmitted Code = "retry_admitted" | ||
| 43 | + WriterContended Code = "writer_contended" | ||
| 44 | + SyncStageChanged Code = "sync_stage_changed" | ||
| 45 | + AdminRequestCompleted Code = "admin_request_completed" | ||
| 46 | + MaintenanceStateChanged Code = "maintenance_state_changed" | ||
| 37 | ) | 47 | ) |
| 38 | 48 | ||
| 39 | type template struct{ stream, severity, component, message string } | 49 | type template struct{ stream, severity, component, message string } |
| 40 | 50 | ||
| 41 | var catalog = map[Code]template{ | 51 | var catalog = map[Code]template{ |
| 42 | - Boot: {"stdout", "info", "daemon", "Daemon observation started."}, | 52 | + Boot: {"stdout", "info", "daemon", "Daemon observation started."}, |
| 43 | - RecoveryStarted: {"stdout", "info", "recovery", "Recovery inspection started."}, | 53 | + RecoveryStarted: {"stdout", "info", "recovery", "Recovery inspection started."}, |
| 44 | - RecoveryFinished: {"stdout", "info", "recovery", "Recovery inspection finished."}, | 54 | + RecoveryFinished: {"stdout", "info", "recovery", "Recovery inspection finished."}, |
| 45 | - RecoveryFailed: {"stderr", "error", "recovery", "Recovery inspection failed."}, | 55 | + RecoveryFailed: {"stderr", "error", "recovery", "Recovery inspection failed."}, |
| 46 | - Shutdown: {"stdout", "info", "daemon", "Daemon workers unwound before observation stopped."}, | 56 | + Shutdown: {"stdout", "info", "daemon", "Daemon workers unwound before observation stopped."}, |
| 47 | - ShutdownIncomplete: {"stderr", "warning", "daemon", "Daemon teardown was incomplete."}, | 57 | + ShutdownIncomplete: {"stderr", "warning", "daemon", "Daemon teardown was incomplete."}, |
| 48 | - PriorBootUnclean: {"stderr", "warning", "daemon", "The preceding observed boot has no clean shutdown marker."}, | 58 | + PriorBootUnclean: {"stderr", "warning", "daemon", "The preceding observed boot has no clean shutdown marker."}, |
| 49 | - LegacyOmitted: {"stderr", "warning", "legacy", "Unrecognized legacy output was omitted."}, | 59 | + LegacyOmitted: {"stderr", "warning", "legacy", "Unrecognized legacy output was omitted."}, |
| 60 | + JobAdmitted: {"stdout", "info", "jobs", "A new job was durably admitted."}, | ||
| 61 | + JobTerminal: {"stdout", "info", "jobs", "A job reached a confirmed terminal state."}, | ||
| 62 | + JobRecovered: {"stdout", "info", "recovery", "An actual job recovery reached a confirmed state."}, | ||
| 63 | + ProviderAttempt: {"stdout", "info", "provider", "An actual bounded provider attempt finished."}, | ||
| 64 | + SyncCommitted: {"stdout", "info", "sync", "Fetched source graphs reached a confirmed cache commit."}, | ||
| 65 | + RetryAdmitted: {"stdout", "info", "sync", "A collection entered an actual retry attempt."}, | ||
| 66 | + WriterContended: {"stderr", "warning", "writer", "An actual cache writer attempt was denied."}, | ||
| 67 | + SyncStageChanged: {"stdout", "info", "sync", "A sync stage reached a confirmed journal state."}, | ||
| 68 | + AdminRequestCompleted: {"stdout", "info", "admin", "An Admin HTTP request completed."}, | ||
| 69 | + MaintenanceStateChanged: {"stdout", "info", "maintenance", "Maintenance reached a confirmed state transition."}, | ||
| 50 | } | 70 | } |
| 51 | 71 | ||
| 52 | // Ref is opaque and cannot be constructed by assigning an unchecked string. | 72 | // Ref is opaque and cannot be constructed by assigning an unchecked string. |
| @@ -59,7 +79,7 @@ func KnownRef(kind, authorityID string) Ref { | |||
| 59 | return Ref{} | 79 | return Ref{} |
| 60 | } | 80 | } |
| 61 | switch kind { | 81 | switch kind { |
| 62 | - case "job", "registration", "cache", "repo", "correlation": | 82 | + case "job", "registration", "cache", "repo", "correlation", "stage", "source": |
| 63 | default: | 83 | default: |
| 64 | return Ref{} | 84 | return Ref{} |
| 65 | } | 85 | } |
| @@ -67,25 +87,34 @@ func KnownRef(kind, authorityID string) Ref { | |||
| 67 | return Ref{kind + "-" + hex.EncodeToString(sum[:16])} | 87 | return Ref{kind + "-" + hex.EncodeToString(sum[:16])} |
| 68 | } | 88 | } |
| 69 | 89 | ||
| 70 | -type Context struct{ Job, Registration, Cache, Repo, Correlation Ref } | 90 | +type Context struct { |
| 91 | + Job, Registration, Cache, Repo, Correlation Ref | ||
| 92 | + Stage, Source Ref | ||
| 93 | + PreviousRegistration Ref | ||
| 94 | + ExecutionDetails | ||
| 95 | +} | ||
| 71 | type Event struct { | 96 | type Event struct { |
| 72 | - Legacy bool `json:"legacy,omitempty"` | 97 | + ExecutionDetails |
| 73 | - ObservedBytes int `json:"observed_bytes,omitempty"` | 98 | + Legacy bool `json:"legacy,omitempty"` |
| 74 | - Schema int `json:"schema"` | 99 | + ObservedBytes int `json:"observed_bytes,omitempty"` |
| 75 | - EventID string `json:"event_id"` | 100 | + Schema int `json:"schema"` |
| 76 | - OccurredAt time.Time `json:"occurred_at"` | 101 | + EventID string `json:"event_id"` |
| 77 | - BootID string `json:"boot_id"` | 102 | + OccurredAt time.Time `json:"occurred_at"` |
| 78 | - Sequence uint64 `json:"sequence"` | 103 | + BootID string `json:"boot_id"` |
| 79 | - Stream string `json:"stream"` | 104 | + Sequence uint64 `json:"sequence"` |
| 80 | - Severity string `json:"severity"` | 105 | + Stream string `json:"stream"` |
| 81 | - Component string `json:"component"` | 106 | + Severity string `json:"severity"` |
| 82 | - Code Code `json:"code"` | 107 | + Component string `json:"component"` |
| 83 | - Message string `json:"message"` | 108 | + Code Code `json:"code"` |
| 84 | - JobRef string `json:"job_ref,omitempty"` | 109 | + Message string `json:"message"` |
| 85 | - RegistrationRef string `json:"registration_ref,omitempty"` | 110 | + JobRef string `json:"job_ref,omitempty"` |
| 86 | - CacheRef string `json:"cache_ref,omitempty"` | 111 | + RegistrationRef string `json:"registration_ref,omitempty"` |
| 87 | - RepoRef string `json:"repo_ref,omitempty"` | 112 | + CacheRef string `json:"cache_ref,omitempty"` |
| 88 | - CorrelationRef string `json:"correlation_ref,omitempty"` | 113 | + RepoRef string `json:"repo_ref,omitempty"` |
| 114 | + CorrelationRef string `json:"correlation_ref,omitempty"` | ||
| 115 | + StageRef string `json:"stage_ref,omitempty"` | ||
| 116 | + SourceRef string `json:"source_ref,omitempty"` | ||
| 117 | + PreviousRegistrationRef string `json:"previous_registration_ref,omitempty"` | ||
| 89 | } | 118 | } |
| 90 | 119 | ||
| 91 | var hexID = regexp.MustCompile(`^[a-f0-9]{32}$`) | 120 | var hexID = regexp.MustCompile(`^[a-f0-9]{32}$`) |
| @@ -99,9 +128,9 @@ func (e Event) valid() bool { | |||
| 99 | if e.Legacy { | 128 | if e.Legacy { |
| 100 | streamOK = e.Stream == "stdout" || e.Stream == "stderr" | 129 | streamOK = e.Stream == "stdout" || e.Stream == "stderr" |
| 101 | } | 130 | } |
| 102 | - return ok && e.ObservedBytes >= 0 && e.ObservedBytes <= MaxPageBytes && (e.Legacy || e.ObservedBytes == 0) && e.Schema == 1 && e.Sequence > 0 && hexID.MatchString(e.BootID) && hexID.MatchString(e.EventID) && | 131 | + return ok && e.validExecution() && e.ObservedBytes >= 0 && e.ObservedBytes <= MaxPageBytes && (e.Legacy || e.ObservedBytes == 0) && e.Schema == 1 && e.Sequence > 0 && hexID.MatchString(e.BootID) && hexID.MatchString(e.EventID) && |
| 103 | !e.OccurredAt.IsZero() && streamOK && e.Severity == t.severity && e.Component == t.component && e.Message == t.message && | 132 | !e.OccurredAt.IsZero() && streamOK && e.Severity == t.severity && e.Component == t.component && e.Message == t.message && |
| 104 | - validRef(e.JobRef, "job") && validRef(e.RegistrationRef, "registration") && validRef(e.CacheRef, "cache") && validRef(e.RepoRef, "repo") && validRef(e.CorrelationRef, "correlation") | 133 | + validRef(e.JobRef, "job") && validRef(e.RegistrationRef, "registration") && validRef(e.CacheRef, "cache") && validRef(e.RepoRef, "repo") && validRef(e.CorrelationRef, "correlation") && validRef(e.StageRef, "stage") && validRef(e.SourceRef, "source") && validRef(e.PreviousRegistrationRef, "registration") |
| 105 | } | 134 | } |
| 106 | func marshalEvent(e Event) ([]byte, error) { | 135 | func marshalEvent(e Event) ([]byte, error) { |
| 107 | if !e.valid() { | 136 | if !e.valid() { |
| @@ -5,6 +5,7 @@ import ( | |||
| 5 | "crypto/rand" | 5 | "crypto/rand" |
| 6 | "encoding/hex" | 6 | "encoding/hex" |
| 7 | "encoding/json" | 7 | "encoding/json" |
| 8 | + "strconv" | ||
| 8 | "sync" | 9 | "sync" |
| 9 | "sync/atomic" | 10 | "sync/atomic" |
| 10 | "time" | 11 | "time" |
| @@ -34,26 +35,35 @@ type Coverage struct { | |||
| 34 | ObservedBoots uint64 `json:"observed_boots"` | 35 | ObservedBoots uint64 `json:"observed_boots"` |
| 35 | } | 36 | } |
| 36 | type Collector struct { | 37 | type Collector struct { |
| 37 | - mu sync.Mutex | 38 | + mu sync.Mutex |
| 38 | - queue chan pending | 39 | + queue chan pending |
| 39 | - stop, done chan struct{} | 40 | + stop, done chan struct{} |
| 40 | - closing bool | 41 | + closing bool |
| 41 | - queued, queueBytes int | 42 | + queued, queueBytes int |
| 42 | - cleanRequested bool | 43 | + cleanRequested bool |
| 43 | - storageFailed bool | 44 | + storageFailed bool |
| 44 | - generation, boot string | 45 | + generation, boot string |
| 45 | - cursorKey string | 46 | + cursorKey string |
| 46 | - sequence uint64 | 47 | + sequence uint64 |
| 47 | - events []Event | 48 | + events []Event |
| 48 | - historyBytes int | 49 | + historyBytes int |
| 49 | - coverage Coverage | 50 | + coverage Coverage |
| 50 | - config Config | 51 | + pendingLoss atomic.Uint64 |
| 52 | + pendingBoundaryLoss atomic.Uint64 | ||
| 53 | + admissionDrops atomic.Uint64 | ||
| 54 | + adminRequests atomic.Uint64 | ||
| 55 | + maintenanceTransitions atomic.Uint64 | ||
| 56 | + config Config | ||
| 51 | // A deterministic private storage seam for fault tests, not a public hook. | 57 | // A deterministic private storage seam for fault tests, not a public hook. |
| 52 | open func(string) (*storage, []Event, bool, error) | 58 | open func(string) (*storage, []Event, bool, error) |
| 53 | } | 59 | } |
| 54 | 60 | ||
| 55 | var entropyFallback atomic.Uint64 | 61 | var entropyFallback atomic.Uint64 |
| 56 | 62 | ||
| 63 | +// The upper bit seals admission loss at Close. Lower bits are pending losses, | ||
| 64 | +// not retained events. A racing post-seal Add is deliberately never published. | ||
| 65 | +const admissionClosed = uint64(1) << 63 | ||
| 66 | + | ||
| 57 | func randomID() string { | 67 | func randomID() string { |
| 58 | var b [16]byte | 68 | var b [16]byte |
| 59 | if _, err := rand.Read(b[:]); err != nil { | 69 | if _, err := rand.Read(b[:]); err != nil { |
| @@ -68,6 +78,23 @@ func randomID() string { | |||
| 68 | return hex.EncodeToString(b[:]) | 78 | return hex.EncodeToString(b[:]) |
| 69 | } | 79 | } |
| 70 | func New(cfg Config) *Collector { return newCollector(cfg, openStorage) } | 80 | func New(cfg Config) *Collector { return newCollector(cfg, openStorage) } |
| 81 | + | ||
| 82 | +// BootID is immutable process-local correlation, not a disk/read operation. | ||
| 83 | +func (c *Collector) BootID() string { return c.boot } | ||
| 84 | + | ||
| 85 | +// AdminRequestCorrelation is local request identity, never a browser-supplied | ||
| 86 | +// request id. Sharing the counter across controllers prevents same-boot reuse. | ||
| 87 | +// Allocation is atomic and performs no I/O or execution/observation lock wait. | ||
| 88 | +func (c *Collector) AdminRequestCorrelation() Ref { | ||
| 89 | + return KnownRef("correlation", c.boot+"\x00admin\x00"+strconv.FormatUint(c.adminRequests.Add(1), 10)) | ||
| 90 | +} | ||
| 91 | + | ||
| 92 | +// MaintenanceTransitionCorrelation identifies a fresh owner-confirmed boundary, | ||
| 93 | +// not a request id, generation or timestamp read from execution authority. | ||
| 94 | +func (c *Collector) MaintenanceTransitionCorrelation() Ref { | ||
| 95 | + return KnownRef("correlation", c.boot+"\x00maintenance\x00"+strconv.FormatUint(c.maintenanceTransitions.Add(1), 10)) | ||
| 96 | +} | ||
| 97 | + | ||
| 71 | func newCollector(cfg Config, open func(string) (*storage, []Event, bool, error)) *Collector { | 98 | func newCollector(cfg Config, open func(string) (*storage, []Event, bool, error)) *Collector { |
| 72 | c := &Collector{queue: make(chan pending, MaxEvents), stop: make(chan struct{}), done: make(chan struct{}), boot: randomID(), config: cfg, open: open, | 99 | c := &Collector{queue: make(chan pending, MaxEvents), stop: make(chan struct{}), done: make(chan struct{}), boot: randomID(), config: cfg, open: open, |
| 73 | coverage: Coverage{State: "initializing", OutputState: "migration_required"}} | 100 | coverage: Coverage{State: "initializing", OutputState: "migration_required"}} |
| @@ -78,27 +105,38 @@ func newCollector(cfg Config, open func(string) (*storage, []Event, bool, error) | |||
| 78 | return c | 105 | return c |
| 79 | } | 106 | } |
| 80 | 107 | ||
| 81 | -// Emit never waits for disk or execution locks. Rejected codes and references | 108 | +// Emit never waits for disk, execution locks or observation readers. Rejected codes and references |
| 82 | // never enter the queue. Diagnostic loss must not become a job failure. | 109 | // never enter the queue. Diagnostic loss must not become a job failure. |
| 83 | func (c *Collector) Emit(code Code, refs Context) bool { | 110 | func (c *Collector) Emit(code Code, refs Context) bool { |
| 111 | + if c.pendingLoss.Load()&admissionClosed != 0 { | ||
| 112 | + return false | ||
| 113 | + } | ||
| 84 | t, ok := catalog[code] | 114 | t, ok := catalog[code] |
| 85 | if !ok { | 115 | if !ok { |
| 86 | return false | 116 | return false |
| 87 | } | 117 | } |
| 88 | e := Event{Schema: 1, EventID: c.boot, OccurredAt: time.Now().UTC(), BootID: c.boot, Sequence: 1, Stream: t.stream, Severity: t.severity, Component: t.component, Code: code, Message: t.message, | 118 | e := Event{Schema: 1, EventID: c.boot, OccurredAt: time.Now().UTC(), BootID: c.boot, Sequence: 1, Stream: t.stream, Severity: t.severity, Component: t.component, Code: code, Message: t.message, |
| 89 | - JobRef: refs.Job.value, RegistrationRef: refs.Registration.value, CacheRef: refs.Cache.value, RepoRef: refs.Repo.value, CorrelationRef: refs.Correlation.value} | 119 | + ExecutionDetails: refs.ExecutionDetails, |
| 120 | + JobRef: refs.Job.value, RegistrationRef: refs.Registration.value, CacheRef: refs.Cache.value, RepoRef: refs.Repo.value, CorrelationRef: refs.Correlation.value, StageRef: refs.Stage.value, SourceRef: refs.Source.value, PreviousRegistrationRef: refs.PreviousRegistration.value} | ||
| 90 | b, err := marshalEvent(e) | 121 | b, err := marshalEvent(e) |
| 91 | if err != nil { | 122 | if err != nil { |
| 92 | return false | 123 | return false |
| 93 | } | 124 | } |
| 94 | - c.mu.Lock() | 125 | + if !c.mu.TryLock() { |
| 126 | + if c.pendingLoss.Add(1)&admissionClosed == 0 { | ||
| 127 | + c.admissionDrops.Add(1) | ||
| 128 | + } | ||
| 129 | + return false | ||
| 130 | + } | ||
| 95 | defer c.mu.Unlock() | 131 | defer c.mu.Unlock() |
| 132 | + c.absorbLossLocked() | ||
| 96 | if c.closing { | 133 | if c.closing { |
| 97 | return false | 134 | return false |
| 98 | } | 135 | } |
| 99 | if c.queued >= MaxEvents || c.queueBytes+len(b) > MaxQueueBytes { | 136 | if c.queued >= MaxEvents || c.queueBytes+len(b) > MaxQueueBytes { |
| 100 | c.loseLocked("queue_overflow") | 137 | c.loseLocked("queue_overflow") |
| 101 | c.coverage.Dropped++ | 138 | c.coverage.Dropped++ |
| 139 | + c.admissionDrops.Add(1) | ||
| 102 | return false | 140 | return false |
| 103 | } | 141 | } |
| 104 | c.queued++ | 142 | c.queued++ |
| @@ -111,11 +149,63 @@ func (c *Collector) loseLocked(reason string) { | |||
| 111 | c.coverage.Reason = reason | 149 | c.coverage.Reason = reason |
| 112 | c.coverage.LossEpoch++ | 150 | c.coverage.LossEpoch++ |
| 113 | } | 151 | } |
| 114 | -func (c *Collector) Coverage() Coverage { c.mu.Lock(); defer c.mu.Unlock(); return c.coverage } | 152 | + |
| 153 | +// UnconfirmedExecution records an omitted execution observation whose durable | ||
| 154 | +// boundary was unavailable. No event was admitted or rejected, so this does | ||
| 155 | +// not increment event_drops. It never waits for a lock, storage or a retry. | ||
| 156 | +func (c *Collector) UnconfirmedExecution() { | ||
| 157 | + c.UnconfirmedExecutions(1) | ||
| 158 | +} | ||
| 159 | + | ||
| 160 | +// UnconfirmedExecutions accounts for actual owner boundaries omitted by one | ||
| 161 | +// bounded capture or retained failed save. Count-only evidence never retains | ||
| 162 | +// identities, invokes callbacks or loops once per omitted job. | ||
| 163 | +func (c *Collector) UnconfirmedExecutions(count uint64) { | ||
| 164 | + if count == 0 { | ||
| 165 | + return | ||
| 166 | + } | ||
| 167 | + if c.pendingBoundaryLoss.Load()&admissionClosed == 0 { | ||
| 168 | + c.pendingBoundaryLoss.Add(count) | ||
| 169 | + } | ||
| 170 | +} | ||
| 171 | + | ||
| 172 | +// A fixed scalar accounts for contention without retaining rejected events. | ||
| 173 | +// Readers and the asynchronous writer fold it into the durable loss boundary; | ||
| 174 | +// no producer waits for that work or retries the rejected event. | ||
| 175 | +func (c *Collector) absorbLossLocked() { | ||
| 176 | + if !c.closing { | ||
| 177 | + c.foldLossLocked(c.pendingLoss.Swap(0)) | ||
| 178 | + c.foldBoundaryLossLocked(c.pendingBoundaryLoss.Swap(0)) | ||
| 179 | + } | ||
| 180 | +} | ||
| 181 | +func (c *Collector) foldBoundaryLossLocked(lost uint64) { | ||
| 182 | + if lost != 0 { | ||
| 183 | + c.coverage.Dropped += lost | ||
| 184 | + c.coverage.LossEpoch += lost | ||
| 185 | + c.coverage.State, c.coverage.Reason = "partial", "execution_boundary_unconfirmed" | ||
| 186 | + } | ||
| 187 | +} | ||
| 188 | +func (c *Collector) foldLossLocked(lost uint64) { | ||
| 189 | + if lost != 0 { | ||
| 190 | + c.coverage.Dropped += lost | ||
| 191 | + c.coverage.LossEpoch += lost | ||
| 192 | + c.coverage.State, c.coverage.Reason = "partial", "observation_contention" | ||
| 193 | + } | ||
| 194 | +} | ||
| 195 | +func (c *Collector) Coverage() Coverage { | ||
| 196 | + c.mu.Lock() | ||
| 197 | + defer c.mu.Unlock() | ||
| 198 | + c.absorbLossLocked() | ||
| 199 | + return c.coverage | ||
| 200 | +} | ||
| 115 | func (c *Collector) Close(ctx context.Context, workersUnwound bool) bool { | 201 | func (c *Collector) Close(ctx context.Context, workersUnwound bool) bool { |
| 116 | c.mu.Lock() | 202 | c.mu.Lock() |
| 117 | if !c.closing { | 203 | if !c.closing { |
| 118 | c.closing = true | 204 | c.closing = true |
| 205 | + // Swap is the loss linearization boundary. A preempted producer that | ||
| 206 | + // increments afterward cannot change coverage or a sealed checkpoint. | ||
| 207 | + c.foldLossLocked(c.pendingLoss.Swap(admissionClosed)) | ||
| 208 | + c.foldBoundaryLossLocked(c.pendingBoundaryLoss.Swap(admissionClosed)) | ||
| 119 | c.cleanRequested = workersUnwound | 209 | c.cleanRequested = workersUnwound |
| 120 | close(c.stop) | 210 | close(c.stop) |
| 121 | } | 211 | } |
| @@ -189,6 +279,7 @@ func (c *Collector) run() { | |||
| 189 | } else { | 279 | } else { |
| 190 | c.coverage.ObservedBoots = 1 | 280 | c.coverage.ObservedBoots = 1 |
| 191 | } | 281 | } |
| 282 | + c.absorbLossLocked() | ||
| 192 | c.mu.Unlock() | 283 | c.mu.Unlock() |
| 193 | if s != nil { | 284 | if s != nil { |
| 194 | defer s.close() | 285 | defer s.close() |
| @@ -280,6 +371,7 @@ func (c *Collector) run() { | |||
| 280 | c.mu.Unlock() | 371 | c.mu.Unlock() |
| 281 | } | 372 | } |
| 282 | c.mu.Lock() | 373 | c.mu.Lock() |
| 374 | + c.absorbLossLocked() | ||
| 283 | s.state.Dropped = c.coverage.Dropped | 375 | s.state.Dropped = c.coverage.Dropped |
| 284 | s.state.LossEpoch = c.coverage.LossEpoch | 376 | s.state.LossEpoch = c.coverage.LossEpoch |
| 285 | s.state.Partial = c.coverage.State != "ready" | 377 | s.state.Partial = c.coverage.State != "ready" |
| @@ -308,8 +400,9 @@ func (c *Collector) write(s *storage, p pending) { | |||
| 308 | sequence := c.sequence | 400 | sequence := c.sequence |
| 309 | c.mu.Unlock() | 401 | c.mu.Unlock() |
| 310 | e := Event{Schema: 1, EventID: randomID(), OccurredAt: p.at, BootID: c.boot, Sequence: sequence, Stream: t.stream, Severity: t.severity, Component: t.component, Code: p.code, Message: t.message, | 402 | e := Event{Schema: 1, EventID: randomID(), OccurredAt: p.at, BootID: c.boot, Sequence: sequence, Stream: t.stream, Severity: t.severity, Component: t.component, Code: p.code, Message: t.message, |
| 311 | - Legacy: p.legacy, ObservedBytes: p.observedBytes, | 403 | + ExecutionDetails: p.refs.ExecutionDetails, |
| 312 | - JobRef: p.refs.Job.value, RegistrationRef: p.refs.Registration.value, CacheRef: p.refs.Cache.value, RepoRef: p.refs.Repo.value, CorrelationRef: p.refs.Correlation.value} | 404 | + Legacy: p.legacy, ObservedBytes: p.observedBytes, |
| 405 | + JobRef: p.refs.Job.value, RegistrationRef: p.refs.Registration.value, CacheRef: p.refs.Cache.value, RepoRef: p.refs.Repo.value, CorrelationRef: p.refs.Correlation.value, StageRef: p.refs.Stage.value, SourceRef: p.refs.Source.value, PreviousRegistrationRef: p.refs.PreviousRegistration.value} | ||
| 313 | if p.legacy { | 406 | if p.legacy { |
| 314 | e.Stream = p.legacyStream | 407 | e.Stream = p.legacyStream |
| 315 | } | 408 | } |
| @@ -323,6 +416,7 @@ func (c *Collector) write(s *storage, p pending) { | |||
| 323 | var evicted uint64 | 416 | var evicted uint64 |
| 324 | if err == nil && s != nil { | 417 | if err == nil && s != nil { |
| 325 | c.mu.Lock() | 418 | c.mu.Lock() |
| 419 | + c.absorbLossLocked() | ||
| 326 | s.state.Dropped = c.coverage.Dropped | 420 | s.state.Dropped = c.coverage.Dropped |
| 327 | s.state.LossEpoch = c.coverage.LossEpoch | 421 | s.state.LossEpoch = c.coverage.LossEpoch |
| 328 | s.state.Partial = c.coverage.State != "ready" | 422 | s.state.Partial = c.coverage.State != "ready" |
| @@ -37,6 +37,13 @@ func ready(t *testing.T, c *Collector) { | |||
| 37 | t.Helper() | 37 | t.Helper() |
| 38 | await(t, func() bool { return c.Coverage().State != "initializing" }) | 38 | await(t, func() bool { return c.Coverage().State != "initializing" }) |
| 39 | } | 39 | } |
| 40 | + | ||
| 41 | +// Fixtures that inspect a specific retained event may retry bounded admission. | ||
| 42 | +// Production instrumentation is deliberately best effort and never does so. | ||
| 43 | +func admitFixture(t *testing.T, c *Collector, code Code, refs Context) { | ||
| 44 | + t.Helper() | ||
| 45 | + await(t, func() bool { return c.Emit(code, refs) }) | ||
| 46 | +} | ||
| 40 | func flush(t *testing.T, c *Collector, clean bool) { | 47 | func flush(t *testing.T, c *Collector, clean bool) { |
| 41 | t.Helper() | 48 | t.Helper() |
| 42 | ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) | 49 | ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) |
| @@ -86,9 +93,7 @@ func TestCatalogRejectsRawTextAndUncheckedRefs(t *testing.T) { | |||
| 86 | if c.Emit(Code(sentinel), Context{}) || c.Emit(RecoveryFailed, Context{Repo: Ref{sentinel}}) { | 93 | if c.Emit(Code(sentinel), Context{}) || c.Emit(RecoveryFailed, Context{Repo: Ref{sentinel}}) { |
| 87 | t.Fatal("unchecked content accepted") | 94 | t.Fatal("unchecked content accepted") |
| 88 | } | 95 | } |
| 89 | - if !c.Emit(RecoveryFailed, Context{Repo: KnownRef("repo", sentinel), Job: KnownRef("job", sentinel)}) { | 96 | + admitFixture(t, c, RecoveryFailed, Context{Repo: KnownRef("repo", sentinel), Job: KnownRef("job", sentinel)}) |
| 90 | - t.Fatal("resolved opaque references rejected") | ||
| 91 | - } | ||
| 92 | flush(t, c, true) | 97 | flush(t, c, true) |
| 93 | p, err := c.Query(Filter{}, "", 200) | 98 | p, err := c.Query(Filter{}, "", 200) |
| 94 | if err != nil { | 99 | if err != nil { |
| @@ -223,9 +228,7 @@ func TestENOSPCNeverStopsAdmissionAndSurvivesRestart(t *testing.T) { | |||
| 223 | }) | 228 | }) |
| 224 | ready(t, c) | 229 | ready(t, c) |
| 225 | for i := 0; i < 20; i++ { | 230 | for i := 0; i < 20; i++ { |
| 226 | - if !c.Emit(RecoveryFinished, Context{}) { | 231 | + admitFixture(t, c, RecoveryFinished, Context{}) |
| 227 | - t.Fatal("disk failure blocked bounded admission") | ||
| 228 | - } | ||
| 229 | } | 232 | } |
| 230 | flush(t, c, true) | 233 | flush(t, c, true) |
| 231 | if c.Coverage().State != "partial" { | 234 | if c.Coverage().State != "partial" { |
| @@ -0,0 +1,231 @@ | |||
| 1 | +//go:build darwin || linux | ||
| 2 | + | ||
| 3 | +package observability | ||
| 4 | + | ||
| 5 | +import ( | ||
| 6 | + "context" | ||
| 7 | + "errors" | ||
| 8 | + "sync" | ||
| 9 | + "sync/atomic" | ||
| 10 | + "testing" | ||
| 11 | + "time" | ||
| 12 | +) | ||
| 13 | + | ||
| 14 | +func TestEmitterDoesNotWaitForReaderAndLossSurvivesRestart(t *testing.T) { | ||
| 15 | + path := testDirectory(t) | ||
| 16 | + c := New(Config{Directory: path, ManagedOutput: true}) | ||
| 17 | + defer flush(t, c, true) | ||
| 18 | + ready(t, c) | ||
| 19 | + await(t, func() bool { | ||
| 20 | + c.mu.Lock() | ||
| 21 | + defer c.mu.Unlock() | ||
| 22 | + return len(c.events) > 0 | ||
| 23 | + }) | ||
| 24 | + before, err := c.Query(Filter{}, "", 200) | ||
| 25 | + if err != nil { | ||
| 26 | + t.Fatal("baseline cursor unavailable") | ||
| 27 | + } | ||
| 28 | + c.mu.Lock() | ||
| 29 | + // Rejected untrusted input is not a validated execution event and must | ||
| 30 | + // neither enter storage nor manufacture an execution-loss boundary. | ||
| 31 | + if c.Emit(Code("synthetic-untrusted-code"), Context{}) || c.Emit(RecoveryFailed, Context{Repo: Ref{"synthetic-untrusted-ref"}}) { | ||
| 32 | + c.mu.Unlock() | ||
| 33 | + t.Fatal("untrusted evidence admitted") | ||
| 34 | + } | ||
| 35 | + if c.pendingLoss.Load() != 0 { | ||
| 36 | + c.mu.Unlock() | ||
| 37 | + t.Fatal("untrusted input changed execution observation") | ||
| 38 | + } | ||
| 39 | + done := make(chan struct{}) | ||
| 40 | + var accepted atomic.Bool | ||
| 41 | + go func() { | ||
| 42 | + defer close(done) | ||
| 43 | + for i := 0; i < 100; i++ { | ||
| 44 | + if c.Emit(RecoveryFinished, Context{}) { | ||
| 45 | + accepted.Store(true) | ||
| 46 | + } | ||
| 47 | + } | ||
| 48 | + }() | ||
| 49 | + // The reader mutex remains held until every emission finishes. This | ||
| 50 | + // barrier, rather than a timing comparison, proves execution isolation. | ||
| 51 | + select { | ||
| 52 | + case <-done: | ||
| 53 | + c.mu.Unlock() | ||
| 54 | + case <-time.After(time.Second): | ||
| 55 | + c.mu.Unlock() | ||
| 56 | + t.Fatal("event admission waited for an observation reader") | ||
| 57 | + } | ||
| 58 | + if accepted.Load() { | ||
| 59 | + t.Fatal("contended admission bypassed queue synchronization") | ||
| 60 | + } | ||
| 61 | + coverage := c.Coverage() | ||
| 62 | + if coverage.State != "partial" || coverage.Dropped != 100 || coverage.LossEpoch != before.Coverage.LossEpoch+100 { | ||
| 63 | + t.Fatal("bounded contention loss was not accounted") | ||
| 64 | + } | ||
| 65 | + _, err = c.Query(Filter{}, before.Cursor, 200) | ||
| 66 | + var queryErr QueryError | ||
| 67 | + if !errors.As(err, &queryErr) || queryErr.Code != "snapshot_required" || queryErr.Reason != "generation_or_loss_changed" { | ||
| 68 | + t.Fatal("pre-loss cursor did not expose the missing evidence") | ||
| 69 | + } | ||
| 70 | + flush(t, c, true) | ||
| 71 | + restarted := New(Config{Directory: path, ManagedOutput: true}) | ||
| 72 | + defer flush(t, restarted, true) | ||
| 73 | + ready(t, restarted) | ||
| 74 | + flush(t, restarted, true) | ||
| 75 | + got := restarted.Coverage() | ||
| 76 | + if got.State != "partial" || got.Dropped != coverage.Dropped || got.LossEpoch != coverage.LossEpoch { | ||
| 77 | + t.Fatal("restart erased or recounted known contention loss") | ||
| 78 | + } | ||
| 79 | + inventory(t, path) | ||
| 80 | +} | ||
| 81 | + | ||
| 82 | +func TestConcurrentEmissionReadersAndCheckpointAccountEveryAttempt(t *testing.T) { | ||
| 83 | + c := New(Config{Directory: testDirectory(t), ManagedOutput: true}) | ||
| 84 | + defer flush(t, c, true) | ||
| 85 | + ready(t, c) | ||
| 86 | + var workers sync.WaitGroup | ||
| 87 | + var accepted atomic.Uint64 | ||
| 88 | + for i := 0; i < 4; i++ { | ||
| 89 | + workers.Add(1) | ||
| 90 | + go func() { | ||
| 91 | + defer workers.Done() | ||
| 92 | + for j := 0; j < 100; j++ { | ||
| 93 | + if c.Emit(RecoveryFinished, Context{}) { | ||
| 94 | + accepted.Add(1) | ||
| 95 | + } | ||
| 96 | + } | ||
| 97 | + }() | ||
| 98 | + workers.Add(1) | ||
| 99 | + go func() { | ||
| 100 | + defer workers.Done() | ||
| 101 | + for j := 0; j < 100; j++ { | ||
| 102 | + _ = c.Coverage() | ||
| 103 | + _, _ = c.Query(Filter{}, "", 1) | ||
| 104 | + } | ||
| 105 | + }() | ||
| 106 | + } | ||
| 107 | + workers.Wait() | ||
| 108 | + flush(t, c, true) | ||
| 109 | + coverage := c.Coverage() | ||
| 110 | + if accepted.Load()+coverage.Dropped != 400 { | ||
| 111 | + t.Fatal("contention lost or counted an attempt twice") | ||
| 112 | + } | ||
| 113 | + var count uint64 | ||
| 114 | + cursor := "" | ||
| 115 | + for { | ||
| 116 | + page, err := c.Query(Filter{Code: RecoveryFinished}, cursor, 200) | ||
| 117 | + if err != nil { | ||
| 118 | + t.Fatal("retained events unavailable after checkpoint") | ||
| 119 | + } | ||
| 120 | + count += uint64(len(page.Events)) | ||
| 121 | + if !page.HasMore { | ||
| 122 | + break | ||
| 123 | + } | ||
| 124 | + if page.Cursor == cursor { | ||
| 125 | + t.Fatal("bounded scan stopped advancing") | ||
| 126 | + } | ||
| 127 | + cursor = page.Cursor | ||
| 128 | + } | ||
| 129 | + if count != accepted.Load() { | ||
| 130 | + t.Fatal("admitted events were lost while readers contended") | ||
| 131 | + } | ||
| 132 | +} | ||
| 133 | + | ||
| 134 | +func TestClosedCollectorRejectsContentionWithoutChangingLossBoundary(t *testing.T) { | ||
| 135 | + path := testDirectory(t) | ||
| 136 | + c := New(Config{Directory: path, ManagedOutput: true}) | ||
| 137 | + defer flush(t, c, true) | ||
| 138 | + ready(t, c) | ||
| 139 | + flush(t, c, true) | ||
| 140 | + baseline, err := c.Query(Filter{}, "", 200) | ||
| 141 | + if err != nil { | ||
| 142 | + t.Fatal("closed baseline unavailable") | ||
| 143 | + } | ||
| 144 | + c.mu.Lock() | ||
| 145 | + for i := 0; i < 100; i++ { | ||
| 146 | + if c.Emit(RecoveryFinished, Context{}) { | ||
| 147 | + c.mu.Unlock() | ||
| 148 | + t.Fatal("closed collector admitted execution evidence") | ||
| 149 | + } | ||
| 150 | + } | ||
| 151 | + c.mu.Unlock() | ||
| 152 | + // Model an already validated failed-TryLock producer preempted just | ||
| 153 | + // before its Add: a late Add after the seal is not published as loss. | ||
| 154 | + c.pendingLoss.Add(1) | ||
| 155 | + if c.Coverage() != baseline.Coverage { | ||
| 156 | + t.Fatal("closed rejection changed published loss coverage") | ||
| 157 | + } | ||
| 158 | + if _, err := c.Query(Filter{}, baseline.Cursor, 200); err != nil { | ||
| 159 | + t.Fatal("closed rejection invalidated a clean cursor") | ||
| 160 | + } | ||
| 161 | + restarted := New(Config{Directory: path, ManagedOutput: true}) | ||
| 162 | + defer flush(t, restarted, true) | ||
| 163 | + ready(t, restarted) | ||
| 164 | + flush(t, restarted, true) | ||
| 165 | + if restarted.Coverage().Dropped != baseline.Coverage.Dropped || restarted.Coverage().LossEpoch != baseline.Coverage.LossEpoch { | ||
| 166 | + t.Fatal("restart changed the sealed loss boundary") | ||
| 167 | + } | ||
| 168 | +} | ||
| 169 | + | ||
| 170 | +func TestCloseSealsLossBeforeShutdownPersistence(t *testing.T) { | ||
| 171 | + path := testDirectory(t) | ||
| 172 | + var pause atomic.Bool | ||
| 173 | + entered, release := make(chan struct{}), make(chan struct{}) | ||
| 174 | + var enteredOnce, releaseOnce sync.Once | ||
| 175 | + c := newCollector(Config{Directory: path, ManagedOutput: true}, func(path string) (*storage, []Event, bool, error) { | ||
| 176 | + s, events, unclean, err := openStorage(path) | ||
| 177 | + if err == nil { | ||
| 178 | + s.appendFault = func() error { | ||
| 179 | + if pause.Load() { | ||
| 180 | + enteredOnce.Do(func() { close(entered) }) | ||
| 181 | + <-release | ||
| 182 | + } | ||
| 183 | + return nil | ||
| 184 | + } | ||
| 185 | + } | ||
| 186 | + return s, events, unclean, err | ||
| 187 | + }) | ||
| 188 | + defer flush(t, c, true) | ||
| 189 | + defer releaseOnce.Do(func() { close(release) }) | ||
| 190 | + ready(t, c) | ||
| 191 | + await(t, func() bool { | ||
| 192 | + c.mu.Lock() | ||
| 193 | + defer c.mu.Unlock() | ||
| 194 | + return len(c.events) > 0 | ||
| 195 | + }) | ||
| 196 | + // A validated loss before sealing must be preserved, unlike late Add. | ||
| 197 | + prior := c.Coverage() | ||
| 198 | + c.pendingLoss.Add(7) | ||
| 199 | + pause.Store(true) | ||
| 200 | + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) | ||
| 201 | + defer cancel() | ||
| 202 | + done := make(chan bool, 1) | ||
| 203 | + go func() { done <- c.Close(ctx, true) }() | ||
| 204 | + select { | ||
| 205 | + case <-entered: | ||
| 206 | + case <-ctx.Done(): | ||
| 207 | + t.Fatal("shutdown persistence barrier unavailable") | ||
| 208 | + } | ||
| 209 | + baseline := c.Coverage() | ||
| 210 | + if baseline.Dropped != prior.Dropped+7 || baseline.LossEpoch != prior.LossEpoch+7 { | ||
| 211 | + t.Fatal("pre-seal loss was not folded exactly once") | ||
| 212 | + } | ||
| 213 | + c.mu.Lock() | ||
| 214 | + accepted := c.Emit(RecoveryFinished, Context{}) | ||
| 215 | + c.mu.Unlock() | ||
| 216 | + c.pendingLoss.Add(3) | ||
| 217 | + if accepted || c.Coverage() != baseline { | ||
| 218 | + t.Fatal("shutdown rejection changed the sealed loss boundary") | ||
| 219 | + } | ||
| 220 | + releaseOnce.Do(func() { close(release) }) | ||
| 221 | + if !<-done { | ||
| 222 | + t.Fatal("shutdown did not finish after releasing persistence") | ||
| 223 | + } | ||
| 224 | + restarted := New(Config{Directory: path, ManagedOutput: true}) | ||
| 225 | + defer flush(t, restarted, true) | ||
| 226 | + ready(t, restarted) | ||
| 227 | + flush(t, restarted, true) | ||
| 228 | + if restarted.Coverage().Dropped != baseline.Dropped || restarted.Coverage().LossEpoch != baseline.LossEpoch { | ||
| 229 | + t.Fatal("final checkpoint lost or recounted sealed losses") | ||
| 230 | + } | ||
| 231 | +} | ||
| @@ -0,0 +1,88 @@ | |||
| 1 | +package observability | ||
| 2 | + | ||
| 3 | +import "context" | ||
| 4 | + | ||
| 5 | +type metricContextKey struct{} | ||
| 6 | + | ||
| 7 | +type observationContextKey struct{} | ||
| 8 | +type observationBinding struct { | ||
| 9 | + collector *Collector | ||
| 10 | + refs Context | ||
| 11 | +} | ||
| 12 | + | ||
| 13 | +// WithObservation copies only already resolved opaque refs into a private | ||
| 14 | +// process-local carrier. It accepts a concrete collector, never a callback. | ||
| 15 | +// Per-event execution details are supplied separately at the actual boundary. | ||
| 16 | +func WithObservation(ctx context.Context, collector *Collector, refs Context) context.Context { | ||
| 17 | + if collector == nil { | ||
| 18 | + return ctx | ||
| 19 | + } | ||
| 20 | + refs.ExecutionDetails = ExecutionDetails{} | ||
| 21 | + refs.Stage = Ref{} // stage identity belongs to one confirmed event, not a worker | ||
| 22 | + refs.Source = Ref{} // source transition identity also belongs to one event | ||
| 23 | + refs.PreviousRegistration = Ref{} // a resolution predecessor is event-owned | ||
| 24 | + return context.WithValue(ctx, observationContextKey{}, observationBinding{collector, refs}) | ||
| 25 | +} | ||
| 26 | + | ||
| 27 | +// EmitFromContext inherits correlation but cannot change execution, retry, | ||
| 28 | +// deadlines or cancellation. Rejected observations are not retried. | ||
| 29 | +func EmitFromContext(ctx context.Context, code Code, details ExecutionDetails) bool { | ||
| 30 | + binding, ok := ctx.Value(observationContextKey{}).(observationBinding) | ||
| 31 | + if !ok { | ||
| 32 | + return false | ||
| 33 | + } | ||
| 34 | + refs := binding.refs | ||
| 35 | + refs.ExecutionDetails = details | ||
| 36 | + return binding.collector.Emit(code, refs) | ||
| 37 | +} | ||
| 38 | + | ||
| 39 | +// HasObservation checks only the private process-local carrier, never storage. | ||
| 40 | +func HasObservation(ctx context.Context) bool { | ||
| 41 | + _, ok := ctx.Value(observationContextKey{}).(observationBinding) | ||
| 42 | + return ok | ||
| 43 | +} | ||
| 44 | + | ||
| 45 | +// OmitRetryFromContext accounts for an actual scheduler admission that cannot | ||
| 46 | +// fit the closed retry catalog. Only an already qualified worker scope may | ||
| 47 | +// affect coverage; no ordinal or unknown collection text is retained. This | ||
| 48 | +// neither admits a fabricated event nor changes the executing retry. | ||
| 49 | +func OmitRetryFromContext(ctx context.Context) { | ||
| 50 | + binding, ok := ctx.Value(observationContextKey{}).(observationBinding) | ||
| 51 | + if !ok { | ||
| 52 | + return | ||
| 53 | + } | ||
| 54 | + refs := binding.refs | ||
| 55 | + // Use fixed catalog details only to validate the inherited scope, never to | ||
| 56 | + // emit or clamp the actual retry. Malformed references remain unobserved. | ||
| 57 | + e := Event{Code: RetryAdmitted, JobRef: refs.Job.value, CacheRef: refs.Cache.value, | ||
| 58 | + RegistrationRef: refs.Registration.value, RepoRef: refs.Repo.value, CorrelationRef: refs.Correlation.value, | ||
| 59 | + StageRef: refs.Stage.value, SourceRef: refs.Source.value, PreviousRegistrationRef: refs.PreviousRegistration.value, | ||
| 60 | + ExecutionDetails: ExecutionDetails{Phase: "retry", Collection: "wiki", Outcome: "admitted", Attempt: 2}} | ||
| 61 | + if !e.validExecution() { | ||
| 62 | + return | ||
| 63 | + } | ||
| 64 | + for _, ref := range [...]struct{ value, kind string }{ | ||
| 65 | + {e.JobRef, "job"}, {e.CacheRef, "cache"}, {e.RegistrationRef, "registration"}, | ||
| 66 | + {e.RepoRef, "repo"}, {e.CorrelationRef, "correlation"}, | ||
| 67 | + } { | ||
| 68 | + if !validRef(ref.value, ref.kind) { | ||
| 69 | + return | ||
| 70 | + } | ||
| 71 | + } | ||
| 72 | + binding.collector.UnconfirmedExecution() | ||
| 73 | +} | ||
| 74 | + | ||
| 75 | +// WithMetrics carries a trusted concrete sink through daemon-owned execution. | ||
| 76 | +// It does not install an arbitrary callback or alter cancellation/deadlines. | ||
| 77 | +// Foreground callers without this private process-local value are unobserved. | ||
| 78 | +func WithMetrics(ctx context.Context, metrics *Metrics) context.Context { | ||
| 79 | + if metrics == nil { | ||
| 80 | + return ctx | ||
| 81 | + } | ||
| 82 | + return context.WithValue(ctx, metricContextKey{}, metrics) | ||
| 83 | +} | ||
| 84 | + | ||
| 85 | +func MetricsFromContext(ctx context.Context) *Metrics { | ||
| 86 | + metrics, _ := ctx.Value(metricContextKey{}).(*Metrics) | ||
| 87 | + return metrics | ||
| 88 | +} | ||
| @@ -0,0 +1,33 @@ | |||
| 1 | +package observability | ||
| 2 | + | ||
| 3 | +import ( | ||
| 4 | + "context" | ||
| 5 | + "strings" | ||
| 6 | + "testing" | ||
| 7 | + "time" | ||
| 8 | +) | ||
| 9 | + | ||
| 10 | +func TestMetricContextPreservesExecutionCancellationAndDeadline(t *testing.T) { | ||
| 11 | + deadline := time.Now().Add(time.Minute) | ||
| 12 | + parent, cancel := context.WithDeadline(context.Background(), deadline) | ||
| 13 | + defer cancel() | ||
| 14 | + metrics := NewMetrics(strings.Repeat("c", 32), time.Now().UTC()) | ||
| 15 | + ctx := WithMetrics(parent, metrics) | ||
| 16 | + if MetricsFromContext(ctx) != metrics || WithMetrics(parent, nil) != parent { | ||
| 17 | + t.Fatal("concrete observation context changed identity") | ||
| 18 | + } | ||
| 19 | + if got, ok := ctx.Deadline(); !ok || !got.Equal(deadline) { | ||
| 20 | + t.Fatal("observation changed deadline") | ||
| 21 | + } | ||
| 22 | + child, stop := context.WithCancel(ctx) | ||
| 23 | + defer stop() | ||
| 24 | + cancel() | ||
| 25 | + select { | ||
| 26 | + case <-child.Done(): | ||
| 27 | + case <-time.After(time.Second): | ||
| 28 | + t.Fatal("observation disconnected execution cancellation") | ||
| 29 | + } | ||
| 30 | + if MetricsFromContext(child) != metrics || MetricsFromContext(context.Background()) != nil { | ||
| 31 | + t.Fatal("trusted sink inheritance leaked into unrelated execution") | ||
| 32 | + } | ||
| 33 | +} | ||
| @@ -0,0 +1,206 @@ | |||
| 1 | +package observability | ||
| 2 | + | ||
| 3 | +// ExecutionDetails is a closed catalog contract, not free-form metadata. Every | ||
| 4 | +// field is validated for both admission and replay. Owners may provide a finite | ||
| 5 | +// attempt ordinal only when it is known from the actual execution policy loop. | ||
| 6 | +// Zero means unspecified, never a fabricated first attempt. | ||
| 7 | +type ExecutionDetails struct { | ||
| 8 | + Phase string `json:"phase,omitempty"` | ||
| 9 | + Collection string `json:"collection,omitempty"` | ||
| 10 | + WorkKind string `json:"work_kind,omitempty"` | ||
| 11 | + Outcome string `json:"outcome,omitempty"` | ||
| 12 | + FailureClass string `json:"failure_class,omitempty"` | ||
| 13 | + Attempt uint32 `json:"attempt,omitempty"` | ||
| 14 | + AdminRoute string `json:"admin_route,omitempty"` | ||
| 15 | + MaintenanceScope string `json:"maintenance_scope,omitempty"` | ||
| 16 | + PreviousState string `json:"previous_state,omitempty"` | ||
| 17 | + PreviousFailureClass string `json:"previous_failure_class,omitempty"` | ||
| 18 | +} | ||
| 19 | + | ||
| 20 | +const MaxExecutionAttempt = 1024 | ||
| 21 | + | ||
| 22 | +func executionCode(code Code) bool { | ||
| 23 | + switch code { | ||
| 24 | + case JobAdmitted, JobTerminal, JobRecovered, ProviderAttempt, SyncCommitted, RetryAdmitted, WriterContended, SyncStageChanged, AdminRequestCompleted, MaintenanceStateChanged: | ||
| 25 | + return true | ||
| 26 | + default: | ||
| 27 | + return false | ||
| 28 | + } | ||
| 29 | +} | ||
| 30 | + | ||
| 31 | +func executionCollection(value string) bool { | ||
| 32 | + switch value { | ||
| 33 | + case "issues", "issue_comments", "wiki", "pulls", "pr_comments": | ||
| 34 | + return true | ||
| 35 | + default: | ||
| 36 | + return false | ||
| 37 | + } | ||
| 38 | +} | ||
| 39 | + | ||
| 40 | +func executionFailure(value string) bool { | ||
| 41 | + switch value { | ||
| 42 | + case "cancelled", "timeout", "rate_limited", "forbidden", "invalid", "operation_failed", "provider_failed", "interrupted": | ||
| 43 | + return true | ||
| 44 | + default: | ||
| 45 | + return false | ||
| 46 | + } | ||
| 47 | +} | ||
| 48 | + | ||
| 49 | +func (e Event) validExecution() bool { | ||
| 50 | + d := e.ExecutionDetails | ||
| 51 | + if e.PreviousRegistrationRef != "" && (e.Code != MaintenanceStateChanged || d.MaintenanceScope != "identity_resolution") { | ||
| 52 | + return false | ||
| 53 | + } | ||
| 54 | + if e.SourceRef != "" && (e.Code != MaintenanceStateChanged || d.MaintenanceScope != "repository_docs") { | ||
| 55 | + return false | ||
| 56 | + } | ||
| 57 | + if e.Code != MaintenanceStateChanged && (d.MaintenanceScope != "" || d.PreviousState != "" || d.PreviousFailureClass != "") { | ||
| 58 | + return false | ||
| 59 | + } | ||
| 60 | + if e.Code != AdminRequestCompleted && d.AdminRoute != "" { | ||
| 61 | + return false | ||
| 62 | + } | ||
| 63 | + if e.Code != SyncStageChanged && e.StageRef != "" { | ||
| 64 | + return false | ||
| 65 | + } | ||
| 66 | + if !executionCode(e.Code) { | ||
| 67 | + // Old schema-1 lifecycle events remain valid with absent fields. Adding | ||
| 68 | + // arbitrary execution dimensions to one must not bypass the catalog. | ||
| 69 | + return d == (ExecutionDetails{}) | ||
| 70 | + } | ||
| 71 | + if e.Legacy || e.CorrelationRef == "" || d.Attempt > MaxExecutionAttempt { | ||
| 72 | + return false | ||
| 73 | + } | ||
| 74 | + if e.Code != WriterContended && d.WorkKind != "" { | ||
| 75 | + return false | ||
| 76 | + } | ||
| 77 | + switch e.Code { | ||
| 78 | + case MaintenanceStateChanged: | ||
| 79 | + if e.JobRef != "" || e.RegistrationRef == "" || e.CacheRef == "" || e.RepoRef == "" || d.Phase != "maintenance" || d.Collection != "" || d.Attempt != 0 { | ||
| 80 | + return false | ||
| 81 | + } | ||
| 82 | + state := maintenanceState | ||
| 83 | + switch d.MaintenanceScope { | ||
| 84 | + case "registration": | ||
| 85 | + case "repository_docs": | ||
| 86 | + if e.SourceRef == "" { | ||
| 87 | + return false | ||
| 88 | + } | ||
| 89 | + state = maintenanceSourceState | ||
| 90 | + case "identity_resolution": | ||
| 91 | + return e.PreviousRegistrationRef != "" && maintenanceIdentityPredecessor(d.PreviousState) && maintenanceIdentityResult(d.Outcome) && maintenanceFailure(d.FailureClass) && maintenanceFailure(d.PreviousFailureClass) && (d.Outcome != d.PreviousState || d.FailureClass != d.PreviousFailureClass) | ||
| 92 | + default: | ||
| 93 | + return false | ||
| 94 | + } | ||
| 95 | + return state(d.Outcome) && (state(d.PreviousState) || d.PreviousState == "absent" || d.PreviousState == "unknown") && maintenanceFailure(d.FailureClass) && maintenanceFailure(d.PreviousFailureClass) && (d.Outcome != d.PreviousState || d.FailureClass != d.PreviousFailureClass) && (d.PreviousState != "absent" || d.PreviousFailureClass == "") | ||
| 96 | + case AdminRequestCompleted: | ||
| 97 | + if e.JobRef != "" || e.CacheRef != "" || e.RegistrationRef != "" || e.RepoRef != "" || d.Phase != "admin" || d.Collection != "" || d.Attempt != 0 || d.FailureClass != "" { | ||
| 98 | + return false | ||
| 99 | + } | ||
| 100 | + switch d.AdminRoute { | ||
| 101 | + case "session", "read", "control", "search", "events", "assets", "unknown": | ||
| 102 | + default: | ||
| 103 | + return false | ||
| 104 | + } | ||
| 105 | + return d.Outcome == "succeeded" || d.Outcome == "failed" || d.Outcome == "rejected" || d.Outcome == "cancelled" | ||
| 106 | + case JobRecovered: | ||
| 107 | + if e.JobRef == "" || d.Phase != "recovery" || d.Collection != "" || d.Attempt != 0 { | ||
| 108 | + return false | ||
| 109 | + } | ||
| 110 | + switch d.Outcome { | ||
| 111 | + case "resumed", "reconciled": | ||
| 112 | + return d.FailureClass == "" | ||
| 113 | + case "rejected": | ||
| 114 | + return executionFailure(d.FailureClass) | ||
| 115 | + } | ||
| 116 | + return false | ||
| 117 | + case SyncStageChanged: | ||
| 118 | + if e.JobRef == "" || e.StageRef == "" || e.CacheRef == "" || e.RegistrationRef == "" || e.RepoRef == "" || d.Phase != "staging" || !executionCollection(d.Collection) { | ||
| 119 | + return false | ||
| 120 | + } | ||
| 121 | + switch d.Outcome { | ||
| 122 | + case "staged", "committing", "committed": | ||
| 123 | + return d.FailureClass == "" | ||
| 124 | + case "waiting_commit": | ||
| 125 | + return d.FailureClass == "writer_busy" | ||
| 126 | + case "superseded": | ||
| 127 | + return d.FailureClass == "superseded" | ||
| 128 | + case "rejected": | ||
| 129 | + return executionFailure(d.FailureClass) || d.FailureClass == "writer_busy" | ||
| 130 | + } | ||
| 131 | + return false | ||
| 132 | + case WriterContended: | ||
| 133 | + switch d.WorkKind { | ||
| 134 | + case "sync", "rag", "repository_docs", "other": | ||
| 135 | + return d.Phase == "writer" && d.Outcome == "denied" && d.FailureClass == "writer_busy" && d.Collection == "" && d.Attempt == 0 | ||
| 136 | + } | ||
| 137 | + return false | ||
| 138 | + case JobAdmitted: | ||
| 139 | + return e.JobRef != "" && d.Phase == "admission" && d.Outcome == "queued" && d.Collection == "" && d.FailureClass == "" && d.Attempt == 0 | ||
| 140 | + case JobTerminal: | ||
| 141 | + if e.JobRef == "" || d.Phase != "completion" || d.Collection != "" || d.Attempt != 0 { | ||
| 142 | + return false | ||
| 143 | + } | ||
| 144 | + switch d.Outcome { | ||
| 145 | + case "succeeded": | ||
| 146 | + return d.FailureClass == "" | ||
| 147 | + case "cancelled", "interrupted", "superseded": | ||
| 148 | + return d.FailureClass == d.Outcome | ||
| 149 | + case "failed": | ||
| 150 | + return executionFailure(d.FailureClass) && d.FailureClass != "cancelled" && d.FailureClass != "interrupted" | ||
| 151 | + } | ||
| 152 | + case ProviderAttempt: | ||
| 153 | + if (d.Phase != "fetch" && d.Phase != "embedding") || (d.Collection != "" && (!executionCollection(d.Collection) || d.Phase != "fetch")) { | ||
| 154 | + return false | ||
| 155 | + } | ||
| 156 | + switch d.Outcome { | ||
| 157 | + case "succeeded": | ||
| 158 | + return d.FailureClass == "" | ||
| 159 | + case "cancelled", "timeout", "rate_limited", "forbidden", "invalid": | ||
| 160 | + return d.FailureClass == d.Outcome | ||
| 161 | + case "failed": | ||
| 162 | + return d.FailureClass == "provider_failed" | ||
| 163 | + } | ||
| 164 | + case SyncCommitted: | ||
| 165 | + return e.JobRef != "" && d.Phase == "commit" && d.Outcome == "succeeded" && executionCollection(d.Collection) && d.FailureClass == "" && d.Attempt == 0 | ||
| 166 | + case RetryAdmitted: | ||
| 167 | + return e.JobRef != "" && d.Phase == "retry" && d.Outcome == "admitted" && executionCollection(d.Collection) && d.FailureClass == "" && d.Attempt >= 2 | ||
| 168 | + } | ||
| 169 | + return false | ||
| 170 | +} | ||
| 171 | + | ||
| 172 | +func maintenanceState(value string) bool { | ||
| 173 | + switch value { | ||
| 174 | + case "enrolled", "disabled", "ready", "degraded", "backfilling", "indexing", "refreshing", "cache_schema_blocked": | ||
| 175 | + return true | ||
| 176 | + } | ||
| 177 | + return false | ||
| 178 | +} | ||
| 179 | + | ||
| 180 | +func maintenanceFailure(value string) bool { | ||
| 181 | + switch value { | ||
| 182 | + case "", "cache", "identity", "content", "frontier", "embedding", "retry", "sync_schedule", "rag_schedule", "repository_docs", "cache_schema_blocked", "operation_failed": | ||
| 183 | + return true | ||
| 184 | + } | ||
| 185 | + return false | ||
| 186 | +} | ||
| 187 | + | ||
| 188 | +func maintenanceSourceState(value string) bool { | ||
| 189 | + switch value { | ||
| 190 | + case "registered", "not_indexed", "indexing", "disabled", "ready", "degraded": | ||
| 191 | + return true | ||
| 192 | + } | ||
| 193 | + return false | ||
| 194 | +} | ||
| 195 | + | ||
| 196 | +func maintenanceIdentityPredecessor(value string) bool { | ||
| 197 | + switch value { | ||
| 198 | + case "identity_conflict", "cache_clone_conflict", "identity_unresolved": | ||
| 199 | + return true | ||
| 200 | + } | ||
| 201 | + return false | ||
| 202 | +} | ||
| 203 | + | ||
| 204 | +func maintenanceIdentityResult(value string) bool { | ||
| 205 | + return maintenanceState(value) || maintenanceIdentityPredecessor(value) || value == "config_snapshot_invalid" || value == "cache_inspection_timeout" | ||
| 206 | +} | ||