( sessionData: string, cookiePassword: string, jwks: CachedRemoteJWKSet, )
| 208 | ); |
| 209 | |
| 210 | const verifySealedSessionLocally = ( |
| 211 | sessionData: string, |
| 212 | cookiePassword: string, |
| 213 | jwks: CachedRemoteJWKSet, |
| 214 | ): Effect.Effect<LocalSessionVerification, ServiceAdapterError> => |
| 215 | Effect.gen(function* () { |
| 216 | // Phase timings, not just child spans. `local_verify` is a leaf in |
| 217 | // production traces, so a ~3.3s verify has nothing under it to blame — |
| 218 | // and it stayed 3.3s after the JWKS fetch was eliminated entirely |
| 219 | // (jwks.fetch_count == 0), so the cost is one of the phases below. Under |
| 220 | // workerd `Date.now()` only advances at I/O boundaries, which is exactly |
| 221 | // what makes a raw span duration misleading here: recording each phase |
| 222 | // explicitly says which await the wall-clock actually crossed. |
| 223 | const verifyStartedAt = Date.now(); |
| 224 | |
| 225 | const unsealStartedAt = Date.now(); |
| 226 | const unsealed = yield* Effect.tryPromise({ |
| 227 | try: () => unsealWorkOSSession(sessionData, cookiePassword), |
| 228 | catch: (cause) => new LocalSessionCookieError({ cause }), |
| 229 | }).pipe( |
| 230 | Effect.catchTag("LocalSessionCookieError", () => Effect.succeed(null as unknown | null)), |
| 231 | Effect.withSpan("workos.session.unseal"), |
| 232 | ); |
| 233 | const unsealMs = Date.now() - unsealStartedAt; |
| 234 | yield* Effect.annotateCurrentSpan({ "verify.unseal_ms": unsealMs }); |
| 235 | if (!unsealed) return { _tag: "InvalidCookie" }; |
| 236 | |
| 237 | const decodeStartedAt = Date.now(); |
| 238 | const session = Option.match(decodeSealedSessionPayload(unsealed), { |
| 239 | onNone: (): SealedSessionPayload | null => null, |
| 240 | onSome: (payload) => payload, |
| 241 | }); |
| 242 | yield* Effect.annotateCurrentSpan({ "verify.decode_ms": Date.now() - decodeStartedAt }); |
| 243 | if (!session) return { _tag: "InvalidCookie" }; |
| 244 | |
| 245 | // Snapshot the JWKS cache around the verify so the `local_verify` span |
| 246 | // says whether THIS verify was a warm-cache signature check or paid for a |
| 247 | // live upstream JWKS fetch. The Aug 2026 latency regression was the cache |
| 248 | // silently missing on most verifies, and no span attribute distinguished |
| 249 | // the two paths. |
| 250 | const jwksBefore = jwks.inspect(); |
| 251 | // Entry-state annotation goes on BEFORE the verify so a failing verify |
| 252 | // (the case worth debugging) still records whether the cache was warm. |
| 253 | yield* Effect.annotateCurrentSpan({ |
| 254 | "jwks.cache_populated_at_start": jwksBefore.hasJwks, |
| 255 | ...(jwksBefore.fetchedAt === null |
| 256 | ? {} |
| 257 | : { "jwks.cache_age_ms": Date.now() - jwksBefore.fetchedAt }), |
| 258 | }); |
| 259 | const jwtStartedAt = Date.now(); |
| 260 | const verified = yield* verifyJwtWithRefreshRetry(session.accessToken, jwks).pipe( |
| 261 | Effect.withSpan("workos.session.jwt_verify"), |
| 262 | Effect.onExit(() => { |
| 263 | const jwksAfter = jwks.inspect(); |
| 264 | const finishedAt = Date.now(); |
| 265 | return Effect.annotateCurrentSpan({ |
| 266 | "verify.jwt_ms": finishedAt - jwtStartedAt, |
| 267 | "verify.total_ms": finishedAt - verifyStartedAt, |
no test coverage detected