How to check correlation id in logs

Send one request carrying an id you chose, then search every service log for that single string with grep -n 'qa-cart-7f31' checkout.log inventory.log. A correlation id that works returns at least one line from every service that touched the request. A service missing from the output never received the header.

Why check this

Run this after any change to an HTTP client, a service template or a message queue consumer, and once per release on staging. The defect it catches is silent: the first service logs the id, the second invents its own, every response is a 200, and nobody notices until an incident needs the two halves of one request joined together.

The check has to span at least two services, because a single service always agrees with itself. The value of the id is its ability to survive a hop. Reading one log proves the id exists; reading both logs for the same string proves it propagates, which is a different claim and the one that fails in practice.

Prerequisites

• Node 22. Confirm with node --version.
• curl 8, any build. The parallel requests in steps 5 and 6 use -Z and --next from the curl manual.
• checkout.mjs below, started with node checkout.mjs > checkout.log. Route /pay forwards the id downstream, /pay-nofwd does not, /slow-global and /slow-als log from inside a setTimeout callback.

import { createServer } from 'node:http';
import { randomUUID } from 'node:crypto';
import { AsyncLocalStorage } from 'node:async_hooks';

const als = new AsyncLocalStorage();
let current = null; // the module-level variable an ALS-free service uses
const log = (o) => console.log(JSON.stringify({ ts: new Date().toISOString(), svc: 'checkout', ...o }));

createServer((req, res) => {
  const cid = req.headers['x-correlation-id'] ?? randomUUID();
  current = cid;
  als.run({ cid }, async () => {
    log({ level: 'info', msg: 'received', path: req.url, correlationId: cid });
    res.setHeader('X-Correlation-Id', cid);
    if (req.url.startsWith('/pay')) {
      const headers = req.url === '/pay' ? { 'X-Correlation-Id': cid } : {};
      const r = await fetch('http://127.0.0.1:9422/reserve', { headers });
      log({ level: 'info', msg: 'inventory replied', status: r.status, correlationId: cid });
    } else {
      setTimeout(() => {
        const late = req.url === '/slow-als' ? als.getStore().cid : current;
        log({ level: 'info', msg: 'async work done', path: req.url, correlationId: late });
      }, 300);
    }
    res.end(JSON.stringify({ ok: true }));
  });
}).listen(9421, '127.0.0.1', () => log({ level: 'info', msg: 'listening', port: 9421 }));

• inventory.mjs below, started with node inventory.mjs > inventory.log. It adopts an inbound id and generates one when none arrives, which is what most service templates do.

import { createServer } from 'node:http';
import { randomUUID } from 'node:crypto';

const log = (o) => console.log(JSON.stringify({ ts: new Date().toISOString(), svc: 'inventory', ...o }));

createServer((req, res) => {
  const incoming = req.headers['x-correlation-id'];
  const cid = incoming ?? randomUUID();
  log({ level: 'info', msg: 'reserve', correlationId: cid, source: incoming ? 'header' : 'generated' });
  res.end(JSON.stringify({ ok: true }));
}).listen(9422, '127.0.0.1', () => log({ level: 'info', msg: 'listening', port: 9422 }));

Steps

1. 1

   Step 1.

   Call the front service with an id you choose and read the response header.

   curl -s -D - -o /dev/null -H 'X-Correlation-Id: qa-cart-7f31' http://127.0.0.1:9421/pay | grep -i 'correlation'
   

   X-Correlation-Id: qa-cart-7f31

   Use a value that cannot occur by accident. A generated UUID works, and a label such as qa-cart-7f31 is easier to keep in a test report.

2. 2

   Step 2.

   Search both service logs for that one string.

   grep -n 'qa-cart-7f31' checkout.log inventory.log
   

   checkout.log:2:{"ts":"2026-09-12T07:27:38.913Z","svc":"checkout","level":"info","msg":"received","path":"/pay","correlationId":"qa-cart-7f31"}
   checkout.log:3:{"ts":"2026-09-12T07:27:38.928Z","svc":"checkout","level":"info","msg":"inventory replied","status":200,"correlationId":"qa-cart-7f31"}
   inventory.log:2:{"ts":"2026-09-12T07:27:38.915Z","svc":"inventory","level":"info","msg":"reserve","correlationId":"qa-cart-7f31","source":"header"}

   This is the passing result: two files in the output, and the inventory line reports source: header, so the id arrived rather than being invented. The three timestamps also order the hop, 38.913 to 38.915 to 38.928.

3. 3

   Step 3.

   Call the route that forgets to forward the header, and note that the response is unchanged.

   curl -s -o /dev/null -w '%{http_code}\n' -H 'X-Correlation-Id: qa-cart-9b02' http://127.0.0.1:9421/pay-nofwd
   

   200

   Nothing in the response distinguishes this call from step 1. The defect lives entirely in the logs.

4. 4

   Step 4.

   Search both logs for the second id, then read the last line the downstream service wrote.

   grep -n 'qa-cart-9b02' checkout.log inventory.log; tail -1 inventory.log
   

   checkout.log:4:{"ts":"2026-09-12T07:27:38.989Z","svc":"checkout","level":"info","msg":"received","path":"/pay-nofwd","correlationId":"qa-cart-9b02"}
   checkout.log:5:{"ts":"2026-09-12T07:27:39.004Z","svc":"checkout","level":"info","msg":"inventory replied","status":200,"correlationId":"qa-cart-9b02"}
   inventory.log:{"ts":"2026-09-12T07:27:38.996Z","svc":"inventory","level":"info","msg":"reserve","correlationId":"c7f8b414-b4e4-46f8-a244-dc1c5ca61b97","source":"generated"}

   inventory.log is absent from the grep output, which is the whole finding. The tail shows why: the service handled the request at 38.996, between the two checkout lines, under an id nobody outside that process has ever seen. Both logs look healthy on their own.

5. 5

   Step 5.

   Send two requests at the same time to a route whose late log line reads a module-level variable.

   curl -sZ -o /dev/null -H 'X-Correlation-Id: cart-AAA' http://127.0.0.1:9421/slow-global --next -s -o /dev/null -H 'X-Correlation-Id: cart-BBB' http://127.0.0.1:9421/slow-global; sleep 1; grep 'async work done' checkout.log
   

   {"ts":"2026-09-12T07:27:46.438Z","svc":"checkout","level":"info","msg":"async work done","path":"/slow-global","correlationId":"cart-BBB"}
   {"ts":"2026-09-12T07:27:46.438Z","svc":"checkout","level":"info","msg":"async work done","path":"/slow-global","correlationId":"cart-BBB"}

   Two requests, two late lines, one id. The cart-AAA work is recorded under cart-BBB, because the second request overwrote the variable while the first was waiting. A test that sends one request at a time never sees this.

6. 6

   Step 6.

   Repeat against the route that keeps the id in AsyncLocalStorage.

   curl -sZ -o /dev/null -H 'X-Correlation-Id: cart-AAA' http://127.0.0.1:9421/slow-als --next -s -o /dev/null -H 'X-Correlation-Id: cart-BBB' http://127.0.0.1:9421/slow-als; sleep 1; grep 'async work done' checkout.log | tail -2
   

   {"ts":"2026-09-12T07:27:54.006Z","svc":"checkout","level":"info","msg":"async work done","path":"/slow-als","correlationId":"cart-AAA"}
   {"ts":"2026-09-12T07:27:54.006Z","svc":"checkout","level":"info","msg":"async work done","path":"/slow-als","correlationId":"cart-BBB"}

   Same timestamp, same route, two ids. The store follows the callback rather than the clock, so each late line belongs to its own request. This is the fix to ask for when step 5 fails.

How to read the result

| What you see | What it means | What to do | | --- | --- | --- | | One or more lines from every service | The id propagates across the hop | Nothing. Record the id in the test report. | | Lines from the caller only | The outbound request carried no header | Fix the HTTP client, not the receiving service. | | Downstream line with source: generated | The receiver invented an id | Same defect as above, seen from the other end. Both logs pass in isolation. | | Two concurrent requests sharing one late id | The id lives in a variable, not in the async context | Move it into AsyncLocalStorage or an explicit argument. | | The id appears in the message text but not as a field | Grep works, filtering in the log tool will not | Promote it to a field, as the pages under What to check next describe. |

Common mistakes

What to check next

• X request id header: the id has to reach the client in a response header before anyone can quote it.
• Trace id in logs: the same discipline when a tracing library owns the id instead of the application.
• How to check trace propagation between services: the standard header that does this hop, with rules a home-made header does not have.
• Json logging format: the id needs to be a field, since grep is a blunt way to find one line among millions.

FAQ

What is the difference between a correlation id and a request id?

A request id names one HTTP request. A correlation id names the operation that request belongs to, which may cover several requests, a queue message and a retry. Many systems use one value for both. Neither name is standardised, so read the code.

What is the difference between a correlation id and a trace id?

A correlation id is invented by the application and carried in a header of its choice. A trace id comes from the traceparent header defined by W3C Trace Context, has a fixed format, and is generated by the tracing library. They coexist, and during a migration a log line often carries both.

Where do I find the correlation id for a failed request?

In the response headers first, then in the log line for that request. If the response carries none, reproduce the call yourself with an id you chose, as in step 1, rather than searching the logs by timestamp.

Which header name should I use?

Pick one name for the whole system and reject the alternatives at the edge. X-Correlation-Id and X-Request-Id are both common. The name matters less than the rule that every outbound call copies it, which steps 3 and 4 test.

Verified