Residuo del aviso de refresh vencido: el gate de v5.5.8 corta ~45x normalizado por trafico, pero el flag no persiste en todos los caminos y todavia salen 6 por minuto para un usuario en DEV (PROD: 1 en 14 dias)

Sub-tickets

Activity

• wi-cli-venus created · 5w ago
• wi-cli-venus descriptionChanged · 5w ago
  was: MEDIDO en app_logs de DEV: 2605 filas de 'Refresh token expired, forcing re-login' (src/lib/auth.ts:422, data.source=auth-jwt, un solo user_id) entre 23:38:34 y 23:39:48 del 2026-09-06, o sea ~35 por segundo durante 74 segundos. En la misma ventana 'Vehiculo detail request' tiene 3 filas y 'Batched dropdowns' 3: no es trafico de pantalla, es el callback jwt reentrando solo. NO es el bucle de MOVILBA-300 (cadencia distinta, 35/s contra ~10/s, y mecanismo distinto: aquel es un Server Action del cliente, este es el callback de NextAuth del lado del servidor). Sigue SIN EXPLICAR y sin reproducir. Lo que hace falta primero es la medicion, no un parche: cuantas rafagas hay en la historia de app_logs, si son siempre el mismo usuario, si arrancan con un login o con un refresh, cuanto duran y como terminan. El camino de exito de auth no loguea, asi que puede haber mas rafagas invisibles: si hace falta instrumentar, el precedente es MOVILBA-300 (loguear la invocacion ANTES del guard). NO ESCRIBIR ninguna credencial ni el user_id literal en ningun artefacto.
• wi-cli-venus titleChanged · 5w ago
  El aviso de refresh vencido se reimprime en cada request porque la rama no limpia la condicion: 28421 filas, 168 por cada sesion creada
• wi-cli-venus assigned · 5w ago
  coder02-mba-l-cc
• wi-cli-venus statusChanged · 5w ago
  Reimpresion arreglada en v5.5.8: el aviso se emite en la transicion, una vez por token. Sigue abierto lo que NO se midio: PROD, el disparador de la condicion (no hay ninguna fila en los 74s previos a un burst) y las rafagas del camino de exito, que no loguea. La decision de que hacer con session.error se separo a MOVILBA-304.
• wi-cli-venus assigned · 4w ago
  coder03-mba-l-cc / coder
• coder03assistant-mba-l-ca progress · 3w ago
  coder03assistant-mba-l-ca | 2026-09-24 04:00:26 ART dev 7d299b6a; main 721b9eb8: src/lib/auth.ts:458 gates expired-refresh logging on token.error transition in both branches. DEV app_logs last 14d has 126 notices; PROD has 1. No per-token runtime cardinality control after deploy; leave open for that check.
• coder03-mba-l-cc progress · 3w ago
  coder03-mba-l-cc 2026-09-24 04:45 -03 - Medicion propia en DEV (movilba_dev / movilba_user, SELECT only) del efecto del gate de v5.5.8, con DENOMINADOR, que es lo que faltaba: un conteo crudo de avisos no dice nada si el trafico cambio. Antes del 2026-09-07: 28416 avisos sobre 113463 filas de app_logs en 142 dias = 25.0 por ciento de la tabla, 200 avisos/dia. Desde el 2026-09-07: 206 sobre 37109 en 14 dias = 0.55 por ciento, 14.7 avisos/dia, Y el trafico SUBIO - 799 filas/dia antes contra 2651 despues, 3.3x. Normalizado contra trafico la caida es ~45x. El gate de auth.ts:458 funciona. PERO NO ES UNA VEZ POR TOKEN, que es lo que el statusChanged del 09-07 afirmo: 206 avisos de 9 usuarios distintos en 14 dias, con picos post-arreglo de 6 en un minuto para el mismo usuario el 09-10 12:59, el 09-16 11:14 y el 09-18 15:34 - las tres fechas son posteriores al deploy, o sea que no es cola del arreglo. Nadie se loguea 6 veces por minuto. EL DISCRIMINANTE, y descarta la lectura facil de que una request loguea dos veces: ninguna request_id aparece mas de una vez (max_rows_same_request_id = 1) y 186 de las 206 filas no tienen request_id, porque el callback jwt corre fuera del contexto de request. O sea que la repeticion es ENTRE requests, no adentro de una. Lectura: token.error se setea y se devuelve, pero la cookie solo se reescribe en los caminos donde Auth.js persiste el token modificado; en los que no, el flag se pierde y la transicion se vuelve a cruzar en la request siguiente. Lo que el gate suprime es la mayoria de los caminos, no todos. PROD: 1 aviso en 14 dias, medido por coder03assistant-mba-l-ca. O sea que en PROD el residuo es inexistente y la p0 ya no describe este item - es ruido de log acotado en DEV, no un incidente. Bajo la prioridad. LO QUE NO SE MIDIO: cual de los caminos de lectura de sesion no reescribe la cookie - eso se falsifica instrumentando, no leyendo. Y el residuo NO se arregla emitiendo menos: si session.error no lo consume nadie (MOVILBA-304, blocked en Elazar), la pregunta previa es si este aviso tiene que existir. No toco el log hasta que 304 se decida.
• coder03-mba-l-cc priorityChanged · 3w ago
  2
• coder03-mba-l-cc titleChanged · 3w ago
  Residuo del aviso de refresh vencido: el gate de v5.5.8 corta ~45x normalizado por trafico, pero el flag no persiste en todos los caminos y todavia salen 6 por minuto para un usuario en DEV (PROD: 1 en 14 dias)
• coder03-mba-l-cc assigned · 2w ago
  coder03-mba-l-cc
• coder03-mba-l-cc assigned · 2w ago
  coder04-mba-l-ca
• coder04-mba-l-ca statusChanged · 1w ago
  2026-10-05: auth.ts now clears refreshTokenExpires while persisting terminal RefreshTokenExpired state; audit requested. Post-deploy app_logs rate remeasurement remains pending the audited rollout.
• audit-mba-l-cc audited · 1w ago
  audit pass: src/lib/auth.ts jwt callback expiry guard
  payload

  {"scope":"src/lib/auth.ts jwt callback expiry guard","outcome":"pass","evidence":"New top guard (token.error==='RefreshTokenExpired') short-circuits before the now>expiry check, clearing refreshTokenExpires and returning without re-logging - fixes the 28451-row amplification (log only fires on the actual transition, confirmed unreachable-but-harmless now-redundant inner 'if error!==RefreshTokenExpired' check left in place, non-blocking). Missing-timestamp treated as terminal (fail-closed) intentionally per description. Equivalent early-return depth to prior code, no other logic skipped. eslint clean, no auth.ts tsc errors. No regression test added (no jsdom harness for this module, same gap as MOVILBA-304) - non-blocking note.","reportRef":null}

• coder04-mba-l-ca statusChanged · 1w ago
  2026-10-05 pre-deploy baseline, SELECT-only last 7d: PROD 0/621 app_logs (0.0000%); DEV 94/12556 (0.7486%), five user IDs, peak 46 notices per user/minute and 17 user-minutes repeated. This is BEFORE the auth.ts diff is shipped. Re-measure the same window after rollout; raw count cannot show a fix until code is live.
• coder04-mba-l-ca progress · 1w ago
  Post-rollout SELECT-only spot check after v5.6.164 reached PROD and DEV (since 2026-10-05 18:57Z): PROD app_logs 0 total rows; DEV 6 total rows through 19:02:10Z; 0 matching Refresh token expired notices on either base. Too little traffic for a rate conclusion; repeat after a full comparable traffic window.
• coder04-mba-l-ca progress · 1w ago
  SELECT-only post-rollout remeasurement at 2026-10-08 ~18:00Z, cutoff v5.6.164 2026-10-05 18:57Z. DEV pre-72h: 11 Refresh token expired notices / 2464 app_logs (0.446%), 4 affected actors, max 2 notices/actor/minute. DEV post: 42 / 5312 (0.791%), 5 actors, max 5/actor/minute; notices recur for the same actor across Oct 6-8. Previous recorded 7d pre baseline was 94/12556 (0.749%), max 46/actor/minute. PROD pre-72h 0/107, post 0/233, no affected cohort. Thus the observed peak is lower but normalized DEV rate did not fall; no evidence yet of one notice per token, because app_logs lacks token identity and multiple sessions per actor are possible. Keep open; next control must distinguish same-token repetition from separate expired sessions, then fix any non-persisting Auth.js path. No DB writes.
• coder04-mba-l-ca progress · 1w ago
  Equal 72h DEV windows around v5.6.164: expiry notices rose from 11/2464 app_logs (0.446%) to 42/5312 (0.791%), +77% normalized; max notices/actor/minute fell 2→5 in this short pre-window vs old recorded peak 46, so no one-per-token proof. PROD 0/107 and 0/233 offers no signal. Since v5.6.199 at 2026-10-08 17:45:49Z, PROD and DEV each have zero expiry notices, so current user_id/request_id columns cannot yet classify new events. Source: auth.ts emits expiry with OLD requestId SYSTEM, which fails UUID_RE, and proxy auth() runs before forwarded request header exists. Added random opaque sessionTraceId only on initial JWT login and to existing login/expiry log payloads; audit requested. Future repeated notices with the same trace ID will prove persistence failure without storing a credential.
• coder04-mba-l-ca progress · 1w ago
  Correction to my immediately preceding note: the equal-window peak per actor/minute ROSE from 2 pre-v164 to 5 post-v164; it did not fall. The older recorded peak of 46 comes from a different seven-day baseline and is not directly comparable to this 72-hour pre-window. The normalized rate likewise rose 0.446% to 0.791% (+77%). Keep the conclusion: the rollout has not demonstrated one notice per token, and the sessionTraceId diff is diagnostic pending audit.
• coder04-mba-l-ca progress · 1w ago
  Measurement boundary clarified: auth.ts expiry log passes old-signature requestId=SYSTEM; UUID_RE stores NULL, and proxy auth() executes before forwarded x-request-id is set. Request-level correlation for this log is MOVILBA-732 residual; sessionTraceId diagnostic is a separate per-JWT random ID created only on initial login, so it cannot track a person across re-logins and is not derived from a credential. No expiry notices yet since patch 199; zero events cannot validate the instrument or rate. Keep open for a nonzero post-deploy cohort.
• audit-mba-l-cc audited · 1w ago
  audit pass: MOVILBA-301, hunks de sessionTraceId en src/lib/auth.ts @ 75fd874e: la asignacion en :398 y los dos campos agregados al log de sesion nueva y al de refresh vencido. NO cubre la conversion de firma de los 8 sitios, que verdicto aparte en MOVILBA-732. Gates por mi bajo lock.
  payload

  {"scope":"MOVILBA-301, hunks de sessionTraceId en src/lib/auth.ts @ 75fd874e: la asignacion en :398 y los dos campos agregados al log de sesion nueva y al de refresh vencido. NO cubre la conversion de firma de los 8 sitios, que verdicto aparte en MOVILBA-732. Gates por mi bajo lock.","outcome":"pass","evidence":"PASS sobre los hunks de sessionTraceId. Detalle en el audit-finding.\nPRIVACIDAD, medida en el codigo. (a) uuid v4 opaco de crypto.randomUUID (utils/uuid.ts:6), minteado UNA vez por login, sin derivar de dato de usuario ni de token: no es identificador estable entre logins. (b) NO llega al cliente - el callback session :555-580 expone id, provider, issuedAt, mustChangePassword, passwordExpired y error, y sessionTraceId no esta. (c) Las 3 unicas ocurrencias del arbol son :398, :427 y :470. (d) Ningun secreto viaja con el.\nCOBERTURA DEL DENOMINADOR. La asignacion de :398 esta DESPUES del if/else de Keycloak vs credenciales, en el bloque comun de login, asi que las dos vias lo reciben. Lo verifique porque importa: DEV registro hoy 4 logins de Keycloak y 15 de credenciales, y un id que cubriera una sola via daria un denominador parcial sin que se note. Los returns tempranos :437 y :444 son POSTERIORES a :398.\nPERSISTENCIA. Se asigna solo en el login; las invocaciones siguientes reciben el token decodificado y lo devuelven intacto (return token en :552), asi que sobrevive la rotacion silenciosa y llega al aviso de refresh vencido - el par que necesita la razon re-logins por sesion creada.\nTRANSITORIO A DECIR ANTES DE MEDIR CON EL: los JWT ya existentes al deploy no traen el campo, asi que los avisos de refresh vencido de esas sesiones lo loguean ausente la primera media hora (refreshTokenMaxAge 1800s). Una cuenta hecha en esa ventana sale corta.\nCARDINALIDAD SIN MEDIR. Hoy CERO filas de app_logs traen sessionTraceId, ni en PROD ni en DEV. El diff no esta shipeado. La cifra de 0.446 a 0.791 por ciento es de ANTES de este campo.\nGATES bajo lock, hash 75fd874e antes y despues: eslint sobre auth.ts exit 0; typecheck sin salida; test:source 66 pass 0 fail. OJO: corrieron sobre el archivo COMBINADO, asi que cubren los dos hunks a la vez - el alcance por hunk es de la revision, no de los gates.\nSIN EJERCITAR: next build; un login vivo; una fila con el campo.","reportRef":null}

• db04-mba-l-ca progress · 1w ago
  db04 SELECT-only PROD patch-200 sessionTraceId readback, measured 2026-10-08 15:41:03 ART, bound created_at >=18:40Z: auth-jwt new-login rows 0, with nonempty sessionTraceId 0; auth-signin new-login rows 0 (its payload is not expected to carry this field). Zero denominator, no runtime verdict; no traffic generated. Historical 18:00-18:40Z had 2 auth-jwt New session created rows and 2 auth-signin successful-login rows, none with sessionTraceId; pre-deploy JWTs do not gain it retroactively. Evidence /data-lezama/movilba/evidencia/MOVILBA-732/2026-10-08-patch200-auth-runtime-zero-denominator.md.
• coder04-mba-l-ca completed · 1w ago
  Shipped in v5.6.200 on PROD+DEV: per-login opaque sessionTraceId in JWT and in the new-session/refresh-expired auth logs (src/lib/auth.ts SHA256 75fd874e; audit PASS 2026-10-08T18:24:24Z). The earlier idempotent expired-token guard is already live. Equal 72h DEV windows around v5.6.164 showed 11/2464 (0.446%) to 42/5312 (0.791%), a 77% increase, so that prior gate did not demonstrate a rate reduction. The new trace enables per-session measurement only for JWTs created after patch 200; no post-patch expiry sample yet, so do not cite this close as proof that notice frequency fell. PROD and DEV patch 200 were health-verified by coder03; pod was still 199 at that report.
• coder04-mba-l-ca statusChanged · 1w ago
  Reopened per coder03's 15:42 ART direction: patch 200 instrumentation shipped, but runtime readback remains SIN EJERCITAR. db04's bounded PROD SELECT at 15:41:03 ART sampled created_at >= 2026-10-08T18:40:00Z and found auth-jwt 0, auth-signin 0; 0 NULL request_id over 0 rows is no verdict. Pre-bound 18:00-18:40Z five auth rows lack sessionTraceId as expected. Evidence: /data-lezama/movilba/evidencia/MOVILBA-732/2026-10-08-patch200-auth-runtime-zero-denominator.md. Next read only after naturally occurring new-login traffic; first 30 min of pre-deploy JWTs cannot carry the field.
• coder04-mba-l-ca progress · 1w ago
  Runtime readback window (db04, SELECT-only PROD): app_logs.created_at >= 2026-10-08T18:40:00Z, sampled at 15:41:03 ART (18:41:03Z). auth-jwt 0 rows, auth-signin 0 rows; therefore neither non-NULL request_id nor sessionTraceId has a runtime denominator yet. Pre-bound 18:00-18:40Z five auth rows lack trace as expected. Evidence /data-lezama/movilba/evidencia/MOVILBA-732/2026-10-08-patch200-auth-runtime-zero-denominator.md. Next sample only after natural new-login traffic.
• coder04-mba-l-ca progress · 1w ago
  Clarification to the 18:41:03Z readback: the SQL bound 18:40:00Z–18:41:03Z spans only 63 seconds (and the actual patch-200 live span may be shorter; the bound is not the exact deploy timestamp). auth-jwt 0 and auth-signin 0 in that brief interval is an EMPTY denominator, not evidence that login traffic or sessionTraceId is absent in PROD. The only positive observation in the report is the 18:00–18:40Z pre-bound five rows without the new field. Keep runtime acceptance SIN EJERCITAR until natural new-login rows exist.
• coder04-mba-l-ca progress · 1w ago
  Timing correction: discard the speculative 23-second live span in my prior note. PROD commit was stamped ~18:37Z and patch-200 health succeeded immediately after, so live PROD exposure before db04's 18:41:03Z sample was about 4 minutes. The SQL itself covered only 18:40:00Z–18:41:03Z (63 seconds) and found zero auth rows: empty denominator, no runtime PASS/FAIL. Five rows in 18:00–18:40Z are PRE-QUERY-BOUND, not necessarily pre-deploy; their exact timestamps must be checked against the ~18:37Z cutover before using them as a pre-fix contrast.
• db04-mba-l-ca progress · 1w ago
  Timing correction, SELECT-only PROD movilba at 2026-10-08 18:56:00Z: the five auth rows from 18:00-18:40Z all occurred 18:24-18:27, before the reported ~18:37 patch-200 cutover; all had NULL request_id and no sessionTraceId. From 18:37Z to query time, exactly two natural auth rows at 18:54:00Z: auth-signin login has non-NULL request_id, no trace (expected); auth-jwt new session has non-NULL request_id and sessionTraceId present. 0 rows in uncertain 18:37-18:40 window. Earlier zero denominator was true only at its 18:41 read, superseded by these new rows. No traffic generated. Evidence: /data-lezama/movilba/evidencia/MOVILBA-732/2026-10-08-patch200-auth-runtime-zero-denominator.md
• coder04-mba-l-ca statusChanged · 1w ago
  Code for sessionTraceId shipped in patch 200 and one natural post-deploy auth-jwt New session created row at 18:54Z carried it; no post-deploy RefreshTokenExpired notice has been observed, so the rate/identity question cannot yet be measured. No coder work active while MOVILBA-367 is inProgress. Resume 301 on natural expiry-notice traffic with a nonzero denominator; do not manufacture a login or infer success from zero notices.
• db04-mba-l-ca progress · 1w ago
  Single bounded SELECT-only PROD movilba sample at server 2026-10-08 22:07:24.020422Z; window created_at >= 2026-10-08 18:37:00+00 AND <= sampled now(), data.source=auth-jwt, message exactly Refresh token expired, forcing re-login. Denominator expiry notices 0; nonempty sessionTraceId 0; distinct trace IDs 0; max notices per trace N/A; max notices per trace per minute N/A; max notices in any minute N/A. Latest app_logs.created_at ANY source was 2026-10-08 18:54:03.165734Z, over 3h before this sample, so zero cannot establish the new diagnostic or a rate change and may reflect no fresh ingest. No traffic/login generated; no raw IDs read out. Keep item open pending natural expiry traffic and a nonzero denominator.
• coder04-mba-l-ca blocked · 1w ago
  Instrumentation shipped in patch 200. Fresh SELECT-only read since the recorded 2026-10-08 18:37Z cutover: PROD has 0 refresh-expired rows and 2 auth-jwt new-session rows, both with sessionTraceId; DEV has 0 refresh-expired rows and 3 auth-jwt new-session rows, all with sessionTraceId, but DEV app_logs has had no rows since 2026-10-08 16:55 ART. The earlier 17 DEV expiry notices in the last 24h all predate the cutover. Thus the trace instrument is observed on new-session events, but there is still no post-cutover expiry denominator to measure notice frequency. Wait for natural expired-token traffic; no login/expiry generated.