Distributed Tracing

บริบท

log ที่รวบรวมและเชื่อมโยงไว้แล้วช่วยให้คุณค้นทุกบรรทัดของ request หนึ่งมาอ่านเรียงตามลำดับได้ ซึ่งตอบคำถามว่า เกิดอะไรขึ้น แต่มีอีกคำถามที่ log ตอบได้ไม่ดีเลยคือ เวลาหายไปไหน checkout ที่ใช้เวลาสี่วินาทีวิ่งผ่าน gateway, order service, payment service และ inventory service โดยแต่ละตัวอาจเรียก database หรือ cache ต่อไปอีก ในต้นไม้ของการเรียกที่ซ้อนกันนั้น มีสามในสี่วินาทีหายไปที่จุดใดจุดหนึ่ง แต่รายการ log แบบแบน ๆ ต่อให้เชื่อมโยงกันได้สมบูรณ์แบบ ก็ไม่แสดงรูปร่างของต้นไม้หรือระยะเวลาของแต่ละกิ่งให้ดูอยู่ดี

ปัญหา

correlation id บอกได้แค่ว่า log ชุดนี้เป็นพวกเดียวกัน แต่ไม่บอกว่า เกี่ยวข้องกันอย่างไร ไม่บอกว่าการเรียก payment เกิดขึ้น ภายใน การเรียก order ไม่บอกว่าการเรียก inventory รัน หลังจาก payment คืนค่ากลับมา และไม่บอกว่า database query ใต้ inventory กินเวลาไป 2.8 จาก 4 วินาทีของ request นั้น ถ้าไม่มีโครงสร้างเชิงสาเหตุที่มี timing กำกับ คุณก็ต้องกลับไปเพ่ง timestamp ข้าม service เพื่อเดา critical path เอาเอง ทั้งที่ timestamp จากคนละเครื่องยังไม่ตรงกันเป๊ะด้วยซ้ำ

แล้วคุณจะสร้าง nested call tree เต็มของคำขอหนึ่งขึ้นใหม่ได้อย่างไร พร้อมระยะเวลาของทุก hop ข้ามบริการที่แต่ละตัวเห็นเฉพาะส่วนของตัวเองเท่านั้น

วิธีแก้

Distributed tracing มองหนึ่ง request เป็นหนึ่ง trace ที่ประกอบขึ้นจาก span หลายอัน trace คือเส้นทางทั้งหมดของ request จากภายนอกหนึ่งครั้ง ส่วน span คือหน่วยงานหนึ่งหน่วยภายในนั้น เช่น request ขาเข้าที่ถูกจัดการ การเรียกขาออกหนึ่งครั้ง หรือ query หนึ่ง query แต่ละ span บันทึก start time, duration และชื่อ พร้อมพก id สองตัวคือ trace id ที่ทุก span ใน request เดียวกันใช้ร่วมกัน และ span id เฉพาะตัว นอกจากนี้แต่ละ span ยังระบุ parent span id ไว้ด้วย และ parent link เหล่านี้เองคือสิ่งที่ใช้ประกอบต้นไม้ขึ้นมาใหม่

กลไกที่ทำให้ข้ามขอบเขต process ได้คือ context propagation เวลา service เรียกออกไปข้างนอก จะฉีด trace id ปัจจุบันกับ span id ของตัวเองลงไปใน request ปกติส่งเป็น header ตามมาตรฐาน W3C Trace Context (traceparent) ฝั่ง service ที่รับก็อ่าน header เหล่านั้น ถือว่า span id ขาเข้าเป็น parent แล้วเปิด span ใหม่ใต้ parent นั้น ไล่ต่อกันไปเรื่อย ๆ ตามต้นไม้ ทุก service รายงาน span ของตัวเองไปยัง collector กลาง ซึ่งจะเย็บทุกอย่างกลับเข้าด้วยกันด้วย trace id และ parent link ออกมาเป็น waterfall พร้อม timing ชุดเดียว

sequenceDiagram
  participant GW as Gateway
  participant O as Order Service
  participant P as Payment Service
  participant I as Inventory Service
  GW->>O: POST /checkout\ntraceparent: trace=abc, span=1
  Note over O: start span 2 (parent 1)
  O->>P: charge()\ntraceparent: trace=abc, span=2
  Note over P: start span 3 (parent 2)
  P-->>O: ok (span 3 ends, 120ms)
  O->>I: reserve()\ntraceparent: trace=abc, span=2
  Note over I: start span 4 (parent 2)
  I-->>O: ok (span 4 ends, 2800ms)
  O-->>GW: 200 (span 2 ends, 2950ms)

แต่ละ hop อ่าน traceparent ขาเข้า, เริ่ม child span และ propagate trace พร้อม span id ของตัวเองต่อไป — collector สร้างต้นไม้ขึ้นใหม่จาก trace id และ parent link

ตัวอย่าง

หัวใจของ tracing คือ propagation ให้อ่าน trace context จาก request ขาเข้า แล้วฉีดลงไปในทุกการเรียกขาออก ตัวอย่างข้างล่างอ่าน traceparent header ขาเข้าแล้วส่งต่อ ที่เป็นขั้นต่ำที่ทำให้ trace ไม่ขาดตอนข้าม hop

TypeScript

import express from 'express';
import { fetch } from 'undici';

const app = express();

app.post('/checkout', async (req, res) => {
  // Read incoming trace context (or start a new trace at the edge).
  const incoming = req.header('traceparent') ?? newTraceparent();
  const { traceId, parentSpanId } = parseTraceparent(incoming);

  // This service's own span becomes the parent of downstream calls.
  const mySpanId = randomSpanId();
  const outgoing = formatTraceparent(traceId, mySpanId);

  // Propagate on every outbound call.
  await fetch('http://payment/charge', {
    method: 'POST',
    headers: { traceparent: outgoing },
  });

  res.sendStatus(200);
});

Python

import httpx
from fastapi import FastAPI, Request

app = FastAPI()

@app.post("/checkout")
async def checkout(request: Request):
    # Read incoming trace context (or start a new trace at the edge).
    incoming = request.headers.get("traceparent") or new_traceparent()
    trace_id, parent_span_id = parse_traceparent(incoming)

    # This service's own span becomes the parent of downstream calls.
    my_span_id = random_span_id()
    outgoing = format_traceparent(trace_id, my_span_id)

    # Propagate on every outbound call.
    async with httpx.AsyncClient() as client:
        await client.post(
            "http://payment/charge",
            headers={"traceparent": outgoing},
        )

    return {"status": "ok"}

Go

func checkout(w http.ResponseWriter, r *http.Request) {
    // Read incoming trace context (or start a new trace at the edge).
    incoming := r.Header.Get("traceparent")
    if incoming == "" {
        incoming = newTraceparent()
    }
    traceID, parentSpanID := parseTraceparent(incoming)
    _ = parentSpanID

    // This service's own span becomes the parent of downstream calls.
    mySpanID := randomSpanID()
    outgoing := formatTraceparent(traceID, mySpanID)

    // Propagate on every outbound call.
    req, _ := http.NewRequest("POST", "http://payment/charge", nil)
    req.Header.Set("traceparent", outgoing)
    http.DefaultClient.Do(req)

    w.WriteHeader(http.StatusOK)
}

Rust

use axum::http::HeaderMap;

async fn checkout(headers: HeaderMap) -> axum::http::StatusCode {
    // Read incoming trace context (or start a new trace at the edge).
    let incoming = headers
        .get("traceparent")
        .and_then(|v| v.to_str().ok())
        .map(String::from)
        .unwrap_or_else(new_traceparent);
    let (trace_id, _parent_span_id) = parse_traceparent(&incoming);

    // This service's own span becomes the parent of downstream calls.
    let my_span_id = random_span_id();
    let outgoing = format_traceparent(&trace_id, &my_span_id);

    // Propagate on every outbound call.
    let client = reqwest::Client::new();
    let _ = client
        .post("http://payment/charge")
        .header("traceparent", outgoing)
        .send()
        .await;

    axum::http::StatusCode::OK
}

ในทางปฏิบัติคุณแทบไม่ต้องเขียน propagation นี้เองเลย instrumentation library อย่างที่สร้างบน OpenTelemetry จะฉีดและ extract trace context จับเวลา span และ export ให้เสร็จสรรพ ความเข้าใจกลไกนี้จะมีค่าที่สุดตอนที่ trace ขาดหายอย่างลึกลับที่ hop ใด hop หนึ่ง

ผลลัพธ์ที่ตามมา

สิ่งที่คุณได้รับ:

• Critical path ที่ถูกทำให้มองเห็นได้ trace waterfall แสดงระยะเวลาของทุก hop ดังนั้นคุณจึงเห็นได้ในพริบตาว่า 2.8 จาก 4 วินาทีถูกใช้ไปใน inventory query หนึ่ง แทนการเดาข้าม log timestamp
• โครงสร้างเชิงสาเหตุ ไม่ใช่แค่ correlation parent link สร้างขึ้นใหม่ว่า การเรียกใดเกิดขึ้นภายในการเรียกใด กู้คืนมุมมองแบบซ้อนที่ stack trace เดียวให้คุณใน monolith
• ชี้ต้นตอของ error ข้าม service ได้ เมื่อ request ล้มเหลว trace จะชี้ตรงไปที่ span และ service ที่พังจริง ไม่ใช่แค่ 500 กว้าง ๆ จาก gateway

สิ่งที่คุณต้องจ่าย:

• Propagation ต้องไม่ขาด hop เดียวที่ทำ trace context หล่นหาย — client ที่ไม่ได้ instrument, queue ที่ไม่พก header, ขอบเขตของ thread — จะแยก trace ออกเป็นสองและซ่อนต้นไม้ที่อยู่เลยจุดนั้นไป
• Sampling มักเป็นข้อบังคับ การบันทึกทุก span ของทุกคำขอที่ทราฟฟิกสูงนั้นแพง คุณจึง sample เลือกกลยุทธ์ sampling ของคุณอย่างตั้งใจ เพราะ head-based sample อาจพลาดคำขอที่ล้มเหลวซึ่งหายากแต่คุณอยากเห็นที่สุด
• ความพยายามในการ instrument ทุกบริการ, client library และขอบเขต async ต้องมีส่วนร่วม; ภาษาและ framework ที่ปะปนกันทำให้การครอบคลุมที่สม่ำเสมอเป็นงานจริง ๆ

เนื้อหาที่เกี่ยวข้อง

• Log Aggregation — ใส่ trace id ลงในทุกบรรทัด log แล้ว traces และ logs ก็อ้างอิงถึงกันและกัน
• Application Metrics — metric บอกว่า latency เพิ่มขึ้น ส่วน trace บอกว่าเพิ่มขึ้น ตรงไหน

ข้อดี	ข้อแลกเปลี่ยน
เห็น request journey ข้าม service ทั้งหมดในที่เดียว	sampling ที่ไม่ดีทำให้พลาด trace สำคัญ
ค้นหา bottleneck ใน distributed system ได้	overhead ของ trace collection และ storage
correlate log และ metric กับ specific request	require instrument ทุก service — ถ้า service หนึ่งไม่ instrument trace ขาด
เห็น dependency map ของ service จาก trace data	ทีมต้องเรียนรู้ tool เพิ่ม (Jaeger, Zipkin, Tempo)

ข้อผิดพลาดที่พบบ่อย

Trace ทุก Request (100% Sampling) — ไม่ใช้ sampling ทำให้ storage พุ่ง อาการ:

• trace storage cost สูงมากใน high-traffic system
• ใช้ head-based หรือ tail-based sampling แทน

Trace ที่ขาดช่วง — service บางตัวไม่ propagate trace context อาการ:

• เปิด trace แล้วเห็น hop ขาดหายไป
• ไม่รู้ว่า service ไหนใช้เวลาเท่าไร
• ต้อง instrument ทุก service และทุก async call

💡 ตัวอย่างจากของจริง

Google (Dapper):

• เป็น paper ที่เป็นต้นแบบของ distributed tracing ทั้งอุตสาหกรรม (2010)
• Zipkin (Twitter) และ Jaeger (Uber) ได้รับแรงบันดาลใจจาก Dapper

Uber (Jaeger):

• สร้าง Jaeger เพื่อ trace request ข้าม 1000+ service
• ปัจจุบัน CNCF graduated project — ใช้แพร่หลายที่สุดในอุตสาหกรรม

🧩 Logs, traces และ metrics คือชุดเครื่องมือเดียวกัน

สัญญาณทั้งสามตอบคนละคำถามและทรงพลังที่สุดเมื่อใช้ร่วมกัน metric เตือนคุณว่า p99 latency พุ่ง trace ของ request ที่ช้าชี้ให้เห็น hop ที่เป็นต้นเหตุ ส่วน log ที่รวบรวมไว้แล้ว filter ด้วย trace id เดียวกันจะเผยข้อความ error ภายใน hop นั้น แค่ประทับ trace id เดียวกันลงในทั้งสามสัญญาณ คุณก็สลับไปมาระหว่างกันได้ลื่นไหลตอนเกิดเหตุ แทนที่จะต้องเริ่มสืบสวนใหม่จากศูนย์ทุกครั้ง

trace กับ span สัมพันธ์กันอย่างไร

span คือ request ทั้งก้อน ส่วน trace คือหน่วยงานหนึ่งหน่วยภายใน request นั้น trace คือเส้นทางทั้งหมดของ request ส่วน span คือหน่วยงานหนึ่งหน่วยพร้อม timing ภายใน trace เป็นชื่อสองชื่อของสิ่งเดียวกัน trace คือบรรทัด log; span คือ metric

อะไรคือสิ่งที่ใช้ประกอบ call tree แบบซ้อนกันของ trace ขึ้นมาใหม่

wall-clock timestamp บนแต่ละบรรทัด log แต่ละ span บันทึก parent span id ไว้ บวกกับ trace id ที่ใช้ร่วมกัน แล้ว collector เย็บทั้งหมดเข้าด้วยกัน ลำดับที่บริการถูก deploy ขนาดของ payload ของแต่ละคำขอ

จะเกิดอะไรขึ้นถ้ามี hop หนึ่งไม่ propagate trace context ต่อ

ไม่มีอะไรเกิดขึ้น; collector เติมช่องว่างให้โดยอัตโนมัติ trace แยกออกและ call tree ที่อยู่เลย hop นั้นไปก็สูญหาย metrics ทั้งหมดสำหรับบริการนั้นหยุดทำงาน คำขอล้มเหลวด้วย HTTP 500

Submit

Mark as complete