Distributed Tracing — DevOps

Distributed Tracing Di arsitektur microservices, satu user request bisa melintasi 5-10 service. Distributed tracing menghubungkan semua operasi menjadi satu…

Distributed tracing menyatukan semua operasi dari satu request, walaupun operasinya tersebar di banyak service, menjadi satu trace yang bisa dibaca dari awal sampai akhir. Bayangin melacak paket kiriman. Paketmu lewat loket pengirim, gudang sortir, truk antarkota, lalu kurir. Tiap tempat memindai nomor resi yang sama dan mencatat jam masuk dan keluarnya. Begitu paket telat, kamu langsung tahu: tiga hari tertahan di gudang sortir. Nomor resi itu trace ID, tiap pindaian di satu tempat adalah span, dan "diterima dari mana" adalah parent span ID.

Di pelajaran OpenTelemetry Fundamentals kamu sudah kenal span, trace ID, dan header traceparent. Sekarang kita pakai semuanya untuk mencari kenapa pencarian catatan di catatan-api lambat.

🧪 Tebakan cepat: Sari mencari catatan berisi "resep", dan request-nya butuh 1.221 ms. Di trace-nya, span catatan-api GET /catatan berdurasi 1.215 ms. Jadi kode catatan-api yang lambat? Jawabannya ada di bagian "Mencari span yang lambat: self time".

Satu request, banyak service, satu trace

Di arsitektur microservices, satu request user bisa melintasi 5 sampai 10 service. Masing-masing punya log dan metric sendiri, dan gak ada satu pun yang melihat gambar utuhnya. Distributed tracing menyambungkan semua operasi itu lewat trace ID yang sama, jadi kamu bisa melihat urutan, durasi, dan letak error-nya dalam satu tampilan.

catatan-api masih sederhana: nginx, catatan-api, PostgreSQL. Tapi polanya sama persis, dan tiga lapis sudah cukup untuk tersesat tanpa trace.

Propagasi: header yang bikin span tersambung

Span cuma tersambung kalau konteks trace ikut terkirim ke tiap service. nginx bisa membuat span sendiri lewat modul resminya, ngx_otel_module:

load_module modules/ngx_otel_module.so;   # paling atas nginx.conf

http {
    otel_exporter {
        endpoint localhost:4317;            # OTLP gRPC ke collector
    }
    otel_service_name nginx;
    otel_trace on;

    server {
        server_name catatan.example.com;

        location / {
            otel_trace_context propagate;   # baca traceparent yang masuk, kirim yang baru
            otel_span_name "$request_method $uri";
            proxy_pass http://127.0.0.1:3000;
        }
    }
}

Kalau header-nya gak sampai, misalnya propagate lupa ditulis, catatan-api gak tahu induknya dan memulai trace baru. Di Jaeger, span catatan-api muncul sebagai trace terpisah yang gak tersambung ke nginx. Coba matikan propagasi di Lab: satu trace pecah jadi dua.

Span PostgreSQL dibuat oleh catatan-api, bukan oleh PostgreSQL. Instrumentasi driver pg mencatat kapan query dikirim dan kapan hasilnya kembali. PostgreSQL sendiri gak menerima traceparent.

Waterfall dari parent ID

Backend tracing menerima span satu per satu, tanpa urutan, dari service yang berbeda. Ini 7 span trace a3c9e1f07b2d4e58961c0d7f3b5a8e24 di Lab:

span ID parent service nama mulai durasi
411040a7e0c772b3 (root) nginx GET /catatan 0 ms 1.221 ms
338bcacd9627d923 411040a7... catatan-api GET /catatan 3 ms 1.215 ms
e7120c544d183da4 338bcacd... catatan-api middleware - auth 4 ms 6 ms
aee6a787c3a60c4d 338bcacd... catatan-api pg-pool.connect 11 ms 1 ms
eb1ae73b369e8c7a 338bcacd... catatan-api SELECT catatan 13 ms 1.178 ms
6c59a15d0fce260e 338bcacd... catatan-api SELECT tag 1.192 ms 7 ms
0008c964f55bab20 338bcacd... catatan-api render-json 1.200 ms 12 ms

Dari parent ID-nya, backend menyusun pohon, lalu menggambarnya sebagai waterfall: satu baris per span, batang mulai di waktu mulai dan panjangnya sebanding dengan durasi. Ini kode yang sama dengan yang dijalankan Lab:

function cetakWaterfall(spans) {
  const anakDari = {};
  for (const span of spans) {
    const key = span.parent || "root";
    if (!anakDari[key]) anakDari[key] = [];
    anakDari[key].push(span);
  }

  function cetak(span, kedalaman, root) {
    const anak = (anakDari[span.id] || []).sort((a, b) => a.start - b.start);
    const msAnak = anak.reduce((jumlah, a) => jumlah + a.ms, 0);
    const lebar = Math.max(1, Math.round((span.ms / root.ms) * 30));
    const kiri = Math.min(30 - lebar, Math.round(((span.start - root.start) / root.ms) * 30));
    const batang = " ".repeat(kiri) + "#".repeat(lebar) + " ".repeat(Math.max(0, 30 - kiri - lebar));
    console.log("|" + batang + "| " + "  ".repeat(kedalaman) + span.name + " " + span.ms + " ms, self " + (span.ms - msAnak) + " ms");
    anak.forEach((a) => cetak(a, kedalaman + 1, root));
  }

  for (const root of anakDari.root || []) {
    console.log("trace " + root.trace);
    cetak(root, 0, root);
  }
}

trace a3c9e1f07b2d4e58961c0d7f3b5a8e24
|##############################| GET /catatan 1221 ms, self 6 ms
|##############################|   GET /catatan 1215 ms, self 11 ms
|#                             |     middleware - auth 6 ms, self 6 ms
|#                             |     pg-pool.connect 1 ms, self 1 ms
|############################# |     SELECT catatan 1178 ms, self 1178 ms
|                             #|     SELECT tag 7 ms, self 7 ms
|                             #|     render-json 12 ms, self 12 ms

Mencari span yang lambat: self time

Durasi span induk termasuk durasi anak-anaknya. Jadi yang dicari bukan span terpanjang, tapi span dengan self time terbesar: durasinya dikurangi durasi anak-anaknya (selama anaknya gak jalan bersamaan). GET /catatan di catatan-api memang 1.215 ms, tapi self time-nya cuma 11 ms. Yang makan waktu adalah anaknya, SELECT catatan: 1.178 ms, 96% dari seluruh request. Jadi bukan kode catatan-api yang lambat, tapi query-nya. Itu jawaban tebakannya.

Atribut span itu menunjukkan query-nya: WHERE user_id = $1 AND isi ILIKE $2, dengan $2 berisi '%resep%'. Pola yang diawali % gak bisa memakai index B-tree biasa, jadi PostgreSQL membaca semua baris catatan. Perbaikannya index trigram:

CREATE EXTENSION IF NOT EXISTS pg_trgm;
CREATE INDEX CONCURRENTLY catatan_isi_trgm ON catatan USING gin (isi gin_trgm_ops);

Setelah index-nya ada, SELECT catatan turun ke 21 ms, dan seluruh request dari 1.221 ms jadi 64 ms. CONCURRENTLY membuat index tanpa mengunci tabel dari INSERT dan UPDATE, penting di tabel yang sedang dipakai.

Sampling: head atau tail

Merekam trace dari setiap request di production berarti data yang sangat banyak. Sampling memilih trace mana yang disimpan, dan ada dua waktu untuk memutuskannya:

processors:
  tail_sampling:
    decision_wait: 10s
    policies:
      - name: semua-error
        type: status_code
        status_code:
          status_codes: [ERROR]
      - name: lambat
        type: latency
        latency:
          threshold_ms: 1000
      - name: sebagian-sisanya
        type: probabilistic
        probabilistic:
          sampling_percentage: 10

Lab memuat 20 trace dari satu menit: 16 normal, 2 lambat (1.221 ms dan 1.480 ms), 2 error. Head 10% menyimpan 2 trace, keduanya normal: trace pencarian Sari yang lambat ikut terbuang, begitu juga kedua error. Tail menyimpan 6: kedua error, kedua yang lambat, plus 2 trace normal. Kalau kamu ingin semua trace error tersimpan dan yang sukses cukup sebagian, pakai tail-based. Harganya: collector butuh memori untuk menahan trace, dan semua span satu trace harus sampai di collector yang sama.

💡 Pilihan backend tracing

Semuanya bisa menerima data OpenTelemetry, jadi instrumentasimu gak terikat ke salah satunya.

⚠️ Jebakan yang sering ketemu

TL;DR: Distributed tracing menyatukan operasi dari banyak service menjadi satu trace, disambung trace ID yang sama. Span tersambung hanya kalau traceparent diteruskan di tiap lapis (nginx: otel_trace_context propagate), kalau putus, service berikutnya memulai trace baru yang terpisah. Backend menyusun waterfall dari parent ID, dan span yang lambat dicari lewat self time (durasi dikurangi anak-anaknya): di Lab, SELECT catatan 1.178 ms dari 1.221 ms, turun ke 21 ms dengan index trigram. Head sampling memutuskan di awal (murah, tapi buta terhadap error), tail sampling memutuskan setelah request selesai di collector, jadi semua error dan request lambat bisa disimpan sementara yang sukses cukup sebagian. Backend-nya bisa Jaeger, Tempo, Datadog APM, atau AWS X-Ray.

Yang akan kamu pelajari