--- title: 'The Three Signals of Observability' source: 'https://academia.sh/en/courses/observability/three-signals-of-observability' course: 'Observability and Reliability' language: en updated: '2026-08-23T14:24:49+00:00' license: 'CC BY-SA 4.0' --- # The Three Signals of Observability Actually producing the log, metric, and trace signals in a split loan system: how many steps each signal takes to answer the same three questions, which question each signal leaves unanswered, and how the three signals grow with request count. The previous course split the system into five processes and measured how every boundary gave birth to a new failure mode. The question left standing at its close was this: no tool was ever built for seeing where a request slows down or gets lost. This lesson builds the three parts of that tool and counts what each part can and cannot answer. The three signals are these. A **log** is the text record of individual events. A **metric** is events reduced to a pre-chosen aggregate. A **trace** is the record that holds a job's steps together with their durations, and each step is a **span**. All three measure, but each answers a different question; this lesson shows that not as a claim but as a step count. Monitoring categories and alert thresholds were established in the Performance Anti-Patterns and Monitoring course; the category list is not repeated here. This course's subject is the production side: how a signal is born in application code, which field it carries, and which it does not. ## The Service Producing Three Signals The setup continues as the previous course left it: catalog, membership, loan, notification, and fee are separate processes. The loan service calls the membership, catalog, and notification services; the membership service calls the fee service. The single source file below takes on all of their roles and produces all three signals on every request. **TL1 — all three signals are produced inside the process handling the request, with no extra collector process involved.** Rationale: what gets measured is not how the signal travels, but which field it carries at the point where it is born. The question of wiring to a collector is handled separately in the fifth lesson. ```js // service.mjs — [downstream...]; every request produces all three signals; long-lived process import { createServer } from "node:http"; import { appendFileSync, writeFileSync } from "node:fs"; const [name, port, ...downstream] = process.argv.slice(2); writeFileSync(`log-${name}.txt`, ""); writeFileSync(`trace-${name}.txt`, ""); const metrics = { requests: 0, errors: 0, duration: 0 }; // metrics: totals only, no id let localSeq = 0; // the trace number is meaningful only in this process const wait = (ms) => new Promise((c) => setTimeout(c, ms)); createServer(async (req, res) => { const u = new URL(req.url, "http://y"); if (u.pathname === "/metrics") { res.end(JSON.stringify({ name, ...metrics, duration: Math.round(metrics.duration) })); return; } const member = u.searchParams.get("member"), copy = Number(u.searchParams.get("copy")); const t0 = performance.now(), no = ++localSeq; metrics.requests += 1; await wait(name === "catalog" && copy % 5 === 0 ? 100 : 5); // every fifth copy is on a slow shelf let status = name === "fee" && member === "4023" ? 402 : 200; // unpaid fee for (const p of downstream) { const y = await fetch(`http://127.0.0.1:${p}/work?member=${member}©=${copy}`); if (y.status !== 200) status = y.status; } const duration = performance.now() - t0; metrics.duration += duration; if (status !== 200) metrics.errors += 1; appendFileSync(`log-${name}.txt`, `[${new Date().toISOString()}] ${name}: member ${member} copy ${copy} request took ` + `${Math.round(duration)} ms, result ${status}\n`); appendFileSync(`trace-${name}.txt`, `${no} ${name} ${Math.round(duration)}\n`); res.statusCode = status; res.end(JSON.stringify({ name, status })); }).listen(Number(port)); ``` This first version of the three signals is deliberately plain. The log line is a flat sentence. The metric is three totals. The span carries only a number that increases within its own process. The next four lessons close these three gaps one at a time. The source of slowness and errors is fixed: the catalog service spends a hundred milliseconds on every copy whose number is a multiple of five, every request from member 4023 comes back from the fee service with a 402, and that status climbs through membership up to the loan service. The client sends requests to the loan endpoint in sequence, picking members from a four-member rotation. ```js // run.mjs — ; sends requests to the loan endpoint in sequence const n = Number(process.argv[2]); const MEMBER = ["4021", "4022", "4023", "4024"]; // 4023 is the member with an unpaid fee for (let i = 1; i <= n; i += 1) { await fetch(`http://127.0.0.1:9101/work?member=${MEMBER[(i - 1) % 4]}©=${i}`); } console.log(`${n} requests sent`); ``` ## Same Question, Three Signals The query tool tries to answer three questions with three signals. The questions are real ones: where did this request slow down, how many requests failed, and which user was affected. A **step** is one pass the query makes over a record store: reading a file or an endpoint is a step, parsing plain text is a step, filtering is a step, trying to join two stores is a step. The counter lives in the code, it is not a guess. Steps are counted even for a question that goes unanswered — the work spent before giving up is also a cost. ```js // query.mjs — tries to answer three questions with three signals; every store pass is one step import { readFileSync, statSync } from "node:fs"; const SERVICES = ["loan", "membership", "catalog", "fee", "notification"]; const PORT = { loan: 9101, membership: 9102, catalog: 9103, fee: 9104, notification: 9105 }; const RE = /member (\d+) copy (\d+) request took ([\d.]+) ms, result (\d+)/; let step = 0; const count = () => { step += 1; }; const lines = (prefix, s) => { count(); return readFileSync(`${prefix}-${s}.txt`, "utf8").split("\n").filter(Boolean); }; const parseLog = () => { // plain text: one parsing pass per service const o = {}; for (const s of SERVICES) o[s] = lines("log", s).map((l) => { const m = l.match(RE); return m && { member: m[1], duration: +m[3], status: +m[4] }; }); for (const s of SERVICES) count(); return o; }; const readTrace = () => { const o = {}; for (const s of SERVICES) o[s] = lines("trace", s).map((l) => { const [no, , duration] = l.split(" "); return { no: +no, duration: +duration }; }); return o; }; const readMetrics = async () => { const o = {}; for (const s of SERVICES) { count(); o[s] = await (await fetch(`http://127.0.0.1:${PORT[s]}/metrics`)).json(); } return o; }; const print = (question, signal, answer) => console.log(`${question.padEnd(12)}${signal.padEnd(9)}${String(step).padStart(5)} ${answer}`); console.log(`${"question".padEnd(12)}${"signal".padEnd(9)}${"step".padStart(5)} answer`); const metrics = await readMetrics(); const baseStep = step; // S1 — where did this request slow down (target: the slowest request at the loan endpoint) const THRESHOLD = 60; // above 60 ms counts as a slow request step = 0; const g = parseLog(); count(); const slow = g.loan.filter((r) => r.duration > THRESHOLD).length; count(); print("S1 where", "log", `unanswered (${slow} loan records above ${THRESHOLD} ms; no shared id with downstream records)`); step = baseStep; count(); print("S1 where", "metric", `unanswered (no per-request breakdown; only the service average)`); step = 0; const trace = readTrace(); count(); const slowSpans = trace.loan.filter((a) => a.duration > THRESHOLD).length; count(); print("S1 where", "trace", `partial (${slowSpans} spans above ${THRESHOLD} ms; which downstream leg is unclear)`); // S2 — how many requests failed step = 0; const g2 = parseLog(); count(); print("S2 errors", "log", `${g2.loan.filter((r) => r.status !== 200).length} requests`); step = baseStep; count(); print("S2 errors", "metric", `${metrics.loan.errors} requests`); step = 0; readTrace(); count(); print("S2 errors", "trace", `unanswered (no status field in the trace record)`); // S3 — which user was affected step = 0; const g3 = parseLog(); count(); print("S3 who", "log", `member ${[...new Set(g3.loan.filter((r) => r.status !== 200).map((r) => r.member))].join(",")}`); step = baseStep; count(); print("S3 who", "metric", `unanswered (total counter, carries no id)`); step = 0; readTrace(); count(); print("S3 who", "trace", `unanswered (no id field in the span)`); const bytes = (prefix) => SERVICES.reduce((t, s) => t + statSync(`${prefix}-${s}.txt`).size, 0); const records = (prefix) => SERVICES.reduce((t, s) => t + lines(prefix, s).length, 0); const avg = (prefix) => Math.round(bytes(prefix) / records(prefix)); // bytes per record: robust to digit-count noise const metricBytes = SERVICES.reduce((t, s) => t + JSON.stringify(metrics[s]).length, 0); console.log(`\nvolume: log ${records("log")} records x avg. ${avg("log")} bytes, ` + `trace ${records("trace")} spans x avg. ${avg("trace")} bytes, ` + `metric ${SERVICES.length * 4} fields (independent of request count) / ${metricBytes} bytes`); ``` The block below brings up the five processes, sends twenty requests and asks the three questions, then sends a hundred and eighty more requests and reprints only the volume line. ```bash node service.mjs fee 9104 & node service.mjs catalog 9103 & node service.mjs notification 9105 & node service.mjs membership 9102 9104 & node service.mjs loan 9101 9102 9103 9105 & sleep 1 node run.mjs 20 node query.mjs node run.mjs 180 node query.mjs | tail -1 pkill -f "node service.mjs" ``` ``` 20 requests sent question signal step answer S1 where log 12 unanswered (4 loan records above 60 ms; no shared id with downstream records) S1 where metric 6 unanswered (no per-request breakdown; only the service average) S1 where trace 7 partial (4 spans above 60 ms; which downstream leg is unclear) S2 errors log 11 5 requests S2 errors metric 6 5 requests S2 errors trace 6 unanswered (no status field in the trace record) S3 who log 11 member 4023 S3 who metric 6 unanswered (total counter, carries no id) S3 who trace 6 unanswered (no id field in the span) volume: log 100 records x avg. 86 bytes, trace 100 spans x avg. 13 bytes, metric 20 fields (independent of request count) / 292 bytes 180 requests sent volume: log 1000 records x avg. 87 bytes, trace 1000 spans x avg. 14 bytes, metric 20 fields (independent of request count) / 305 bytes ``` ## Five of Nine Attempts Came Back Empty The table has nine rows and five are unanswered. The ones that are answered: the metric gives the error count in six steps, the log in eleven; only the log gives the affected member, also in eleven steps. No signal fully answers the first question. The difference is not signal quality but which field it carries. The metric gives the cheapest answer because the question it can answer was already chosen when the metric was written: the `errors` counter is the "how many requests failed" question, frozen into code. For the same reason it cannot answer "which member" — there is no id inside the total, and none can be recovered afterward. The log is the opposite: every event has its own line, so it answers the id question, but because it is a flat sentence, every query needs five separate parsing passes and the regular expression depends on the line format. ## Volume The last two lines are the third measure. Twenty external requests produced a hundred log records and a hundred spans across five processes; two hundred external requests produced a thousand records and a thousand spans. The ratio is fixed: five records per external request, because the call amplification is five and every process writes its own record. The average size per record is eighty-six to eighty-seven bytes for the log, thirteen to fourteen bytes for the trace; the roughly sixfold gap comes from the log carrying a fresh timestamp and sentence pattern on every line. The metric sits outside this growth. Five services, four fields per service: twenty fields, no matter how many requests come in. The total payload grew from 292 to 305 bytes; the entire increase comes from the digit count of the accumulated duration total, not from the record count. The metric's cost grows with the **field count**, not the request count; the log's and the trace's cost grow with the request count. This is also why the three signals are kept together: they answer the same question at different costs and different resolutions. ## Summary - The log records individual events, the metric records pre-chosen totals, the trace records a job's steps as spans; all three were born from the same request in the same process. - Five of nine attempts stayed unanswered: the metric could not answer the id question, the trace could not answer the status or id question, and no signal fully answered "where did this request slow down." - The metric spent the fewest steps (6), the log the most (11–12); the gap comes from plain text needing one parsing pass per service. - The metric chooses its question when it is written: the `errors` counter makes one question cheap and closes off the id question permanently. - Volume follows two different laws: 20 requests produced 100 records, 200 requests produced 1000; the metric stayed at 20 fields in both cases and grew only by its digit count. ## Next Step Three of the five unanswered questions share a single cause: there is no field in the records that identifies the request. Nothing connects the line the loan service writes to the line the catalog service writes, because the lines are written as sentences and a sentence carries only what that one process knows. The next lesson takes the log out of being a flat sentence, splits it into fields, and attaches to the request an id that crosses the process boundary. What gets measured is clear: how many of the same question's filtering and parsing steps drop away, how many services a request becomes traceable across, and how many call sites are left without the id carried through them.