diff --git a/src/modules/creator/creator-observability.utils.ts b/src/modules/creator/creator-observability.utils.ts new file mode 100644 index 0000000..60cb45d --- /dev/null +++ b/src/modules/creator/creator-observability.utils.ts @@ -0,0 +1,32 @@ +import { logger } from '../../utils/logger.utils'; + +const creatorRouteBootMs = Date.now(); +const loggedHandlers = new Set(); + +/** + * Emits a one-time debug log for the first invocation of a creator route handler. + * + * The log is intentionally debug-level so it stays out of production info logs + * while still giving operators a signal when a route's first request is slower + * than expected. + */ +export function logCreatorRouteColdStart( + handler: string, + requestId?: string +): void { + if (loggedHandlers.has(handler)) { + return; + } + + loggedHandlers.add(handler); + + logger.debug( + { + type: 'creator_route_cold_start', + handler, + elapsedMs: Date.now() - creatorRouteBootMs, + ...(requestId ? { requestId } : {}), + }, + 'Creator route cold start detected' + ); +} diff --git a/src/modules/creator/creator-profile.handlers.ts b/src/modules/creator/creator-profile.handlers.ts index 94579db..46f164a 100644 --- a/src/modules/creator/creator-profile.handlers.ts +++ b/src/modules/creator/creator-profile.handlers.ts @@ -5,6 +5,7 @@ import { sendValidationError, ErrorCode, } from '../../utils/api-response.utils'; +import { logger } from '../../utils/logger.utils'; import { CreatorProfileParamsSchema, UpsertCreatorProfileBodySchema, @@ -13,6 +14,7 @@ import { getCreatorProfile, upsertCreatorProfile, } from './creator-profile.service'; +import { logCreatorRouteColdStart } from './creator-observability.utils'; /** * @route GET /api/v1/creators/:creatorId/profile @@ -21,6 +23,8 @@ import { */ export async function getCreatorProfileHandler(req: Request, res: Response) { try { + logCreatorRouteColdStart('getCreatorProfileHandler', req.requestId); + const paramsResult = CreatorProfileParamsSchema.safeParse(req.params); if (!paramsResult.success) { return sendValidationError( @@ -36,7 +40,15 @@ export async function getCreatorProfileHandler(req: Request, res: Response) { const profile = await getCreatorProfile(paramsResult.data.creatorId); return sendSuccess(res, profile, 200, 'Creator profile retrieved'); } catch (error) { - console.error('Error retrieving creator profile:', error); + logger.error( + { + type: 'creator_profile_handler_error', + handler: 'getCreatorProfileHandler', + ...(req.requestId ? { requestId: req.requestId } : {}), + error, + }, + 'Error retrieving creator profile' + ); return sendError( res, 500, @@ -53,6 +65,8 @@ export async function getCreatorProfileHandler(req: Request, res: Response) { */ export async function upsertCreatorProfileHandler(req: Request, res: Response) { try { + logCreatorRouteColdStart('upsertCreatorProfileHandler', req.requestId); + const paramsResult = CreatorProfileParamsSchema.safeParse(req.params); if (!paramsResult.success) { return sendValidationError( @@ -88,7 +102,15 @@ export async function upsertCreatorProfileHandler(req: Request, res: Response) { 'Creator profile write accepted (placeholder)' ); } catch (error) { - console.error('Error upserting creator profile:', error); + logger.error( + { + type: 'creator_profile_handler_error', + handler: 'upsertCreatorProfileHandler', + ...(req.requestId ? { requestId: req.requestId } : {}), + error, + }, + 'Error upserting creator profile' + ); return sendError( res, 500, diff --git a/src/modules/creator/creator-profile.service.ts b/src/modules/creator/creator-profile.service.ts index e3bb531..7d0d32b 100644 --- a/src/modules/creator/creator-profile.service.ts +++ b/src/modules/creator/creator-profile.service.ts @@ -1,4 +1,5 @@ import { prisma } from '../../utils/prisma.utils'; +import { logger } from '../../utils/logger.utils'; import { CreatorProfileReadResponse, UpsertCreatorProfileBody, @@ -30,7 +31,13 @@ export async function getCreatorProfile( }); if (!profile) { - console.warn(buildCreatorDetailCacheMissContext(creatorId)); + logger.warn( + { + ...buildCreatorDetailCacheMissContext(creatorId), + type: 'creator_profile_cache_miss', + }, + 'Creator profile cache miss; returning placeholder response' + ); // Fallback for placeholder behavior if profile not found return { diff --git a/src/modules/creator/creator.controller.ts b/src/modules/creator/creator.controller.ts index 6039368..56efaa9 100644 --- a/src/modules/creator/creator.controller.ts +++ b/src/modules/creator/creator.controller.ts @@ -16,6 +16,8 @@ import { wrapPublicCreatorListResponse } from '../creators/public-creator-list-e import { buildCreatorListRequestContext } from '../creators/creator-list-context.utils'; import { warnIfUnrecognizedCreatorListSort } from '../creators/creators.sort-field.utils'; import { normalizeCreatorListPage } from './creator-list-page.guard'; +import { logCreatorRouteColdStart } from './creator-observability.utils'; +import { logger } from '../../utils/logger.utils'; // Legacy query schema import { LegacyCreatorQuerySchema } from '../creators/creators.schemas'; @@ -69,70 +71,84 @@ function pickFields>( // Typed Express handler export const listCreators: RequestHandler = async (req, res) => { - try { - // Build request context - const ctx = buildCreatorListRequestContext(req); - - warnIfUnrecognizedCreatorListSort(ctx.query, req.requestId); - - // Parse query using legacy schema - const parsed = parsePublicQuery( - LegacyCreatorQuerySchema, - ctx.query, - { debugContext: 'legacy-creator-list-query' } - ); - - if (!parsed.ok) { - return sendValidationError(res, 'Invalid query parameters', parsed.details); - } - - const selectedFields = parseSelectFields(ctx.query['select-fields']); - const invalidFields = getInvalidSelectFields(selectedFields); - - if (invalidFields.length > 0) { - return sendValidationError(res, 'Invalid query parameters', [ - { - field: 'select-fields', - message: `Invalid select-fields: ${invalidFields.join(', ')}`, - }, - ]); - } - - // Destructure using schema fields - const { offset, limit, sort, order: sortOrder } = parsed.data; - - // Convert offset to page number - const page = normalizeCreatorListPage(offset); - - // Build sort options - const sortOptions = parseCreatorSortOptions(sort, sortOrder); - - // Fetch paginated creators - const { creators, meta } = await getPaginatedCreators({ - page, - limit, - sort: sortOptions, - }); - - const response = wrapPublicCreatorListResponse(creators, meta); - attachTimestampHeader(res); - const filteredItems = Array.isArray(response.items) - ? response.items.map((item) => - pickFields(item as Record, selectedFields) - ) - : response.items; - - return sendSuccess( - res, - { - ...response, - items: filteredItems, - }, - 200, - 'Creators retrieved successfully' - ); - } catch (error) { - console.error('Error listing creators:', error); - return sendError(res, 500, ErrorCode.INTERNAL_ERROR, 'Failed to retrieve creators'); - } + try { + logCreatorRouteColdStart('listCreators', req.requestId); + + // Build request context + const ctx = buildCreatorListRequestContext(req); + + warnIfUnrecognizedCreatorListSort(ctx.query, req.requestId); + + // Parse query using legacy schema + const parsed = parsePublicQuery( + LegacyCreatorQuerySchema, + ctx.query, + { debugContext: 'legacy-creator-list-query' } + ); + + if (!parsed.ok) { + return sendValidationError( + res, + 'Invalid query parameters', + parsed.details + ); + } + + const selectedFields = parseSelectFields(ctx.query['select-fields']); + const invalidFields = getInvalidSelectFields(selectedFields); + + if (invalidFields.length > 0) { + return sendValidationError(res, 'Invalid query parameters', [ + { + field: 'select-fields', + message: `Invalid select-fields: ${invalidFields.join(', ')}`, + }, + ]); + } + + // Destructure using schema fields + const { offset, limit, sort, order: sortOrder } = parsed.data; + + // Convert offset to page number + const page = normalizeCreatorListPage(offset); + + // Build sort options + const sortOptions = parseCreatorSortOptions(sort, sortOrder); + + // Fetch paginated creators + const { creators, meta } = await getPaginatedCreators({ + page, + limit, + sort: sortOptions, + }); + + const response = wrapPublicCreatorListResponse(creators, meta); + attachTimestampHeader(res); + const filteredItems = Array.isArray(response.items) + ? response.items.map((item) => + pickFields(item as Record, selectedFields) + ) + : response.items; + + return sendSuccess( + res, + { + ...response, + items: filteredItems, + }, + 200, + 'Creators retrieved successfully' + ); + } catch (error) { + logger.error( + { + type: 'creator_list_handler_error', + handler: 'listCreators', + ...(req.requestId ? { requestId: req.requestId } : {}), + error, + }, + 'Error listing creators' + ); + return sendError(res, 500, ErrorCode.INTERNAL_ERROR, 'Failed to retrieve creators'); + } }; diff --git a/src/modules/creators/creator-feed-empty-filters.integration.test.ts b/src/modules/creators/creator-feed-empty-filters.integration.test.ts index dc8d9e6..bcd6fb8 100644 --- a/src/modules/creators/creator-feed-empty-filters.integration.test.ts +++ b/src/modules/creators/creator-feed-empty-filters.integration.test.ts @@ -7,6 +7,8 @@ import { httpListCreators } from './creators.controllers'; import * as creatorsUtils from './creators.utils'; import { logger } from '../../utils/logger.utils'; +import { resolveCreatorListLimit } from './creators.limit.utils'; +import { PUBLIC_OFFSET_PAGINATION_DEFAULTS } from '../../utils/public-list-query-defaults'; // ── Lightweight request/response mocks ──────────────────────────────────────── @@ -109,17 +111,47 @@ describe('GET /api/v1/creators — empty feed with filter combinations', () => { expect(body.data.meta.offset).toBe(0); }); - it('applies default sort when not specified', async () => { - const req = makeReq(); - const res = makeRes(); - await httpListCreators(req, res, makeNext()); + it('treats explicit defaults the same as omitted filter params', async () => { + const omittedReq = makeReq(); + const omittedRes = makeRes(); + await httpListCreators(omittedReq, omittedRes, makeNext()); - expect(creatorsUtils.fetchCreatorList).toHaveBeenCalledWith( + const explicitDefaultsReq = makeReq({ + limit: String(resolveCreatorListLimit()), + offset: String(PUBLIC_OFFSET_PAGINATION_DEFAULTS.offset), + sort: 'createdAt', + order: 'desc', + search: ' ', + include: ' ', + }); + const explicitDefaultsRes = makeRes(); + await httpListCreators(explicitDefaultsReq, explicitDefaultsRes, makeNext()); + + expect(creatorsUtils.fetchCreatorList).toHaveBeenNthCalledWith( + 1, + expect.objectContaining({ + sort: 'createdAt', + order: 'desc', + }) + ); + expect(creatorsUtils.fetchCreatorList).toHaveBeenNthCalledWith( + 2, expect.objectContaining({ - sort: expect.any(String), - order: expect.any(String), + limit: resolveCreatorListLimit(), + offset: PUBLIC_OFFSET_PAGINATION_DEFAULTS.offset, + sort: 'createdAt', + order: 'desc', }) ); + + const explicitCallArgs = (creatorsUtils.fetchCreatorList as jest.Mock).mock + .calls[1][0]; + expect(explicitCallArgs).not.toHaveProperty('search'); + expect(explicitCallArgs).not.toHaveProperty('include'); + + expect(explicitDefaultsRes.json.mock.calls[0][0]).toEqual( + omittedRes.json.mock.calls[0][0] + ); }); // ── Empty Filter Combinations ─────────────────────────────────────────────── diff --git a/src/modules/creators/creator-feed-newest-sort.integration.test.ts b/src/modules/creators/creator-feed-newest-sort.integration.test.ts index ba469a5..c54d2ff 100644 --- a/src/modules/creators/creator-feed-newest-sort.integration.test.ts +++ b/src/modules/creators/creator-feed-newest-sort.integration.test.ts @@ -7,7 +7,7 @@ import { httpListCreators } from './creators.controllers'; import * as creatorsUtils from './creators.utils'; -import type { CreatorProfile } from '../../types/profile.types'; +import { buildCreatorRegistrationFixtures } from './creator-registration-fixtures.utils'; // ── Lightweight request/response mocks ──────────────────────────────────────── @@ -30,35 +30,8 @@ function makeNext(): jest.Mock { // ── Fixtures with distinct registration timestamps ──────────────────────────── -const FIXTURE_OLDEST: CreatorProfile = { - id: 'cuid-oldest', - userId: 'user-oldest', - handle: 'oldest_creator', - displayName: 'Oldest Creator', - isVerified: false, - createdAt: new Date('2023-01-01T00:00:00.000Z'), - updatedAt: new Date('2023-01-01T00:00:00.000Z'), -}; - -const FIXTURE_MIDDLE: CreatorProfile = { - id: 'cuid-middle', - userId: 'user-middle', - handle: 'middle_creator', - displayName: 'Middle Creator', - isVerified: false, - createdAt: new Date('2023-06-15T00:00:00.000Z'), - updatedAt: new Date('2023-06-15T00:00:00.000Z'), -}; - -const FIXTURE_NEWEST: CreatorProfile = { - id: 'cuid-newest', - userId: 'user-newest', - handle: 'newest_creator', - displayName: 'Newest Creator', - isVerified: true, - createdAt: new Date('2024-03-01T00:00:00.000Z'), - updatedAt: new Date('2024-03-01T00:00:00.000Z'), -}; +const [FIXTURE_OLDEST, FIXTURE_MIDDLE, FIXTURE_NEWEST] = + buildCreatorRegistrationFixtures(3, '2023-01-01T00:00:00.000Z', 90); // Intentionally out of order to confirm the mock drives the assertion const FIXTURES_ASCENDING = [FIXTURE_OLDEST, FIXTURE_MIDDLE, FIXTURE_NEWEST]; diff --git a/src/modules/creators/creator-registration-fixtures.utils.ts b/src/modules/creators/creator-registration-fixtures.utils.ts new file mode 100644 index 0000000..092bb66 --- /dev/null +++ b/src/modules/creators/creator-registration-fixtures.utils.ts @@ -0,0 +1,30 @@ +import type { CreatorProfile } from '../../types/profile.types'; + +/** + * Builds a deterministic set of creator fixtures with evenly spaced timestamps. + * + * The helper is used by creator list integration tests that need stable + * registration ordering without duplicating timestamp setup in each file. + */ +export function buildCreatorRegistrationFixtures( + count: number, + startTimestamp: string | Date, + stepDays = 1 +): CreatorProfile[] { + const start = typeof startTimestamp === 'string' ? new Date(startTimestamp) : startTimestamp; + const stepMs = stepDays * 24 * 60 * 60 * 1000; + + return Array.from({ length: count }, (_, index) => { + const timestamp = new Date(start.getTime() + index * stepMs); + + return { + id: `cuid-${index + 1}`, + userId: `user-${index + 1}`, + handle: `creator_${index + 1}`, + displayName: `Creator ${index + 1}`, + isVerified: index % 2 === 0, + createdAt: timestamp, + updatedAt: timestamp, + }; + }); +} diff --git a/src/utils/rpc-timeout.utils.ts b/src/utils/rpc-timeout.utils.ts index 3359831..589fad5 100644 --- a/src/utils/rpc-timeout.utils.ts +++ b/src/utils/rpc-timeout.utils.ts @@ -1,5 +1,13 @@ // src/utils/rpc-timeout.utils.ts import { ErrorCode } from '../constants/error.constants'; +import { requestContextStorage } from './als.utils'; +import { logger } from './logger.utils'; + +type RpcResponseLike = { + status?: number; + endpoint?: string; + url?: string; +}; /** * Structured error thrown when an RPC call exceeds its timeout. @@ -23,6 +31,39 @@ export class RpcTimeoutError extends Error { */ export const DEFAULT_RPC_TIMEOUT_MS = 5000; +function isRpcResponseLike(value: unknown): value is RpcResponseLike { + return ( + typeof value === 'object' && + value !== null && + 'status' in value && + typeof (value as RpcResponseLike).status === 'number' + ); +} + +function logUnexpectedRpcStatus( + operation: string, + response: RpcResponseLike +): void { + const status = response.status; + if (typeof status !== 'number' || (status >= 200 && status < 300)) { + return; + } + + const requestId = requestContextStorage.getStore()?.requestId; + const endpoint = response.endpoint || response.url || operation; + + logger.warn( + { + type: 'unexpected_rpc_response_status', + operation, + endpoint, + status, + ...(requestId ? { requestId } : {}), + }, + 'Unexpected response status from external RPC call' + ); +} + /** * Wraps an outbound RPC call with a timeout. * @@ -55,6 +96,9 @@ export async function withRpcTimeout( try { const result = await Promise.race([fn(), timeout]); + if (isRpcResponseLike(result)) { + logUnexpectedRpcStatus(operation, result); + } return result; } finally { clearTimeout(timer);