diff --git a/.env.example b/.env.example index 1f98f40..eecd54a 100644 --- a/.env.example +++ b/.env.example @@ -142,3 +142,10 @@ INDEXER_MAX_POLL_INTERVAL_MS=300000 INDEXER_BACKOFF_FACTOR=2 # INDEXER_LAG_ALERT_THRESHOLD: ledgers behind the tip before lag is alerted. Default: 100. INDEXER_LAG_ALERT_THRESHOLD=100 + +# Time handling (issue #494) +# All instants are created, stored and compared in UTC, and serialized in API +# responses as ISO-8601 strings with a Z suffix. TZ pins the process default; +# the application sets it to UTC itself when this is unset, and remains +# correct even if it is overridden (see README.md#time-handling). +TZ=UTC diff --git a/Dockerfile b/Dockerfile index 3530316..96bb559 100644 --- a/Dockerfile +++ b/Dockerfile @@ -1,5 +1,8 @@ # --- Base & Development Stage --- FROM node:20-alpine AS development +# Issue #494 — all instants are UTC; pin the container default explicitly so +# log rotation filenames and any date the runtime formats are UTC too. +ENV TZ=UTC WORKDIR /app # Instalar dependencias completas (incluye devDependencies para nodemon/hot-reload) @@ -27,6 +30,8 @@ COPY public ./public FROM node:20-alpine AS production WORKDIR /app ENV NODE_ENV=production +# Issue #494 — UTC process default (see development stage above). +ENV TZ=UTC COPY --from=builder /app/node_modules ./node_modules COPY --from=builder /app/src ./src diff --git a/README.md b/README.md index 29d6d73..281f2e1 100644 --- a/README.md +++ b/README.md @@ -304,6 +304,24 @@ Each price source (`stellar_dex`, `coingecko`, `coinmarketcap`) gets one circuit | `API_KEY_RATELIMIT_ADMIN_MAX` | Requests per window for `admin`-tier keys | 10000 | No | +--- + +## Time handling + +All instants are created, computed, compared and stored in **UTC**, and serialized in API responses as ISO-8601 strings with a `Z` suffix (e.g. `2026-06-30T19:00:00.000Z`). Local time is a presentation concern: clients convert a UTC value to their own zone. The server does not accept or emit local times. + +- Shared helpers live in `src/utils/dates.js` (`nowIso`, `toIso`, `startOfUtcDay`, `utcDayKey`). +- Day-boundary logic (daily limits, expiries, "today" queries) must use `utcDayKey()`/`startOfUtcDay()` — never a slice of a local-time string. +- PostgreSQL sessions are pinned to UTC (`SET TIME ZONE 'UTC'` on every pooled connection), and every timestamp column is `TIMESTAMPTZ`. +- Log file rotation (`winston-daily-rotate-file`) uses `utc: true`, so filenames and retention are bucketed by UTC date regardless of the host's time zone. +- `TZ` is set to `UTC` by default (in `Dockerfile`/`docker-compose`, and defensively at process start when unset). This is **not** the fix for time-zone bugs — it only provides a stable default, and the code stays correct if it is overridden. `TZ` is reported in the startup banner as `time_zone`. + +Regression coverage: `test/timezone.test.js` runs the date helpers under `TZ=UTC`, `TZ=America/New_York` and `TZ=Asia/Tokyo` and asserts identical UTC results. + +| Variable | Description | Default | Required | +| --- | --- | --- | --- | +| `TZ` | Process time zone. The app sets `UTC` when unset and warns if set to a non-UTC zone. | `UTC` | No | + --- ## Observability diff --git a/docker-compose.yml b/docker-compose.yml index 6165086..b64e1d5 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -7,6 +7,8 @@ services: - "4000:4000" environment: - PORT=4000 + # Issue #494 — UTC process default; all instants are stored/serialized in UTC. + - TZ=UTC - REDIS_URL=redis://redis:6379 - REDIS_HOST=redis - REDIS_PORT=6379 diff --git a/knexfile.js b/knexfile.js index 3b1e0d4..de2b7c7 100644 --- a/knexfile.js +++ b/knexfile.js @@ -28,23 +28,32 @@ function connectionFor(fallback) { return process.env.DATABASE_URL || fallback; } +// Issue #494 — migrations and ad-hoc knex CLI queries must render timestamps +// in UTC too, not in the database server's local zone. Runs per pooled +// connection. +function afterCreateUtcConnection(conn, done) { + conn.query("SET TIME ZONE 'UTC'", (err) => done(err, conn)); +} + module.exports = { development: { client: 'pg', connection: connectionFor('postgres://localhost/smartdrop'), + pool: { min: 2, max: 10, afterCreate: afterCreateUtcConnection }, migrations, }, test: { client: 'pg', connection: connectionFor('postgres://localhost/smartdrop_test'), + pool: { min: 2, max: 10, afterCreate: afterCreateUtcConnection }, migrations, }, production: { client: 'pg', connection: connectionFor(undefined), - pool: { min: 2, max: 10 }, + pool: { min: 2, max: 10, afterCreate: afterCreateUtcConnection }, migrations, }, }; diff --git a/src/auth/cookies.js b/src/auth/cookies.js new file mode 100644 index 0000000..47a4854 --- /dev/null +++ b/src/auth/cookies.js @@ -0,0 +1,99 @@ +'use strict'; + +// Issue #496 — Secure cookie helpers. +// No cookies are set anywhere in the codebase today. However, future +// authenticated UI/admin sessions must use these helpers so the flags are +// applied consistently: +// - Secure: only over HTTPS (production). In dev/test HTTP is allowed but +// still constrained by SameSite (and trust proxy affects req.secure). +// - HttpOnly: prevents JS access to auth/session cookies. +// - SameSite: 'Strict' by default to mitigate CSRF for same-site flows; use +// 'Lax' only when cross-site GET redirects are necessary. +// - Path: scoped to '/'. +// - Max-Age/Expires: set explicitly (no session cookies by default). +// +// The decision to *not* force Secure in non-prod is deliberate so local +// development over http://localhost works. Trust proxy must be configured +// (app.set('trust proxy', ...)) when running behind a reverse proxy/load +// balancer; without it, req.secure remains false even if the client connected +// via TLS to the proxy. + +const config = require('../config'); + +const DEFAULT_SAME_SITE = 'Strict'; +const DEFAULT_PATH = '/'; + +function isSecure(req) { + // req.secure is true only if the request was made over HTTPS. If the app is + // behind a proxy, trust proxy must be enabled for this to reflect the + // original protocol. + if (req && req.secure) return true; + if (req && req.headers && req.headers['x-forwarded-proto']) { + return String(req.headers['x-forwarded-proto']).toLowerCase() === 'https'; + } + // Production default is to require Secure where possible; still, if no + // indicator is present, fall back to config flag (dev/test). + return config.nodeEnv === 'production'; +} + +function getCookieDomain(domain) { + if (domain) return domain; + return undefined; +} + +function buildCookieOptions(options = {}) { + const { + req, + maxAgeMs, + expires, + sameSite = DEFAULT_SAME_SITE, + path = DEFAULT_PATH, + domain, + httpOnly = true, + secure, + } = options; + + const secureFlag = typeof secure === 'boolean' ? secure : isSecure(req); + const opts = { + httpOnly, + secure: secureFlag, + sameSite, + path, + }; + + const resolvedDomain = getCookieDomain(domain); + if (resolvedDomain) opts.domain = resolvedDomain; + + if (Number.isFinite(maxAgeMs)) { + opts.maxAge = Math.trunc(maxAgeMs); + } + if (expires instanceof Date) { + opts.expires = expires; + } + return opts; +} + +function setCookie(res, name, value, options = {}) { + if (!res || typeof res.cookie !== 'function') { + throw new Error('res.cookie is not available'); + } + const opts = buildCookieOptions(options); + res.cookie(name, value, opts); +} + +function clearCookie(res, name, options = {}) { + if (!res || typeof res.clearCookie !== 'function') { + throw new Error('res.clearCookie is not available'); + } + const opts = buildCookieOptions({ ...options, maxAgeMs: 0, expires: new Date(0) }); + res.clearCookie(name, opts); +} + +module.exports = { + buildCookieOptions, + setCookie, + clearCookie, + isSecure, + DEFAULT_SAME_SITE, + DEFAULT_PATH, +}; diff --git a/src/config.js b/src/config.js index 87fc9c7..60589f6 100644 --- a/src/config.js +++ b/src/config.js @@ -139,6 +139,14 @@ const env = cleanEnv(rawEnv, { API_KEY_RATELIMIT_FREE_MAX: positiveInteger({ default: 100 }), API_KEY_RATELIMIT_PRO_MAX: positiveInteger({ default: 1000 }), API_KEY_RATELIMIT_ADMIN_MAX: positiveInteger({ default: 10000 }), + // Issue #495 — cache warming startup behavior + CACHE_WARM_ENABLED: str({ default: 'true' }), + CACHE_WARM_TIMEOUT_MS: num({ default: 30000 }), + CACHE_WARM_ENTRY_TIMEOUT_MS: num({ default: 10000 }), + CACHE_WARM_MAX_ENTRIES: num({ default: 500 }), + CACHE_WARM_CONCURRENCY: num({ default: 8 }), + CACHE_WARM_JITTER_MS: num({ default: 0 }), + CACHE_WARM_LOCK_TTL_MS: num({ default: 60000 }), }); const usdcIssuer = env.USDC_ISSUER; @@ -306,11 +314,32 @@ const config = module.exports = { max: parseInt(process.env.WEBHOOK_TEST_RATELIMIT_MAX, 10) || 5, }, orderedDelivery: process.env.WEBHOOK_ORDERED_DELIVERY === 'true', + shutdownDrainMs: parseInt(process.env.WEBHOOK_RETRY_SHUTDOWN_DRAIN_MS, 10) || 2000, + leaseMs: parseInt(process.env.WEBHOOK_RETRY_LEASE_MS, 10) || 300000, + recoverBatch: parseInt(process.env.WEBHOOK_RETRY_RECOVER_BATCH, 10) || 100, + dlqMax: parseInt(process.env.WEBHOOK_DLQ_MAX, 10) || 10000, + deliveryTtlSeconds: parseInt(process.env.WEBHOOK_DELIVERY_TTL_SECONDS, 10) || 2592000, }, ws: { maxConnections: parseInt(process.env.WS_MAX_CONNECTIONS, 10) || 100, maxConnectionsPerIp: parseInt(process.env.WS_MAX_CONNECTIONS_PER_IP, 10) || 5, }, + cacheWarm: { + enabled: (process.env.CACHE_WARM_ENABLED || 'true').toLowerCase() !== 'false', + timeoutMs: parseInt(process.env.CACHE_WARM_TIMEOUT_MS, 10) || 30000, + entryTimeoutMs: parseInt(process.env.CACHE_WARM_ENTRY_TIMEOUT_MS, 10) || 10000, + maxEntries: parseInt(process.env.CACHE_WARM_MAX_ENTRIES, 10) || 500, + concurrency: parseInt(process.env.CACHE_WARM_CONCURRENCY, 10) || 8, + jitterMs: parseInt(process.env.CACHE_WARM_JITTER_MS, 10) || 0, + lockTtlMs: parseInt(process.env.CACHE_WARM_LOCK_TTL_MS, 10) || 60000, + }, + trustProxy: (process.env.TRUST_PROXY || 'false').toLowerCase() === 'true', + cookies: { + secure: (process.env.COOKIE_SECURE || 'auto').toLowerCase(), + sameSite: (process.env.COOKIE_SAME_SITE || 'Strict'), + path: (process.env.COOKIE_PATH || '/'), + domain: process.env.COOKIE_DOMAIN || undefined, + }, }; @@ -367,11 +396,19 @@ function reload() { SLOW_REQUEST_THRESHOLD_MS: num({ default: 1000 }), ROUTE_TIMEOUT_MS: num({ default: 30000 }), API_KEY_RATELIMIT_WINDOW_SECONDS: positiveInteger({ default: 60 }), - API_KEY_RATELIMIT_FREE_MAX: positiveInteger({ default: 100 }), - API_KEY_RATELIMIT_PRO_MAX: positiveInteger({ default: 1000 }), - API_KEY_RATELIMIT_ADMIN_MAX: positiveInteger({ default: 10000 }), - BCRYPT_ROUNDS: positiveInteger({ default: 12 }), - }); + API_KEY_RATELIMIT_FREE_MAX: positiveInteger({ default: 100 }), + API_KEY_RATELIMIT_PRO_MAX: positiveInteger({ default: 1000 }), + API_KEY_RATELIMIT_ADMIN_MAX: positiveInteger({ default: 10000 }), + BCRYPT_ROUNDS: positiveInteger({ default: 12 }), + CACHE_WARM_ENABLED: str({ default: 'true' }), + CACHE_WARM_TIMEOUT_MS: num({ default: 30000 }), + CACHE_WARM_ENTRY_TIMEOUT_MS: num({ default: 10000 }), + CACHE_WARM_MAX_ENTRIES: num({ default: 500 }), + CACHE_WARM_CONCURRENCY: num({ default: 8 }), + CACHE_WARM_JITTER_MS: num({ default: 0 }), + CACHE_WARM_LOCK_TTL_MS: num({ default: 60000 }), +}); + const reloadedUsdcIssuer = reloaded.USDC_ISSUER; const reloadedWatchedAssets = Array.isArray(reloaded.WATCHED_ASSETS) @@ -417,14 +454,32 @@ function reload() { corsMaxAgeSeconds: reloaded.CORS_MAX_AGE_SECONDS, watchedAssets: reloadedWatchedAssets, webhooks: { - ...config.webhooks, - maxAttempts: parseInt(process.env.WEBHOOK_MAX_ATTEMPTS, 10) || 3, - retryBaseMs: parseInt(process.env.WEBHOOK_RETRY_BASE_MS, 10) || 30000, - retryFactor: parseFloat(process.env.WEBHOOK_RETRY_FACTOR) || 2, - timeoutMs: parseInt(process.env.WEBHOOK_TIMEOUT_MS, 10) || 5000, - }, - LOG_LEVEL: reloaded.LOG_LEVEL, - }); + ...config.webhooks, + maxAttempts: parseInt(process.env.WEBHOOK_MAX_ATTEMPTS, 10) || 3, + retryBaseMs: parseInt(process.env.WEBHOOK_RETRY_BASE_MS, 10) || 30000, + retryFactor: parseFloat(process.env.WEBHOOK_RETRY_FACTOR) || 2, + timeoutMs: parseInt(process.env.WEBHOOK_TIMEOUT_MS, 10) || 5000, + }, + cacheWarm: { + ...config.cacheWarm, + enabled: (process.env.CACHE_WARM_ENABLED || 'true').toLowerCase() !== 'false', + timeoutMs: parseInt(process.env.CACHE_WARM_TIMEOUT_MS, 10) || 30000, + entryTimeoutMs: parseInt(process.env.CACHE_WARM_ENTRY_TIMEOUT_MS, 10) || 10000, + maxEntries: parseInt(process.env.CACHE_WARM_MAX_ENTRIES, 10) || 500, + concurrency: parseInt(process.env.CACHE_WARM_CONCURRENCY, 10) || 8, + jitterMs: parseInt(process.env.CACHE_WARM_JITTER_MS, 10) || 0, + lockTtlMs: parseInt(process.env.CACHE_WARM_LOCK_TTL_MS, 10) || 60000, + }, + trustProxy: (process.env.TRUST_PROXY || 'false').toLowerCase() === 'true', + cookies: { + secure: (process.env.COOKIE_SECURE || 'auto').toLowerCase(), + sameSite: (process.env.COOKIE_SAME_SITE || 'Strict'), + path: (process.env.COOKIE_PATH || '/'), + domain: process.env.COOKIE_DOMAIN || undefined, + }, + LOG_LEVEL: reloaded.LOG_LEVEL, +}); + return config; } diff --git a/src/database/index.js b/src/database/index.js index f48cd65..993fc3a 100644 --- a/src/database/index.js +++ b/src/database/index.js @@ -20,13 +20,24 @@ let db = null; * @param {Object} [overrideConfig] - Optional configuration overrides (useful for testing) * @returns {import('knex').Knex} */ +// Issue #494 — every timestamp column is TIMESTAMPTZ, and all application +// code stores/compares UTC. Pinning the session TimeZone to UTC as well means +// anything the database renders itself in a text form (to_char, ::date, +// CURRENT_TIMESTAMP without a zone, a query typed by hand) is UTC too, rather +// than following the server's local zone. A pool `afterCreate` hook runs for +// every pooled connection, not just the first. +function afterCreateUtcConnection(conn, done) { + conn.query("SET TIME ZONE 'UTC'", (err) => done(err, conn)); +} + function getDb(overrideConfig = {}) { if (!db) { + const pool = { min: 2, max: 10, afterCreate: afterCreateUtcConnection, ...(overrideConfig.pool || {}) }; db = knexFactory({ client: 'pg', connection: overrideConfig.connection || config.databaseUrl, - pool: overrideConfig.pool || { min: 2, max: 10 }, ...overrideConfig, + pool, }); defaultPoolMonitor.attach(db); } diff --git a/src/index.js b/src/index.js index 23889d4..0ae7c7a 100644 --- a/src/index.js +++ b/src/index.js @@ -1,6 +1,15 @@ "use strict"; +// Issue #494 — establish a UTC default for the process before anything +// formats a date. This is a defensive default only: every timestamp the app +// emits is built from toISOString()/UTC math (src/utils/dates.js), so +// behaviour must not depend on this line. The primary fix is the TZ=UTC +// environment in Dockerfile/docker-compose; see README.md#time-handling. +const { assertUtcTimeZone } = require("./utils/dates"); +const timeZoneState = assertUtcTimeZone(); + const express = require("express"); +const config = require("./config"); const compression = require("compression"); const helmet = require("helmet"); const config = require("./config"); @@ -14,7 +23,7 @@ const airdropExpiryJob = require("./jobs/airdropExpiry"); const jobQueue = require("./services/jobQueue"); const { createLeaderElection } = require("./services/leaderElection"); const { makeLeaderAwareJob } = require("./jobs/leaderAwareJob"); -const { warmCache } = require("./startup/cacheWarm"); +const { warmCacheInBackground, getWarmStatus } = require("./startup/cacheWarm"); const buildCorsMiddleware = require("./middleware/cors"); const { buildRateLimit, @@ -83,6 +92,14 @@ const wrappedAirdropExpiryJob = makeLeaderAwareJob({ }); const app = express(); + +// Issue #496 — secure cookies require trust proxy to reflect original +// protocol when behind a load balancer/reverse proxy. Default is `false` +// (explicit, to avoid rate-limit/IP spoofing if ever used). The config +// exposes TRUST_PROXY; enable only if the deployment is proxy-fronted. +if (typeof config.trustProxy === 'boolean') { + app.set('trust proxy', config.trustProxy); +} let server = { close(callback) { if (callback) callback(); @@ -209,6 +226,9 @@ app.get("/health", healthRateLimit, async (req, res) => { draining: subscriptionManager.isDraining, drain_stats: subscriptionManager.drainStats, }, + // Issue #495 — cache warm status is an optimization, not a readiness + // dependency (warming runs in the background). + cache_warm: getWarmStatus(), jobs: { price_refresh: { healthy: priceRefreshHealth.healthy, @@ -449,10 +469,24 @@ function logStartupBanner() { indexer_enabled: config.indexer.enabled, instance_id: config.leaderElection.instanceId, log_level: process.env.LOG_LEVEL || config.nodeEnv, + // Issue #494 — surface the process time zone so an operator can confirm + // the UTC default is in effect (or that they overrode it deliberately). + time_zone: process.env.TZ, }); } async function startServer() { + // Issue #494 — report a deliberately overridden, non-UTC process time zone. + // The code stays UTC-correct regardless (all instants use ISO-8601 Z), but + // a non-UTC default is worth a warning: anything that later relies on the + // environment default rather than the shared helpers will drift. + if (timeZoneState.isNonUtc) { + logger.warn( + "Process time zone is not UTC; dates are still handled in UTC (issue #494)", + { time_zone: timeZoneState.timeZone }, + ); + } + // Redis being unreachable at boot must not stop the process from coming up // (#342): everything below degrades to "no cached state" and recovers on // its own once ioredis reconnects. Say so once, explicitly, so an operator @@ -477,13 +511,24 @@ async function startServer() { ); } - try { - await warmCache(config.watchedAssets); - } catch (err) { + // Issue #495 — do NOT block listen on cache warming. Warm in the + // background with bounding (max entries, concurrency, per-entry timeout), + // Redis lock so only one replica warms at a time, jitter and TTL. + // The server can accept traffic immediately; /health exposes cache_warm. + warmCacheInBackground({ + assets: config.watchedAssets, + timeoutMs: config.cacheWarm.timeoutMs, + entryTimeoutMs: config.cacheWarm.entryTimeoutMs, + maxEntries: config.cacheWarm.maxEntries, + concurrency: config.cacheWarm.concurrency, + jitterMs: config.cacheWarm.jitterMs, + lockTtlMs: config.cacheWarm.lockTtlMs, + enabled: config.cacheWarm.enabled, + }).catch((err) => { logger.warn("Cache warm failed; starting server anyway", { error: err.message, }); - } + }); server = app.listen(config.port, () => { logStartupBanner(); diff --git a/src/jobs/leaderAwareJob.js b/src/jobs/leaderAwareJob.js index a215105..d56e191 100644 --- a/src/jobs/leaderAwareJob.js +++ b/src/jobs/leaderAwareJob.js @@ -169,7 +169,10 @@ function makeLeaderAwareJob({ job, jobName, leaderElection, logger }) { await trueStopRenewLoop(); if (underlyingStarted) { - job.stop(); + const result = job.stop(); + if (result && typeof result.then === 'function') { + await result; + } underlyingStarted = false; } diff --git a/src/jobs/webhookRetryWorker.js b/src/jobs/webhookRetryWorker.js index adf0fde..58bc86b 100644 --- a/src/jobs/webhookRetryWorker.js +++ b/src/jobs/webhookRetryWorker.js @@ -63,13 +63,14 @@ function start() { logger.info('Webhook retry worker started', { intervalMs: interval }); } -function stop() { +async function stop({ drainMs = config.webhooks.shutdownDrainMs || 2000 } = {}) { if (timer) { clearInterval(timer); timer = null; health.startedAt = null; logger.info('Webhook retry worker stopped'); } + return Promise.resolve(); } /** diff --git a/src/logger.js b/src/logger.js index 1725059..a854640 100644 --- a/src/logger.js +++ b/src/logger.js @@ -3,6 +3,7 @@ const DailyRotateFile = require('winston-daily-rotate-file'); const { name: serviceName, version } = require('../package.json'); const { requestContext } = require('./middleware/requestId'); const { redactFormat } = require('./services/logRedaction'); +const { nowIso } = require('./utils/dates'); // ==================== LOG LEVEL ==================== const getLogLevel = () => { @@ -45,7 +46,7 @@ const errorTrackerFormat = winston.format((info) => { // ==================== BASE FORMATS ==================== const baseFormats = [ - winston.format.timestamp({ format: () => new Date().toISOString() }), + winston.format.timestamp({ format: () => nowIso() }), winston.format.errors({ stack: true }), requestIdFormat(), redactFormat(), @@ -87,6 +88,11 @@ if (process.env.LOG_FILE_PATH) { new DailyRotateFile({ filename: `${process.env.LOG_FILE_PATH}/application-%DATE%.log`, datePattern: 'YYYY-MM-DD', + // Issue #494 — winston-daily-rotate-file resolves %DATE% from the host + // wall clock by default, so two servers in different time zones named + // (and rotated) the same UTC log window differently. utc: true pins the + // filename/rotation date to UTC. + utc: true, zippedArchive: true, maxSize: '20m', maxFiles: '14d', diff --git a/src/services/apiKeyAuditLog.js b/src/services/apiKeyAuditLog.js index b19d8f3..fbae921 100644 --- a/src/services/apiKeyAuditLog.js +++ b/src/services/apiKeyAuditLog.js @@ -1,5 +1,6 @@ const { getDb } = require('../database'); const logger = require('../logger'); +const { nowIso } = require('../utils/dates'); /** * Log API key usage to audit trail @@ -25,7 +26,10 @@ async function logUsage({ keyId, endpoint, ipAddress, statusCode, responseTimeMs ip_address: ipAddress, status_code: statusCode, response_time_ms: responseTimeMs, - created_at: new Date(), + // Issue #494 — serialize the instant in UTC explicitly. A bare Date + // relies on the driver/host time zone for its text form; the shared + // helper always emits ISO-8601 with a Z suffix. + created_at: nowIso(), }); } catch (err) { // Log the error but don't fail the request diff --git a/src/startup/cacheWarm.js b/src/startup/cacheWarm.js index cd15813..1d2504c 100644 --- a/src/startup/cacheWarm.js +++ b/src/startup/cacheWarm.js @@ -3,8 +3,33 @@ const config = require('../config'); const logger = require('../logger'); const priceOracle = require('../services/priceOracle'); +const cache = require('../services/cache'); const DEFAULT_TIMEOUT_MS = 30000; +const DEFAULT_ENTRY_TIMEOUT_MS = 10000; +const DEFAULT_MAX_ENTRIES = 500; +const DEFAULT_CONCURRENCY = 8; +const DEFAULT_LOCK_TTL_MS = 60000; +const WARM_LOCK_KEY = 'cache:warm:lock'; + +// Issue #495 — startup cache warming used to be awaited before app.listen(), +// so a slow upstream held the port closed for up to `timeoutMs` and every +// replica of a fleet hammered the price sources at the same instant. Warming +// is now fired in the background (the server accepts traffic immediately), +// bounded in breadth (maxEntries), in parallelism (concurrency), per call +// (entryTimeoutMs) and overall (timeoutMs), guarded by a Redis lock so only +// one replica warms at a time, and observable via getWarmStatus(). +const warmStatus = { + state: 'idle', + enabled: true, + reason: null, + lockSkipped: false, + startedAt: null, + finishedAt: null, + durationMs: null, + summary: null, + error: null, +}; function isWarmSuccess(result) { return ( @@ -15,43 +40,22 @@ function isWarmSuccess(result) { ); } -async function runWarmCache(assets, oracle, abortSignal) { - const startedAt = Date.now(); - const results = await Promise.allSettled( - assets.map(({ code, issuer }) => { - if (abortSignal && abortSignal.aborted) { - return Promise.reject(new Error('Warming cancelled')); - } - return Promise.resolve().then(() => oracle.fetchFreshPrice(code, issuer || null)); - }) - ); - const succeeded = results.filter(isWarmSuccess).length; - - return { - total: assets.length, - succeeded, - failed: assets.length - succeeded, - timedOut: false, - durationMs: Date.now() - startedAt, - }; +function assetKey(asset) { + return asset.issuer ? `${asset.code}:${asset.issuer}` : asset.code; } -async function warmCache( - assets = config.watchedAssets, - oracle = priceOracle, - { timeoutMs = DEFAULT_TIMEOUT_MS, log = logger } = {} -) { - let allAssets = Array.isArray(assets) ? [...assets] : []; +async function collectAssets(assets, oracle, log) { + const all = Array.isArray(assets) ? [...assets] : []; if (oracle && typeof oracle.getQueriedAssets === 'function') { try { const queried = await oracle.getQueriedAssets(); - const seen = new Set(allAssets.map((a) => (a.issuer ? `${a.code}:${a.issuer}` : a.code))); + const seen = new Set(all.map(assetKey)); for (const item of queried) { - const key = item.issuer ? `${item.code}:${item.issuer}` : item.code; + const key = assetKey(item); if (!seen.has(key)) { seen.add(key); - allAssets.push(item); + all.push(item); } } } catch (err) { @@ -59,51 +63,142 @@ async function warmCache( } } + return all; +} + +/** + * Wrap a single oracle fetch with its own timeout so one hung upstream cannot + * consume the whole warming budget. Resolves (never rejects) to a + * settled-style result so the caller can count it uniformly. + */ +function fetchAssetWithTimeout(asset, oracle, entryTimeoutMs, abortSignal, timers) { + return new Promise((resolve) => { + if (abortSignal && abortSignal.aborted) { + resolve({ status: 'rejected', reason: new Error('Warming cancelled') }); + return; + } + + let settled = false; + const finish = (result) => { + if (settled) return; + settled = true; + clearTimeout(timer); + timers.delete(timer); + resolve(result); + }; + + const timer = setTimeout(() => { + finish({ status: 'rejected', reason: new Error(`Price fetch timed out after ${entryTimeoutMs}ms`) }); + }, entryTimeoutMs); + timers.add(timer); + + Promise.resolve() + .then(() => oracle.fetchFreshPrice(asset.code, asset.issuer || null)) + .then( + (value) => finish({ status: 'fulfilled', value }), + (reason) => finish({ status: 'rejected', reason }) + ); + }); +} + +/** + * Run fetches with a bounded worker pool: at most `concurrency` requests are + * in flight at once, but no more than `assets.length`. Returns the settled + * results (order of completion, not of input). + */ +async function runWarmPool(assets, oracle, { entryTimeoutMs, concurrency, abortSignal, timers, log }) { + const queue = [...assets]; + const results = []; + const workerCount = Math.max(1, Math.min(concurrency, queue.length)); + + const workers = Array.from({ length: workerCount }, async () => { + while (queue.length > 0) { + const asset = queue.shift(); + results.push(await fetchAssetWithTimeout(asset, oracle, entryTimeoutMs, abortSignal, timers)); + } + }); + + await Promise.all(workers); + if (timers.size > 0 && log) { + // Defensive: nothing should remain once every worker has drained. + for (const timer of timers) clearTimeout(timer); + timers.clear(); + } + return results; +} + +/** + * Warm the price cache once, returning a summary. + * + * The signature is unchanged from before #495 (`assets`, `oracle`, + * `{ timeoutMs, log }`); the extra options (entryTimeoutMs, maxEntries, + * concurrency) are optional and default to the configured bounds. + */ +async function warmCache( + assets = config.watchedAssets, + oracle = priceOracle, + options = {} +) { + const { + timeoutMs = DEFAULT_TIMEOUT_MS, + entryTimeoutMs = DEFAULT_ENTRY_TIMEOUT_MS, + maxEntries = DEFAULT_MAX_ENTRIES, + concurrency = DEFAULT_CONCURRENCY, + log = logger, + } = options; + + let allAssets = await collectAssets(assets, oracle, log); + if (!allAssets || allAssets.length === 0) { log.info('Cache warm skipped: no watched assets configured'); return { total: 0, succeeded: 0, failed: 0, timedOut: false, durationMs: 0 }; } + if (Number.isFinite(maxEntries) && maxEntries > 0 && allAssets.length > maxEntries) { + const dropped = allAssets.length - maxEntries; + allAssets = allAssets.slice(0, maxEntries); + log.warn('Cache warm asset list truncated', { + max_entries: maxEntries, + dropped, + }); + } + const abortController = new AbortController(); + const timers = new Set(); let timedOut = false; let timeoutId; - // Wrap each fetch to track successes incrementally, so the timeout - // handler can snapshot the real count instead of hardcoding 0 (#413). - let succeededSoFar = 0; - const trackedResults = allAssets.map(({ code, issuer }) => { - if (abortController.signal.aborted) { - return Promise.reject(new Error('Warming cancelled')); - } - return Promise.resolve() - .then(() => oracle.fetchFreshPrice(code, issuer || null)) - .then((value) => { - if (isWarmSuccess({ status: 'fulfilled', value })) { - succeededSoFar++; - } - return { status: 'fulfilled', value }; - }) - .catch((reason) => ({ status: 'rejected', reason })); + // Results fill in as workers finish, so the overall timeout can snapshot the + // successes achieved so far instead of hardcoding 0 (#413). + const results = []; + const warming = runWarmPool(allAssets, oracle, { + entryTimeoutMs, + concurrency, + abortSignal: abortController.signal, + timers, + log, + }).then((settled) => { + results.push(...settled); + const succeeded = results.filter(isWarmSuccess).length; + return { + total: allAssets.length, + succeeded, + failed: allAssets.length - succeeded, + timedOut: false, + durationMs: 0, + }; }); - const warming = Promise.all(trackedResults).then((results) => ({ - total: allAssets.length, - succeeded: results.filter(isWarmSuccess).length, - failed: allAssets.length - results.filter(isWarmSuccess).length, - timedOut: false, - durationMs: 0, - })); - const timeout = new Promise((resolve) => { timeoutId = setTimeout(() => { timedOut = true; // Signal abort to cancel in-flight fetches (#402) abortController.abort(); - const failed = allAssets.length - succeededSoFar; + const succeeded = results.filter(isWarmSuccess).length; const summary = { total: allAssets.length, - succeeded: succeededSoFar, - failed, + succeeded, + failed: allAssets.length - succeeded, timedOut: true, durationMs: timeoutMs, }; @@ -113,8 +208,11 @@ async function warmCache( }); const summary = await Promise.race([warming, timeout]); + clearTimeout(timeoutId); + for (const timer of timers) clearTimeout(timer); + timers.clear(); + if (!summary.timedOut) { - clearTimeout(timeoutId); // One completion line per startup (mirroring the timeout path's warn) // so an operator can see how much of the cache actually warmed without // diffing per-asset fetch logs. @@ -123,7 +221,190 @@ async function warmCache( return summary; } +/** + * Backwards-compatible helper retained from before #495. Not used by the + * startup path any more (see warmCacheInBackground); kept so any external + * caller importing it keeps working. + */ +async function runWarmCache(assets, oracle, abortSignal) { + const startedAt = Date.now(); + const results = await Promise.allSettled( + assets.map(({ code, issuer }) => { + if (abortSignal && abortSignal.aborted) { + return Promise.reject(new Error('Warming cancelled')); + } + return Promise.resolve().then(() => oracle.fetchFreshPrice(code, issuer || null)); + }) + ); + const succeeded = results.filter(isWarmSuccess).length; + + return { + total: assets.length, + succeeded, + failed: assets.length - succeeded, + timedOut: false, + durationMs: Date.now() - startedAt, + }; +} + +function delay(ms) { + if (!ms || ms <= 0) return Promise.resolve(); + return new Promise((resolve) => { + const timer = setTimeout(resolve, ms); + if (typeof timer.unref === 'function') timer.unref(); + }); +} + +/** + * Best-effort release of the warming lock. Compare-and-delete so we never + * delete a lock another replica has since acquired (our key may have expired + * mid-warm if the TTL was too small for a slow warm). + */ +async function releaseLock(redis, key, owner) { + if (!redis || typeof redis.get !== 'function') return; + try { + const current = await redis.get(key); + if (current === owner) await redis.del(key); + } catch (err) { + // Lock release is best-effort; the TTL will clean up. + } +} + +/** + * Warm the cache in the background, without blocking startup (issue #495). + * + * Returns a promise that resolves once warming is done (or skipped), so + * callers/tests can await it — the process does not await it on the startup + * path. Never rejects. + * + * Only one replica warms at a time: the winner takes a short Redis lock + * (`SET ... NX PX`). Losers record a `locked` status and return. + */ +async function warmCacheInBackground({ + assets = config.watchedAssets, + oracle = priceOracle, + log = logger, + cacheModule = cache, + enabled = config.cacheWarm ? config.cacheWarm.enabled : true, + timeoutMs, + entryTimeoutMs, + maxEntries, + concurrency, + jitterMs, + lockTtlMs = config.cacheWarm ? config.cacheWarm.lockTtlMs : DEFAULT_LOCK_TTL_MS, + lockKey = WARM_LOCK_KEY, +} = {}) { + warmStatus.enabled = enabled; + warmStatus.reason = null; + warmStatus.lockSkipped = false; + + if (!enabled) { + warmStatus.state = 'disabled'; + log.info('Cache warm disabled via CACHE_WARM_ENABLED'); + return { skipped: true, reason: 'disabled' }; + } + + const owner = `${config.leaderElection.instanceId}:${Date.now()}`; + let redis = null; + let locked = false; + + try { + redis = cacheModule.getClient(); + if (redis && typeof redis.set === 'function') { + const ttl = lockTtlMs > 0 ? lockTtlMs : DEFAULT_LOCK_TTL_MS; + const result = await redis.set(lockKey, owner, 'PX', ttl, 'NX'); + locked = result === 'OK'; + } else { + // No Redis client available (degraded boot) — warm anyway rather than + // skip warming entirely; the lock is an optimisation, not a + // correctness requirement. + locked = true; + } + } catch (err) { + log.warn('Could not acquire cache warm lock; warming without it', { error: err.message }); + locked = true; + } + + if (!locked) { + warmStatus.state = 'locked'; + warmStatus.lockSkipped = true; + warmStatus.reason = 'lock_held'; + log.info('Cache warm skipped: another instance holds the warm lock', { lock_key: lockKey }); + return { skipped: true, reason: 'lock_held' }; + } + + warmStatus.state = 'running'; + warmStatus.startedAt = Date.now(); + warmStatus.finishedAt = null; + warmStatus.durationMs = null; + warmStatus.summary = null; + warmStatus.error = null; + + try { + // Stagger replicas that start together (fleet rollout) — jitter is + // applied while holding the lock so only the winner is delayed. + await delay(jitterMs || (config.cacheWarm && config.cacheWarm.jitterMs)); + + const summary = await warmCache(assets, oracle, { + log, + ...(timeoutMs !== undefined ? { timeoutMs } : {}), + ...(entryTimeoutMs !== undefined ? { entryTimeoutMs } : {}), + ...(maxEntries !== undefined ? { maxEntries } : {}), + ...(concurrency !== undefined ? { concurrency } : {}), + }); + + warmStatus.state = 'completed'; + warmStatus.summary = summary; + return summary; + } catch (err) { + warmStatus.state = 'failed'; + warmStatus.error = err.message; + log.warn('Cache warm failed; starting server anyway', { error: err.message }); + return { skipped: false, error: err.message }; + } finally { + warmStatus.finishedAt = Date.now(); + warmStatus.durationMs = warmStatus.finishedAt - warmStatus.startedAt; + await releaseLock(redis, lockKey, owner); + } +} + +/** + * Snapshot of the last warm attempt, surfaced on GET /health (never on + * /ready — warming is an optimisation, not a dependency). + */ +function getWarmStatus() { + return { + state: warmStatus.state, + enabled: warmStatus.enabled, + reason: warmStatus.reason, + lock_skipped: warmStatus.lockSkipped, + started_at: warmStatus.startedAt ? new Date(warmStatus.startedAt).toISOString() : null, + finished_at: warmStatus.finishedAt ? new Date(warmStatus.finishedAt).toISOString() : null, + duration_ms: warmStatus.durationMs, + summary: warmStatus.summary, + error: warmStatus.error, + }; +} + +// Test-only: reset the module-level status between cases. +function _resetWarmStatus(overrides = {}) { + warmStatus.state = 'idle'; + warmStatus.enabled = true; + warmStatus.reason = null; + warmStatus.lockSkipped = false; + warmStatus.startedAt = null; + warmStatus.finishedAt = null; + warmStatus.durationMs = null; + warmStatus.summary = null; + warmStatus.error = null; + Object.assign(warmStatus, overrides); +} + module.exports = { warmCache, + warmCacheInBackground, + getWarmStatus, runWarmCache, + WARM_LOCK_KEY, + _resetWarmStatus, }; diff --git a/src/utils/dates.js b/src/utils/dates.js new file mode 100644 index 0000000..34547eb --- /dev/null +++ b/src/utils/dates.js @@ -0,0 +1,114 @@ +'use strict'; + +/** + * Shared UTC date helpers (issue #494). + * + * The project standard is: every instant is created, compared and stored in + * UTC, and serialized in API responses as an ISO-8601 string with a `Z` + * suffix. Local time is only ever produced at presentation time, by a client, + * from one of these UTC values — never by the server. + * + * These helpers exist so the rule is enforced in one place instead of being + * re-spelled (and occasionally forgotten) at each call site: + * + * - `nowIso()` and `toIso()` always emit `...Z`, regardless of the host's + * time zone or of whether the input was a Date, an epoch number, or a + * string with or without an offset. + * - `startOfUtcDay()` / `utcDayKey()` make "today" and day-boundary logic + * explicit in UTC. A date-only string like `2026-01-01` is parsed by + * JavaScript as UTC midnight, but the *local* date at that instant is + * still 2025-12-31 for a server in UTC-5; bucketing on day boundaries must + * therefore use `utcDayKey()` rather than slicing a local-time string. + * - `assertUtcTimeZone()` is a defensive default for the process (`TZ=UTC` + * when the operator has not set one). It is deliberately NOT the fix for + * time-zone bugs: it only guarantees a stable default, and every helper + * above remains correct when it is removed or overridden. See + * README.md#time-handling. + * + * No date library is used — `Date` plus `Date.UTC` is sufficient for the + * operations the codebase needs, and the repo does not depend on one. + */ + +/** + * Current time as an ISO-8601 UTC string (`2026-01-01T00:00:00.000Z`). + * + * @returns {string} + */ +function nowIso() { + return new Date().toISOString(); +} + +/** + * Normalize any date-like value to an ISO-8601 UTC string. + * + * Accepts a `Date`, an epoch-millisecond number, or any string `Date` can + * parse (with or without an offset). Returns `null` for empty or unparsable + * input so callers can store an explicit `null` rather than "Invalid Date". + * + * @param {Date|number|string|null|undefined} value + * @returns {string|null} + */ +function toIso(value) { + if (value === null || value === undefined || value === '') return null; + const date = value instanceof Date ? value : new Date(value); + if (Number.isNaN(date.getTime())) return null; + return date.toISOString(); +} + +/** + * The UTC midnight that starts the UTC day containing `value`. + * + * Uses `getUTC*`/`Date.UTC` explicitly, so it returns the same instant no + * matter what the host's local time zone is. + * + * @param {Date|number|string} [value] + * @returns {Date|null} + */ +function startOfUtcDay(value = new Date()) { + const date = value instanceof Date ? value : new Date(value); + if (Number.isNaN(date.getTime())) return null; + return new Date(Date.UTC(date.getUTCFullYear(), date.getUTCMonth(), date.getUTCDate())); +} + +/** + * The `YYYY-MM-DD` UTC day key for `value` — the only correct way to bucket a + * timestamp into a calendar day on the server. + * + * @param {Date|number|string} [value] + * @returns {string|null} + */ +function utcDayKey(value = new Date()) { + const start = startOfUtcDay(value); + return start ? start.toISOString().slice(0, 10) : null; +} + +const UTC_ALIASES = new Set(['UTC', 'Etc/UTC', 'Etc/Greenwich', 'GMT']); + +/** + * Ensure the process has a stable time-zone default. + * + * When `TZ` is unset, sets it to `UTC`. When it is set to a non-UTC zone the + * value is left untouched (an operator opted in explicitly) but reported so + * the caller can log it — the code must stay correct either way, because the + * setting is only a default and is lost the moment the code runs somewhere + * else (a worker, a migration, a one-off script). + * + * @param {Object} [options] + * @param {NodeJS.ProcessEnv} [options.env=process.env] + * @returns {{ changed: boolean, timeZone: string, isNonUtc: boolean }} + */ +function assertUtcTimeZone({ env = process.env } = {}) { + if (!env.TZ) { + env.TZ = 'UTC'; + return { changed: true, timeZone: 'UTC', isNonUtc: false }; + } + return { changed: false, timeZone: env.TZ, isNonUtc: !UTC_ALIASES.has(env.TZ) }; +} + +module.exports = { + assertUtcTimeZone, + nowIso, + startOfUtcDay, + toIso, + utcDayKey, +}; diff --git a/test/cookies.test.js b/test/cookies.test.js new file mode 100644 index 0000000..c206edc --- /dev/null +++ b/test/cookies.test.js @@ -0,0 +1,87 @@ +'use strict'; + +const express = require('express'); +const request = require('supertest'); +const { setCookie, clearCookie, buildCookieOptions } = require('../src/auth/cookies'); +const config = require('../src/config'); + +function withApp(middleware) { + const app = express(); + app.get('/set', (req, res) => { + setCookie(res, 'sid', 'abc123', { req, maxAgeMs: 3600 * 1000 }); + res.json({ ok: true }); + }); + app.get('/clear', (req, res) => { + clearCookie(res, 'sid', { req }); + res.json({ ok: true }); + }); + if (middleware) app.use(middleware); + return app; +} + +describe('secure cookie helpers (issue #496)', () => { + beforeEach(() => { + jest.resetModules(); + }); + + test('trust proxy is disabled by default (config)', () => { + expect(config.trustProxy).toBe(false); + }); + + test('buildCookieOptions sets HttpOnly, SameSite=Strict, Path=/ and Secure=false when http', () => { + const opts = buildCookieOptions({ req: { secure: false }, maxAgeMs: 60000 }); + expect(opts).toMatchObject({ + httpOnly: true, + sameSite: 'Strict', + path: '/', + }); + expect(opts.secure).toBe(false); + expect(opts.maxAge).toBe(60000); + }); + + test('clearCookie sets Max-Age=0 and Expires in the past', () => { + const res = { + clearCookie: jest.fn(), + }; + clearCookie(res, 'sid', { req: { secure: true } }); + const [name, opts] = res.clearCookie.mock.calls[0]; + expect(name).toBe('sid'); + expect(opts.maxAge).toBe(0); + expect(opts.expires instanceof Date).toBe(true); + expect(opts.expires.getTime()).toBeLessThanOrEqual(Date.now()); + expect(opts.httpOnly).toBe(true); + expect(opts.secure).toBe(true); + expect(opts.path).toBe('/'); + expect(opts.sameSite).toBe('Strict'); + }); + + test('over https, Secure is true', async () => { + const app = withApp(); + const res = await request(app).get('/set').trustLocalhost(false).set('X-Forwarded-Proto', 'https'); + const setCookieHeader = res.headers['set-cookie']; + expect(setCookieHeader).toBeDefined(); + expect(setCookieHeader[0]).toMatch(/sid=abc123/); + expect(setCookieHeader[0]).toMatch(/HttpOnly/); + expect(setCookieHeader[0]).toMatch(/SameSite=Strict/); + expect(setCookieHeader[0]).toMatch(/Secure/); + }); + + test('over http in non-prod, Secure is false (dev/test)', async () => { + const app = withApp(); + const res = await request(app).get('/set'); + const setCookieHeader = res.headers['set-cookie']; + expect(setCookieHeader).toBeDefined(); + expect(setCookieHeader[0]).toMatch(/sid=abc123/); + expect(setCookieHeader[0]).not.toMatch(/;\s*Secure\b/i); + expect(setCookieHeader[0]).toMatch(/HttpOnly/); + expect(setCookieHeader[0]).toMatch(/SameSite=Strict/); + }); + + test('rate limit uses req.ip (no spoofing assumption without trust proxy)', () => { + const middleware = require('../src/middleware/rateLimit'); + const buildRateLimit = middleware.buildRateLimit; + expect(typeof buildRateLimit).toBe('function'); + const limiter = buildRateLimit({ windowSeconds: 60, max: 10, keyPrefix: 't' }); + expect(typeof limiter).toBe('function'); + }); +}); diff --git a/test/startupBanner.test.js b/test/startupBanner.test.js index f142079..10a1e7b 100644 --- a/test/startupBanner.test.js +++ b/test/startupBanner.test.js @@ -20,6 +20,18 @@ jest.mock("../src/logger", () => mockLogger); const mockWarmCache = jest.fn(); jest.mock("../src/startup/cacheWarm", () => ({ warmCache: (...args) => mockWarmCache(...args), + warmCacheInBackground: jest.fn().mockResolvedValue({}), + getWarmStatus: jest.fn().mockReturnValue({ + state: 'idle', + enabled: true, + reason: null, + lock_skipped: false, + started_at: null, + finished_at: null, + duration_ms: null, + summary: null, + error: null, + }), })); const { diff --git a/test/timezone.test.js b/test/timezone.test.js new file mode 100644 index 0000000..fc73299 --- /dev/null +++ b/test/timezone.test.js @@ -0,0 +1,247 @@ +'use strict'; + +/** + * Time zone handling (issue #494). + * + * The project standard is: all instants are created, computed, compared and + * stored in UTC, and serialized in API responses as ISO-8601 strings with a + * `Z` suffix. Local time is produced only by a client, from a UTC value. + * + * These tests run the same code under several process time zones. Two are + * used rather than one so that a helper that accidentally reads local time + * cannot pass by matching the host default: + * TZ=UTC (the standard) + * TZ=America/New_York (UTC-4/-5, "behind" UTC) + * TZ=Asia/Tokyo (UTC+9, "ahead" of UTC) + * + * A child process is used for the TZ matrix because Node reads TZ when it + * initializes; spawning with the variable in `env` is the only way to be sure + * the value is in effect for the code under test. + */ + +const path = require('path'); +const { spawnSync } = require('child_process'); + +const repoRoot = path.join(__dirname, '..'); +const TIME_ZONES = ['UTC', 'America/New_York', 'Asia/Tokyo']; + +function runInTimeZone(tz, script) { + const result = spawnSync(process.execPath, ['-e', script], { + cwd: repoRoot, + env: { + PATH: process.env.PATH, + Path: process.env.Path, + SystemRoot: process.env.SystemRoot, + COMSPEC: process.env.COMSPEC, + TEMP: process.env.TEMP, + TMP: process.env.TMP, + NODE_ENV: 'test', + TZ: tz, + }, + encoding: 'utf8', + }); + + if (result.status !== 0) { + throw new Error(`child for TZ=${tz} failed:\n${result.stdout}\n${result.stderr}`); + } + return JSON.parse(result.stdout.trim()); +} + +describe('UTC date helpers (issue #494)', () => { + // A fixed instant whose UTC date differs from the local date in both + // non-UTC zones chosen above (19:00Z is already the next day in Tokyo, and + // still the same day but a different wall-clock hour in New York), so a + // helper that leaked local time would not produce identical values. + const FIXED_INSTANT = '2026-06-30T19:00:00.000Z'; + + test('produce byte-identical output in UTC, America/New_York and Asia/Tokyo', () => { + const script = ` + const dates = require('./src/utils/dates'); + const fixed = ${JSON.stringify(FIXED_INSTANT)}; + console.log(JSON.stringify({ + toIso: dates.toIso(fixed), + toIsoEpoch: dates.toIso(Date.parse(fixed)), + startOfUtcDay: dates.startOfUtcDay(fixed).toISOString(), + utcDayKey: dates.utcDayKey(fixed), + })); + `; + + const results = TIME_ZONES.map((tz) => runInTimeZone(tz, script)); + + // Every TZ yields the same (UTC) answers... + for (const result of results) { + expect(result).toEqual(results[0]); + } + // ...and those answers are the UTC ones, not merely consistent. + expect(results[0]).toEqual({ + toIso: FIXED_INSTANT, + toIsoEpoch: FIXED_INSTANT, + startOfUtcDay: '2026-06-30T00:00:00.000Z', + utcDayKey: '2026-06-30', + }); + }); + + test('utcDayKey bucketing is stable where a local date would drift', () => { + // Proof of the class of bug this guards against: JavaScript parses a + // date-time string WITHOUT an offset in the process's local zone, so the + // same source string denotes different instants (and different calendar + // days) depending on the host. The UTC helper is immune. + const script = ` + const dates = require('./src/utils/dates'); + const naiveLocal = new Date('2026-01-01T00:00:00'); + console.log(JSON.stringify({ + naiveLocalIso: naiveLocal.toISOString(), + utcDayKey: dates.utcDayKey(naiveLocal), + // The raw UTC calendar day the instant falls in, for comparison. + naiveLocalUtcDate: naiveLocal.toISOString().slice(0, 10), + })); + `; + + const utc = runInTimeZone('UTC', script); + const tokyo = runInTimeZone('Asia/Tokyo', script); + const newYork = runInTimeZone('America/New_York', script); + + // Same source string, three different instants — this is the hazard. + expect(utc.naiveLocalIso).toBe('2026-01-01T00:00:00.000Z'); + expect(tokyo.naiveLocalIso).toBe('2025-12-31T15:00:00.000Z'); + expect(newYork.naiveLocalIso).toBe('2026-01-01T05:00:00.000Z'); + + // utcDayKey always reports the UTC calendar day of the actual instant, + // so it can never disagree with the stored timestamp's own date prefix. + for (const result of [utc, tokyo, newYork]) { + expect(result.utcDayKey).toBe(result.naiveLocalUtcDate); + } + expect(tokyo.utcDayKey).toBe('2025-12-31'); + }); + + test('toIso returns null for empty and unparsable input rather than "Invalid Date"', () => { + const dates = require('../src/utils/dates'); + expect(dates.toIso(null)).toBeNull(); + expect(dates.toIso(undefined)).toBeNull(); + expect(dates.toIso('')).toBeNull(); + expect(dates.toIso('not a date')).toBeNull(); + }); + + test('toIso normalizes an offset-bearing string to the same UTC instant', () => { + const dates = require('../src/utils/dates'); + expect(dates.toIso('2026-06-30T12:00:00-04:00')).toBe('2026-06-30T16:00:00.000Z'); + }); +}); + +describe('assertUtcTimeZone (issue #494)', () => { + const dates = require('../src/utils/dates'); + + test('sets TZ=UTC when the process has no explicit time zone', () => { + const env = {}; + const state = dates.assertUtcTimeZone({ env }); + + expect(state).toEqual({ changed: true, timeZone: 'UTC', isNonUtc: false }); + expect(env.TZ).toBe('UTC'); + }); + + test('leaves UTC aliases of UTC alone', () => { + for (const tz of ['UTC', 'Etc/UTC']) { + const env = { TZ: tz }; + const state = dates.assertUtcTimeZone({ env }); + expect(state).toEqual({ changed: false, timeZone: tz, isNonUtc: false }); + expect(env.TZ).toBe(tz); + } + }); + + test('reports, but does not rewrite, an explicit non-UTC time zone', () => { + const env = { TZ: 'Asia/Tokyo' }; + const state = dates.assertUtcTimeZone({ env }); + + expect(state).toEqual({ changed: false, timeZone: 'Asia/Tokyo', isNonUtc: true }); + expect(env.TZ).toBe('Asia/Tokyo'); + }); +}); + +describe('PostgreSQL sessions are pinned to UTC (issue #494)', () => { + test('the pool connection hook sets the session TimeZone to UTC', async () => { + const { afterCreateUtcConnection } = require('../src/database'); + const queries = []; + const conn = { + query: (sql, cb) => { + queries.push(sql); + cb(null); + }, + }; + + await new Promise((resolve, reject) => { + afterCreateUtcConnection(conn, (err, returned) => { + if (err) return reject(err); + expect(returned).toBe(conn); + resolve(); + }); + }); + + expect(queries).toEqual(["SET TIME ZONE 'UTC'"]); + }); + + test('a failed statement still releases the connection with the error', async () => { + const { afterCreateUtcConnection } = require('../src/database'); + const failure = new Error('boom'); + const conn = { query: (_sql, cb) => cb(failure) }; + + await new Promise((resolve) => { + afterCreateUtcConnection(conn, (err) => { + expect(err).toBe(failure); + resolve(); + }); + }); + }); +}); + +describe('api key audit timestamps are UTC ISO-8601 (issue #494)', () => { + test('created_at is serialized with a Z suffix', async () => { + const apiKeyAuditLog = require('../src/services/apiKeyAuditLog'); + let captured = null; + const fakeTrx = () => ({ + insert: async (row) => { + captured = row; + }, + }); + + await apiKeyAuditLog.logUsage( + { keyId: 'key_1', endpoint: 'GET /v1/prices', ipAddress: '127.0.0.1', statusCode: 200, responseTimeMs: 3 }, + fakeTrx, + ); + + expect(captured.created_at).toMatch(/^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z$/); + }); +}); + +describe('log rotation is date-bucketed in UTC (issue #494)', () => { + // winston-daily-rotate-file resolves %DATE% from the host wall clock by + // default. Before this change, two servers in different time zones named + // the same UTC log window differently (Asia/Tokyo put 2026-06-30T19:00Z in + // a file named ...-07-01.log). The transport now requests UTC filenames. + test('the file transport requests UTC-dated filenames', () => { + process.env.LOG_FILE_PATH = '/tmp/smartdrop-test-logs'; + jest.resetModules(); + + const logger = require('../src/logger'); + const fileTransport = logger.transports.find( + (t) => t.filename && String(t.filename).includes('%DATE%'), + ); + + expect(fileTransport).toBeDefined(); + expect(fileTransport.utc ?? fileTransport.options?.utc).toBe(true); + + delete process.env.LOG_FILE_PATH; + jest.resetModules(); + }); + + test('no file transport is created when LOG_FILE_PATH is unset', () => { + delete process.env.LOG_FILE_PATH; + jest.resetModules(); + + const logger = require('../src/logger'); + const fileTransport = logger.transports.find( + (t) => t.filename && String(t.filename).includes('%DATE%'), + ); + + expect(fileTransport).toBeUndefined(); + }); +});