It is 11:40 on a Thursday. A customer writes: "I tried to pay for my order and it gave me an error". Nothing more. With what you have in src/app.js today — that console.log at position 5 we have spent five lessons promising to replace — the investigation consists of hand-searching through thousands of lines of plain text for something resembling POST /v1/orders/ord_5001/payment → 500 (312 ms), with no idea which customer it was, no way to filter by status, no sight of the error that caused it and no way to relate it to the SQL query that failed.

Worse still: most of the time you do not even find out. Problems are discovered because a customer complains, not because the system warns you. And the decisions we have been taking since 04-01 — the limits from 04-04, the caching from 04-06, the design debt from 04-01 — depend on data you are not collecting right now.

This lesson closes module 4 with the layer that makes everything else governable. We will replace the console.log with pino and structured logs correlated by traceId, instrument the API with prom-client and expose /metrics, look at the distributed trace of a complete POST /v1/orders, distinguish liveness from readiness in /health, and define what to alert on and what to watch on launch day.

Warning. Logs are one of the easiest places for personal data and credentials to leak, with legal consequences under the GDPR. The redaction of sensitive fields and the retention policy in this lesson are a starting point; any real deployment requires a compliance and security review. All the data is fictional.

1. Monitoring versus observability
2. The three pillars and the question each one answers
3. Structured logs: why JSON and not text
4. pino and the Aroma Store logger
5. What to always log and what to never log
6. Automatic redaction of sensitive fields
7. The src/middleware/logging.js middleware
8. End-to-end correlation with Aroma-Trace-Id
9. 5xx errors: what gets logged versus what gets returned
10. Metrics: the four golden signals and the RED method
11. Metric types and why the histogram
12. Instrumenting with prom-client and exposing /metrics
13. Cardinality: why ord_5001 blows the system up
14. Distributed tracing: spans, context and traceparent
15. A trace of POST /v1/orders
16. Health checks: liveness and readiness
17. Useful alerts, SLOs and the error budget
18. The minimum launch-day dashboard
19. The usual stack
20. Taking stock of module 4

Monitoring is necessary and is not enough. Modern systems fail in ways nobody foresaw: an interaction between the rate limiting and one specific client, a query that degrades only with a certain data distribution, a webhook that jams only when SwiftShip is slow.

The operational definition that is actually useful: a system is observable if you can answer new questions about its behaviour without deploying new code. If understanding an incident means adding a console.log and waiting for it to happen again, your system is not observable.

A real incident's workflow uses them in this order:

1. A metric fires the alert: the error rate on POST /v1/orders/{id}/payment has risen.
2. A trace of a failing request shows where it breaks: the call to the gateway.
3. A log carrying that trace's traceId gives the detail: the exact error message and the customerId.

That is why all three have to be correlated. Three excellent systems with no shared identifier are worth far less than three mediocre ones that share the traceId. And we already have that identifier: Aroma-Trace-Id, since 03-02.

What our middleware emits today:

What it should emit:

The only real disadvantage — readability in development — is solved with a formatter, so there is no reason not to structure.

Two underlying rules that avoid most of the problems:

Logs are events, not sentences. "User cus_842 has created order ord_5001" forces you to extract the identifiers with a regular expression. {"event":"order_created","customerId":"cus_842","orderId":"ord_5001"} is queryable.

The route is logged as a template, not as a URI. "/v1/orders/:id/payment", never "/v1/orders/ord_5001/payment". If you log the real URI, you cannot group: every order produces a different route and per-endpoint statistics become impossible. The identifier goes in its own field, where it is genuinely useful for filtering.

pino is the de facto standard logger in Node: it writes JSON, it is extremely fast — it serialises off the critical path — and it ships with sensitive-field redaction and child loggers built in.

Five decisions explained:

pino's levels are trace (10), debug (20), info (30), warn (40), error (50) and fatal (60). Aroma Store's criteria:

A frequent mistake: logging 4xxs as error. A 404 or a 400 is normal API behaviour, not a system failure. If you mark them as errors, your alerts will fill with noise and you will stop looking at them. Only 5xxs are error.

base adds service, version, environment and instance to every line. Without it, in a system with several instances you will not know which one emitted what, nor be able to tell one deployment's problem apart from another's.

Output to stdout. Not to a file. In a modern deployment, the process writes to standard output and the platform is what collects, rotates and ships the logs. Writing to a file from the application complicates rotation, permissions and containers.

Two nuances that are not obvious:

The IP address is personal data under the GDPR. Logging it is usually justified on security grounds (legitimate interest), but it demands a short, documented retention policy. A prudent option is storing a salted hash instead of the IP, which allows correlation without identification.

The customerId is also a personal identifier, but it is pseudonymous and necessary to operate. The identifier is logged (cus_842), never the name or the email address: if you need to know who it is, you query the database with the appropriate access controls.

Retention. Logs are kept for a limited, documented period — 30, 90, 180 days depending on the type — because every extra day of retention is risk and cost. And remember that logs fall within the scope of the GDPR's right to erasure, another reason not to put identifying data in them.

Manual redaction always fails, because all it takes is somebody adding a new field or logging a whole object:

That is why pino's redact, already configured, works at the logger level: wherever it is applied, those paths are censored.

The wildcards (*.password) cover any depth, which catches nested objects you had not anticipated.

Two reinforcements worth adding:

A test that verifies it. Redaction is one of those things that breaks in a refactor with nobody noticing:

A scanner in continuous integration that looks for secret patterns in the tests' logs. It is the same idea as the repository secret scanner from 04-02.

Here we finally replace the console.log at position 5.

Point 4 is the most important one for security: by default, pino-http logs every request header, Authorization included. The serialiser allowlist is what prevents that, and it is defence in depth alongside redact.

A child logger is a logger that automatically carries a fixed context. pino-http creates it in req.log, and from then on any line you write inside the request carries the traceId without you having to pass it around:

Passing req.log down to the service is how the inner layers log with the same context without knowing anything about HTTP. The alternative — Node's AsyncLocalStorage — avoids the explicit hand-off and is what the more advanced solutions use; for a project of this size, passing the logger is simpler and more explicit.

Why logging at 5 and metrics at 6:

• After CORS (4): if CORS rejects something, there is nothing to log as an API request.
• Before the rate limiting (7): if it came afterwards, the 429s would be neither logged nor counted, and you would be blind precisely during an attack.
• Before the parser (9): so that requests with malformed JSON are logged too; they produce a 400 and are a sign of a broken client.
• The metrics right after the logging, so as to measure every request that gets logged, with no mismatch between the two.

The traceId we have been emitting since 03-02 now comes fully into its own. Its journey:

The format validation in point 1 is not paranoia: without it, an attacker can inject line breaks into the header and forge complete log lines (log injection), or slip in payloads that exploit the log viewer.

In the SPA, the loop closes by showing the identifier to the user:

And for that to work, Aroma-Trace-Id had to be in 04-05's exposedHeaders. Every piece fits together.

In 03-07 we promised the traceId would be the bridge between what the client sees and what the team sees. Here it materialises.

The asymmetry, in a table:

Notice the last row: not even the team gets the body logged. The temptation to "save everything just in case" is exactly how passwords end up in a log system with a year's retention.

The four golden signals (from Google's SRE book):

The RED method is the simplified version for request-response services, and it is the one that applies to a REST API:

• Rate: requests per second.
• Errors: failed requests per second.
• Duration: the distribution of latency.

With those three, by route and by status code, you cover 90% of what you need from an API. Saturation is added as resource metrics: process memory, the event loop, the connection pool.

One nuance that avoids a common mistake about latency: you have to measure it separating successes from errors. A 401 responds in 2 ms, so an avalanche of 401s improves your average latency while the service is broken. Splitting by status avoids that.

Why the histogram and not the average. As we saw in 04-06, the mean lies. But on top of that, if every instance sent its own mean, those means cannot be combined correctly: the mean of the means is not the global mean unless they all have the same number of samples.

A histogram solves both. You define buckets and count how many observations fall into each:

The buckets can be summed across instances, and the percentile is computed afterwards by interpolation. In PromQL:

The precision depends on the buckets: if the real p99 is 180 ms and your buckets jump from 100 ms to 500 ms, you will get a poor interpolation. The buckets are chosen from your latency budget (04-06), placing boundaries around the values you care about.

/metrics goes outside /v1, just like /health: it is not part of the business contract and it is not versioned with it. And it must be protected: it reveals your internal routes, your versions, your order volume and your error rates, information that is valuable to a competitor and to an attacker alike. We answer 404 rather than 401 so as not even to confirm that it exists. In a real deployment it is also exposed only on the internal network or on a separate, unpublished port.

An example of business instrumentation:

Business metrics are the most valuable ones and the ones almost nobody adds. "Orders per minute have fallen to zero" detects incidents no technical metric sees: the API answers 200, the CPU is fine, and yet a change in the SPA has broken the buy button.

A metric's cardinality is the number of distinct label combinations. Every combination is an independent time series, with its own memory and its own cost.

It is called a cardinality explosion and it is the number-one way to bring down a metrics system — sometimes along with the rest of the cluster.

The mnemonic rule:

Identifiers go in the logs and in the traces. In metrics you only put categories with a small, known number of values.

When you need to investigate a specific case, the correct path is: the metric tells you that there is a problem and where; the log and the trace tell you which one. Never the other way round.

Beware also of the 404 for non-existent routes: if you logged req.path with no route match, anybody could blow up your cardinality by requesting random URLs. That is why the middleware in section 12 groups them under 'unknown'.

When a request crosses several services, each one's logs tell a fragment of the story. A trace stitches them together.

The propagation standard is W3C Trace Context, with the traceparent header:

• The trace-id is the same throughout the trace: it is what joins the services.
• The span-id identifies the current operation; the next service will use it as its parent.
• The flags indicate, among other things, whether this trace is sampled.

OpenTelemetry is the instrumentation standard (API, SDK and protocol) that has established itself across the industry; its main advantage is that it decouples the instrumentation from the backend: you instrument once and can ship to Jaeger, Tempo, Datadog or whatever you use later.

The automatic instrumentations cover incoming and outgoing HTTP, Express, gRPC and the usual database clients, so most of the trace appears without writing any code. Manual spans are added only where there is business logic you want to see.

Sampling. Tracing 100% of the traffic is expensive in network, storage and CPU. The usual approach is low sampling (1–10%) with two exceptions: traces of failing requests and of slow ones are always kept, since they are precisely the interesting ones.

Seen as a tree of spans, with each one's duration:

What you can see at a glance and that no other tool would have given you:

• The inventory gRPC call consumes 70% of the time. Optimising the SQL queries, which add up to 13 ms, would be working in the wrong place.
• The webhook is asynchronous and does not block the response. If it were on the critical path, the 201 would take 188 ms.
• The transaction is well bounded: three consecutive writes, with no network calls inside, which is exactly what we were after in 03-05. A gRPC call inside the transaction would hold the database lock for 48 ms.

A manual span, for when the automatic instrumentation does not reach:

A single /health mixes two different questions, and confusing them causes deployment incidents.

Three decisions that avoid classic incidents:

Liveness does not check the database. If it did and the database went down, the orchestrator would restart every instance in a loop, adding a storm of start-ups to an incident that already existed.

Redis is "degraded", not fatal. It is consistent with the decisions from 04-04 (fail-open) and 04-06 (the cache is never a hard dependency).

Readiness returns 503, not 500. It is "not now", not "I am broken", and it fits the catalogue's service_unavailable. During the graceful shutdown from 03-07, the correct approach is to start returning 503 on readiness while carrying on serving the requests in flight: that way the load balancer stops sending new traffic before the process dies, and no request is lost. That detail is what makes a deployment with no visible errors possible, and we will come back to it in 05-05.

The rule: alert on symptoms that affect users, not on causes that may affect nobody.

A CPU at 90% with latency inside the budget is not a problem: it is a well-used server. Waking somebody up for that is the fastest way to make sure alerts stop being looked at.

• SLI (indicator): what you measure. "The proportion of requests with a status below 500".
• SLO (objective): the threshold you commit to. "99.9% over 30 days".
• Error budget: what you are allowed to fail. At 99.9%, that is 0.1% of the month: about 43 minutes.

Aroma Store's:

The error budget turns an argument about opinions into a rule: if there is budget left, new features get deployed; if it has been used up, the time goes on reliability. There is no more negotiating "do we fix this or ship that?": the data decides.

And the correct alert is not on the instantaneous value but on the rate at which the budget is being consumed (the burn rate): "at this pace, the month's budget runs out in two hours". That is what tells an irrelevant spike apart from a real problem.

Every alert must meet four conditions, and if it fails any of them it should be deleted: it is actionable (there is something concrete to do), it is urgent (it cannot wait until tomorrow), it is documented (a runbook with the first steps) and it is not noisy (if it fires daily, either it is a real problem that needs fixing or it is an alert that should not exist).

Six charts. Not one more, because a dashboard with forty charts is a dashboard nobody looks at:

Charts 4 and 5 are what tell a useful dashboard from a decorative one. Chart 4 detects the failure no technical metric sees: everything answers 200 and yet nobody is buying. Chart 5 is the direct check that the work from 04-04 has not turned against you.

On launch day, in addition: have to hand the log query filtered by status >= 500 sorted by time, and the link to the traces of the slowest requests. That is what turns "something is wrong" into "the inventory gRPC call is taking 2 s" in under a minute.

Two pieces of advice when choosing, without getting into installations:

Start with the managed option. Operating Prometheus, Loki and Jaeger is a part-time job. For a project like Aroma Store, a managed service costs less than the time to maintain it.

Instrument with OpenTelemetry whatever happens. It is the only thing that lets you change provider without touching the code again.

When the module started you had a correct API. This is what has been hardened:

The src/app.js chain has gone from 8 steps to 16, and each one answers a concrete problem you can now name. The error catalogue grew with precondition_required, and the scope catalogue appeared with OAuth. And above all, the API has stopped being a black box: when something fails, you will know before your customers do and you will be able to work out what it was.

Logging the complete URI instead of the template. It prevents grouping in the logs and it blows up cardinality in the metrics.

Logging the request body "for debugging". It is the fastest route to putting passwords and personal data into a system with long retention.

Marking 4xxs as error. It generates noise, and noise makes alerts stop being read.

Using identifiers as metric labels. customerId or orderId blow up the metrics system.

Putting the database check in liveness. It turns a database outage into a restart loop across the whole fleet.

Leaving /metrics public. It exposes internal routes, versions and business volume.

Alerting on CPU and memory. They are causes, not symptoms. Alert on latency, errors and business metrics.

Looking at the average instead of the percentiles. We saw it in 04-06 and it is still the most frequent measurement mistake.

Registering the logger without serialisers. pino-http includes every header by default, Authorization among them.

Tip: put the traceId into the SPA's error messages. It turns "it does not work for me" into a two-minute investigation.

Tip: instrument the business, not just the technology. "Orders per minute" detects incidents no infrastructure metric sees.

Tip: review your alerts every quarter. Delete the ones that have never been actionable. A noisy alerting system is worse than none at all.

Tip: write the runbook before the incident. At three in the morning nobody improvises well.

This code has been proposed for instrumenting the payment endpoint. Find at least five problems and fix them.

Aroma Store is adding the monthly coffee subscription. Design the metrics for observing it: name, type, labels (with their estimated cardinality) and what question each one answers. Include at least one business metric and one useful alert expressed in words.

At 10:15 the alert "5xx rate > 1% on POST /v1/orders" fires. Describe, step by step, how you would use the three pillars to reach the cause, saying what you look for in each one and what conclusion you would draw from each possible result.

Solution 1

Problems:

1. console.log instead of the logger. No structure, no level, no traceId, and it never reaches the log system in the right format.
2. It logs the complete body. A payment's body may contain card data. It is a serious security and GDPR failure.
3. Explosive cardinality in the metric. route with the real identifier and a customer label carrying the customerId: one series per order and per customer.
4. It only counts successes. The inc() sits inside the try after the operation, so errors are not counted and the error rate is always zero.
5. It does not measure latency as a metric, it only prints it. There is no histogram and no percentiles.
6. It returns error.message to the client. It leaks the system's internals: it breaks what was established in 03-07 and 04-02.
7. It does not use the central error handler. The error's format does not meet the contract (code, message, details, traceId).
8. asyncHandler() is missing: an uncaught rejection would leave the request hanging. (Here the try/catch papers over it, but the project's convention is asyncHandler.)

The fix:

Solution 2

The main business metric: aroma_subscriptions_active. It is the one that reflects the feature's real value; if it falls, there is a problem even with every technical indicator green.

Labels rejected on cardinality grounds: customerId (millions), subscriptionId (unlimited), coffeeId (it grows with the catalogue, and with thousands of lines it would be a problem).

A useful alert: "the proportion of subscription charges with result failure exceeds 5% over a 30-minute window". It meets the four conditions: it is actionable (check the gateway and expired payment methods), it is urgent (every hour is lost revenue and annoyed customers), it can be documented in a runbook, and it is not noisy, because a small percentage of failures is normal and the threshold sits above it.

A complementary alert: "the monthly shipment generation process has recorded no increase in aroma_subscription_shipments_generated_total during its execution window". It detects the most dangerous silent failure of a scheduled process: that it simply did not run.

Solution 3

Step 1 — Metrics: bounding the problem (2 minutes).

• The error rate by route chart: is it only POST /v1/orders or others too? If it is all of them, that points to something cross-cutting (the database, a deployment). If it is only that one, to its logic or to one of its dependencies.
• When exactly did it start? Correlate with the deployment history. A sharp jump at an exact time is usually a deployment or a configuration change; a gradual rise points to resource exhaustion or data growth.
• Latency: if the p99 rose before the errors, they are probably timeouts. If the errors appeared with no change in latency, it is a logic failure (an exception).
• aroma_orders_created_total: has it fallen? It confirms the real business impact and gives urgency.
• Saturation: memory, event loop, connection pool. It rules resource exhaustion in or out.

Step 2 — Traces: locating where it breaks (3 minutes).

• Filter traces for POST /v1/orders with an error in the last 15 minutes.
• Look at the span tree: which span does the trace end on? The possible results and how to read them:
  • It cuts off at grpc.inventory.ReserveStock → the inventory service is failing or slow.
  • It cuts off at db.transaction → a database problem: a lock, the disk, a half-applied migration.
  • It finishes quickly without reaching the dependencies → an exception in the validation or in the logic.
  • Every span is normal but the total is enormous → contention or garbage collector pauses.
• Compare against a correct trace from before the incident: the difference leaps out.

Step 3 — Logs: getting the detail (2 minutes).

• Take the traceId from a failing trace and search for all its lines.
• Read the error-level line: message, exception type and full stack.
• Check the pattern: do all orders fail or only some? Filter by oauthClient (only the SPA? only CataBox?), by customerId (one specific customer with odd data?), by the number of items in the order.
• Look for warns in the preceding minutes: slow queries, Redis down, 429s. The root cause often shows up there before the error does.

Conclusion and action. With the three steps you have: what is failing (the metric), where (the trace) and why (the log). If the cause is a recent deployment, it is rolled back before investigating any further — restore the service first, understand afterwards. If it is an external dependency, the circuit breaker from 04-04 is engaged to degrade rather than fail. And the incident is closed with two things: a regression test that reproduces it (03-08) and, if the alert arrived late, a new alert or an adjusted threshold.

Observability is the layer that turns a system that works into a system that can be operated. You have finally replaced the console.log at position 5 with pino and structured JSON logs, with a child logger per request carrying the traceId we have been emitting since 03-02, the route logged as a template rather than a URI, levels assigned properly — 4xxs are not errors — allowlisted serialisers and automatic redaction of passwords, tokens and personal data, with its test and with the retention policy the GDPR demands. You have seen how Aroma-Trace-Id is correlated end to end, from the SPA through the inventory gRPC call and the webhooks to SwiftShip, and how the circle opened in 03-07 closes: to the team, the full stack; to the client, internal_error and a reference with which support finds everything in ten seconds. You have instrumented the API with prom-client following the four golden signals and the RED method, with histograms whose buckets come out of 04-06's latency budget, business metrics — orders created, stock depleted, 429s emitted, cache hits — and a protected /metrics outside /v1, knowing why labelling with ord_5001 blows the system up. You know about distributed tracing, W3C's traceparent and OpenTelemetry, and you can read a span tree for POST /v1/orders and discover that 70% of the time was somewhere you were not looking. And you have separated liveness from readiness, defined SLOs with an error budget, and chosen what to alert on — symptoms, never CPU — and what to watch on launch day.

That closes module 4. The Aroma Store API is no longer merely correct: it has design judgement with identified antipatterns and contract linting; it knows its threats and defends against them with helmet, secrets management and GDPR controls; it delegates third-party access with OAuth 2.0 and OpenID Connect without ever seeing a password; it protects itself from abuse with per-tier limits, 429 and Retry-After; it lets the SPA and the back office in without opening the door to anyone else; it answers 304 instead of repeating itself and closes optimistic concurrency with If-Match and the 412; and it reports what is happening to it in correlated logs, metrics and traces. It is an API ready for production.

What is missing is no longer the API: it is the tools around it and the teamwork that sustains it. In module 5, Tools and Frameworks, we will stop writing server code and start working on it: Postman for exploring, testing and sharing executable collections (05-01); Swagger and OpenAPI for turning that openapi.yaml we have been carrying since 02-08 into living documentation, client generation and validation (05-02); a comparative tour of the popular frameworks — Fastify, NestJS, Django REST, Spring Boot, ASP.NET Core — so you know what is gained and what is lost by choosing each (05-03); contracts, mocks and automated tests so that consumer and provider do not break each other (05-04); continuous integration and deployment, where Spectral, npm audit, the tests and the readiness endpoint we have just written become a pipeline that deploys with no downtime (05-05); and API gateways and developer portals, where several of this module's mechanisms — rate limiting, authentication, caching, metrics — reappear solved one layer above (05-06).