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

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

🧵 धडा 05 — Distributed tracing: एका विद्यार्थिनीचे मार्ग कार्ड

📍 तुम्ही इथे आहात: 12 पैकी धडा 05 · मागे: lesson-04-percentiles · पुढे: lesson-06-opentelemetry

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

धडे 01–04, आणि तिसरा signal व भाग 2 ची सुरुवात: traces. तुम्ही spans, parent आणि child, critical path, आणि trace एका service कडून पुढच्या service कडे नेणारा W3C traceparent header शिकता. Span, trace_tree(), critical_path() आणि traceparent() obs/signals.py मध्ये आहेत; obs/demo.py मधील tracing() एका पालकाची अयशस्वी request काढून दाखवते.

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

एका विद्यार्थिनीला बरे वाटत नाही आणि तिला आरोग्य कक्षात पाठवले जाते. वाटेत ती office, शिक्षक कक्ष आणि ग्रंथालयात जाते. कुठेतरी तिची 15 मिनिटे गेली. कुठे?

म्हणून कतरिना प्रत्येक विद्यार्थ्याला एक मार्ग कार्ड 🗺️ देते, ज्यावर वर एक क्रमांक असतो. ती जिथे जाते ती प्रत्येक खोली कार्डावर शिक्का मारते: खोलीचे नाव, आत येण्याची वेळ, बाहेर जाण्याची वेळ. Office जेव्हा तिला शिक्षक कक्षात पाठवते, तेव्हा office कार्डावर स्वतःच्या शिक्क्याचा क्रमांक लिहिते, म्हणजे शिक्षक कक्षाला कळते की तिला कोणी पाठवले.

शेवटी, कतरिना कार्ड टेबलवर ठेवते. प्रत्येक शिक्का म्हणजे एक चौकट. चौकटी इतर चौकटींच्या आत असतात: शिक्षक कक्षाच्या भेटीत त्याची ग्रंथालयाची फेरी येते. चौकटींची एक साखळी बाकी सगळ्यांपेक्षा लांब आहे — 15 पैकी 12 मिनिटे ग्रंथालयात गेली. ती साखळी म्हणजे critical path. इतर कोणतीही खोली जलद केली तरी तिला अजिबात मदत होणार नाही.

🗺️ आकृती

flowchart TB
    a["GET /results/3A · gateway · 0–1040 ms ✗<br/>(root span)"]
    b["check parent login · auth · 40 ms"]
    c["load class list · results-api · 40 ms"]
    d["fetch grades · results-api · 940 ms ✗"]
    e["SELECT grades · postgres · 60 ms"]
    f["grade service call · grade-service · 865 ms ✗"]
    a --> b
    a --> c
    a ==>|"critical path"| d
    d --> e
    d ==>|"critical path"| f
    h["📨 every hop carries:<br/>traceparent: 00-4bf92f35…4736-00f067aa0ba902b7-01"]

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

❓ काय

Trace — एका request चा ती स्पर्श करते त्या प्रत्येक service मधून होणारा संपूर्ण प्रवास. तिच्या सगळ्या भागांचा एकच trace id असतो (16 bytes, 32 hex अक्षरे म्हणून लिहिलेला).
Span — trace मधला वेळ मोजलेला कामाचा एक तुकडा: एक नाव, एक service, सुरुवातीची वेळ, शेवटची वेळ (म्हणजे कालावधी), एक span id (8 bytes, 16 hex अक्षरे), त्याच्या parent span चा id, एक status (ok किंवा error), attributes (key–value तपशील जसे http.route किंवा db.system) आणि ऐच्छिक events (timestamp असलेल्या नोंदी, जसे एखादे exception).
Root span — पहिला span, ज्याला parent नाही (इथे: gateway चा GET /results/3A).
Parent / child — जो span दुसरे काम बोलावतो तो त्या कामाच्या spans चा parent असतो. Children एकामागून एक (sequential) किंवा एकाच वेळी (parallel) चालू शकतात.
Critical path — एकूण वेळ ठरवणारी spans ची साखळी. Critical path वर नसलेला span जलद केल्याने request जलद होत नाही. (Lab एक सोपा नियम वापरतो: root पासून, सर्वात शेवटी संपणाऱ्या child चा पाठलाग करा. खरी tools children मधल्या रिकाम्या वेळेचाही हिशोब करतात.)
Context propagation — trace id आणि बोलावणाऱ्याचा span id पुढच्या service कडे पाठवणे, सहसा HTTP header मध्ये, म्हणजे तिचे spans त्याच trace मध्ये जोडले जातात.
W3C Trace Context — standard header: traceparent: 00-<32 hex trace-id>-<16 hex parent-id>-<2 hex flags>
- 00 — version;
- trace-id — trace मधल्या प्रत्येक span साठी तोच;
- parent-id — बोलावणाऱ्या चा span id (ज्या span ने ही request पाठवली तो);
- flags — 01 म्हणजे sampled (हा trace record होत आहे), 00 म्हणजे नाही. सगळे शून्य असलेले ids अवैध असतात. दुसरा header, tracestate, vendor-specific data नेतो.
Signals जोडणे — trace id प्रत्येक log ओळीत ठेवा (धडा 02); अनेक tools metric points ना उदाहरणादाखल trace ids सुद्धा जोडतात (exemplars), म्हणजे graph वरच्या एका हळू बिंदूवरून थेट एका हळू trace वर जाता येते.

🤔 का

कारण एक page load अनेक services ओलांडतो, आणि प्रत्येक team ला फक्त तिचे स्वतःचे दिसते. Gateway team ला 1,040 ms ची request दिसते. results-api team ला 940 ms चा call दिसतो. फक्त trace दाखवतो की त्यातले 865 ms grade service ला केलेल्या एका call मध्ये गेले — आणि database, auth आणि class list ठीक होते. त्याशिवाय, पाच teams पाच dashboards पाहतात आणि वाद घालतात.

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

obs/signals.py मधील Span(span_id, parent, name, start, end, service, error=False) म्हणजे कार्डावरचा एक शिक्का; .ms त्याचा कालावधी. trace_tree(spans) spans indent केलेल्या झाडासारखे print करते (children सुरुवातीच्या वेळेनुसार sort केलेले, errors साठी ✗). critical_path(spans) root पासून सुरू करून सर्वात शेवटी संपणाऱ्या child चा पाठलाग करत राहते. traceparent(trace_id, span_id, sampled=True) W3C header बनवते. tracing() 11:40 ची अयशस्वी request बनवते: पाच services मधले सहा spans.

🧪 करून पाहा

Grade service दुरुस्त करा (865 ms च्या call ऐवजी 5 ms चे cache read), parallel मध्ये load होणारा एक photo जोडा — आणि critical path सरकताना पाहा:

python3 obs/demo.py tracing
python3 - <<'EOF'
import sys; sys.path.insert(0, "obs"); from signals import Span, trace_tree, critical_path, traceparent
fixed = [Span("a", None, "GET /results/3A", 0, 240, "gateway"), Span("b", "a", "check parent login", 5, 45, "auth"),
         Span("c", "a", "load class list", 50, 90, "results-api"), Span("d", "a", "fetch grades", 95, 235, "results-api"),
         Span("e", "d", "SELECT grades", 100, 160, "postgres"), Span("f", "d", "grade cache GET", 165, 170, "redis"),
         Span("g", "a", "load photo", 50, 238, "photo-service")]
for line in trace_tree(fixed): print(line)
print("critical path:", " → ".join(critical_path(fixed)))
print(traceparent("a3ce929d0e0e47364bf92f3577b34da6", "b7ad6b7169203331"))
print(traceparent("a3ce929d0e0e47364bf92f3577b34da6", "b7ad6b7169203331", sampled=False))
EOF
python3 obs/test_obs.py

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

tracing हे print करते:

── one parent's request, as a trace (one tree of spans):
   GET /results/3A [gateway] 0–1040 ms (1040 ms) ✗
     check parent login [auth] 5–45 ms (40 ms)
     load class list [results-api] 50–90 ms (40 ms)
     fetch grades [results-api] 95–1035 ms (940 ms) ✗
       SELECT grades [postgres] 100–160 ms (60 ms)
       grade service call [grade-service] 165–1030 ms (865 ms) ✗
   critical path: GET /results/3A → fetch grades → grade service call — 865 of 1040 ms is the grade service
   passed between services in a header: traceparent: 00-a3ce929d0e0e47364bf92f3577b34da6-00f067aa0ba902b7-01

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

GET /results/3A [gateway] 0–240 ms (240 ms)
  check parent login [auth] 5–45 ms (40 ms)
  load class list [results-api] 50–90 ms (40 ms)
  load photo [photo-service] 50–238 ms (188 ms)
  fetch grades [results-api] 95–235 ms (140 ms)
    SELECT grades [postgres] 100–160 ms (60 ms)
    grade cache GET [redis] 165–170 ms (5 ms)
critical path: GET /results/3A → load photo
00-a3ce929d0e0e47364bf92f3577b34da6-b7ad6b7169203331-01
00-a3ce929d0e0e47364bf92f3577b34da6-b7ad6b7169203331-00

Tests मध्ये ✅ L05 the critical path follows the child that ends last आणि ✅ L05 W3C traceparent has version-trace-span-flags असतात.

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

अयशस्वी request मध्ये, critical path fetch grades → grade service call मधून गेला: 1,040 पैकी 865 ms. दुरुस्तीनंतर request ला 240 ms लागतात, आणि आता critical path म्हणजे photo (188 ms, 50 ते 238 ms parallel मध्ये चालणारा). fetch grades आणखी जलद केले तरी काहीच बदलणार नाही — तो photo च्या आधीच संपतो. Header ने तोच trace id ठेवला; फक्त parent id (बोलावणाऱ्याचा span) आणि sampled flag बदलले.

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

traceparent पुढे न पाठवणारी एक service — trace दोन असंबंधित traces मध्ये तुटतो
येणारा trace पुढे चालू ठेवण्याऐवजी प्रत्येक service मध्ये नवा trace सुरू करणे
critical path वर नसताना सर्वात हळू दिसणारा span optimise करणे
आत ids असलेली span names (GET /results/3A/pupil/1234) — route template वापरा आणि id attribute मध्ये ठेवा
message मध्ये context नसलेल्या queues आणि background jobs, त्यामुळे trace queue वरच थांबतो
span attributes मध्ये वैयक्तिक माहिती — ती logs सारखीच साठवली आणि दाखवली जाते (धडा 02)

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

On a real account — एका call भोवती span, आणि header हाताने पुढे पाठवलेला (OpenTelemetry SDK धडा 06 मध्ये set up होतो; requests, Flask, FastAPI आणि इतरांसाठीचे auto-instrumentation हे दोन्ही तुमच्यासाठी करते):

import requests
from opentelemetry import trace
from opentelemetry.propagate import inject
from opentelemetry.trace import Status, StatusCode

tracer = trace.get_tracer("results-api")

def fetch_grades(cls):
    with tracer.start_as_current_span("fetch grades") as span:
        span.set_attribute("school.class", cls)
        headers = {}
        inject(headers)            # adds traceparent: 00-<trace-id>-<this span's id>-01
        try:
            return requests.get(f"http://grade-service/grades/{cls}", headers=headers, timeout=1.0).json()
        except requests.Timeout as e:
            span.record_exception(e)
            span.set_status(Status(StatusCode.ERROR, "grade service timeout"))
            raise

Wire वरचा header:

GET /grades/3A HTTP/1.1
Host: grade-service
traceparent: 00-a3ce929d0e0e47364bf92f3577b34da6-00f067aa0ba902b7-01

Trace backends: Grafana Tempo, Jaeger, AWS X-Ray (ADOT Collector मार्फत; X-Ray W3C trace ids सुद्धा स्वीकारतो), Datadog APM. Tempo मध्ये TraceQL ने हळू traces शोधा:

{ resource.service.name = "results-api" && duration > 500ms && status = error }

🏭 Production मध्ये हे का महत्त्वाचे: प्रत्येक सीमेवर propagation तपासा — HTTP, gRPC, queues, scheduled jobs. Header टाकून देणारी एक service तिच्या नंतरचे सगळे लपवते.

⏭️ पुढे

पाच services, तीन signals, अनेक vendors. प्रत्येक service एकदाच, एका standard पद्धतीने instrument करा, आणि data कुठेही पाठवा: OpenTelemetry.

git checkout lesson-06-opentelemetry

🧵 Lesson 05 — Distributed tracing: one pupil's route card

📍 You are here: Lesson 05 of 12 · Previous: lesson-04-percentiles · Next: lesson-06-opentelemetry

📦 What's in this branch

Lessons 01–04, plus the third signal and the start of Part 2: traces. You learn spans, parent and child, the critical path, and the W3C traceparent header that carries the trace from one service to the next. Span, trace_tree(), critical_path() and traceparent() live in obs/signals.py; tracing() in obs/demo.py draws one parent's failed request.

🧒 Explain like I'm 5

A pupil feels ill and is sent to the health room. On the way she visits the office, the staff room and the library. Somewhere she lost 15 minutes. Where?

So Katrina gives every pupil a route card 🗺️ with a number on top. Every room she visits stamps the card: the room name, the time in, the time out. When the office sends her on to the staff room, the office writes its own stamp number on the card, so the staff room knows who sent her.

At the end, Katrina lays the card on the table. Each stamp is a box. Boxes sit inside other boxes: the staff room's visit contains its trip to the library. One chain of boxes is longer than all the rest — the library took 12 of the 15 minutes. That chain is the critical path. Making any other room faster would not help her at all.

🗺️ Diagram

flowchart TB
    a["GET /results/3A · gateway · 0–1040 ms ✗<br/>(root span)"]
    b["check parent login · auth · 40 ms"]
    c["load class list · results-api · 40 ms"]
    d["fetch grades · results-api · 940 ms ✗"]
    e["SELECT grades · postgres · 60 ms"]
    f["grade service call · grade-service · 865 ms ✗"]
    a --> b
    a --> c
    a ==>|"critical path"| d
    d --> e
    d ==>|"critical path"| f
    h["📨 every hop carries:<br/>traceparent: 00-4bf92f35…4736-00f067aa0ba902b7-01"]

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

❓ What

Trace — the whole journey of one request through every service it touches. All its parts share one trace id (16 bytes, written as 32 hex characters).
Span — one timed piece of work inside a trace: a name, a service, a start time, an end time (so a duration), a span id (8 bytes, 16 hex characters), the id of its parent span, a status (ok or error), attributes (key–value details such as http.route or db.system) and optional events (timestamped notes, such as an exception).
Root span — the first span, with no parent (here: the gateway's GET /results/3A).
Parent / child — a span that calls other work is the parent of the spans for that work. Children can run one after another (sequential) or at the same time (parallel).
Critical path — the chain of spans that decides the total time. Speeding up a span that is not on the critical path does not make the request faster. (The lab uses a simple rule: from the root, follow the child that ends last. Real tools also account for gaps between children.)
Context propagation — passing the trace id and the caller's span id to the next service, usually in an HTTP header, so its spans join the same trace.
W3C Trace Context — the standard header: traceparent: 00-<32 hex trace-id>-<16 hex parent-id>-<2 hex flags>
- 00 — the version;
- trace-id — the same for every span in the trace;
- parent-id — the span id of the caller (the span that sent this request);
- flags — 01 means sampled (this trace is being recorded), 00 means not. All-zero ids are invalid. A second header, tracestate, carries vendor-specific data.
Joining the signals — put the trace id in every log line (lesson 02); many tools also attach example trace ids to metric points (exemplars), so you can jump from a slow point on a graph straight to one slow trace.

🤔 Why

Because one page load crosses many services, and each team sees only its own. The gateway team sees a 1,040 ms request. The results-api team sees a 940 ms call. Only the trace shows that 865 ms of it was one call to the grade service — and that the database, auth and class list were fine. Without it, five teams look at five dashboards and argue.

🔧 How (in this repo)

Span(span_id, parent, name, start, end, service, error=False) in obs/signals.py is one stamp on the card; .ms is its duration. trace_tree(spans) prints the spans as an indented tree (children sorted by start time, ✗ for errors). critical_path(spans) starts at the root and keeps following the child that ends last. traceparent(trace_id, span_id, sampled=True) builds the W3C header. tracing() builds the failed request from 11:40: six spans across five services.

🧪 Try it

Fix the grade service (a 5 ms cache read instead of an 865 ms call), add a photo that loads in parallel — and watch the critical path move:

python3 obs/demo.py tracing
python3 - <<'EOF'
import sys; sys.path.insert(0, "obs"); from signals import Span, trace_tree, critical_path, traceparent
fixed = [Span("a", None, "GET /results/3A", 0, 240, "gateway"), Span("b", "a", "check parent login", 5, 45, "auth"),
         Span("c", "a", "load class list", 50, 90, "results-api"), Span("d", "a", "fetch grades", 95, 235, "results-api"),
         Span("e", "d", "SELECT grades", 100, 160, "postgres"), Span("f", "d", "grade cache GET", 165, 170, "redis"),
         Span("g", "a", "load photo", 50, 238, "photo-service")]
for line in trace_tree(fixed): print(line)
print("critical path:", " → ".join(critical_path(fixed)))
print(traceparent("a3ce929d0e0e47364bf92f3577b34da6", "b7ad6b7169203331"))
print(traceparent("a3ce929d0e0e47364bf92f3577b34da6", "b7ad6b7169203331", sampled=False))
EOF
python3 obs/test_obs.py

✅ Verify — what you should see

tracing prints:

── one parent's request, as a trace (one tree of spans):
   GET /results/3A [gateway] 0–1040 ms (1040 ms) ✗
     check parent login [auth] 5–45 ms (40 ms)
     load class list [results-api] 50–90 ms (40 ms)
     fetch grades [results-api] 95–1035 ms (940 ms) ✗
       SELECT grades [postgres] 100–160 ms (60 ms)
       grade service call [grade-service] 165–1030 ms (865 ms) ✗
   critical path: GET /results/3A → fetch grades → grade service call — 865 of 1040 ms is the grade service
   passed between services in a header: traceparent: 00-a3ce929d0e0e47364bf92f3577b34da6-00f067aa0ba902b7-01

Your snippet prints:

GET /results/3A [gateway] 0–240 ms (240 ms)
  check parent login [auth] 5–45 ms (40 ms)
  load class list [results-api] 50–90 ms (40 ms)
  load photo [photo-service] 50–238 ms (188 ms)
  fetch grades [results-api] 95–235 ms (140 ms)
    SELECT grades [postgres] 100–160 ms (60 ms)
    grade cache GET [redis] 165–170 ms (5 ms)
critical path: GET /results/3A → load photo
00-a3ce929d0e0e47364bf92f3577b34da6-b7ad6b7169203331-01
00-a3ce929d0e0e47364bf92f3577b34da6-b7ad6b7169203331-00

The tests include ✅ L05 the critical path follows the child that ends last and ✅ L05 W3C traceparent has version-trace-span-flags.

🏁 What you just proved

In the failed request, the critical path went through fetch grades → grade service call: 865 ms of the 1,040. After the fix the request takes 240 ms, and the critical path is now the photo (188 ms, running in parallel from 50 to 238 ms). Making fetch grades any faster would change nothing — it ends before the photo does. The header kept the same trace id; only the parent id (the caller's span) and the sampled flag changed.

⚠️ Common mistakes

one service that does not pass traceparent on — the trace breaks into two unrelated traces
starting a new trace in every service instead of continuing the incoming one
optimising the slowest-looking span when it is not on the critical path
span names with ids inside (GET /results/3A/pupil/1234) — use the route template and put the id in an attribute
queues and background jobs with no context in the message, so the trace stops at the queue
personal data in span attributes — they are stored and shown just like logs (lesson 02)

🏭 In production

On a real account — a span around a call, and the header passed on by hand (the OpenTelemetry SDK is set up in lesson 06; auto-instrumentation for requests, Flask, FastAPI and others does both for you):

import requests
from opentelemetry import trace
from opentelemetry.propagate import inject
from opentelemetry.trace import Status, StatusCode

tracer = trace.get_tracer("results-api")

def fetch_grades(cls):
    with tracer.start_as_current_span("fetch grades") as span:
        span.set_attribute("school.class", cls)
        headers = {}
        inject(headers)            # adds traceparent: 00-<trace-id>-<this span's id>-01
        try:
            return requests.get(f"http://grade-service/grades/{cls}", headers=headers, timeout=1.0).json()
        except requests.Timeout as e:
            span.record_exception(e)
            span.set_status(Status(StatusCode.ERROR, "grade service timeout"))
            raise

The header on the wire:

GET /grades/3A HTTP/1.1
Host: grade-service
traceparent: 00-a3ce929d0e0e47364bf92f3577b34da6-00f067aa0ba902b7-01

Trace backends: Grafana Tempo, Jaeger, AWS X-Ray (through the ADOT Collector; X-Ray also accepts W3C trace ids), Datadog APM. Find slow traces in Tempo with TraceQL:

{ resource.service.name = "results-api" && duration > 500ms && status = error }

🏭 Why this matters in production: check propagation at every boundary — HTTP, gRPC, queues, scheduled jobs. One service that drops the header hides everything after it.

⏭️ Next

Five services, three signals, many vendors. Instrument each service once, in one standard way, and send the data anywhere: OpenTelemetry.

git checkout lesson-06-opentelemetry

← Previouspercentiles Next →opentelemetry

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