🖼️ See the drawing + lab 🏠 Course home 🌿 Branch on GitHub ✏️ View source

🖼️ आकृती आणि labThe drawing + lab पूर्ण पानावर उघडा ↗Open full page ↗

📓 धडा 02 — Logs: आरोग्य कक्षाची दैनंदिनी

📍 तुम्ही इथे आहात: 12 पैकी धडा 02 · मागे: lesson-01-why-observability · पुढे: lesson-03-metrics

📦 या ब्रँचमध्ये काय आहे

धडा 01, आणि पहिला signal: logs. तुम्ही structured logging (प्रत्येक ओळीत एक JSON object), log levels, प्रत्येक ओळीत trace id का असतो, आणि काय कधीच लिहू नये हे शिकता. obs/signals.py मधील log() आणि query() log ओळी लिहितात आणि शोधतात; obs/demo.py मधील logs() त्या चालवते.

🧒 5 वर्षांच्या मुलाला समजावल्यासारखे

प्रत्येक वेळी एखादा विद्यार्थी आला की कतरिना आरोग्य कक्षाच्या दैनंदिनी 📓 मध्ये लिहिते.

तिची पहिली दैनंदिनी मोकळ्या मजकुरात होती: "3A ची मुलगी आली, थोडी गरम, पाणी दिले, साधारण 11 च्या सुमारास परत पाठवले." नंतर दीपिकाने विचारले: "या आठवड्यात 3A वर्गातले किती विद्यार्थी तापाने आले?" कतरिनाला प्रत्येक पान वाचावे लागले.

म्हणून कतरिनाने प्रत्येक ओळीवर चौकटी काढल्या: वेळ · किती गंभीर · काय घडले · वर्ग · विद्यार्थ्याचा कार्ड क्रमांक. आता तो प्रश्न एका सेकंदात सुटतो: "वर्ग" चौकटीत 3A आणि "काय" चौकटीत ताप शोधायचा.

आणखी दोन नियम. प्रत्येक विद्यार्थ्याकडे एक मार्ग कार्ड क्रमांक असतो, आणि कतरिना तो ओळीवर लिहिते — म्हणजे दैनंदिनीतली ओळ नंतर कार्डाशी जुळवता येते (धडा 05). आणि कतरिना दैनंदिनीत विद्यार्थ्याचा घरचा पत्ता किंवा पालकांचे bank details कधीच लिहित नाही. दैनंदिनी अनेक लोक वाचतात. गुपिते तिथे जात नाहीत.

🗺️ आकृती

flowchart LR
    app["🍳 results-api"] -->|"one JSON object per line"| line["📓 {ts, level, msg,<br/>route, status, ms,<br/>trace_id}"]
    line --> store["🗄️ log store<br/>Loki · CloudWatch Logs · Datadog"]
    store -->|"level=ERROR AND route=/results/3A"| two["2 lines<br/>trace ids a3ce929d, b7ad6b71"]
    two -.->|"trace_id joins"| tr["🗺️ the trace (lesson 05)"]
    no["🚫 never: passwords, tokens,<br/>card numbers, full personal data"]

🗺️ काढलेली आवृत्ती + एक lab: https://school-edh.pages.dev/observability/lesson-diagrams.html#l02

❓ काय

Log — एका घटनेची नोंद, timestamp सह. App ती लिहिते, log system ती साठवते आणि शोधते.
Unstructured log — मोकळा मजकूर: 11:40:02 ERROR grade timeout for 3A after 1000ms. लिहायला सोपा; शोधायला, मोजायला किंवा graph काढायला कठीण (प्रत्येक प्रश्नासाठी एक regular expression लागते).
Structured log — ठरलेल्या field names सह प्रत्येक ओळीत एक JSON object: {"ts": "11:40:02", "level": "ERROR", "msg": "grade service timeout", "route": "/results/3A", "status": 504, "ms": 1000, "trace_id": "a3ce929d"}. प्रत्येक field filter, मोजता आणि group करता येते.
Log levels — घटना किती गंभीर आहे. सर्वात कमी ते सर्वात जास्त गंभीर:
- DEBUG — developers साठी तपशील; production मध्ये सहसा बंद;
- INFO — ठेवण्याजोग्या सामान्य घटना ("results viewed");
- WARN / WARNING — काहीतरी विचित्र जे system ने हाताळले ("slow grade service");
- ERROR — एखादी क्रिया अयशस्वी झाली ("grade service timeout", पालकाला 504);
- FATAL / CRITICAL — process पुढे चालू शकत नाही. अनेक tools मध्ये DEBUG च्या खाली TRACE सुद्धा असतो. Python चे logging DEBUG, INFO, WARNING, ERROR, CRITICAL वापरते. तुम्ही एक किमान level ठरवता: WARN ठेवला तर INFO आणि DEBUG ओळी टाकल्या जातात.
Correlation id / trace id — प्रत्येक request साठी एक id, जो ती request निर्माण करते त्या प्रत्येक ओळीत, प्रत्येक service मध्ये लिहिला जातो. तो एका request चे logs एकत्र जोडतो, आणि logs ना trace शी जोडतो (धडा 05). (Page वर बसावेत म्हणून lab 8 अक्षरांचे छोटे ids वापरते; खरा W3C trace id 32 hex अक्षरांचा असतो.)
गुपिते किंवा वैयक्तिक माहिती (PII) कधीच log करू नका — passwords, tokens, API keys, session cookies, card numbers किंवा पूर्ण वैयक्तिक माहिती (पत्त्यासह नावे, emails, phone numbers, आरोग्याचे तपशील) नको. Logs अनेक ठिकाणी copy होतात आणि अनेक लोक ते वाचतात. व्यक्ती नव्हे, एक id log करा (user: parent-9), आणि logger मध्येच redact करा म्हणजे एखादी निष्काळजी ओळ माहिती बाहेर टाकू शकणार नाही.
Retention — logs किती काळ ठेवले जातात. प्रति byte logs हा सर्वात महाग signal आहे, म्हणून DEBUG कमी काळ ठेवा (किंवा बंद) आणि ERROR जास्त काळ.

🤔 का

कारण outage दरम्यान प्रश्न नेहमी नवा असतो. "11:30 पासून /results/3A वर किती 504s?" "कोणते trace ids?" "फक्त 3A वर्ग, की सगळे वर्ग?" मोकळ्या मजकुरात प्रत्येक प्रश्न म्हणजे नवे regular expression आणि हळू scan. Structured logs मध्ये प्रत्येक प्रश्न म्हणजे एका field वरचा filter. आणि प्रत्येक ओळीत trace id असेल तर एक अयशस्वी request काही सेकंदांत प्रत्येक service मधून follow करता येते.

🔧 कसे (या repo मध्ये)

obs/signals.py मधील log(ts, level, msg, **fields) एक JSON ओळ परत करते, ज्यात आधी ts, level आणि msg, मग तुमची fields असतात. query(lines, **match) प्रत्येक ओळ parse करते आणि ज्यात प्रत्येक field जुळते त्या ठेवते — log search ची एक छोटी आवृत्ती. obs/demo.py मधील logs() 11:40 पासूनच्या चार ओळी लिहिते आणि route=/results/3A वर level=ERROR मागते.

🧪 करून पाहा

एक field (cls) जोडा, एक WARN ओळ जोडा, मग मोकळा मजकूर पटकन उत्तर देऊ शकला नसता अशा fields वर query करा:

python3 obs/demo.py logs
python3 - <<'EOF'
import sys, json; sys.path.insert(0, "obs"); from signals import log, query
lines = [log("11:40:01", "INFO", "results viewed", route="/results/3A", status=200, ms=92, trace_id="4bf92f35", cls="3A"),
         log("11:40:02", "ERROR", "grade service timeout", route="/results/3A", status=504, ms=1000, trace_id="a3ce929d", cls="3A"),
         log("11:40:02", "WARN", "slow grade service", route="/results/3B", status=200, ms=870, trace_id="00f067aa", cls="3B"),
         log("11:40:03", "ERROR", "grade service timeout", route="/results/3A", status=504, ms=1000, trace_id="b7ad6b71", cls="3A")]
print(lines[2])
print("status=504         →", len(query(lines, status=504)), "lines")
print("cls=3B             →", [d["msg"] for d in query(lines, cls="3B")])
print("trace_id=a3ce929d  →", [(d["ts"], d["level"], d["msg"]) for d in query(lines, trace_id="a3ce929d")])
order = ["DEBUG", "INFO", "WARN", "ERROR"]
for floor in ("INFO", "WARN", "ERROR"):
    kept = [l for l in lines if order.index(json.loads(l)["level"]) >= order.index(floor)]
    print(f"keep level ≥ {floor:<5} → {len(kept)} of {len(lines)} lines")
EOF

✅ तपासा — तुम्हाला काय दिसायला हवे

logs हे print करते:

── structured logs: one JSON object per line, not free text
   {"ts": "11:40:02", "level": "ERROR", "msg": "grade service timeout", "route": "/results/3A", "status": 504, "ms": 1000, "trace_id": "a3ce929d", "user": "parent-9"}
── query level=ERROR route=/results/3A → 2 lines · trace ids ['a3ce929d', 'b7ad6b71']
   levels: DEBUG < INFO < WARN < ERROR · never log passwords, tokens or full personal data
   a request id / trace id in EVERY line is what joins logs to traces

तुमचा snippet हे print करतो:

{"ts": "11:40:02", "level": "WARN", "msg": "slow grade service", "route": "/results/3B", "status": 200, "ms": 870, "trace_id": "00f067aa", "cls": "3B"}
status=504         → 2 lines
cls=3B             → ['slow grade service']
trace_id=a3ce929d  → [('11:40:02', 'ERROR', 'grade service timeout')]
keep level ≥ INFO  → 4 of 4 lines
keep level ≥ WARN  → 3 of 4 lines
keep level ≥ ERROR → 2 of 4 lines

🏁 तुम्ही आत्ताच काय सिद्ध केले

नवे field (cls) लगेच विचारता येणारा नवा प्रश्न बनले — कोणतेही regular expression नाही. Trace id ने नेमकी एक request वेगळी काढली. आणि किमान level ठरवतो की तुम्ही किती ठेवता: ERROR ला तुम्ही अर्ध्या ओळी साठवता, पण grade service हळू होत चालली आहे हे सांगणारी WARN ओळ गमावता — म्हणजे पहिली खूण.

⚠️ नेहमीच्या चुका

महत्त्वाच्या किमती वाक्याच्या आत असलेल्या मोकळ्या मजकुराच्या ओळी ("timeout for 3A after 1000ms")
प्रत्येक service मध्ये वेगळे field name (userId, user_id, uid) — नावांवर एकमत करा (धडा 06)
trace id नाही, त्यामुळे एका request च्या ओळी services पलीकडे जोडता येत नाहीत
गुपिते किंवा वैयक्तिक माहिती log करणे: headers मधले tokens, failed-login ओळीतले passwords, पूर्ण request bodies
production मध्ये "फक्त आत्तापुरता" DEBUG चालू — bug सापडण्याआधीच bill येते
loop च्या प्रत्येक पायरीसाठी एक log ओळ: घटना log करा, आणि पुन्हा पुन्हा होणाऱ्या गोष्टी metric ने मोजा (धडा 03)
error-ratio metric ऐवजी log मजकुरावर alert करणे ("ERROR दिसते") (धडा 08)

🏭 प्रत्यक्ष वापरात

On a real account — Python मधून structlog वापरून JSON logs, redaction च्या पायरीसह आणि सध्याचा OpenTelemetry trace id प्रत्येक ओळीत जोडून:

import structlog
from opentelemetry import trace

SECRET_KEYS = {"password", "token", "authorization", "card_number"}

def redact(logger, method, event):
    for k in SECRET_KEYS & event.keys():
        event[k] = "[REDACTED]"
    return event

def add_trace_id(logger, method, event):
    ctx = trace.get_current_span().get_span_context()
    if ctx.is_valid:
        event["trace_id"] = format(ctx.trace_id, "032x")     # 32 hex characters
        event["span_id"] = format(ctx.span_id, "016x")       # 16 hex characters
    return event

structlog.configure(processors=[
    structlog.contextvars.merge_contextvars,
    structlog.processors.add_log_level,
    structlog.processors.TimeStamper(fmt="iso", utc=True),
    add_trace_id,
    redact,
    structlog.processors.JSONRenderer(),
])
log = structlog.get_logger(service="results-api")
log.error("grade service timeout", route="/results/3A", status=504, duration_ms=1000, user="parent-9")

फक्त standard logging module वापरून, एक छोटा JSON formatter तेच काम करतो:

import json, logging
class JsonFormatter(logging.Formatter):
    def format(self, record):
        return json.dumps({"ts": self.formatTime(record), "level": record.levelname,
                           "msg": record.getMessage(), **getattr(record, "fields", {})})
handler = logging.StreamHandler(); handler.setFormatter(JsonFormatter())
logging.basicConfig(level=logging.INFO, handlers=[handler])
logging.getLogger("results-api").warning("slow grade service", extra={"fields": {"route": "/results/3B", "ms": 870}})

CloudWatch Logs Insights मध्ये तोच search:

fields @timestamp, level, msg, route, trace_id
| filter level = "ERROR" and route = "/results/3A"
| stats count(*) as errors by bin(1m)

Grafana Loki (LogQL) आणि Datadog Logs मध्ये:

{service="results-api"} | json | level="ERROR" | route="/results/3A"
service:results-api status:error @route:"/results/3A"

🏭 Production मध्ये हे का महत्त्वाचे: सामायिक field names (service, trace_id, route, status, duration_ms) एकदाच, सगळ्या teams साठी ठरवा, आणि redaction सामायिक logger मध्ये ठेवा — प्रत्येक developer च्या आठवणीवर सोडू नका.

⏭️ पुढे

दैनंदिनी एका भेटीची गोष्ट सांगते. वेळेनुसार किती आणि किती जलद हे पाहण्यासाठी कतरिनाला एक तक्ता लागतो.

git checkout lesson-03-metrics

📓 Lesson 02 — Logs: the health room diary

📍 You are here: Lesson 02 of 12 · Previous: lesson-01-why-observability · Next: lesson-03-metrics

📦 What's in this branch

Lesson 01, plus the first signal: logs. You learn structured logging (one JSON object per line), log levels, why every line carries a trace id, and what you must never write down. log() and query() in obs/signals.py write and search log lines; logs() in obs/demo.py runs them.

🧒 Explain like I'm 5

Katrina writes in the health room diary 📓 every time a pupil comes in.

Her first diary was free text: "girl from 3A came in, bit hot, gave her water, sent back maybe 11-ish." Later, Dipika asked: "How many pupils from class 3A came in with a fever this week?" Katrina had to read every page.

So Katrina drew boxes on each line: time · how serious · what happened · class · pupil card number. Now the question takes one second: look down the "class" box for 3A and the "what" box for fever.

Two more rules. Every pupil has a route card number, and Katrina writes it on the line — so the diary line can be matched with the card later (lesson 05). And Katrina never writes a pupil's home address or a parent's bank details in the diary. Many people read the diary. Secrets do not go there.

🗺️ Diagram

flowchart LR
    app["🍳 results-api"] -->|"one JSON object per line"| line["📓 {ts, level, msg,<br/>route, status, ms,<br/>trace_id}"]
    line --> store["🗄️ log store<br/>Loki · CloudWatch Logs · Datadog"]
    store -->|"level=ERROR AND route=/results/3A"| two["2 lines<br/>trace ids a3ce929d, b7ad6b71"]
    two -.->|"trace_id joins"| tr["🗺️ the trace (lesson 05)"]
    no["🚫 never: passwords, tokens,<br/>card numbers, full personal data"]

🗺️ Drawn version + a lab: https://school-edh.pages.dev/observability/lesson-diagrams.html#l02

❓ What

Log — a record of one event, with a timestamp. Written by the app, stored and searched by a log system.
Unstructured log — free text: 11:40:02 ERROR grade timeout for 3A after 1000ms. Easy to write; hard to search, count or graph (you need a regular expression for every question).
Structured log — one JSON object per line with fixed field names: {"ts": "11:40:02", "level": "ERROR", "msg": "grade service timeout", "route": "/results/3A", "status": 504, "ms": 1000, "trace_id": "a3ce929d"}. Every field can be filtered, counted and grouped.
Log levels — how serious the event is. From least to most serious:
- DEBUG — details for developers; usually off in production;
- INFO — normal events worth keeping ("results viewed");
- WARN / WARNING — something odd that the system handled ("slow grade service");
- ERROR — an operation failed ("grade service timeout", a 504 to a parent);
- FATAL / CRITICAL — the process cannot continue. Many tools also have TRACE below DEBUG. Python's logging uses DEBUG, INFO, WARNING, ERROR, CRITICAL. You set a minimum level: at WARN, INFO and DEBUG lines are dropped.
Correlation id / trace id — one id per request, written in every line that the request causes, in every service. It joins the logs of one request together, and joins logs to the trace (lesson 05). (The lab uses short 8-character ids to fit the page; a real W3C trace id is 32 hex characters.)
Never log secrets or personal data (PII) — no passwords, tokens, API keys, session cookies, card numbers or full personal data (names with addresses, emails, phone numbers, health details). Logs are copied to many places and read by many people. Log an id (user: parent-9), not the person, and redact in the logger so one careless line cannot leak.
Retention — how long logs are kept. Logs are the most expensive signal per byte, so keep DEBUG short (or off) and ERROR longer.

🤔 Why

Because during an outage, the question is always new. "How many 504s on /results/3A since 11:30?" "Which trace ids?" "Only class 3A, or all classes?" With free text, each question is a new regular expression and a slow scan. With structured logs, each question is a filter on a field. And with a trace id in every line, one failed request can be followed across every service in seconds.

🔧 How (in this repo)

log(ts, level, msg, **fields) in obs/signals.py returns one JSON line with ts, level and msg first, then your fields. query(lines, **match) parses each line and keeps those where every field matches — a tiny version of a log search. logs() in obs/demo.py writes four lines from 11:40 and asks for level=ERROR on route=/results/3A.

🧪 Try it

Add a field (cls), add a WARN line, then query by fields that free text could not answer quickly:

python3 obs/demo.py logs
python3 - <<'EOF'
import sys, json; sys.path.insert(0, "obs"); from signals import log, query
lines = [log("11:40:01", "INFO", "results viewed", route="/results/3A", status=200, ms=92, trace_id="4bf92f35", cls="3A"),
         log("11:40:02", "ERROR", "grade service timeout", route="/results/3A", status=504, ms=1000, trace_id="a3ce929d", cls="3A"),
         log("11:40:02", "WARN", "slow grade service", route="/results/3B", status=200, ms=870, trace_id="00f067aa", cls="3B"),
         log("11:40:03", "ERROR", "grade service timeout", route="/results/3A", status=504, ms=1000, trace_id="b7ad6b71", cls="3A")]
print(lines[2])
print("status=504         →", len(query(lines, status=504)), "lines")
print("cls=3B             →", [d["msg"] for d in query(lines, cls="3B")])
print("trace_id=a3ce929d  →", [(d["ts"], d["level"], d["msg"]) for d in query(lines, trace_id="a3ce929d")])
order = ["DEBUG", "INFO", "WARN", "ERROR"]
for floor in ("INFO", "WARN", "ERROR"):
    kept = [l for l in lines if order.index(json.loads(l)["level"]) >= order.index(floor)]
    print(f"keep level ≥ {floor:<5} → {len(kept)} of {len(lines)} lines")
EOF

✅ Verify — what you should see

logs prints:

── structured logs: one JSON object per line, not free text
   {"ts": "11:40:02", "level": "ERROR", "msg": "grade service timeout", "route": "/results/3A", "status": 504, "ms": 1000, "trace_id": "a3ce929d", "user": "parent-9"}
── query level=ERROR route=/results/3A → 2 lines · trace ids ['a3ce929d', 'b7ad6b71']
   levels: DEBUG < INFO < WARN < ERROR · never log passwords, tokens or full personal data
   a request id / trace id in EVERY line is what joins logs to traces

Your snippet prints:

{"ts": "11:40:02", "level": "WARN", "msg": "slow grade service", "route": "/results/3B", "status": 200, "ms": 870, "trace_id": "00f067aa", "cls": "3B"}
status=504         → 2 lines
cls=3B             → ['slow grade service']
trace_id=a3ce929d  → [('11:40:02', 'ERROR', 'grade service timeout')]
keep level ≥ INFO  → 4 of 4 lines
keep level ≥ WARN  → 3 of 4 lines
keep level ≥ ERROR → 2 of 4 lines

🏁 What you just proved

A new field (cls) became a new question you could ask at once — no regular expression. The trace id picked out exactly one request. And the minimum level decides how much you keep: at ERROR you store half the lines, but you lose the WARN line that said the grade service was getting slow — the early sign.

⚠️ Common mistakes

free-text lines with the important values inside the sentence ("timeout for 3A after 1000ms")
a different field name in every service (userId, user_id, uid) — agree on names (lesson 06)
no trace id, so one request's lines cannot be joined across services
logging secrets or personal data: tokens in headers, passwords in a failed-login line, full request bodies
DEBUG on in production "just for now" — the bill arrives before the bug is found
one log line per loop step: log events, and count repeated things with a metric (lesson 03)
alerting on log text ("ERROR appears") instead of an error-ratio metric (lesson 08)

🏭 In production

On a real account — JSON logs from Python with structlog, with a redaction step and the current OpenTelemetry trace id added to every line:

import structlog
from opentelemetry import trace

SECRET_KEYS = {"password", "token", "authorization", "card_number"}

def redact(logger, method, event):
    for k in SECRET_KEYS & event.keys():
        event[k] = "[REDACTED]"
    return event

def add_trace_id(logger, method, event):
    ctx = trace.get_current_span().get_span_context()
    if ctx.is_valid:
        event["trace_id"] = format(ctx.trace_id, "032x")     # 32 hex characters
        event["span_id"] = format(ctx.span_id, "016x")       # 16 hex characters
    return event

structlog.configure(processors=[
    structlog.contextvars.merge_contextvars,
    structlog.processors.add_log_level,
    structlog.processors.TimeStamper(fmt="iso", utc=True),
    add_trace_id,
    redact,
    structlog.processors.JSONRenderer(),
])
log = structlog.get_logger(service="results-api")
log.error("grade service timeout", route="/results/3A", status=504, duration_ms=1000, user="parent-9")

With the standard logging module only, a small JSON formatter does the same job:

import json, logging
class JsonFormatter(logging.Formatter):
    def format(self, record):
        return json.dumps({"ts": self.formatTime(record), "level": record.levelname,
                           "msg": record.getMessage(), **getattr(record, "fields", {})})
handler = logging.StreamHandler(); handler.setFormatter(JsonFormatter())
logging.basicConfig(level=logging.INFO, handlers=[handler])
logging.getLogger("results-api").warning("slow grade service", extra={"fields": {"route": "/results/3B", "ms": 870}})

The same search in CloudWatch Logs Insights:

fields @timestamp, level, msg, route, trace_id
| filter level = "ERROR" and route = "/results/3A"
| stats count(*) as errors by bin(1m)

In Grafana Loki (LogQL) and Datadog Logs:

{service="results-api"} | json | level="ERROR" | route="/results/3A"
service:results-api status:error @route:"/results/3A"

🏭 Why this matters in production: decide the shared field names (service, trace_id, route, status, duration_ms) once, for every team, and put the redaction in the shared logger — not in each developer's memory.

⏭️ Next

The diary tells the story of one visit. To see how many and how fast over time, Katrina needs a chart.

git checkout lesson-03-metrics

← Previouswhy observability Next →metrics

This page is the lesson's README from the lesson-02-logs branch, shown here so the whole School stays on one site. Code files open on GitHub at the same branch.