Structured Logging in Node.js: How a Business ID Became My correlationId
The Chaos
The pipeline wasn’t huge, but it wasn’t trivial either: a few decision steps with branches (the path changed depending on the flow type), and a callback step (a Lambda waiting on an external response before continuing). Each Lambda logged on its own, with console.log() scattered through the code. The bare minimum identifier (the case ID) did show up in some logs, but there was no consistency across functions. One Lambda logged a plain string, another logged an object, and none of them followed the same format.
The result: no real correlation. To reconstruct what had happened, you had to guess the workflow’s likely execution order and open the log groups one by one, trying to piece the timeline together by hand. And the short retention window made things worse: without the execution history, all that was left were the raw CloudWatch logs, and since they had no shared structure, you couldn’t use one to make up for the absence of the other. The one missing piece was exactly the link that would have made the two complete each other.
The Turning Point
One option would be to generate a fresh correlationId (a UUID) at the start of each execution and pass it manually through every Lambda. It’s the more obvious solution, and it works. But in my case it didn’t make sense: I already had the case ID, which identified the execution from start to finish. Creating a second ID just to correlate logs would mean keeping two identifiers for the same thing, and every investigation would turn into a translation exercise: find the case ID first, then look up its associated correlationId, and only then search the logs.
It wasn’t a complicated realization. AWS Step Functions already lets you name each execution (name) when it starts, and that name is available in every state in the workflow through the $$.Execution.Name context variable, with nothing to pass manually between steps. All I had to do was use what was already there: instead of generating a random UUID as the execution name, I used the case ID itself:
const input: StartExecutionCommandInput = {
stateMachineArn: getStateMachineArn(),
name: data.id, // the case ID becomes the execution name
input: JSON.stringify(data),
};
From there, any state in the state machine can access that ID with zero effort:
"Parameters": {
"data.$": "$",
"correlationId.$": "$$.Execution.Name"
}
One single identifier, from start to finish: the same case ID that shows up in the database is what shows up in the logs of every Lambda in the pipeline. No extra UUID, no mapping table, no translation needed.
The Implementation
The solution has a few pieces that fit together.
1) The Logger: structured, with context per layer
The core is a createLogger(layer, category) function that returns a logger that’s already “pre-configured,” aware of where it’s being called from. This eliminates the repetition of manual fields in every log call:
export type LogLevel = 'info' | 'warn' | 'error';
export type LogLayer = 'handler' | 'service' | 'wrapper' | 'authorizer' | 'util';
export interface LogEntry {
message: string;
eventCode: string;
category: string;
layer: LogLayer;
correlationId?: string;
[key: string]: unknown;
}
const REDACTED_KEYS = ['token', 'authorization', 'password', 'secret', 'apikey', 'x-api-key'];
const REDACTED_VALUE = '[REDACTED]';
export const redact = (value: unknown): unknown => {
if (Array.isArray(value)) return value.map(redact);
if (value !== null && typeof value === 'object') {
return Object.entries(value as Record<string, unknown>).reduce<Record<string, unknown>>(
(acc, [key, nestedValue]) => {
const shouldRedact = REDACTED_KEYS.some((k) => key.toLowerCase().includes(k));
acc[key] = shouldRedact ? REDACTED_VALUE : redact(nestedValue);
return acc;
},
{},
);
}
return value;
};
const writeLog = (level: LogLevel, entry: LogEntry): void => {
const redacted = redact(entry) as Record<string, unknown>;
console[level === 'warn' ? 'warn' : level === 'error' ? 'error' : 'info'](redacted);
};
export const createLogger = (layer: LogLayer, category: string) => ({
info: (entry: Omit<LogEntry, 'layer' | 'category'>) => writeLog('info', { ...entry, layer, category }),
warn: (entry: Omit<LogEntry, 'layer' | 'category'>) => writeLog('warn', { ...entry, layer, category }),
error: (entry: Omit<LogEntry, 'layer' | 'category'>) => writeLog('error', { ...entry, layer, category }),
});
Three details worth calling out:
- Automatic redaction: any field with a name resembling
token,password,secret, etc. gets replaced before it hits the console, without relying on manual discipline in every log call. - layer + category: every log entry already knows where it came from (
handler,service,wrapper...) without having to write that out every time. - Generic enough:
entryaccepts any additional field ([key: string]: unknown), so you can log practically any object (request, response, a query result, an error payload) without adapting the logger for every data type. The same logger works for handlers, services, wrappers, or utils.
2) Entry via the workflow: the wrapper for each step
Each state in the state machine passes $$.Execution.Name along as the correlationId in the payload for the next Lambda:
{
"Type": "Task",
"Resource": "${SomeFunctionArn}",
"Parameters": {
"data.$": "$",
"correlationId.$": "$$.Execution.Name"
},
"ResultPath": "$.someResult"
}
A generic wrapper in each Lambda in the flow handles the entry/exit/error logging automatically:
export function stepFunctionWrapper<TIn, TOut>(
stepName: string,
fn: (arg: TIn) => Promise<TOut>
) {
return async (data: TIn): Promise<TOut> => {
const log = createLogger('wrapper', stepName);
const correlationId = (data as { correlationId?: string })?.correlationId;
try {
log.info({ message: 'Starting step execution', eventCode: 'StepStarted', correlationId });
const result = await fn(data);
log.info({ message: 'Step execution successful', eventCode: 'StepCompleted', correlationId });
return result;
} catch (err) {
log.error({ message: 'Step execution failed', eventCode: 'StepFailed', correlationId, error: String(err) });
throw err;
}
};
}
3) The logger inside the handler
The wrapper handles the generic “step started / completed / failed” logging. But inside the business logic, it makes sense to log specific points too: not just “started and finished,” but also decisions and IDs that will matter in a future investigation. The pattern that repeats in every handler:
import { createLogger } from '../../../util/logger';
import { stepFunctionWrapper } from '../stepFunctionWrapper';
// Logger created once, at the top of the module, reused throughout the function
const log = createLogger('handler', 'createRecord');
export const handler = async ({
data: request,
correlationId,
}: {
data: CreateRecordRequest;
correlationId?: string;
}): Promise<number> => {
log.info({
message: 'Creating record',
eventCode: 'HandlerStarted',
correlationId,
externalId: request.externalId, // the case ID, always attached
});
// ...business logic (validation, creation, etc.)
const { id: recordId } = await models.Record.create({ /* ... */ });
log.info({
message: 'Record created',
eventCode: 'HandlerSuccess',
correlationId,
externalId: request.externalId,
recordId, // the internal ID too, for cross-referencing with the database later
});
return recordId;
};
export const createRecord = stepFunctionWrapper('createRecordHandler', handler);
Three small decisions that make a difference when it’s time to investigate:
logis created once, outside the function: this avoids recreating the logger on every call and makes it clear, just by glancing at the top of the file, which layer / category that module represents.correlationIdis always present, but never generated here: the handler only receives it and passes it along; the wrapper, in this case the Step Functions one, is what creates it. This keeps anyone from accidentally generating a new ID somewhere in the middle of the code and breaking the correlation.eventCodeas an implicit enum (HandlerStarted,HandlerSuccess,HandlerError...): this lets you filter in CloudWatch by event type without depending on the free-textmessage.
The main payoff: even in a business investigation (not just a technical error, like “why did this record end up with the wrong status?”), the logs already have the right IDs attached from the moment they were created. There’s no need to instrument anything when the incident happens; it’s already there.
4) Propagating the correlationId outward: calls to external services
The correlationId doesn’t stay confined to the pipeline itself. When a handler calls an external API, the correlationId gets passed as a parameter to the service function, which logs the request and response around the call:
export const searchExternalService = async (
request: SearchRequest,
correlationId?: string,
isRetry = false,
): Promise<SearchResponse> => {
try {
log.info({
message: 'Requesting external service',
eventCode: 'ServiceRequest',
correlationId,
requestBody: request,
});
const { data } = await axios.post<SearchResponse>(/* ... */);
log.info({
message: 'External service responded successfully',
eventCode: 'ServiceResponse',
correlationId,
responseBody: data,
});
return data;
} catch (error: unknown) {
handleError(error, isRetry, correlationId);
return searchExternalService(request, correlationId, true);
}
};
It’s not the correlationId traveling as a header to the third-party service. The external system has no idea it exists. It’s the request and response for that specific call getting tied to the same correlation ID used across the rest of the pipeline. In practice, this means that when you investigate a case, you also see exactly what was sent and received for each external integration, in the right spot on the timeline, not just what happened inside your own Lambdas.
Bonus: entry via API (the correlationId comes for free)
The main case in this post is the Step Functions-orchestrated workflow, but it’s worth noting: for regular HTTP endpoints (outside a state machine context), there’s nothing to generate. API Gateway itself already provides a unique requestId per request, which can play the same role:
export function apiWrapper<TIn, TOut>(
handlerName: string,
fn: (arg: TIn, event: APIGatewayProxyEvent, correlationId?: string) => Promise<TOut>,
) {
return async (event: APIGatewayProxyEvent): Promise<APIGatewayProxyResult> => {
const correlationId = event.requestContext?.requestId;
const log = createLogger('wrapper', handlerName);
log.info({ message: 'Request started', eventCode: 'HandlerStarted', correlationId });
try {
const inputData = event.body ? JSON.parse(event.body) as TIn : {} as TIn;
const result = await fn(inputData, event, correlationId);
log.info({ message: 'Request handled successfully', eventCode: 'EndpointSuccess', correlationId });
return { statusCode: 200, body: JSON.stringify(result) };
} catch (err) {
log.error({ message: 'Request failed', eventCode: 'EndpointError', correlationId, error: String(err) });
return { statusCode: 500, body: JSON.stringify({ message: 'Internal error' }) };
}
};
}
The same principle from the previous section (use an identifier that already exists, instead of creating a new one) applies here too.
The Result: What the Search Looks Like Today
The customer calls again, same scenario: “Did you receive my request?” Except now the investigation flow is different. The ID the customer gives me is the correlationId. There’s nothing to figure out beforehand. In CloudWatch Logs Insi
Comments
No comments yet. Start the discussion.