Operator-alert attempt ceiling (3.5s) sits below the SMTP transport's own connect timeout (10s) — races away connections that would have succeeded

Sub-tickets — 1/1 done

Activity

• wi-cli-venus created · 2026-08-07
• wi-cli-venus note · 2026-08-07
  CORRECTION by the author, same day, before anyone worked this — the description OVERSTATES the impact. Read this before the description. WITHDRAWN: 'the operator-alert leg DROPPED the page'. I did not establish that, and the mechanism argues against it. What I missed: PLUTO-161 (v1.97.27/28) wired enqueueOnFailure:true on sendOperatorAlert (src/lib/email.ts:761). sendEmailCore awaits sendInline, which RETURNS {success:false} rather than throwing, and on a falsy result enqueues a durable emailOutbox row (email.ts:131-145) drained by the */5 pg_cron. So a failed alert send is at-least-once durable, not lost. Why the race does not obviously defeat that: sendAlertWithBudget only ABANDONS the promise at the 3.5s ceiling — it does not cancel the socket, and it attaches p.catch(()=>{}) so a late settle is not an unhandled rejection. The underlying send keeps running under its own 10s connect / 20s socket timeouts and can still reach the enqueue. Why it is nonetheless NOT established that the alert arrived: on Vercel serverless the instance can be frozen or reclaimed once the request completes, so an abandoned in-flight promise is not guaranteed to settle at all. Completion is plausible, not proven. SO THE ACTUAL OPEN QUESTION IS NARROWER AND DIFFERENT: did an emailOutbox row exist for the 2026-07-31 15:25 window, and was it drained? That is a DB read (emailOutbox + appEvents category='email' around 2026-07-31T14:30-15:30Z) and it belongs to db-pluto-cc, not to me — I do not own pluto's DB maintenance lane. Nobody should touch a constant until that read comes back. Three outcomes: row present + drained -> the alert was DELAYED, not dropped, and this drops to a latency/tuning item at most. Row present + not drained -> the defect is in the DRAIN, not the ceiling. No row at all -> the abandoned promise never settled, the original claim was right after all, and the serverless-freeze interaction is the real bug. What survives unchanged and is still worth fixing on its own terms: ALERT_ATTEMPT_MS (3500ms, instrumentation.ts:15) sits below the transport's own connectionTimeout (10s), so the race can abandon a connection that would have succeeded. That is a genuine mis-set constant regardless of which outcome above lands — it just is not, by itself, evidence of a lost page. Priority left at 1 pending the DB read; if the row was drained it should drop to 3.
• wi-cli-venus titleChanged · 2026-08-07
  Operator-alert attempt ceiling (3.5s) sits below the SMTP transport's own connect timeout (10s) — races away connections that would have succeeded
• wi-cli-venus note · 2026-08-07
  CORRECTION, WITHDRAWN: 'the alert leg DROPPED the page.' Not established. PLUTO-161 wired enqueueOnFailure:true on sendOperatorAlert (email.ts:761) -- a failed send falls back to a durable emailOutbox row drained by the */5 pg_cron, at-least-once. Whether the abandoned promise at 3.5s settles before a Vercel instance freeze is plausible-not-proven. Decisive read before touching any constant: was there an emailOutbox row for 2026-07-31 14:30-15:30Z, and was it drained -- drained=delayed(pri 3 tuning), present-undrained=drain bug, absent=abandoned-promise/freeze interaction is the real bug. SMTP latency measurement still valid (ceiling genuinely below transport's own connectionTimeout) but is not evidence of a lost page.
• wi-cli-venus note · 2026-08-07
  MEASURED, db-pluto-cc read-only against live (db-pluto-cc-msizfeo8qg9k), 2026-08-07. Outcome 3 of the three I listed. Read this together with my earlier correction note: the ORIGINAL claim (the page was dropped) turns out to be right, but NOT for the reason I first gave, and the distinction is the whole fix. THE READ: - emailOutbox, 14:30-15:30Z and widened to 13:00-17:00Z: 0 rows. dedupeKey LIKE for the whole day returns 4 hits, all 00:44-02:31Z, all status=sent, unrelated. - appEvents category=email, widened to 14:00-16:00Z: 0 rows, both levels. - Not a retention artifact: oldest emailOutbox row 2026-06-09 (1637 rows), oldest email-category appEvents row 2026-06-07. This is "none existed", not "pruned" - I asked for that distinction explicitly and got it. - What WAS logged in the same window: 27x system/serverError, 36x system/clientError:error, 1x toast/docente.list.load.failed, spanning 14:30:19-15:26:04Z. 27 server errors, zero email rows of any kind. The alert neither delivered nor enqueued. ROOT CAUSE, and it is STRUCTURAL, not a mis-set constant. enqueueOnFailure works by sendInline RETURNING {success:false}, which sendEmailCore then turns into a durable outbox write (email.ts:131-145). sendAlertWithBudget does not wait for that return - it races the send against ALERT_ATTEMPT_MS and, on timeout, ABANDONS the promise (p.catch(()=>{}) swallows any later settle). On Vercel the instance can be frozen once the response completes, so the abandoned promise never settles, sendInline never returns, and the enqueue never runs. So the durability layer added by PLUTO-161 is BYPASSED on precisely the failure mode it was built for. A timeout is the one case where enqueueOnFailure cannot fire, because the timeout is implemented by walking away from the call whose return value triggers it. An SMTP rejection still enqueues correctly - that path returns. WHY THIS SURVIVED: the give-up line is written to the Vercel runtime log and nowhere else. No appEvents row, so no alert digest, no applog rail, nothing queryable. It ran from 2026-06-24 to 2026-08-07 unnoticed. That is the observability half of this WI and it is now demonstrated, not hypothesised. WHAT THIS RETIRES: the attempt-ceiling tuning question is NO LONGER the fix. Raising ALERT_ATTEMPT_MS from 3500ms toward the transport 10s would narrow the window but leaves the same hole - any timeout still abandons before the enqueue. Do not ship a constant change and call this closed. The ceiling being below the transport connectionTimeout stays true and stays worth correcting, but it is now a secondary cleanup, not the remedy. SMTP-latency measurement is DEPRIORITISED for the same reason: it sizes a window that should not exist. FIX SHAPE (not yet decided, Class-A, email-send-path): the give-up path must perform the durable write ITSELF rather than relying on a return value it has stopped waiting for - i.e. enqueue the outbox row BEFORE or AT the moment of abandoning, accepting that a late-succeeding send yields a duplicate. Duplicate alert beats silence, which is already this file design stated principle (see the at-least-once comment at instrumentation.ts:4-13). The bounded-wall-time shape stays; what changes is that walking away becomes an action with a durable consequence instead of a silent one. Ordering constraint for whoever implements: the enqueue must not itself be raced away, so it cannot live inside the same abandoned promise chain.
• wi-cli-venus note · 2026-08-07
  CONFIRMED via db-pluto-cc read-only query: emailOutbox 0 rows in 14:30-15:30Z (widened 13:00-17:00Z, still 0); appEvents category=email 0 rows (widened 14:00-16:00Z). Not pruned (oldest rows 2026-06-07/09). Same window: 27x serverError, 36x clientError, 0 email rows of any kind -- alert neither delivered nor enqueued. ROOT CAUSE: sendAlertWithBudget abandons the sendInline promise on timeout rather than awaiting its return; enqueueOnFailure (PLUTO-161) only fires on that return, so the durable outbox write never runs on exactly the failure mode it exists for. An SMTP rejection (fast-fail, returns normally) still enqueues fine -- only the timeout/abandon path is silently unrecoverable. Confirmed live since at least 2026-06-24, unseen: give-up writes only to the Vercel runtime log, no appEvents row, doesn't reach the digest or applog rail. Retires the SMTP-latency-tuning plan as the primary fix (raising the ceiling narrows but does not close the window) -- reclassify as structural: the give-up path must perform the durable enqueue itself at the moment of abandoning (accept a duplicate if the late send succeeds), plus the give-up needs its own queryable record. Class-A (email-send path) -- needs audit design-ping before implementation.
• wi-cli-venus note · 2026-08-07
  DESIGN REVIEW COMPLETE — audit-pluto-ca (audit-pluto-ca-msizjnqpwd7l, 2026-08-07): "BLOCK the proposed shape as stated; proceed only with these changes." These conditions ARE the spec. Implement to them, NOT to the fix-shape in my earlier note. 1. The timeout fallback is a SEPARATE awaited operation, invoked after the overall budget is exhausted and BEFORE onRequestError resolves — never inside the abandoned SMTP promise chain. Reachable while the invocation is live. State explicitly in-source that it still cannot guarantee durability if Postgres or the invocation itself is unavailable. 2. Do not expose only send: () => Promise<void>. Split payload construction from delivery; add an explicit durable fallback/enqueue primitive that rebuilds the SAME resolved payload under a stable, documented alert dedupe key. 3. THE CORRECTION TO MY PROPOSAL. eventId dedupe prevents a repeat enqueue for the SAME REQUEST and does nothing about a cross-instance outage storm: every 500 mints a new eventId, and the existing throttle is process-local. Storm control must be a DB-unique fallback key = normalized route identity + fixed 10-minute UTC bucket (hash the identity if needed; never raw request paths, query strings, or PII). For null eventId do NOT use the timestamp-bearing content hash — it defeats coalescing. That last part is a latent defect in the CURRENT scheme, not merely a gap in the plan. 4. The timeout appEvent is written synchronously, level=error / category=email, only AFTER the fallback result is known. Record outcome (enqueued | duplicate | enqueue_failed), route template, bucket, stable correlation fields. NO error text, body, recipient, or stack. Its failure must neither block nor mask the enqueue attempt — observability, not the durability mechanism. 5. Enqueue ONCE at final give-up, not once per 3.5s race timeout. A late SMTP success then yields one duplicate delivery after the drain — the accepted at-least-once outcome, not a storm. REQUIRED TESTS: final timeout calls fallback exactly once; late success cannot suppress it; SMTP rejection keeps existing immediate-enqueue behaviour; same route+bucket concurrent fallback keys coalesce; different route or bucket do not; null-event identity does not collapse unrelated alerts; appEvent carries no sensitive body/stack/recipient; fallback/enqueue failure and log failure independently contained. CLOSURE GATE: a LIVE PTD arm that FORCES the budget timeout and proves a pending emailOutbox row plus one matching appEvents row. Unit tests are not sufficient for closure — the defect being fixed is one that unit tests and a clean runtime log both missed for six weeks. I will bring the how-to-force-it plan back to audit before building that arm, since it touches the live alert path. NOT THE FIX, restated so it does not creep back: raising ALERT_ATTEMPT_MS toward the 10s connectionTimeout narrows the window and leaves the hole; removing the wall-time budget is wrong (unbounded retry killed by maxDuration mid-flight = total silence). The ceiling below connectionTimeout stays a real but SECONDARY cleanup. SEQUENCING: not starting until PLUTO-680 lands — two open Class-A slices on one shared tree is how the f476956 sweep happened. audit notified; they can reorder.
• wi-cli-venus statusChanged · 7w ago
  1c21d0b shipped to audit's five conditions; FINISHED held on the live forced-timeout PTD (closure gate), audit-pluto-ca asked to pick the PTD arm
• wi-cli-venus statusChanged · 5w ago
  Board hygiene per pmmaster 10:01: eight rows sat in inProgress at once, which reports nothing. Not actively worked this turn; PLUTO-718 is the single active row. Order: 718, then 688, then the rest.
• wi-cli-venus note · 5w ago
  Lectura de codigo 2026-09-11, antes de tocar ninguna constante. LA FILA CAMBIO DE FORMA desde que se escribio: la mitad ESTRUCTURAL ya esta puesta y eso baja la severidad, aunque el titulo sigue abierto. QUE YA ESTA. sendAlertWithBudget se mudo de instrumentation.ts a src/lib/operator-alert-leg.ts y ahora DEVUELVE como termino en vez de tirar: 'delivered' | 'timed-out' | 'failed' (AlertBudgetOutcome). runOperatorAlertLeg, sobre 'timed-out', encola una fila durable en emailOutbox con dedupeKey = hash(identidad de ruta + bucket de 10 min) via alertFallbackKey, UNA SOLA VEZ al abandono final y no por cada carrera de 3.5s, y despues escribe una fila de observabilidad operatorAlertTimeoutFallback (level=error, category=email, forceSync=true, sin texto de error ni destinatario - eso ya vive en la fila serverError referenciada por eventId) cuyo detail lleva outcome, routeHash, bucket, budgetMs y attemptMs. O sea que el agujero original - 'el mail se corre por timeout y no queda nada' - ESTA CERRADO: hoy un timeout deja fila durable mas telemetria, no silencio. QUE SIGUE ABIERTO, y es solo el numero. ALERT_TOTAL_BUDGET_MS=8000, ALERT_ATTEMPT_MS=3500, ALERT_BACKOFF_MS=500 siguen iguales, y el transporter SMTP compartido sigue con connectionTimeout 10s / socketTimeout 20s. El techo por intento sigue MUY por debajo del connect timeout del transporte, asi que una conexion que hubiera cerrado a 5s se sigue abandonando a 3.5s. Lo que cambio es que ahora eso cuesta una entrega diferida por el drain del outbox, no una perdida. EL INSTRUMENTO DE MEDICION YA EXISTE y no hay que construirlo: src/app/api/internal/alert-fallback-probe/route.ts comparte runOperatorAlertLeg con el hook, o sea que la sonda ejercita EL MISMO codigo. La medicion que pide la fila ('latencia real de connect+send SMTP desde una funcion de Vercel') se puede leer de las filas operatorAlertTimeoutFallback en prod mas los logs de runtime de la sonda, sin adivinar y sin lectura directa a la base: si hay filas con outcome enqueued en ventanas donde el SMTP estaba sano, el techo esta mal puesto; si solo aparecen en incidentes reales de transporte, 3.5s esta bien y no se toca. NO HACER: sacar el budget. La forma de tiempo de pared acotado es deliberada y correcta (comentario en operator-alert-leg.ts:4-13) - un retry sin techo lo mata maxDuration a mitad de vuelo y eso si es silencio total. PENDIENTE ESTRUCTURAL QUE LA FILA YA NOMBRABA: el aviso de rendicion sigue viajando por SMTP, y un aviso por SMTP de que el SMTP falla no puede llegar. Hoy lo tapa a medias la fila appEvents (la lee el riel de applog, que no es SMTP), asi que no esta tan crudo como cuando se escribio la fila.
• wi-cli-venus note · 5w ago
  MEDICION HECHA 2026-09-11 (db-pluto-cc, prod, SELECT only) + la rama que quedaba la cierro yo desde el codigo. LA FILA NO SE PUEDE CERRAR TODAVIA, pero por un motivo distinto al que decia: no es que el numero este mal puesto, es que NO HAY INSTRUMENTO QUE MIDA LO QUE LA FILA PIDE.\n\nLO QUE DAN LAS FILAS. operatorAlertTimeoutFallback: CERO filas en appEvents, sin cota de tiempo, consultando action y detail->>action. Corroboracion pedida por db-pluto-cc para que el cero no se confunda con una lectura fallida: category=email o action ILIKE fallback/timeout/operatorAlert devuelve seis acciones y ninguna es esta (email-sent 2979, sendEmailFailed 12 ultima 2026-07-17, support-reply-email-enqueued 12, support-reply-email 7, approvalEmailResent 1, support-reply-email-skipped 1). emailOutbox 30d: sent 1270 y NINGUN otro estado; all-time sent 3080, un solo estado, attemptCount maximo 2.\n\nLA RAMA QUE FALTABA, resuelta desde el fuente: operator-alert-leg.ts:154 escribe literalmente action operatorAlertTimeoutFallback con category email, y sus unicos llamadores son instrumentation.ts:181 y la sonda /api/internal/alert-fallback-probe. O sea que el cero es real: el camino de timeout NO SE EJERCITO NUNCA en prod desde que shipeo la mitad estructural (1c21d0b, 2026-08-22). No escribe bajo otro nombre.\n\nQUE SIGNIFICA. No hay evidencia de que ALERT_ATTEMPT_MS=3500 este mal puesto, y TAMPOCO de que este bien: el camino no se ejercito. Ademas sendEmailFailed no aparece desde 2026-07-17 y la outbox nunca tuvo una falla terminal ni backlog, asi que el SMTP viene sano hace ocho semanas. Eso baja la prioridad pero no responde la pregunta.\n\nEL HALLAZGO QUE IMPORTA: el ESTABLISH FIRST de esta fila (latencia real de connect+send SMTP desde una funcion de Vercel) NO SE PUEDE LEER DE NINGUNA FILA EXISTENTE. email-sent (email-outbox.ts:167) persiste subject y attemptCount y NADA DE TIEMPO; ningun sitio del riel de mail registra milisegundos. Asi que la pregunta no esta sin responder por falta de lectura, esta sin responder porque no hay con que.\n\nPROXIMO PASO PROPUESTO, barato y no invasivo: agregar durationMs al detail de email-sent. Es aditivo, no cambia comportamiento, y a 1270 envios por 30 dias da una distribucion real de connect+send en una semana. Recien con eso el techo de 3.5s se compara contra un numero medido en vez de contra el connectionTimeout de 10s del transporte, que es una cota del transporte y no una medicion. La alternativa - correr la sonda que fuerza el timeout contra prod - es la arm de cierre que pidio audit y es una accion viva sobre el camino de alerta; no la corro sin decision explicita.\n\nNO HACER, sin cambios: sacar el budget.
• wi-cli-venus note · 5w ago
  CODIGO ESCRITO, SIN VERIFICAR Y SIN PUSHEAR - esperando la push-gate (la tiene coder-mars-cc desde 11:33). GO de pmmaster 11:35 para el instrumento; NO para la sonda que fuerza el timeout contra prod (accion viva sobre el riel de alerta, queda rechazada salvo que Elazar lo decida directo).\n\nARCHIVOS TOCADOS, tres: src/lib/email-outbox.ts (reloj alrededor de deliverResolvedEmail en finalizeClaimedRow; durationMs al detail del email-sent que ya existia y al del email-outbox-dead-letter), src/lib/email.ts (durationMs al detail de sendEmailFailed en sendInline; el camino de exito inline NO escribe fila y NO se le agrega una, porque acunar una fila por envio para llevar un numero cambia una medicion por ruido contra la linea de base de cero ruido), y src/lib/email-send-duration.test.ts (nuevo, 3 casos).\n\nEL CASO QUE SOSTIENE EL TEST es el segundo: hace que el transporte mockeado tarde tiempo de pared real y exige que el valor registrado lo siga. Un campo hardcodeado en 0 pasa cualquier assert de tipo numero y no mide nada; esa es la unica prueba que distingue un instrumento de un placeholder.\n\nAL PUSHEAR: correr npx vitest run src/lib/email-send-duration.test.ts src/lib/email-defer-delivery.test.ts, tsc, eslint sobre los tres, mutation-check (hardcodear durationMs en 0 y confirmar que falla exactamente el caso 2), y despues gitpush con --only sobre los tres archivos. No cambiar ninguna constante en esta pasada: el punto de la fila es decidir el techo CON la distribucion en la mano, no antes.
• wi-cli-venus statusChanged · 5w ago
  INSTRUMENT SHIPPED dd7a95e / v2.23.91 (2026-09-11 11:52 ART). durationMs now recorded on three existing appEvents details: email-sent and email-outbox-dead-letter (finalizeClaimedRow, src/lib/email-outbox.ts) and sendEmailFailed (sendInline, src/lib/email.ts). Additive, no behaviour change, NO new appEvents row minted - the inline success path deliberately stays silent, because one row per send would trade a measurement for noise against a zero-noise baseline an operator reads. Guarded by src/lib/email-send-duration.test.ts (3 cases); the load-bearing one makes the mocked transport take real wall time so a hard-coded 0 cannot pass - mutation-checked by doing exactly that, which failed that one case and no other. 921 tests / 72 files green at the gate. WHY THIS AND NOT A CONSTANT CHANGE: the row says ESTABLISH FIRST. That could not be satisfied from existing data. db-pluto-cc prod read (SELECT only, all-time) found 2979 email-sent rows, 3080 emailOutbox rows all status sent, max attemptCount 2, and NOT ONE MILLISECOND anywhere on the mail rail. So ALERT_ATTEMPT_MS=3500 was being compared against the transports own connectionTimeout of 10s - a BOUND the transport imposes, not a measurement of what it does. Six weeks of clean logs could never have answered it; nothing was measuring. The gap was a missing instrument, not a missing query. OTHER HALF CLOSED BY THE SAME READ: operatorAlertTimeoutFallback has ZERO rows all-time, corroborated against the six email-category actions that do exist and ruled out as a name mismatch from source (operator-alert-leg.ts:154 writes that literal action; only callers are instrumentation.ts:181 and the probe route). The timeout path has not fired in prod since 1c21d0b (2026-08-22). Priority drops; the ceiling question stays open, because a path that never fires is evidence neither way. COLUMN PATH IS NOT MINE: db-pluto-cc 11:43 - appEvents.durationMs does not exist as a COLUMN; it is one of the four (httpStatus/durationMs/path/failureCode) in Step 1 of the appEvents SSOT conform plan now copied onto PLUTO-533. This instrument therefore writes into the detail JSON meanwhile, and needs no migration. When 533 Step 1 lands, these three sites are the first candidates to move to the column. RULINGS CARRIED: pmmaster 11:35 GO on the instrument, NO on running /api/internal/alert-fallback-probe against prod to force the budget timeout - refused not on cost but because it is a live action on the one rail whose failure mode is that nobody finds out; stays refused unless Elazar rules directly. The bounded wall-time budget is NOT touched and must not be: unbounded retry gets killed by maxDuration mid-flight, which is total silence and strictly worse than a bounded give-up. NEXT, NOT NOW: at ~1270 sends/30d through the drain there is a real distribution inside a week. Re-open on ~2026-09-18 with a percentile read of email-sent detail durationMs and decide ALERT_ATTEMPT_MS then. NOT EXERCISED: no real SMTP, no Vercel runtime, no assertion about the distribution. This commit builds the instrument and reads nothing from it.
• wi-cli-venus deferred · 5w ago
  Instrument shipped dd7a95e / v2.23.91. Deferred, not blocked: nothing is waiting on a person or a gate - it is waiting on ~1270 sends/30d to accumulate a distribution. Re-open ~2026-09-18 with a percentile read of email-sent detail durationMs (db-pluto-cc, SELECT only) and decide ALERT_ATTEMPT_MS then. The forced-timeout prod probe stays refused per pmmaster 11:35 unless Elazar rules directly.
• wi-cli-venus note · 4w ago
  PREMISE CORRECTION - "zero operatorAlertTimeoutFallback rows all-time" IS NO LONGER TRUE, and the row that falsifies it arrived buried inside a DB incident where it would have been invisible at the 2026-09-18 re-open. applog paged email/operatorAlertTimeoutFallback on /mi-cursada at 2026-09-11T23:19:06Z, inside the PLUTO-742 Supabase connect/auth window. That action literal is written at exactly one site, src/lib/operator-alert-leg.ts:154, and only after sendAlertWithBudget returns "timed-out" - i.e. it IS this row's fallback path, not a same-named event from elsewhere. Its only callers are src/instrumentation.ts:181 and /api/internal/alert-fallback-probe, and the probe was never run against prod (pmmaster ruled NO on that), so this is the real path firing in production for the first time since the structural half shipped at 1c21d0b on 2026-08-22. WHAT THIS CHANGES. The 2026-09-11 read ("ZERO rows, all time") was the half of the evidence that lowered this row's priority - a path that never fires produces no evidence either way. It has now fired, and it fired in the one condition that matters: the DB was unreachable, which is precisely the case the deferred-delivery fallback exists for and the case operator-alert-leg.ts:110-112 says out loud it cannot close, because the enqueue itself needs the DB. So the interesting field is the row's detail.outcome - if it reads enqueue_failed, the alert was LOST, and the fallback did not do its job on its first real firing. WHAT IS NOT MEASURED YET, asked of db-pluto-cc in the same turn: the all-time count of operatorAlertTimeoutFallback and the detail.outcome / detail.attemptMs of the 23:19:06Z row. No appEvents read was done here - prod reads go through db-pluto-cc, SELECT only - so "at least one row exists" is what the paged alert proves and nothing more. The ALERT_ATTEMPT_MS=3500 ceiling question is UNCHANGED by this and still waits on the durationMs distribution shipped at dd7a95e; a timeout under a DB outage says nothing about ordinary SMTP latency. Keep the 2026-09-18 re-open date.
• wi-cli-venus commented · 4w ago
  PROD READ 2026-09-12, SELECT only, answering coder-pluto-cc's three questions (tag coder-pluto-cc-mtxyz46thq1x). COUNT: operatorAlertTimeoutFallback all-time = 1, not zero and not many. first = last = 2026-09-11 23:19:06.958036+00, appVersion 2.23.95, level error, route /mi-cursada, id 76521be1-f902-4985-9e98-cdfc581dcb51. The earlier all-time-ZERO read was true when taken; this row supersedes it rather than contradicting it. OUTCOME, the load-bearing field: detail->>'outcome' = 'enqueue_failed'. detail->>'attemptMs' = 3500, budgetMs = 8000, bucket = 2981947, routeType = render, routeTemplate = /mi-cursada. durationMs key absent. So the alert was LOST at 3500ms of an 8000ms budget on the path's first real firing in production - condition 1's explicitly stated bound (the fallback enqueue also needs Postgres, and Postgres was the thing that was down) realised rather than hypothesised. DEFECT FOUND IN PASSING, and it is in the shipped telemetry rather than in the durability path - filing it here because it gates closure. detail carries the key serverErrorEventId and its VALUE IS NULL. Condition 4 of the approved spec requires 'stable correlation fields'; the implementation writes the correlation key and does not populate it. Consequence: a fallback row cannot be joined to the serverError it was alerting about. Not by id, and not by time either - the nearest /mi-cursada serverError on this ref is 22:57:03.083624+00, 22 minutes before the fallback, and all three serverError rows in the 22:00Z-02:00Z window share digest 2097667694 with actorUserId NULL, so time-nearest would pick an arbitrary one of three identical faults. A present-but-null key is worse than an absent one because it reads as a join that exists, and the first incident write-up to use this row was about to assert a link that is not there. ASK: populate serverErrorEventId at the write site (operator-alert-leg.ts:154 path), and strengthen the closure gate from 'a pending emailOutbox row plus one matching appEvents row' to also assert that field non-null. As written the gate passes on a row that cannot be correlated, which is the same class of miss as the six weeks of green logs that hid the original defect. Window context for whoever reads this next: 2026-09-11T22:00Z-2026-09-12T02:00Z holds 31 appEvents rows in 7 groups - systemBannerQueryFailed warn 10 (22:33:35.773092 -> 00:48:00.682241), email-sent 10, applogListenerHeartbeat 4, /mi-cursada serverError 3, assetlinks page_not_found 2, this fallback 1, login 1. The applog pull watermark froze at 00:48:00.682241+00, which is EXACTLY the max createdAt of systemBannerQueryFailed - it did not drift or stall mid-stream, it stopped on the last row of the dominant action, and three rows exist after it unpulled (two page_not_found at 00:55:13/00:55:15 and the serverError at 01:53:30).
• wi-cli-venus statusChanged · 3w ago
  Deferral date 2026-09-18 reached. Instrument has been recording durationMs since 2026-09-11 14:52Z; distribution read requested from db-pluto-cc (email-sent p50/p90/p95/p99/max, plus sendEmailFailed and dead-letter). Re-opened to decide ALERT_ATTEMPT_MS on the evidence.
• wi-cli-venus completed · 3w ago
  Ceiling decision, measured (db-pluto-cc, prod appEvents SELECT only, 2026-09-11 15:26Z-2026-09-19 04:22Z): email-sent durationMs n=406, min 2138, p50 3553, p90 5324, p95 6704, p99 21555, max 26221; 0 unmeasured sends; 0 sendEmailFailed; 0 dead-letters. p50 sits ABOVE ALERT_ATTEMPT_MS=3500, so roughly half of direct alert attempts race-timeout on this transport. DECISION: leave 3500 and the 8s budget unchanged. Reason: the shipped PLUTO-688 fallback enqueues a durable emailOutbox row whenever the budget ends 'timed-out', so a race-timeout no longer loses the alert - it degrades to drain-path latency plus a possible duplicate, which the leg's own header calls harmless. Raising the ceiling to cover p95 (~7s) would consume nearly the whole 8s budget in one attempt, leaving no retry, and p99 21.5s cannot be covered by any ceiling under maxDuration. Not claimed: that alerts arrive fast - roughly half take the drain path; the drain interval is the real alert latency. Follow-up on the fallback's own telemetry lives on PLUTO-743 (child, open).