Get Monitoring Working on the Live Service

I built the monitoring and observability system on a live scorer from scratch, and the first thing I learned was that the service had been running for weeks with no way to see inside it. It served predictions, it returned 200, and the only way anyone found out it had broken was a user telling us their score looked wrong. There was no log we could query for a single request, no number that said how often it was erroring, and the health check the load balancer trusted returned success the instant the process started, before the model was even loaded. The service was alive and we were blind. This lesson stands up the smallest real observability that fixes that: structured logs you can query for one request, a count of errors, and a health check that asserts the service can actually serve. It is the baseline every later lesson in this module hardens.

That deployed scorer from the serving work is the Lending Club default model, the one whose feature contract from the packaging modules forbids post-outcome columns like recoveries and total_pymnt because they are all zero at origination. It runs as an endpoint that takes a request, runs a handler, and returns a response. Right now if that endpoint broke, the first signal would be a human noticing. By the end of this lesson it emits one structured log line per prediction, counts the requests that failed, and answers a health check that means ready to serve, not merely process is up. Build this first, before any of the harder monitoring the module covers, because everything else attaches to one of these three pieces, and a piece you did not build before the incident cannot be added during it.

What observability is, and the shape it moves a signal through

An intuitive way to think about monitoring is “add a logging library and write some log lines.” That model treats observability as a feature you bolt onto the service. It breaks the first time you need a signal during an incident and discover the line was being written but nothing was collecting it, or that the one field you needed at the moment of failure was never emitted and is now gone forever. Observability is not a library call. It is the ability to answer “what is my system doing right now, and what did it do an hour ago” from the outside, without attaching a debugger to a running process. That ability has to be built, and it is built from three signal types moving through one shape: emit, then collect, then view.

See the shape before writing a single line of instrumentation, because the three stages fail independently and live in different places. Emission runs inside your service’s process; if the service crashes, emission stops. Collection is a separate system (a log aggregator, a metrics store, a collector agent running on the same host) that survives your service restarting, which is the entire reason you can investigate after the failing instance is already gone. The standard fix for losing telemetry on a crash is to make export batches very small so data is evacuated quickly from the application to a local collector, because the collector being on the same host makes it a fast and reliable place to send the data before the process dies. Viewing is a third system, a dashboard, a query, or a curl /health, that reads the collected store and never touches your live process.

These three signal types are not interchangeable. Each trades resolution against cost, and that trade is why a real setup uses all three rather than picking one. A log is the highest-resolution and the most expensive to keep at volume, so logging everything makes log volume grow very quickly; a metric is an aggregate that is cheap to keep for a year but has thrown away the individual events; a trace shows where inside one request the time went but is expensive enough at full volume that production samples it.

One shape serves all three signals because it separates three concerns that fail independently, and that separation is the entire reason monitoring data outlives the process it describes. The scrolly below traces one prediction event through emit, collect, and view, and then cuts the service mid-incident to show which stages keep their data and which go dark.

A senior states the non-obvious rule before naming any tool, and it is the last step made concrete: a signal you did not emit at the moment of failure is unrecoverable. This is the rule the whole module hardens against. Drift detection, alerting, and tracing all attach to one of these three stages, and every one of them depends on the signal having been emitted in the first place. The baseline you build in this lesson, a log line, an error count, and a health check, is the emission half of that contract for the live scorer.

def simulate(events: list[str], crash_after: int) -> dict[str, list[str]]:
    buffer: list[str] = []
    collected: list[str] = []
    for i, event in enumerate(events):
        if i == crash_after:
            # process dies here -- emission stops, buffer never flushes again
            break
        buffer.append(event)
        if len(buffer) == 3:
            collected.extend(buffer)
            buffer = []
    # what the collector durably has after the crash:
    return {"collected": collected, "lost_in_buffer": buffer}


result = simulate(["e0", "e1", "e2", "e3", "e4"], crash_after=4)
print(result)

def simulate(events: list[str], crash_after: int) -> dict[str, list[str]]:
    buffer: list[str] = []
    collected: list[str] = []
    for i, event in enumerate(events):
        if i == crash_after:
            break
        buffer.append(event)
        if len(buffer) == 3:
            collected.extend(buffer)
            buffer = []
    return {"collected": collected, "lost_in_buffer": buffer}


result = simulate(["e0", "e1", "e2", "e3", "e4"], crash_after=4)
print(result)
print("smaller batch would have saved:", "e3" in result["lost_in_buffer"])

Structured logs you can actually query

The scorer the team inherited logged one human-readable string per prediction, "scored user 42 -> 0.81 in 12ms", and it looked fine. It was readable, it had every fact in it, and at the terminal during development it was the right thing. Then a prediction was disputed weeks later and we needed that one request among millions. The only way to pull prediction or latency out of that string was a regular expression that hard-coded the exact wording.

That regex is where the model breaks, because wording is the least stable thing in a codebase. Anyone can reword a log message in an unrelated change (drop “in”, change “scored” to “predicted”, swap the arrow) and every query that depended on the old phrasing silently returns nothing. The query does not error; it stops matching, and the dispute goes unanswered. A senior states the principle before reaching for any format: a log line’s job is not to be read by a human at the terminal, it is to be found by a machine among millions of others. Free text optimizes for the human reading one line. Structure optimizes for the machine filtering a billion.

Here is the same event logged the broken way, with the regex that has to parse it. Watch the wording become the schema:

import re

# the log line a human wrote to be readable
line = "scored user 42 -> 0.81 in 12ms"

# the only way to extract the prediction is to hard-code the wording
m = re.search(r"-> ([\d.]+) in (\d+)ms", line)
prediction = float(m.group(1))
latency_ms = int(m.group(2))

# now a teammate rewords the message in an unrelated commit:
line = "user 42 predicted 0.81 (12 ms)"
m = re.search(r"-> ([\d.]+) in (\d+)ms", line)   # m is None: query silently breaks
prediction = float(m.group(1))                   # AttributeError: 'NoneType'

The fix inverts the problem. JSONL, one JSON object per line and newline-delimited, makes the line be the parsed structure. A structured event is one that can be parsed into key-value pairs; the consumer calls json.loads() and reads event["prediction"] by key, and the wording is now a value inside a field, not the schema. That newline-per-object framing is what makes it streamable at volume: a collector reads one line, indexes its fields, moves on without buffering the whole file, and builds an inverted index from request_id to line offsets, so finding one request is a lookup, not a scan of millions of lines. Here is the same event as one JSON object per line, and the lookup it enables:

import json
import logging

# configure a logger that emits one JSON object per line to stdout
logger = logging.getLogger("scorer")
logger.handlers.clear()
handler = logging.StreamHandler()
handler.setFormatter(logging.Formatter("%(message)s"))
logger.addHandler(handler)
logger.setLevel(logging.INFO)


def log_prediction(
    request_id: str, prediction: float, latency_ms: int, level: str = "INFO"
) -> str:
    # same key set on every event, a correlation id, no raw feature payload
    event = {
        "request_id": request_id,
        "level": level,
        "prediction": round(prediction, 4),
        "latency_ms": latency_ms,
    }
    line = json.dumps(event)
    logger.info(line)
    return line


# emit a few events as the scorer would
lines = [
    log_prediction("req-001", 0.81, 12),
    log_prediction("req-002", 0.13, 9),
    log_prediction("req-003", 0.77, 41),
]

# weeks later, find ONE disputed request by key -- a lookup, not a regex
target = "req-002"
for line in lines:
    event = json.loads(line)
    if event["request_id"] == target:
        print("found:", event["request_id"], "prediction =", event["prediction"])

Reading event["request_id"] and event["prediction"] by key involves no wording at all, so no reword can break it, and the dispute over req-002 is now answerable from the log store alone. Why does emitting the same key set on every event, even when a value is null, matter more than it looks? Because a field that appears only sometimes cannot be reliably aggregated: a filter like “latency over 100ms” silently skips every line that omitted the field, so the query is wrong without erroring.

Three disciplines are load-bearing, and they are not three independent rules. They are one rule, that the line must mean the same thing every time and tie to its request, seen from three failure angles.

How much structure to add is a tunable, and both extremes are failures, so the thing to learn is the curve, not the default. Too little and too much both break, in opposite ways.

The target band is exactly what log_prediction emits: four fixed fields, a correlation id, no feature payload. That is the structured-log half of the baseline for the live scorer, and the request_id is the same field every later lesson in this module joins on. The one discipline this band still has to hold is the key set itself: when a scorer logs different keys on its success branch than on its failure branch, a query for slow requests silently skips every failure that dropped the latency_ms key, so the fix is to build the event dict with all four keys on both branches and write None where a value is absent, which makes the failure show up as latency_ms: null instead of a missing key the filter walks past.

A health check that means “ready,” not just “running”

A natural way to write a health check is a handler that returns 200. The process is up, the handler answers, the dashboard goes green, and the load balancer sees a healthy instance. It looks correct, since the service is, after all, running. The scorer’s first rollout shipped exactly this, and it failed in a way the dashboard never showed.

An orchestrator routes live traffic to an instance the moment its health endpoint returns success. But on that rollout the model artifact, the joblib file, was still loading into memory when the endpoint started answering 200. So the first wave of requests hit a code path where the model was still None, and they 500’d, while the dashboard showed “healthy” the entire time. Here is the shape of that handler and the window it opens:

from fastapi import FastAPI

app = FastAPI()
model = None  # loaded in the background after startup

@app.get("/health")
def health() -> dict[str, str]:
    return {"status": "ok"}   # 200 the instant the process answers HTTP

@app.post("/predict")
def predict(features: dict) -> dict[str, float]:
    # the load balancer already routed traffic here, but model is still None
    score = model.predict(features)   # AttributeError: 'NoneType' has no 'predict'
    return {"score": float(score)}

Returning 200 before the model is loaded makes “healthy” a lie for the seconds the artifact is still loading. The correct model is that “the process is up” and “the service can actually serve” are two different claims, and a health check is a claim about serving capability, not a pulse. Whatever the endpoint asserts, the orchestrator believes. If it asserts “the process answered an HTTP call,” traffic arrives before the model is loaded. If it asserts “every dependency this service needs to produce a correct answer is satisfied,” traffic arrives only when the service can actually serve. The fix is to gate the success response on the model being loaded:

from typing import Any


class Scorer:
    def __init__(self) -> None:
        self.model: Any | None = None  # not loaded yet

    def load(self) -> None:
        # stands in for joblib.load(...) of the default-model artifact
        self.model = object()

    def readiness(self) -> tuple[int, dict[str, bool]]:
        # ready ONLY when the model artifact is in memory
        ready = self.model is not None
        status = 200 if ready else 503
        return status, {"model_loaded": ready}


scorer = Scorer()

# the window after process start, before the artifact finishes loading
print("before load:", scorer.readiness())  # 503 -- keep traffic away

scorer.load()
print("after load: ", scorer.readiness())  # 200 -- safe to route traffic

Before load() runs, readiness returns 503, so the load balancer keeps traffic away during the exact window that produced the 500s. After the artifact is in memory, it returns 200 and routing begins. Why return 503 rather than letting the handler answer 200 and catching the None later? Because the contract is the only thing the orchestrator reads: a 503 pulls the instance from rotation, which is a different action from a crash, and that distinction is the whole point of separating the two probes.

There are two distinct claims, and conflating them breaks in opposite directions. This is a genuine choice, so compare them.

One non-obvious rule falls out, and most engineers get it backwards on the first design: liveness must check only the process; readiness checks the dependencies. The diagram below shows why the wiring is asymmetric: what each probe is allowed to look at, and the restart storm that follows from pointing liveness at a downstream.

[Liveness probe] as live
[Readiness probe] as ready
[This process] as proc
[Model artifact] as model
[Downstream dependency] as down

live --> proc : checks ONLY (restart on fail)
ready --> proc : checks
ready --> model : checks loaded (pull from LB on fail)
ready ..> down : may check (pull, not restart)
live ..> down : NEVER (blip = restart storm)

Point liveness at a downstream and a downstream outage becomes a restart storm; let readiness pass before the model loads and you get premature traffic. The scorer’s first rollout failed exactly the second way: it passed its health check immediately, the balancer sent it live traffic, and the early requests 500’d because the joblib model was still loading. Making the readiness check assert model_loaded closed the window, and that is the health-check third of the baseline. This is also the seed of the module’s central thesis, carried in service-up-model-right: every signal can be green while the thing that matters is wrong. A health check that asserts the wrong claim is the first place that divergence opens.

def liveness(process_ok: bool, downstream_ok: bool) -> int:
    # BUG: a downstream blip makes liveness fail, so the process gets restarted
    return 200 if process_ok and downstream_ok else 500


def readiness(model_loaded: bool, downstream_ok: bool) -> int:
    return 200 if model_loaded and downstream_ok else 503


# downstream feature store has a 30s blip; process and model are fine
print("liveness:", liveness(process_ok=True, downstream_ok=False))  # restart?
print("readiness:", readiness(model_loaded=True, downstream_ok=False))  # pull from LB?

def liveness(process_ok: bool) -> int:
    # liveness checks ONLY the process -- a downstream blip is not a reason to restart
    return 200 if process_ok else 500


def readiness(model_loaded: bool, downstream_ok: bool) -> int:
    # readiness checks the dependencies -- pull from rotation, do not restart
    return 200 if (model_loaded and downstream_ok) else 503


# downstream feature store has a 30s blip; process and model are fine
print("liveness:", liveness(process_ok=True))  # 200 -- no restart
print(
    "readiness:", readiness(model_loaded=True, downstream_ok=False)
)  # 503 -- pulled, not killed

# when the blip clears, readiness recovers on its own -- no restart was needed
print("after blip clears:", readiness(model_loaded=True, downstream_ok=True))

Summary

• Observability is answering “what is my system doing, and what did it do an hour ago” from the outside, built from three signal types (logs, metrics, traces) moving through one shape: emit, collect, view. The stages fail independently, and a signal not emitted at the moment of failure is unrecoverable, because collection can only store what was emitted.
• The three signals trade resolution against cost: a log is the highest-resolution per-event record and the most expensive at volume; a metric is a cheap aggregate that cannot recover which request errored; a trace shows where inside one request the time went and is sampled in production.
• A structured (JSONL) log is found by a machine among millions, where a free-text log is parsed only by a wording-dependent regex that breaks the moment anyone rewords the message. The target band is a fixed minimal key set, a request_id correlation id on every line, and no raw feature payload, since full payloads are both a storage blowup and a PII exposure.
• A health check is a claim about serving capability, not a pulse. Readiness gates traffic on dependencies being satisfied (model loaded) and pulls a failing instance from rotation without restarting it; liveness checks only the process and restarts a wedged one. Pointing liveness at a downstream turns a blip into a restart storm.

Check your understanding:

• Without looking back: a service crashes mid-incident and you find the dashboard still has data from before the crash, but not the one field you needed at the moment of failure. Which stage saved the old data, and why is the missing field unrecoverable?
• Why does a query like “latency over 100ms” silently return wrong results when some events omit the latency_ms key entirely, and what discipline prevents it?
• You wire your liveness probe to also check that a downstream feature store is reachable. Describe the production failure this causes when the feature store has a brief blip, and state which probe should have checked the downstream instead.