Session transform: performance, two-layer caching, region handoff, and observability

.eslintrc

@@ -3,5 +3,17 @@
   "root": true,
   "env": {
     "node": true
-  }
+  },
+  "rules": {
+    "@typescript-eslint/no-explicit-any": "off",
+    "max-params": "off"
+  },
+  "overrides": [
+    {
+      "files": ["node/typings/**/*.ts"],
+      "rules": {
+        "@typescript-eslint/no-unused-vars": "off"
+      }
+    }
+  ]
 }

.gitignore

@@ -2,4 +2,5 @@ node_modules
 .idea
 .qodo
 .cursor
-.claude
+.claude
+AGENTS.md

.vtexignore

@@ -0,0 +1,2 @@
+node/__tests__/
+node/jest.config.js

CHANGELOG.md

@@ -8,10 +8,66 @@ and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.
 
 ## [Unreleased]
 
+## [3.8.1] - 2026-08-26
+
+### Changed
+
+- GraphQL `checkUserPermission` / `getUserByEmail` reuse the memory `active-user-permissions` cache already used by the REST `checkPermissions` route (TTL 5 minutes), so sibling B2B apps (and repeated hops in the same navigation) no longer hit Master Data on every call.
+- `getAllUsers` fetches page 1 with the fields callers need and only requests further pages when `total` exceeds the page size. The previous count probe (`fields: ['id']`) then re-fetched page 1 in full, doubling the cost of every small search — including the `active=true` lookup that returns 0..1 records.
+- `setProfile.timings` is emitted on every transform while diagnosing session latency. Production still has the slow/sampled logger path behind `sessionTimingsSlowThresholdMs`; this always-on trace is temporary.
+
+## [3.8.0] - 2026-08-26
+
+## [3.7.0] - 2026-08-26
+
+### Added
+
+- Two-layer caching (per-pod in-memory LRU + cross-pod VBase stale-while-revalidate) for the data `setProfile` reads on every session transform: app settings, sales channel list, B2B settings, organization, cost center, active user, region lookup, session watcher flag (memory-only, it already lives in VBase) and roles (memory-only, same reason). Warm-pod transform time drops from roughly 1.2s to under 150ms, and a cold pod reads the entry a sibling pod populated instead of paying the origin call. The cost center cache is bounded by bytes rather than entry count, because its documents were measured spanning 400B to 29KB.
+- The active-user cache key includes the session's `public.b2bCurrentCostCenter`, which `setCurrentOrganization` writes on every organization switch, so switching organizations invalidates the cache by key instead of waiting out a TTL. TTL configurable through the `sessionUserCacheTtlMs` app setting (0 disables).
+- New app setting `deferRegionToCheckoutSession` (default `false`). When enabled, `setProfile` stops calling the checkout regions API and instead publishes the selected cost center address as `public.postalCode` and `public.country`, leaving `public.regionId` untouched so `vtex.checkout-session` resolves `checkout.regionId` itself (it performs the same lookup, cached). Also makes `vtex.search-session` regionalize search with the same address the cart uses. Falls back to resolving the region locally when the cost center address lacks a country or postal code, and stands down when region overwrite is active for the request.
+- Session transform telemetry: a `withRequestTimings` middleware logs one `setProfile.timings` line with per-step durations when a request is slow (default threshold 1000ms, configurable via `sessionTimingsSlowThresholdMs`) or sampled (`sessionTimingsSampleRate`, default 0), and always when the transform throws (`failed: true`), so incidents show which dependency degraded without redeploying.
+- Per-pod cache hit-rate and size stats logged as `cacheStats` every five minutes, piggybacked on the session transform route.
+- New app setting `logSessionPayloads` (default `false`) gating the full request/response session payload log, which previously ran on every transform and included the shopper's email and organization data.
+- Errors in the stale-while-revalidate cache layer are now logged (`staleFromVBase.readError`, `saveError`, `revalidateError`) instead of being silently swallowed - in particular a failing origin behind a stale-served cache is now visible. These logs reference the hashed storage key, never the logical key, which can carry identifiers (the active-user key contains the shopper's email).
+- Jest test suite (77 tests) covering the caches, the stale-while-revalidate helper, the timings middleware, the `checkPermissions` cache, and `setProfile` behaviors: sales channel deferral, region handoff and its fallbacks, organization-switch cache invalidation, payload log gating, session watcher kill switch, and the inactive-organization recovery path.
+
+### Changed
+
+- Signals that need exact counting are shipped through two channels: the log line (the debugging surface - the platform log pipeline samples it, including `error` level, so log-based counts are estimates) and an analytics event via `sendObservabilityEvent`, the same channel as the app's auth audit events (the measuring surface, exact counts, identifiers only - never emails or addresses). Double-shipped today: `organization-recovered`, `organization-unavailable`, `cart-address-sanitized`, `cart-address-field-rejected`, `cart-address-update-failed`. Delivery is fire-and-forget and a failure never affects the request.
+- Every error log in the app (63 sites) now goes through `describeClientError` instead of passing the client error object through. That object carries the request it came from - `config.data` is the request body (addresses, profile data) and `config.url` can hold emails in Master Data `_where` query strings - so it must never be logged whole. The described object keeps what debugging needs: message and codes (email-redacted), HTTP status, the VTEX backend's own error contract (`vtexErrorCode`/`vtexErrorMessage`), the correlation ids backends answer with (`operationId`, `requestId`, `backend` - enough for the owning team to locate the request on their side), the request line with the query string stripped, and a bounded stack.
+- `setProfile` starts its user-independent lookups (sales channel list, B2B settings, app settings) before the user lookup instead of awaiting everything in one batch, hiding their latency behind the user and organization reads.
+- `getMarketingTags` and `generateClUser` no longer block the session transform response: both only feed fire-and-forget cart updates, and `generateClUser` had measured spikes near 1s. The CL profile lookup is also skipped entirely when there is no cart to update.
+- The sellers facets branch reuses the already-fetched cached app settings instead of issuing a second, uncached `getAppSettings` call.
+- `checkPermissions` resolves the user through a short-lived (60s, memory-only) cache; it is called per request by sibling B2B apps and previously hit Master Data every time.
+- Service resources aligned with the rest of the B2B suite: memory 256MB to 1024MB, ttl 60 to 300, timeout 45 to 60 (`b2b-organizations-graphql` and `b2b-checkout-settings` already run this profile).
+
+### Fixed
+
+- The active B2B record is now resolved with a Master Data query filtered by `active=true`, instead of paginating through every record for the email and picking the active one in memory. For a shopper holding records in many organizations, the paginated scan can come back without the active row, and the code then fell back to `users[0]` - placing the shopper in an arbitrary organization, and failing the transform outright when that record pointed at an organization that is not active, which Session Manager surfaces as a generic 502 on login. The filtered query returns 0..1 records in a single call, so the unstable scan no longer runs. Covered by a regression test proven to fail against the old code.
+- Organization status matches `b2b-organizations-graphql` again. Since the `setProfile` performance refactors replaced that app's GraphQL with a direct Master Data read, the status rule was reimplemented here as `!== 'inactive'` in three places, while the owning app's `checkOrganizationIsActive` answers `status === 'active'` - so an `on-hold` organization, a canonical status there, was shoppable here and rejected there. The rule now lives in a single module (`node/utils/organizationStatus.ts`) that mirrors the owner's vocabulary, and an unrecognized status fails closed and is reported (`setProfile.unknownOrganizationStatus`, `getUserOrganizationsData.unknownOrganizationStatus`) instead of diverging silently.
+- The cart address is sanitized before it is sent to checkout. Checkout answers `CHK0040` for a fixed set of characters (`< > ? + " ; %`) and discards the entire `shippingData` attachment, so a single offending character made the cart silently keep its previous address - a common condition for integration-populated cost center addresses, whose `reference` field often carries a JSON blob with quotes in it. Which fields checkout validates is not documented (the error codes carry a `{0}` field placeholder), so it was established by probing the attachment field by field: of the 13 fields in the address contract, `addressId`, `addressType` and `addressQuery` accept the characters and the other 10 do not. Only the two **annotation** fields are cleaned - `reference` and `complement` describe *how* to deliver, never *where*, and they are where the offending values are typically found. The eight **location-bearing** fields (`street`, `number`, `city`, `state`, `neighborhood`, `receiverName`, `postalCode`, `country`) are never rewritten: the characters can be legitimate in them worldwide (Plus Codes are built around `+`; B2B receiver names carry `"` as an inch mark), so stripping one may point the delivery somewhere else. Those are reported as `CART_ADDRESS_FIELD_REJECTED` and left untouched, for the record to be fixed at the source - a corrupted location is worse than a rejected one. (The service enforces `< > ? + " ; %`; the docs additionally list `*` for `CHK0040`, which it does not reject.) Each rewrite is reported as `CART_ADDRESS_SANITIZED` (which fields, which characters, plus `orgId` / `costId` / `costCenterAddressId`) and an update that still fails is tagged `CART_ADDRESS_UPDATE_FAILED` with checkout's own error code, so the fix and what it prevents are both countable. **No address value is logged** at any level or setting: the sanitizer returns only metadata, and the checkout failure is reported field by field rather than by passing the client error object through - that object carries the request body, and therefore the address.
+- Organization stickiness: absent an explicit selection, the session now keeps the organization *and cost center* it was already resolved to, instead of re-deriving them on every transform. `storefront-permissions.organization` and `costcenter` are declared as transform inputs (the same pattern the app already uses for `hash`) and the pair is resolved with a targeted, single-call lookup; matching on the organization alone would pick an arbitrary cost center for shoppers who hold several inside one organization. When only the cost center is gone, the session stays in the same organization (`getActiveUserByEmail-stickyCostCenterNoLongerAvailable`); when the shopper no longer has a record for the pinned organization at all, it is reported as `getActiveUserByEmail-stickyOrgNoLongerAvailable`. Without this, a shopper with many records could be resolved to a different organization on consecutive requests, which is what made switching cost center appear not to work.
+- The session transform no longer writes to Master Data, under any circumstance. Which record is active is a decision that belongs to the shopper (through the organization switch) or to whoever manages the account's organizations - previously, when the selected organization was inactive, `setProfile` picked another organization and **persisted** that choice on its own, which turned an admin deactivating an organization into a silent, permanent relocation of its users. The recovery now only shapes the response: the session's own organization/cost center pin keeps consecutive responses on the same recovered organization (preferred over the list-based pick precisely because nothing is persisted), the shopper's stored selection is left intact for them or an admin to resolve, and each recovered session is reported as `setProfile.organizationRecovered` with the unusable and the recovered organization ids. If the shopper's original organization is reactivated, their stored selection takes effect again - instead of having been overwritten.
+- When the user has no active record at all (records are created with `active: false`), the fallback used for a first login is deterministic and strictly read-only: it never writes an `active` flag, because an unvalidated record can point at an inactive or deleted organization and persisting it would make a bad selection permanent. The case is logged as `getActiveUserByEmail-noActiveRecord`.
+- An organization that no longer exists no longer surfaces as an opaque failure: the lookup resolves it to "not found" (without caching the miss) and it follows the same recovery path as an inactive organization. When nothing can be recovered, `setProfile.organizationUnavailable` logs the shopper, the organization and whether it was `organizationNotFound` or `organizationInactive` - previously the sessions service reported only "App storefront-permissions failed", with nothing identifying who or why.
+- `setProfile` returned a 500 for any user whose organization is inactive but who has another active organization - the exact path meant to recover them. The recovery branch still unwrapped the response shape of the old GraphQL client (`.data.getOrganizationById`) after the Master Data client migration, resolving `organization` to `undefined` and throwing on `organization.name`. Covered by a regression test proven to fail against the old code.
+
+### Removed
+
+- The per-step `setProfile.timing` debug logging introduced in 3.6.2/3.6.3, superseded by the gated `setProfile.timings` telemetry above: same step coverage, but one log line per slow/failed/sampled request instead of one debug line per step on every request.
+
 ## [3.6.3] - 2026-08-19
 
+### Changed
+
+- Grouped the `setProfile` process-time debug logging into step timings.
+
 ## [3.6.2] - 2026-08-19
 
+### Added
+
+- Step-by-step process-time debug logging in `setProfile`.
+
 ## [3.6.1] - 2026-08-11
 
 ### Added

docs/COST_CENTER_ADDRESS_AND_REGION.md

@@ -2,6 +2,8 @@
 
 This document describes how **Storefront Permissions** handles multiple cost center addresses and optional region overwrite in the `setProfile` session transform. It is intended for developers integrating with the session or debugging region/address behavior.
 
+> For the full picture of who resolves the session region — including the `deferRegionToCheckoutSession` handoff that lets `vtex.checkout-session` resolve it instead of this app, and how it composes with the region overwrite described here — see [Region resolution](REGION_RESOLUTION.md).
+
 ## Overview
 
 When a B2B user has a cost center with **multiple addresses**, the storefront may let them choose which address to use for shipping, region (e.g. delivery options, pricing), and document type (e.g. Brazil CPF). In addition, the user may temporarily **override** the region (e.g. “check delivery to another location”) by entering a postal code and country, without changing the cost center’s selected address. This app supports both behaviors in an **opt-in** way via app settings.