From 753c92b4de4bcbf4cd2bdc5081ec6026e25499bb Mon Sep 17 00:00:00 2001 From: Pato Perpetua Date: Sat, 29 Aug 2026 21:00:19 +1000 Subject: [PATCH 1/2] feat(api): record delivery IDs and structured send telemetry (#39) Populate the full send log contract (environment, failureCategory, recipientHash) and document operational Kusto queries for volume, latency, and retry analysis. Co-authored-by: Cursor --- apps/api/src/functions/send.spec.ts | 103 +++++++++ apps/api/src/functions/send.ts | 86 ++++++-- apps/api/src/telemetry/index.ts | 2 +- apps/api/src/telemetry/logger.spec.ts | 37 +++- apps/api/src/telemetry/logger.ts | 19 ++ docs/README.md | 4 +- docs/architecture/multi-tenant-security.md | 1 + docs/architecture/request-lifecycle.md | 6 +- docs/operations/send-metrics-queries.md | 196 ++++++++++++++++++ docs/operations/troubleshooting.md | 13 +- .../src/providers/email-provider.spec.ts | 13 ++ .../src/providers/email-types.ts | 5 + 12 files changed, 456 insertions(+), 29 deletions(-) create mode 100644 docs/operations/send-metrics-queries.md diff --git a/apps/api/src/functions/send.spec.ts b/apps/api/src/functions/send.spec.ts index 7788d29..f947f89 100644 --- a/apps/api/src/functions/send.spec.ts +++ b/apps/api/src/functions/send.spec.ts @@ -14,6 +14,7 @@ import { } from '@singleton-sd/post-kit-types'; import { TenantResolverError, type TenantResolver } from '../tenant'; import { TemplateStoreError, type TemplateStore } from '../templates'; +import { createLogger } from '../telemetry'; import { createSendHandler } from './send'; const TENANT: TenantContext = { tenantId: 'inkads', environment: 'development' }; @@ -283,6 +284,108 @@ describe('sendHandler', () => { assert.equal(sent[0]?.html, '

InkAds

'); }); + it('emits the full structured log contract on success', async () => { + const lines: string[] = []; + const handler = createSendHandler({ + tenantResolver: fakeResolver(), + templateStore: fakeStore(COMPILED), + emailProvider: fakeProvider(), + fromAddress: () => 'noreply@example.com', + createLogger: (correlationId) => createLogger(correlationId, (line) => lines.push(line)), + }); + + await handler( + fakeRequest({ + headers: { 'x-correlation-id': 'corr-log-success' }, + json: validBody(), + }), + fakeContext(), + ); + + const completed = lines + .map((l) => JSON.parse(l)) + .find((e) => e.msg === 'send.request.completed'); + assert.ok(completed, 'send.request.completed must be logged'); + assert.equal(completed.correlationId, 'corr-log-success'); + assert.equal(completed.tenantId, 'inkads'); + assert.equal(completed.environment, 'development'); + assert.equal(completed.templateKey, 'marketing.contact-us'); + assert.equal(completed.outcome, 'sent'); + assert.equal(typeof completed.durationMs, 'number'); + assert.equal(completed.providerMessageId, 'msg-1'); + assert.equal(typeof completed.recipientHash, 'string'); + assert.equal(completed.recipientHash.length, 16); + assert.ok(!('failureCategory' in completed)); + assert.ok(!JSON.stringify(completed).includes('user@example.com')); + assert.ok(!JSON.stringify(completed).includes('Ada')); + }); + + it('emits the full structured log contract on validation failure', async () => { + const lines: string[] = []; + const handler = createSendHandler({ + tenantResolver: fakeResolver(), + templateStore: fakeStore(COMPILED), + emailProvider: fakeProvider(), + fromAddress: () => 'noreply@example.com', + createLogger: (correlationId) => createLogger(correlationId, (line) => lines.push(line)), + }); + + await handler( + fakeRequest({ + headers: { 'x-correlation-id': 'corr-log-validation' }, + json: { template: 'marketing.contact-us', to: 'user@example.com', variables: {} }, + }), + fakeContext(), + ); + + const failed = lines.map((l) => JSON.parse(l)).find((e) => e.msg === 'send.request.failed'); + assert.ok(failed); + assert.equal(failed.correlationId, 'corr-log-validation'); + assert.equal(failed.tenantId, 'inkads'); + assert.equal(failed.environment, 'development'); + assert.equal(failed.templateKey, 'marketing.contact-us'); + assert.equal(failed.outcome, 'validation_error'); + assert.equal(failed.errorCode, PostKitErrorCode.MISSING_VARIABLES); + assert.equal(failed.failureCategory, 'missing_variables'); + assert.equal(typeof failed.durationMs, 'number'); + assert.equal(typeof failed.recipientHash, 'string'); + assert.ok(!JSON.stringify(failed).includes('user@example.com')); + }); + + it('emits provider failureCategory and providerMessageId on provider errors', async () => { + const { EmailProviderError } = await import('@singleton-sd/post-kit-email'); + const lines: string[] = []; + const handler = createSendHandler({ + tenantResolver: fakeResolver(), + templateStore: fakeStore(COMPILED), + emailProvider: { + name: 'development', + isConfigured: () => true, + send: async () => { + throw new EmailProviderError({ + message: 'boom', + kind: 'permanent', + provider: 'development', + providerRequestId: 'req-42', + }); + }, + }, + fromAddress: () => 'noreply@example.com', + createLogger: (correlationId) => createLogger(correlationId, (line) => lines.push(line)), + }); + + await handler(fakeRequest({ json: validBody() }), fakeContext()); + + const failed = lines.map((l) => JSON.parse(l)).find((e) => e.msg === 'send.request.failed'); + assert.ok(failed); + assert.equal(failed.outcome, 'failed'); + assert.equal(failed.failureCategory, 'permanent'); + assert.equal(failed.providerMessageId, 'req-42'); + assert.equal(failed.environment, 'development'); + assert.ok(!JSON.stringify(failed).includes('user@example.com')); + assert.ok(!JSON.stringify(failed).includes('Ada')); + }); + it('returns PROVIDER_FAILURE when the provider throws', async () => { const { EmailProviderError } = await import('@singleton-sd/post-kit-email'); const handler = createSendHandler({ diff --git a/apps/api/src/functions/send.ts b/apps/api/src/functions/send.ts index df883bf..22a0132 100644 --- a/apps/api/src/functions/send.ts +++ b/apps/api/src/functions/send.ts @@ -12,10 +12,11 @@ import { type SendResponse, type TenantBranding, type TenantContext, + type TenantEnvironment, type TemplateVariables, } from '@singleton-sd/post-kit-types'; import { ensureAppConfiguration } from '../config/app-configuration'; -import { createLogger, resolveCorrelationId, type Logger } from '../telemetry'; +import { createLogger, hashRecipient, resolveCorrelationId, type Logger } from '../telemetry'; import { ApiKeyTenantResolver, TenantResolverError, @@ -90,20 +91,42 @@ export function createSendHandler(deps: SendHandlerDependencies) { 'X-Correlation-Id': correlationId, }; + let tenantId: string | undefined; + let environment: TenantEnvironment | undefined; + let templateKey: string | undefined; + let recipientHash: string | undefined; + + const logContext = (): { + tenantId?: string; + environment?: TenantEnvironment; + templateKey?: string; + recipientHash?: string; + } => ({ + tenantId, + environment, + templateKey, + recipientHash, + }); + const errorResponse = ( status: number, code: PostKitErrorCode, error: string, outcome: 'failed' | 'validation_error' | 'auth_error' = 'failed', - extra?: { tenantId?: string; templateKey?: string }, + extra?: { + failureCategory?: string; + providerMessageId?: string; + }, ): HttpResponseInit => { const durationMs = Date.now() - startMs; + const failureCategory = extra?.failureCategory ?? failureCategoryFromErrorCode(code, outcome); logger.error('send.request.failed', { outcome, errorCode: code, + failureCategory, durationMs, - tenantId: extra?.tenantId, - templateKey: extra?.templateKey, + providerMessageId: extra?.providerMessageId, + ...logContext(), }); const body: PostKitErrorResponse = { error, code, correlationId }; return { status, headers, jsonBody: body }; @@ -122,20 +145,19 @@ export function createSendHandler(deps: SendHandlerDependencies) { ); } - let tenantId: string | undefined; - let templateKey: string | undefined; - try { const tenant = await deps.tenantResolver.resolve(request); tenantId = tenant.tenantId; + environment = tenant.environment; const body = await request.json().catch(() => null); const parsed = parseSendRequest(body); if (!parsed.ok) { - return errorResponse(400, parsed.code, parsed.error, 'validation_error', { tenantId }); + return errorResponse(400, parsed.code, parsed.error, 'validation_error'); } const sendRequest = parsed.value; templateKey = sendRequest.template; + recipientHash = hashRecipient(sendRequest.to); let compiled; try { @@ -148,10 +170,7 @@ export function createSendHandler(deps: SendHandlerDependencies) { : err.code === PostKitErrorCode.INVALID_TEMPLATE ? 400 : 500; - return errorResponse(status, err.code, err.message, 'failed', { - tenantId, - templateKey, - }); + return errorResponse(status, err.code, err.message, 'failed'); } throw err; } @@ -172,7 +191,6 @@ export function createSendHandler(deps: SendHandlerDependencies) { PostKitErrorCode.MISSING_VARIABLES, `Missing required variables: ${missing.join(', ')}`, 'validation_error', - { tenantId, templateKey }, ); } @@ -186,7 +204,7 @@ export function createSendHandler(deps: SendHandlerDependencies) { PostKitErrorCode.PROVIDER_FAILURE, 'Email sender is not configured.', 'failed', - { tenantId, templateKey }, + { failureCategory: 'provider_not_configured' }, ); } @@ -206,9 +224,8 @@ export function createSendHandler(deps: SendHandlerDependencies) { logger.info('send.request.completed', { outcome: 'sent', durationMs, - tenantId, - templateKey, providerMessageId: result.providerMessageId, + ...logContext(), }); const response: SendResponse = { id: correlationId, status: 'sent' }; @@ -221,10 +238,7 @@ export function createSendHandler(deps: SendHandlerDependencies) { : error.code === PostKitErrorCode.UNAUTHORIZED ? 403 : 401; - return errorResponse(status, error.code, error.message, 'auth_error', { - tenantId, - templateKey, - }); + return errorResponse(status, error.code, error.message, 'auth_error'); } if (error instanceof EmailProviderError) { @@ -242,7 +256,10 @@ export function createSendHandler(deps: SendHandlerDependencies) { PostKitErrorCode.PROVIDER_FAILURE, 'Email provider failed to send the message.', 'failed', - { tenantId, templateKey }, + { + failureCategory: error.failureCategory, + providerMessageId: error.providerRequestId, + }, ); } @@ -255,12 +272,37 @@ export function createSendHandler(deps: SendHandlerDependencies) { PostKitErrorCode.PROVIDER_FAILURE, 'We could not send your message. Please try again shortly.', 'failed', - { tenantId, templateKey }, + { failureCategory: 'unhandled' }, ); } }; } +function failureCategoryFromErrorCode( + code: PostKitErrorCode, + outcome: 'failed' | 'validation_error' | 'auth_error', +): string { + if (outcome === 'auth_error') { + return code === PostKitErrorCode.UNAUTHENTICATED ? 'auth_unauthenticated' : 'auth_unauthorized'; + } + switch (code) { + case PostKitErrorCode.INVALID_TEMPLATE: + return 'invalid_template'; + case PostKitErrorCode.INVALID_RECIPIENT: + return 'invalid_recipient'; + case PostKitErrorCode.MISSING_VARIABLES: + return 'missing_variables'; + case PostKitErrorCode.TEMPLATE_NOT_FOUND: + return 'template_not_found'; + case PostKitErrorCode.STORAGE_FAILURE: + return 'storage_failure'; + case PostKitErrorCode.PROVIDER_FAILURE: + return 'provider_failure'; + default: + return 'unknown'; + } +} + function isSafeTemplateKey(templateKey: string): boolean { return ( Boolean(templateKey) && diff --git a/apps/api/src/telemetry/index.ts b/apps/api/src/telemetry/index.ts index 82b071e..115628e 100644 --- a/apps/api/src/telemetry/index.ts +++ b/apps/api/src/telemetry/index.ts @@ -1,3 +1,3 @@ export { generateCorrelationId, resolveCorrelationId } from './correlation'; -export { createLogger } from './logger'; +export { createLogger, hashRecipient } from './logger'; export type { LogEntry, Logger } from './logger'; diff --git a/apps/api/src/telemetry/logger.spec.ts b/apps/api/src/telemetry/logger.spec.ts index 3bb31d8..804c1df 100644 --- a/apps/api/src/telemetry/logger.spec.ts +++ b/apps/api/src/telemetry/logger.spec.ts @@ -1,7 +1,8 @@ import assert from 'node:assert/strict'; +import { createHash } from 'node:crypto'; import { describe, it } from 'node:test'; import { PostKitErrorCode } from '@singleton-sd/post-kit-types'; -import { createLogger } from './logger'; +import { createLogger, hashRecipient } from './logger'; describe('createLogger', () => { it('info() emits JSON containing msg and correlationId', () => { @@ -102,4 +103,38 @@ describe('createLogger', () => { assert.doesNotThrow(() => logger.info('smoke')); assert.doesNotThrow(() => logger.error('smoke')); }); + + it('includes failureCategory and recipientHash in the contract', () => { + const lines: string[] = []; + const logger = createLogger('corr-fc', (line) => lines.push(line)); + + logger.error('send.request.failed', { + outcome: 'failed', + failureCategory: 'permanent', + recipientHash: 'abc123', + durationMs: 10, + }); + + const entry = JSON.parse(lines[0]!); + assert.equal(entry.failureCategory, 'permanent'); + assert.equal(entry.recipientHash, 'abc123'); + }); +}); + +describe('hashRecipient', () => { + it('returns a deterministic 16-char hex digest of the normalized address', () => { + const expected = createHash('sha256') + .update('user@example.com', 'utf8') + .digest('hex') + .slice(0, 16); + assert.equal(hashRecipient('user@example.com'), expected); + assert.equal(hashRecipient(' User@Example.COM '), expected); + }); + + it('does not return the raw email address', () => { + const hash = hashRecipient('secret.user@acme.com'); + assert.ok(!hash.includes('secret')); + assert.ok(!hash.includes('@')); + assert.equal(hash.length, 16); + }); }); diff --git a/apps/api/src/telemetry/logger.ts b/apps/api/src/telemetry/logger.ts index 1ff7f35..b21d89f 100644 --- a/apps/api/src/telemetry/logger.ts +++ b/apps/api/src/telemetry/logger.ts @@ -6,10 +6,25 @@ * write function (default: console.log, suitable for Azure Functions). * - Logger instances are per-request — never use as a singleton. * - Never log PII: no recipient addresses, variable values, or tokens. + * + * Recipient privacy: `recipientHash` is a 16-character hex prefix of the + * SHA-256 digest of the trimmed, lowercased recipient address. The raw address + * is never logged; the hash is deterministic so duplicate/retry analysis can + * correlate sends to the same recipient without exposing PII. */ +import { createHash } from 'node:crypto'; import type { PostKitErrorCode } from '@singleton-sd/post-kit-types'; +/** + * Privacy-safe recipient identifier for structured logs. + * See module header for the documented approach. + */ +export function hashRecipient(email: string): string { + const normalized = email.trim().toLowerCase(); + return createHash('sha256').update(normalized, 'utf8').digest('hex').slice(0, 16); +} + /** * Structured fields that may appear in a log entry. * All fields are optional except correlationId (carried by the logger instance). @@ -22,6 +37,8 @@ export interface LogEntry { outcome?: 'sent' | 'failed' | 'validation_error' | 'auth_error'; durationMs?: number; providerMessageId?: string; + failureCategory?: string; + recipientHash?: string; errorCode?: PostKitErrorCode | string; // NOTE: never log recipient addresses, variable values, or tokens } @@ -34,6 +51,8 @@ const LOG_ENTRY_KEYS: ReadonlyArray> = [ 'outcome', 'durationMs', 'providerMessageId', + 'failureCategory', + 'recipientHash', 'errorCode', ]; diff --git a/docs/README.md b/docs/README.md index 1797aa9..ba1be69 100644 --- a/docs/README.md +++ b/docs/README.md @@ -42,7 +42,8 @@ docs/ │ ├── tenant-onboarding.md (new tenant → first email) │ └── environments.md (dev/staging/prod separation, local dev) ├── operations/ -│ └── troubleshooting.md (send endpoint triage, correlation IDs, runbooks) +│ ├── troubleshooting.md (send endpoint triage, correlation IDs, runbooks) +│ └── send-metrics-queries.md (Kusto queries for send telemetry) └── examples/ └── publish-email-templates.yml (sample consumer publish workflow) ``` @@ -66,4 +67,5 @@ docs/ | [`architecture/template-lifecycle.md`](./architecture/template-lifecycle.md) | Template source → compiler → publisher → Blob layout → send-time load | | [`architecture/multi-tenant-security.md`](./architecture/multi-tenant-security.md) | Tenant resolution, environment separation, path safety, credential boundaries, unimplemented controls | | [`operations/troubleshooting.md`](./operations/troubleshooting.md) | `POST /emails/send` error triage, correlation-ID tracing, incident runbooks | +| [`operations/send-metrics-queries.md`](./operations/send-metrics-queries.md) | Kusto queries for send volume, success rate, provider failures, latency, duplicates | | [`guides/public-forms.md`](./guides/public-forms.md) | Public web forms (Contact Us, waitlist): trusted server endpoint pattern, credential-exposure anti-patterns, consumer-side validation / abuse / rate-limit duties | diff --git a/docs/architecture/multi-tenant-security.md b/docs/architecture/multi-tenant-security.md index 4396a73..57759ab 100644 --- a/docs/architecture/multi-tenant-security.md +++ b/docs/architecture/multi-tenant-security.md @@ -49,6 +49,7 @@ Consequences that follow directly from this design: - The token value is never included in an error message or a log entry. Logs carry only the declared `LogEntry` fields — `correlationId`, `tenantId`, `environment`, `templateKey`, `outcome`, `durationMs`, `providerMessageId`, + `failureCategory`, `recipientHash`, `errorCode`. Recipient addresses and and `errorCode`. The Azure Functions binding uses `authLevel: 'anonymous'`. That is diff --git a/docs/architecture/request-lifecycle.md b/docs/architecture/request-lifecycle.md index a23dda4..90b8cc8 100644 --- a/docs/architecture/request-lifecycle.md +++ b/docs/architecture/request-lifecycle.md @@ -92,8 +92,10 @@ template variables. - The success body's `id` field is the same correlation ID. - Logs are newline-delimited JSON. The logger emits only the fields declared on `LogEntry` (`correlationId`, `tenantId`, `environment`, `templateKey`, - `outcome`, `durationMs`, `providerMessageId`, `errorCode`). Recipient - addresses, variable values, and tokens are never logged. + `outcome`, `durationMs`, `providerMessageId`, `failureCategory`, + `recipientHash`, `errorCode`). Recipient addresses, variable values, and + tokens are never logged. See [`send-metrics-queries.md`](../operations/send-metrics-queries.md) + for the field contract and operational queries. ## Error codes and HTTP statuses diff --git a/docs/operations/send-metrics-queries.md b/docs/operations/send-metrics-queries.md new file mode 100644 index 0000000..4098277 --- /dev/null +++ b/docs/operations/send-metrics-queries.md @@ -0,0 +1,196 @@ +# Send endpoint — operational metrics queries + +Copy-pasteable Kusto queries for day-to-day operational questions about +`POST /emails/send`. All queries assume newline-delimited JSON log entries +emitted by `apps/api/src/telemetry/logger.ts` and parsed from the `message` +column in Application Insights `traces`. + +**Field contract** (terminal events `send.request.completed` and +`send.request.failed`): + +| Field | Description | +| --- | --- | +| `correlationId` | Per-request trace id | +| `tenantId` | Resolved tenant (absent on auth failures before resolution) | +| `environment` | `development`, `staging`, or `production` from the credential | +| `templateKey` | Requested template key (absent when body validation fails early) | +| `outcome` | `sent`, `failed`, `validation_error`, or `auth_error` | +| `durationMs` | Handler wall time in milliseconds | +| `providerMessageId` | Provider-assigned message or request id when available | +| `failureCategory` | Stable failure bucket (see below) | +| `recipientHash` | 16-char SHA-256 prefix of normalized recipient (never the raw address) | +| `errorCode` | `PostKitErrorCode` on failures | + +`failureCategory` values for API-level failures: +`auth_unauthenticated`, `auth_unauthorized`, `invalid_template`, +`invalid_recipient`, `missing_variables`, `template_not_found`, +`storage_failure`, `provider_not_configured`, `provider_failure`, +`unhandled`. + +Provider failures use the six `EmailProviderError` kinds directly: +`configuration`, `transient`, `rate_limit`, `permanent`, `validation`, +`cancelled`. + +For triage runbooks and error-code mapping, see +[`troubleshooting.md`](./troubleshooting.md). + +## Setup helper + +Every query below uses this parse step. Adjust the time range as needed. + +```kusto +let SendEvents = traces +| where timestamp > ago(7d) +| extend payload = parse_json(message) +| where tostring(payload.msg) in ("send.request.completed", "send.request.failed"); +``` + +## Sends per tenant and template + +```kusto +SendEvents +| summarize sendCount = count() by + tenantId = tostring(payload.tenantId), + templateKey = tostring(payload.templateKey), + environment = tostring(payload.environment) +| order by sendCount desc +``` + +## Success and failure rate + +```kusto +SendEvents +| extend outcome = tostring(payload.outcome) +| summarize + total = count(), + sent = countif(outcome == "sent"), + failed = countif(outcome != "sent") +| extend successRate = 100.0 * sent / total, failureRate = 100.0 * failed / total +``` + +Per tenant over time: + +```kusto +SendEvents +| extend outcome = tostring(payload.outcome) +| summarize + total = count(), + sent = countif(outcome == "sent") + by tenantId = tostring(payload.tenantId), bin(timestamp, 1h) +| extend successRate = 100.0 * sent / total +| order by timestamp asc +``` + +## Provider failures + +All terminal failures where the provider rejected or could not deliver: + +```kusto +SendEvents +| where tostring(payload.msg) == "send.request.failed" +| where tostring(payload.errorCode) == "PROVIDER_FAILURE" +| extend failureCategory = tostring(payload.failureCategory) +| summarize count() by failureCategory, bin(timestamp, 1h) +| order by timestamp asc +``` + +Provider-kind breakdown (the six `EmailProviderError` kinds): + +```kusto +SendEvents +| where tostring(payload.msg) == "send.request.failed" +| where tostring(payload.failureCategory) in ( + "configuration", "transient", "rate_limit", "permanent", "validation", "cancelled") +| summarize count() by failureCategory = tostring(payload.failureCategory) +``` + +## Template not found + +```kusto +SendEvents +| where tostring(payload.msg) == "send.request.failed" +| where tostring(payload.failureCategory) == "template_not_found" +| project timestamp, + correlationId = tostring(payload.correlationId), + tenantId = tostring(payload.tenantId), + environment = tostring(payload.environment), + templateKey = tostring(payload.templateKey) +| order by timestamp desc +``` + +## Validation failures + +```kusto +SendEvents +| where tostring(payload.outcome) == "validation_error" +| summarize count() by + failureCategory = tostring(payload.failureCategory), + errorCode = tostring(payload.errorCode), + bin(timestamp, 1h) +| order by timestamp asc +``` + +## Latency distribution + +Successful sends: + +```kusto +SendEvents +| where tostring(payload.msg) == "send.request.completed" +| extend durationMs = toint(payload.durationMs) +| summarize + p50 = percentile(durationMs, 50), + p90 = percentile(durationMs, 90), + p99 = percentile(durationMs, 99), + avg = avg(durationMs), + max = max(durationMs) + by tenantId = tostring(payload.tenantId) +``` + +All terminal events (includes failures): + +```kusto +SendEvents +| extend durationMs = toint(payload.durationMs) +| summarize percentiles(durationMs, 50, 90, 99) by tostring(payload.msg) +``` + +## Duplicate and retry behaviour + +Correlate retries by the caller-supplied correlation id (same id retried by +the consumer): + +```kusto +SendEvents +| summarize attempts = count() by correlationId = tostring(payload.correlationId) +| where attempts > 1 +| order by attempts desc +``` + +Detect duplicate sends to the same recipient within a window (uses +`recipientHash`, not the raw address): + +```kusto +SendEvents +| where tostring(payload.msg) == "send.request.completed" +| extend recipientHash = tostring(payload.recipientHash) +| where isnotempty(recipientHash) +| summarize sendCount = count(), correlationIds = make_set(tostring(payload.correlationId), 10) + by recipientHash, templateKey = tostring(payload.templateKey), bin(timestamp, 1h) +| where sendCount > 1 +| order by sendCount desc +``` + +Join handler logs to provider adapter logs on `correlationId`: + +```kusto +traces +| where timestamp > ago(1d) +| extend payload = parse_json(message) +| where tostring(payload.correlationId) == "" +| project timestamp, msg = tostring(payload.msg), outcome = tostring(payload.outcome), + failureCategory = tostring(payload.failureCategory), + providerMessageId = tostring(payload.providerMessageId), + durationMs = toint(payload.durationMs) +| order by timestamp asc +``` diff --git a/docs/operations/troubleshooting.md b/docs/operations/troubleshooting.md index 4c1eeca..0353092 100644 --- a/docs/operations/troubleshooting.md +++ b/docs/operations/troubleshooting.md @@ -102,8 +102,10 @@ Fields that may appear (only non-`undefined` values are emitted): | `durationMs` | completed / failed | Milliseconds from handler entry | | `tenantId` | completed / failed | Set once the credential resolves; absent on 401/403 and on `STORAGE_FAILURE` | | `templateKey` | completed / failed | Set once the body validates | -| `providerMessageId` | completed | Provider-assigned message id | -| `environment` | — | Part of the log entry contract but not currently populated by the send handler | +| `environment` | completed / failed | `development`, `staging`, or `production` from the credential; absent on 401/403 and on `STORAGE_FAILURE` | +| `providerMessageId` | completed / failed | Provider-assigned message id on success; provider request id on provider failures when available | +| `failureCategory` | failed | Stable failure bucket — API-level categories (`template_not_found`, `missing_variables`, …) or one of the six provider kinds (`configuration`, `transient`, `rate_limit`, `permanent`, `validation`, `cancelled`) | +| `recipientHash` | completed / failed | 16-character SHA-256 prefix of the normalized recipient address; see [`send-metrics-queries.md`](./send-metrics-queries.md) | Three additional diagnostic entries are written through the Functions invocation context rather than the structured logger, so they are searchable by message @@ -119,9 +121,16 @@ The provider adapter logs its own entries — `email.send.accepted`, provider API keys, request bodies, recipient addresses, or variable values. The tenant resolver deliberately never includes the token in its error messages, and the logger only emits a fixed set of known keys for exactly this reason. +Recipient correlation uses `recipientHash` (documented in +[`send-metrics-queries.md`](./send-metrics-queries.md)) — never the raw address. ### Example queries +Operational metrics queries (sends per tenant, success rate, provider failures, +latency, duplicate/retry behaviour) live in +[`send-metrics-queries.md`](./send-metrics-queries.md). The examples below cover +single-request tracing and failure breakdown. + Placeholder names only — substitute your own workspace and table names. Trace one request end to end by correlation ID: diff --git a/packages/post-kit-email/src/providers/email-provider.spec.ts b/packages/post-kit-email/src/providers/email-provider.spec.ts index 66113a1..15e89ea 100644 --- a/packages/post-kit-email/src/providers/email-provider.spec.ts +++ b/packages/post-kit-email/src/providers/email-provider.spec.ts @@ -97,6 +97,19 @@ describe('loadEmailRuntimeConfig', () => { }); }); +describe('EmailProviderError', () => { + it('exposes failureCategory as a stable alias of kind', () => { + const error = new EmailProviderError({ + message: 'rate limited', + kind: 'rate_limit', + provider: 'forward-email', + providerRequestId: 'req-1', + }); + assert.equal(error.failureCategory, 'rate_limit'); + assert.equal(error.kind, error.failureCategory); + }); +}); + describe('ForwardEmailProvider', () => { it('reports unconfigured when FORWARD_EMAIL_TOKEN is missing', () => { const provider = new ForwardEmailProvider({ apiToken: '' }); diff --git a/packages/post-kit-email/src/providers/email-types.ts b/packages/post-kit-email/src/providers/email-types.ts index 3f68c17..5c15c5d 100644 --- a/packages/post-kit-email/src/providers/email-types.ts +++ b/packages/post-kit-email/src/providers/email-types.ts @@ -41,6 +41,11 @@ export class EmailProviderError extends Error { readonly cause?: unknown; + /** Stable failure category for delivery telemetry — alias of `kind`. */ + get failureCategory(): EmailProviderErrorKind { + return this.kind; + } + constructor(options: { message: string; kind: EmailProviderErrorKind; From e2224239a9285f765691a2f65c6a78b719eb4ca7 Mon Sep 17 00:00:00 2001 From: Pato Perpetua Date: Sun, 30 Aug 2026 13:40:35 +1000 Subject: [PATCH 2/2] fix(api): address CodeRabbit review on send telemetry contract - Add providerRequestId as a separate log field from providerMessageId - Capture templateKey/recipientHash on late validation failures - Enforce recipientHash format in logger emission - Fix metrics query docs and multi-tenant-security typo Co-authored-by: Cursor --- apps/api/src/functions/send.spec.ts | 32 ++++++++- apps/api/src/functions/send.ts | 81 ++++++++++++++-------- apps/api/src/telemetry/logger.spec.ts | 30 +++++++- apps/api/src/telemetry/logger.ts | 17 ++++- docs/architecture/multi-tenant-security.md | 4 +- docs/operations/send-metrics-queries.md | 27 +++++--- docs/operations/troubleshooting.md | 3 +- 7 files changed, 145 insertions(+), 49 deletions(-) diff --git a/apps/api/src/functions/send.spec.ts b/apps/api/src/functions/send.spec.ts index f947f89..adcfe28 100644 --- a/apps/api/src/functions/send.spec.ts +++ b/apps/api/src/functions/send.spec.ts @@ -352,7 +352,34 @@ describe('sendHandler', () => { assert.ok(!JSON.stringify(failed).includes('user@example.com')); }); - it('emits provider failureCategory and providerMessageId on provider errors', async () => { + it('emits templateKey and recipientHash when variables validation fails after template and recipient succeed', async () => { + const lines: string[] = []; + const handler = createSendHandler({ + tenantResolver: fakeResolver(), + templateStore: fakeStore(COMPILED), + emailProvider: fakeProvider(), + fromAddress: () => 'noreply@example.com', + createLogger: (correlationId) => createLogger(correlationId, (line) => lines.push(line)), + }); + + await handler( + fakeRequest({ + headers: { 'x-correlation-id': 'corr-log-variables-null' }, + json: { template: 'marketing.contact-us', to: 'user@example.com', variables: null }, + }), + fakeContext(), + ); + + const failed = lines.map((l) => JSON.parse(l)).find((e) => e.msg === 'send.request.failed'); + assert.ok(failed); + assert.equal(failed.templateKey, 'marketing.contact-us'); + assert.equal(failed.errorCode, PostKitErrorCode.MISSING_VARIABLES); + assert.equal(typeof failed.recipientHash, 'string'); + assert.equal(failed.recipientHash.length, 16); + assert.ok(!JSON.stringify(failed).includes('user@example.com')); + }); + + it('emits provider failureCategory and providerRequestId on provider errors', async () => { const { EmailProviderError } = await import('@singleton-sd/post-kit-email'); const lines: string[] = []; const handler = createSendHandler({ @@ -380,7 +407,8 @@ describe('sendHandler', () => { assert.ok(failed); assert.equal(failed.outcome, 'failed'); assert.equal(failed.failureCategory, 'permanent'); - assert.equal(failed.providerMessageId, 'req-42'); + assert.equal(failed.providerRequestId, 'req-42'); + assert.ok(!('providerMessageId' in failed)); assert.equal(failed.environment, 'development'); assert.ok(!JSON.stringify(failed).includes('user@example.com')); assert.ok(!JSON.stringify(failed).includes('Ada')); diff --git a/apps/api/src/functions/send.ts b/apps/api/src/functions/send.ts index 22a0132..8d5c339 100644 --- a/apps/api/src/functions/send.ts +++ b/apps/api/src/functions/send.ts @@ -116,6 +116,7 @@ export function createSendHandler(deps: SendHandlerDependencies) { extra?: { failureCategory?: string; providerMessageId?: string; + providerRequestId?: string; }, ): HttpResponseInit => { const durationMs = Date.now() - startMs; @@ -126,6 +127,7 @@ export function createSendHandler(deps: SendHandlerDependencies) { failureCategory, durationMs, providerMessageId: extra?.providerMessageId, + providerRequestId: extra?.providerRequestId, ...logContext(), }); const body: PostKitErrorResponse = { error, code, correlationId }; @@ -153,6 +155,12 @@ export function createSendHandler(deps: SendHandlerDependencies) { const body = await request.json().catch(() => null); const parsed = parseSendRequest(body); if (!parsed.ok) { + if (parsed.templateKey) { + templateKey = parsed.templateKey; + } + if (parsed.recipientHash) { + recipientHash = parsed.recipientHash; + } return errorResponse(400, parsed.code, parsed.error, 'validation_error'); } const sendRequest = parsed.value; @@ -258,7 +266,7 @@ export function createSendHandler(deps: SendHandlerDependencies) { 'failed', { failureCategory: error.failureCategory, - providerMessageId: error.providerRequestId, + providerRequestId: error.providerRequestId, }, ); } @@ -312,53 +320,66 @@ function isSafeTemplateKey(templateKey: string): boolean { ); } -function parseSendRequest( - body: unknown, -): { ok: true; value: SendRequest } | { ok: false; code: PostKitErrorCode; error: string } { +function parseSendRequest(body: unknown): + | { ok: true; value: SendRequest } + | { + ok: false; + code: PostKitErrorCode; + error: string; + templateKey?: string; + recipientHash?: string; + } { + let templateKey: string | undefined; + let recipientHash: string | undefined; + + const fail = ( + code: PostKitErrorCode, + error: string, + ): { + ok: false; + code: PostKitErrorCode; + error: string; + templateKey?: string; + recipientHash?: string; + } => ({ + ok: false, + code, + error, + templateKey, + recipientHash, + }); + if (body === null || typeof body !== 'object' || Array.isArray(body)) { - return { - ok: false, - code: PostKitErrorCode.INVALID_RECIPIENT, - error: 'Request body must be a JSON object.', - }; + return fail(PostKitErrorCode.INVALID_RECIPIENT, 'Request body must be a JSON object.'); } const obj = body as Record; if (typeof obj['template'] !== 'string' || !obj['template'].trim()) { - return { ok: false, code: PostKitErrorCode.INVALID_TEMPLATE, error: 'template is required.' }; + return fail(PostKitErrorCode.INVALID_TEMPLATE, 'template is required.'); } if (!isSafeTemplateKey(obj['template'])) { - return { - ok: false, - code: PostKitErrorCode.INVALID_TEMPLATE, - error: 'template key contains unsafe path characters.', - }; + return fail(PostKitErrorCode.INVALID_TEMPLATE, 'template key contains unsafe path characters.'); } + templateKey = obj['template']; + if (typeof obj['to'] !== 'string' || !BASIC_EMAIL.test(obj['to'])) { - return { - ok: false, - code: PostKitErrorCode.INVALID_RECIPIENT, - error: 'to must be a valid email address.', - }; + return fail(PostKitErrorCode.INVALID_RECIPIENT, 'to must be a valid email address.'); } + recipientHash = hashRecipient(obj['to']); + if ( obj['variables'] === null || typeof obj['variables'] !== 'object' || Array.isArray(obj['variables']) ) { - return { - ok: false, - code: PostKitErrorCode.MISSING_VARIABLES, - error: 'variables must be an object of string values.', - }; + return fail( + PostKitErrorCode.MISSING_VARIABLES, + 'variables must be an object of string values.', + ); } const variables: Record = {}; for (const [key, value] of Object.entries(obj['variables'] as Record)) { if (typeof value !== 'string') { - return { - ok: false, - code: PostKitErrorCode.MISSING_VARIABLES, - error: `variables.${key} must be a string.`, - }; + return fail(PostKitErrorCode.MISSING_VARIABLES, `variables.${key} must be a string.`); } variables[key] = value; } diff --git a/apps/api/src/telemetry/logger.spec.ts b/apps/api/src/telemetry/logger.spec.ts index 804c1df..0126194 100644 --- a/apps/api/src/telemetry/logger.spec.ts +++ b/apps/api/src/telemetry/logger.spec.ts @@ -111,13 +111,39 @@ describe('createLogger', () => { logger.error('send.request.failed', { outcome: 'failed', failureCategory: 'permanent', - recipientHash: 'abc123', + recipientHash: 'a'.repeat(16), durationMs: 10, }); const entry = JSON.parse(lines[0]!); assert.equal(entry.failureCategory, 'permanent'); - assert.equal(entry.recipientHash, 'abc123'); + assert.equal(entry.recipientHash, 'a'.repeat(16)); + }); + + it('omits recipientHash values that are not a 16-char hex digest', () => { + const lines: string[] = []; + const logger = createLogger('corr-rh', (line) => lines.push(line)); + + logger.error('send.request.failed', { + outcome: 'failed', + recipientHash: 'user@example.com', + }); + + const entry = JSON.parse(lines[0]!); + assert.ok(!('recipientHash' in entry)); + }); + + it('includes providerRequestId in the contract', () => { + const lines: string[] = []; + const logger = createLogger('corr-pr', (line) => lines.push(line)); + + logger.error('send.request.failed', { + outcome: 'failed', + providerRequestId: 'req-99', + }); + + const entry = JSON.parse(lines[0]!); + assert.equal(entry.providerRequestId, 'req-99'); }); }); diff --git a/apps/api/src/telemetry/logger.ts b/apps/api/src/telemetry/logger.ts index b21d89f..3541411 100644 --- a/apps/api/src/telemetry/logger.ts +++ b/apps/api/src/telemetry/logger.ts @@ -25,6 +25,13 @@ export function hashRecipient(email: string): string { return createHash('sha256').update(normalized, 'utf8').digest('hex').slice(0, 16); } +/** 16-character lowercase hex digest emitted by `hashRecipient`. */ +export const RECIPIENT_HASH_PATTERN = /^[a-f0-9]{16}$/; + +export function isValidRecipientHash(value: string): boolean { + return RECIPIENT_HASH_PATTERN.test(value); +} + /** * Structured fields that may appear in a log entry. * All fields are optional except correlationId (carried by the logger instance). @@ -37,6 +44,7 @@ export interface LogEntry { outcome?: 'sent' | 'failed' | 'validation_error' | 'auth_error'; durationMs?: number; providerMessageId?: string; + providerRequestId?: string; failureCategory?: string; recipientHash?: string; errorCode?: PostKitErrorCode | string; @@ -51,6 +59,7 @@ const LOG_ENTRY_KEYS: ReadonlyArray> = [ 'outcome', 'durationMs', 'providerMessageId', + 'providerRequestId', 'failureCategory', 'recipientHash', 'errorCode', @@ -81,9 +90,13 @@ export function createLogger( if (fields) { for (const key of LOG_ENTRY_KEYS) { const value = fields[key]; - if (value !== undefined) { - entry[key] = value; + if (value === undefined) { + continue; + } + if (key === 'recipientHash' && typeof value === 'string' && !isValidRecipientHash(value)) { + continue; } + entry[key] = value; } } diff --git a/docs/architecture/multi-tenant-security.md b/docs/architecture/multi-tenant-security.md index 57759ab..f801618 100644 --- a/docs/architecture/multi-tenant-security.md +++ b/docs/architecture/multi-tenant-security.md @@ -49,8 +49,8 @@ Consequences that follow directly from this design: - The token value is never included in an error message or a log entry. Logs carry only the declared `LogEntry` fields — `correlationId`, `tenantId`, `environment`, `templateKey`, `outcome`, `durationMs`, `providerMessageId`, - `failureCategory`, `recipientHash`, `errorCode`. Recipient addresses and - and `errorCode`. + `failureCategory`, `recipientHash`, and `errorCode`. Recipient addresses and + variable values are never logged. The Azure Functions binding uses `authLevel: 'anonymous'`. That is deliberate: PostKit performs its own authentication, and no Functions host key diff --git a/docs/operations/send-metrics-queries.md b/docs/operations/send-metrics-queries.md index 4098277..3eb778a 100644 --- a/docs/operations/send-metrics-queries.md +++ b/docs/operations/send-metrics-queries.md @@ -16,7 +16,8 @@ column in Application Insights `traces`. | `templateKey` | Requested template key (absent when body validation fails early) | | `outcome` | `sent`, `failed`, `validation_error`, or `auth_error` | | `durationMs` | Handler wall time in milliseconds | -| `providerMessageId` | Provider-assigned message or request id when available | +| `providerMessageId` | Provider-assigned message id on successful sends | +| `providerRequestId` | Provider trace/request id on provider failures when available | | `failureCategory` | Stable failure bucket (see below) | | `recipientHash` | 16-char SHA-256 prefix of normalized recipient (never the raw address) | | `errorCode` | `PostKitErrorCode` on failures | @@ -83,25 +84,26 @@ SendEvents ## Provider failures -All terminal failures where the provider rejected or could not deliver: +Provider-kind failures (the six `EmailProviderError` kinds). Excludes +`provider_not_configured`, `unhandled`, and other API-level categories that also +use `errorCode == "PROVIDER_FAILURE"`: ```kusto SendEvents | where tostring(payload.msg) == "send.request.failed" -| where tostring(payload.errorCode) == "PROVIDER_FAILURE" -| extend failureCategory = tostring(payload.failureCategory) -| summarize count() by failureCategory, bin(timestamp, 1h) +| where tostring(payload.failureCategory) in ( + "configuration", "transient", "rate_limit", "permanent", "validation", "cancelled") +| summarize count() by failureCategory = tostring(payload.failureCategory), bin(timestamp, 1h) | order by timestamp asc ``` -Provider-kind breakdown (the six `EmailProviderError` kinds): +Misconfigured sender (`provider_not_configured`) separately: ```kusto SendEvents | where tostring(payload.msg) == "send.request.failed" -| where tostring(payload.failureCategory) in ( - "configuration", "transient", "rate_limit", "permanent", "validation", "cancelled") -| summarize count() by failureCategory = tostring(payload.failureCategory) +| where tostring(payload.failureCategory) == "provider_not_configured" +| summarize count() by tenantId = tostring(payload.tenantId), bin(timestamp, 1h) ``` ## Template not found @@ -176,7 +178,11 @@ SendEvents | extend recipientHash = tostring(payload.recipientHash) | where isnotempty(recipientHash) | summarize sendCount = count(), correlationIds = make_set(tostring(payload.correlationId), 10) - by recipientHash, templateKey = tostring(payload.templateKey), bin(timestamp, 1h) + by recipientHash, + templateKey = tostring(payload.templateKey), + tenantId = tostring(payload.tenantId), + environment = tostring(payload.environment), + bin(timestamp, 1h) | where sendCount > 1 | order by sendCount desc ``` @@ -191,6 +197,7 @@ traces | project timestamp, msg = tostring(payload.msg), outcome = tostring(payload.outcome), failureCategory = tostring(payload.failureCategory), providerMessageId = tostring(payload.providerMessageId), + providerRequestId = tostring(payload.providerRequestId), durationMs = toint(payload.durationMs) | order by timestamp asc ``` diff --git a/docs/operations/troubleshooting.md b/docs/operations/troubleshooting.md index 0353092..01aa9d8 100644 --- a/docs/operations/troubleshooting.md +++ b/docs/operations/troubleshooting.md @@ -103,7 +103,8 @@ Fields that may appear (only non-`undefined` values are emitted): | `tenantId` | completed / failed | Set once the credential resolves; absent on 401/403 and on `STORAGE_FAILURE` | | `templateKey` | completed / failed | Set once the body validates | | `environment` | completed / failed | `development`, `staging`, or `production` from the credential; absent on 401/403 and on `STORAGE_FAILURE` | -| `providerMessageId` | completed / failed | Provider-assigned message id on success; provider request id on provider failures when available | +| `providerMessageId` | completed | Provider-assigned message id on successful sends | +| `providerRequestId` | failed | Provider trace/request id on provider failures when available | | `failureCategory` | failed | Stable failure bucket — API-level categories (`template_not_found`, `missing_variables`, …) or one of the six provider kinds (`configuration`, `transient`, `rate_limit`, `permanent`, `validation`, `cancelled`) | | `recipientHash` | completed / failed | 16-character SHA-256 prefix of the normalized recipient address; see [`send-metrics-queries.md`](./send-metrics-queries.md) |