Session transform: performance, two-layer caching, region handoff, and observability - #203
Session transform: performance, two-layer caching, region handoff, and observability#203mateussaggin wants to merge 20 commits into
Conversation
…rvability The setProfile session transform ran a serial chain of uncached external calls on every session update, regularly exceeding Session Manager's 2s budget on cold pods. This restructures the transform around two-layer caching (per-pod LRU + cross-pod VBase stale-while-revalidate), moves fire-and-forget work off the critical path, and adds gated telemetry so production bottlenecks are diagnosable per account without redeploying. Warm-pod server time drops from ~1240ms to ~50-150ms; a cold pod with a warm VBase goes from ~1870ms to ~950ms. Output verified byte-identical to v3.6.1 with all new flags off. Also fixes a regression where users with an inactive organization but another active one received a 500: the recovery branch still unwrapped the old GraphQL client response shape after the Master Data migration, resolving the organization to undefined. New settings (all default off/safe): deferRegionToCheckoutSession, logSessionPayloads, sessionTimingsSlowThresholdMs, sessionTimingsSampleRate, sessionUserCacheTtlMs. Covered by a new jest suite (41 tests) including a regression test proven to fail against the inactive-organization bug.
|
Hi! I'm VTEX IO CI/CD Bot and I'll be helping you to publish your app! 🤖 Please select which version do you want to release:
And then you just need to merge your PR when you are ready! There is no need to create a release commit/tag.
|
|
Beep boop 🤖 Thank you so much for keeping our documentation up-to-date ❤️ |
…bservability Master's 3.6.2/3.6.3 added per-step debug process-time logging to setProfile (#201, #202) to investigate the same latency problem this branch fixes. Resolution keeps this branch's version of the transform: the gated setProfile.timings telemetry covers the same steps with one log line per slow/failed/sampled request instead of a debug line per step on every request, and master's wrapping had preserved the inactive-organization response-shape bug that this branch fixes. Also from master: @vtex/api 6.51.3 (no longer a delta of this branch) and version 3.6.3.
|
Resolved the conflicts with master (3.6.3). Two things reviewers should know about the resolution:
The earlier note about the Post-merge validation: |
There was a problem hiding this comment.
Pull request overview
Optimizes the session transform through parallel execution, two-layer caching, region handoff, and production telemetry while adding regression coverage.
Changes:
- Adds shared VBase plus per-pod memory caching for frequently accessed resources.
- Moves nonessential cart updates off the response path and introduces optional downstream region resolution.
- Adds configurable timing telemetry, cache statistics, documentation, and Jest coverage.
Reviewed changes
Copilot reviewed 36 out of 37 changed files in this pull request and generated 7 comments.
Show a summary per file
| File | Description |
|---|---|
vtex.session/configuration.json |
Adds locality outputs. |
node/utils/staleFromVBaseWhileRevalidate.ts |
Implements VBase stale-while-revalidate. |
node/utils/requestTimings.ts |
Adds request timing utilities. |
node/utils/constants.ts |
Defines cache policies. |
node/typings/staleFromVBaseWhileRevalidate.ts |
Types cached VBase data. |
node/services/sessionWatcherCache.ts |
Caches watcher settings. |
node/services/salesChannelCache.ts |
Caches sales channels. |
node/services/rolesCache.ts |
Caches roles. |
node/services/regionCache.ts |
Caches region lookups. |
node/services/organizationsCache.ts |
Caches organization resources. |
node/services/cache.ts |
Provides the shared cache abstraction. |
node/services/appSettingsCache.ts |
Adds cross-pod settings caching. |
node/services/activeUserCache.ts |
Caches active-user lookups. |
node/service.json |
Increases service resources and lifetime. |
node/resolvers/Routes/index.ts |
Restructures session and permission routes. |
node/resolvers/Queries/Roles.ts |
Uses cached role retrieval. |
node/package.json |
Adds Jest dependencies and scripts. |
node/middlewares/withRequestTimings.ts |
Emits timing and cache telemetry. |
node/jest.config.js |
Configures TypeScript tests. |
node/index.ts |
Registers timing middleware. |
node/.vtexignore |
Excludes test assets. |
node/__tests__/withRequestTimings.test.ts |
Tests timing middleware. |
node/__tests__/stubs/diagnostics.js |
Stubs diagnostics for Jest. |
node/__tests__/staleFromVBaseWhileRevalidate.test.ts |
Tests VBase cache behavior. |
node/__tests__/setProfile.test.ts |
Tests session-transform behavior. |
node/__tests__/requestTimings.test.ts |
Tests timing utilities. |
node/__tests__/checkPermissions.test.ts |
Tests permission caching. |
node/__tests__/cache.test.ts |
Tests cache isolation and bounds. |
manifest.json |
Adds caching, region, and telemetry settings. |
docs/REGION_RESOLUTION.md |
Documents region resolution. |
docs/README.md |
Indexes technical documentation. |
docs/PERFORMANCE_AND_CACHING.md |
Documents performance architecture. |
docs/OBSERVABILITY.md |
Documents operational signals. |
docs/COST_CENTER_ADDRESS_AND_REGION.md |
Links region-handoff guidance. |
CHANGELOG.md |
Records the release changes. |
.vtexignore |
Excludes Node test assets globally. |
Suppressed comments (2)
node/resolvers/Routes/index.ts:327
- The fetcher catches a Master Data failure and resolves
undefined, which makesgetCachedOrganizationtreat the failure as a value and persist it in memory/VBase. Subsequent requests can keep failing atorganization.statusafter Master Data recovers; catch after the cached call so rejected origin reads are never stored.
return getCachedOrganization(ctx, String(orgId), () =>
masterDataExtended
.getDocumentById('organizations', orgId, [
'name',
'tradeName',
'status',
'priceTables',
'salesChannel',
'collections',
'sellers',
])
.catch((error) => {
logger.error({
error,
message: 'setProfile.graphqlGetOrganizationById',
})
})
node/resolvers/Routes/index.ts:281
- Like the sales-channel lookup, this promise is abandoned by the early return for users without an organization/cost center. An Apps API rejection then escapes as an unhandled promise rejection; attach a handler immediately without replacing the original promise that is awaited on the normal path.
const appSettingsPromise = timer.track(
'getCachedAppSettings',
getCachedAppSettings(ctx)
)
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
- Inactive-organization recovery fetched the organizations document with the b2b_users record id instead of the organization id, which still resolved to undefined and preserved the 500 this branch fixes. It also kept stamping the response and cart with the inactive organization's data; the fallback is now adopted locally (user, session fields, hash, cost center refetch) so the same request reflects the activated org. - getActiveUserByEmail resolves Master Data failures into an error sentinel; the fetcher now rethrows it so neither cache layer stores an outage as a valid user (which produced empty B2B sessions until the TTL expired). Failures are handled outside the cached call so they are retried, in both setProfile and checkPermissions. - The user-independent promises started before the early-return user checks now get an immediate rejection observer, so an early return can no longer leave an unhandled rejection. - sessionUserCacheTtlMs is stored per account/workspace instead of process-globally (a pod serves multiple tenants), and setting it to 0 now bypasses the VBase layer too, matching its documentation. - Tests: the inactive-org mock is id-exact so the wrong-id lookup fails the suite; the recovery test asserts the response is stamped with the activated organization; the CL-profile test now actually reaches the hanging cart update instead of passing vacuously.
…ter Data failures are never cached as users
…overy Three findings from a deep review of the branch: - A transient organization lookup failure resolved to undefined and was stored by both cache layers, turning one Master Data blip into minutes of errors served from cache. The fetcher now rethrows, so a failure fails only its own request and the next one retries. - A user lookup that found no B2B user was cached for the full TTL, pinning shoppers hit by replication lag (e.g. right after being added to an organization) to an empty B2B session. Misses now bypass the cache in both setProfile and checkPermissions, restoring the pre-cache behavior for non-B2B shoppers. - The inactive-organization recovery adopted the fallback org but kept hashChanged computed against the old organization, so a session whose hash matched the inactive org skipped the clearCart branch despite the shopper moving organizations. hashChanged is now recomputed from the adopted organization. Each fix carries a regression test (44 total).
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 36 out of 37 changed files in this pull request and generated 3 comments.
Suppressed comments (5)
Previously missed (2) — in code that hasn't changed since the last review.
node/resolvers/Routes/index.ts:797
- This handoff is still inside the enclosing
if (selectedAddress && orderFormId). When a session has a selected cost-center address but no order form, enabling the flag publishes neitherpostalCodenorcountryand leaves the default emptyregionId, so checkout-session/search-session cannot perform the documented handoff. Separate the session output logic from cart mutations and guard only the checkout API updates withorderFormId.
if (hashChanged && orderFormId) {
try {
const b2bSettingsResponse = await b2bSettingsPromise
const b2bSettings = (b2bSettingsResponse as any)?.data?.getB2BSettings
node/resolvers/Routes/index.ts:805
- These fields become persistent session state, but no non-deferred/fallback path clears values previously written by this branch (omitting a key preserves it—the code relies on that behavior for
regionId). After the flag is disabled, the address loses a postal code, or the user moves to a cost center without an address,vtex.search-sessioncan therefore keep using the old cost center's locality. Clear app-owned locality when deferral no longer applies, while preserving values only for an active shopper region overwrite.
if (clearCart) {
await timer.track(
'updateSalesChannel',
Promise.all(salesChannelPromise)
node/resolvers/Routes/index.ts:501
- The fallback switches only
orgIdandcostId;validOrganization.idis the fallbackb2b_usersrecord ID, butuser.idand the already-populated sessionuserIdstill identify the inactive record. The latergetB2BUserById(user.id)can consequently select the old organization's price table. Adopt the fallback record ID as well and restampstorefront-permissions.userId.
getUserOrganizationsData(email, ctx).catch((error) => {
logger.error({
error,
node/resolvers/Routes/index.ts:504
- The response hash is changed to the fallback organization here, but
hashChangedremains the comparison against the original inactive organization. If the incoming hash matched that old value, the laterif (hashChanged && orderFormId)skips the configured cart clear even though the organization actually changed. RecomputehashChangedfrom the fallback hash before the clear-cart branch (and use that updated value in timing metadata).
message: 'setProfile.getUserOrganizationsData',
})
node/resolvers/Routes/index.ts:381
- This promise is permanently keyed to the original user's cost center before the inactive-organization recovery runs. When recovery switches to another cost center, the marketing update later combines the fallback
utmMediumwith tags fetched for the inactive cost center. Fetch the tags from the finalized cost-center ID, or replace this promise when the fallback is adopted.
'status',
'priceTables',
'salesChannel',
'collections',
- Clone the cached active user before request-local fallback branches reassign orgId/costId on it: the LRU hands out the same reference, so those mutations corrupted the shared cache entry under its original key for every later request. - Roles cache TTL lowered from 5 minutes to 60 seconds: saveRole and deleteRole write VBase but cannot invalidate other pods' memory caches, so the TTL is the upper bound on how long a revoked permission stays effective. Documented in the caching doc. - (The third finding - organization lookup failures being cached - was already fixed in 022dd8c; that review ran against the previous head.)
Never cache failures, never cache transient misses, never mutate cached objects - each rule grounded in the concrete bug both review rounds found and pointing at the regression test that guards it.
…rors - Resolve the active B2B record with an active=true filtered Master Data query (0..1 records, single call) instead of paginating every record for the email and falling back to an arbitrary users[0] - Keep the organization and cost center the session already carries: storefront-permissions.organization/costcenter become transform inputs (same pattern as hash) resolved through targeted single-call lookups, so the resolution no longer drifts between requests - Evaluate organization status in one module mirroring b2b-organizations (only 'active' is usable); unknown statuses fail closed and are reported - Sanitize the characters checkout rejects (CHK0040) from the two annotation address fields (reference, complement); location-bearing fields are reported via CART_ADDRESS_FIELD_REJECTED and never rewritten, established by probing which of the 13 address fields checkout validates - Route all 63 error logs through describeClientError: keeps message, codes, status and the correlation ids VTEX backends answer with (operationId, requestId, backend), never the request body or query string - Organization lookups tolerate a hard 404 (document gone) without caching the miss, and the recovery path validates the fallback before adopting it - Docs: organization-data source rationale with measurements, new observability signals, and a public-repo hygiene pass over comments/docs
New commit: organization resolution, cart address handling, and log hygiene
Organization resolution
Cart address (CHK0040)
Log hygiene
Countable signals
75+ unit tests cover the above; the key regression tests were verified to fail against the previous logic. |
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 56 out of 57 changed files in this pull request and generated 8 comments.
Suppressed comments (1)
node/resolvers/Routes/utils/index.ts:279
- The recovery candidate is selected solely by organization status. A record can reference an active organization while its cost center has been deleted, in which case recovery stamps that deleted
costIdand receives an empty cost-center response. Require a non-nullcostCenterNamewhen selecting the candidate.
- Route the active-user lookup failure log through describeClientError (the one catch the sweep missed, key-at-end form) - Redact emails from the described stack: its first line repeats the error message, which survived truncation unredacted - staleFromVBase logs reference the hashed storage key, never the logical key - the active-user key contains the shopper's email - Validate the fallback organization's status before recovery adopts it: a stale list nomination could recover into another unusable organization - Recovery also adopts the record id and restamps userId, so the price-table lookup and the emitted userId agree with the adopted pair - Start the marketing-tags lookup after recovery, from the final cost center id, so a recovered session tags the cart for the right pair - getUserOrganizationsData only nominates a record whose usable organization and live cost center come from the *same* record, both in the early-stop check and in the selection - Region handoff cart guard documented as a deliberate parity limitation
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 57 out of 58 changed files in this pull request and generated 4 comments.
Suppressed comments (5)
Previously missed (4) — in code that hasn't changed since the last review.
node/resolvers/Routes/index.ts:1039
- When this condition becomes false after a previous successful handoff (for example, the next address has no postal code or the setting is disabled), the response never clears the
public.postalCode/countryvalues that this branch previously wrote. Session merging retains those old values, so search-session continues regionalizing against the previous cost-center address even while this app falls back to a different region/address. Add an ownership-aware cleanup path for locality values when handoff is no longer active, without clearing shopper-provided overwrite values.
node/services/activeUserCache.ts:46 - Updating this map does not change
maxAgeon entries already present incachedActiveUser;createCachedResourceapplies the per-call TTL only when inserting a miss. Lowering a tenant's nonzero TTL therefore does not apply on the next request as documented—an entry inserted under the old five-minute value can continue being served for five minutes. Invalidate that tenant's existing entries or version the cache key when its configured TTL changes.
manifest.json:189 - This setting accepts negative thresholds, and
totalMs >= thresholdthen marks every transform as slow, generating a warning on this high-volume route. Constrain the schema to nonnegative values so a malformed setting cannot flood the log pipeline.
This issue also appears on line 190 of the same file.
"sessionTimingsSlowThresholdMs": {
"title": "Session timings slow threshold (ms)",
"description": "When a session transform (setProfile) takes at least this many milliseconds, a 'setProfile.timings' warning is logged with the duration of every external call, so the bottleneck can be identified in production. Defaults to 1000ms.",
"type": "number",
"default": 1000
node/resolvers/Routes/index.ts:1044
- Deleting this output key does not remove an existing
public.regionIdfrom the session; this file already relies on omission preserving prior values forsc(lines 982-986). After this flag is enabled, checkout-session can therefore keep short-circuiting on the region written by an earlier transform instead of resolving from the newly published locality, especially after an address switch. Emit the empty value used by the existing postal-code overwrite path so downstream resolution is actually triggered.
manifest.json:194
- The implementation uses this value directly in
Math.random() < sampleRate; values above 1 therefore sample every healthy request and can flood logs, while negative values silently disable sampling. Enforce the documented 0–1 fraction in the settings schema.
"sessionTimingsSampleRate": {
"title": "Session timings sample rate",
"description": "Fraction (0 to 1) of non-slow session transforms that also log their timings, to establish a baseline. Keep low on high-traffic accounts: 0.01 logs 1% of requests. Defaults to 0 (only slow requests are logged).",
"type": "number",
"default": 0
The builder compiles with noImplicitAny under an older TypeScript that cannot infer the type of `let user = null` through its reassignments, and the fire-and-forget catch closures that capture `user` turn that gap into TS7034/TS7005 build errors. Local tsc accepts it, which is why CI's vtexio/build was the first to fail. Reproduced and verified against the real builder via a linked workspace.
- Tenant-scope getUserOrganizationsData's module-level cache: keyed only by email, a pod serving two accounts could hand one account's organization ids to the same email on the other - Route the three remaining raw client-error sites through describeClientError (two logger calls with the error key at the end, plus changeTeam's console.warn, whose payload carries the user email) - Validate the session-pinned cost center before recovery adopts the pinned pair: a deleted cost center would replace the validated list candidate with a broken pair - setProfile.regionIdSkipped reports postal-code presence, never the value
Summary
setProfile(thevtex.sessiontransform) runs several times per storefront navigation on every B2B account and has a hard 2s budget from Session Manager. It was running a serial chain of uncached external calls, so cold pods regularly timed out (confirmed at Kohler and visible as errors across other accounts in OpenSearch).This PR restructures the transform, adds caching, fixes a production 500, and adds the observability to diagnose future incidents per account without redeploying.
Performance
getOrganization+getCostCenterByIdwait for the user.getMarketingTagsandgenerateClUsermoved off the critical path entirely — they only feed fire-and-forget cart updates (generateClUsermeasured spikes near 1s).node/services/cache.ts): per-pod LRU (warm pod = zero I/O) + cross-pod VBase stale-while-revalidate (cold pod reads what a sibling populated). Applied to app settings, sales channel list, B2B settings, organization, cost center, active user, region lookup; memory-only for the VBase-sourced session watcher and roles. The cost-center cache is bounded by bytes (documents measured 400B–29KB, a 70x spread). Full rationale indocs/PERFORMANCE_AND_CACHING.md.public.b2bCurrentCostCenter(written bysetCurrentOrganizationon every switch), so switching organizations invalidates by key, not TTL.checkPermissions(called per request by sibling B2B apps) now resolves the user through a 60s memory-only cache.Bug fix
Users whose organization is inactive but who have another active organization received a 500 on the exact path meant to recover them: the recovery branch still unwrapped
.data.getOrganizationById(the old GraphQL client shape) after the Master Data client migration, resolvingorganizationtoundefinedand throwing onorganization.name. Fixed; the regression test was verified to fail against the old code with the exact productionTypeError.New app settings (all default off / backward compatible)
deferRegionToCheckoutSessionfalsepublic.postalCode/country) and letvtex.checkout-sessionresolvecheckout.regionId(same lookup, cached downstream). Also makesvtex.search-sessionregionalize search with the same address the cart uses. Falls back to local resolution without a postal code; stands down when region overwrite is active. Seedocs/REGION_RESOLUTION.md.logSessionPayloadsfalseJSON.stringify+ PII in logs).sessionTimingsSlowThresholdMs1000sessionTimingsSampleRate0sessionUserCacheTtlMs300000Observability
withRequestTimingsmiddleware: onesetProfile.timingslog with per-step durations when slow, sampled, or — always — when the transform throws (failed: true).cacheStatshit-rate/size line per pod every 5 minutes.staleFromVBase.readError/saveError/revalidateError) — previously a dead origin behind a warm cache was invisible.docs/OBSERVABILITY.md.Infra
service.jsonaligned with the suite profile already used byb2b-organizations-graphqlandb2b-checkout-settings: memory 256→1024, ttl 60→300, timeout 45→60.workers: 1kept deliberately (each worker would duplicate the caches).Tests
New jest suite, 41 tests / 6 suites: cache layers (tenant isolation, byte bounds, TTL bypass), SWR semantics incl. failure logging, timings middleware (failure path rethrows and always logs),
checkPermissionscache, andsetProfilebehaviors (sales-channel deferral, region handoff + fallbacks, org-switch invalidation, payload-log gating, watcher kill switch, inactive-org recovery). Tests are excluded from the app bundle via.vtexignore.Notes for reviewers
@vtex/apiwas bumped 6.50.1 → 6.51.3 byvtex linkduring development and is included here — flag if you'd rather it land separately.vtex release; CHANGELOG is under[Unreleased].docs/SALES_CHANNEL_NULL_ORG_WORKAROUND.mdwas a stale working draft superseded bySALES_CHANNEL_BINDING_COEXISTENCE.mdand is not included.Test plan
yarn jest— 41/41 greentsc --noEmitclean; tslint at 94 errors vs 99 on master (no new violations, several pre-existing ones fixed)kohlerqa/scdebug), builder compiles clean, transform responds 200 with output byte-identical to v3.6.1 with flags offscomitted underdeferSalesChannelToBinding;postalCode/countrypublished and regions API skipped underdeferRegionToCheckoutSession