Tracing Dasar

Crate log mencatat kejadian sebagai baris teks yang berdiri sendiri, dan pendekatan tersebut cukup untuk program yang sederhana. Masalah muncul ketika pertanyaan kita berubah dari “apa yang terjadi” menjadi “kejadian ini bagian dari alur yang mana”: dua ratus baris INFO dari sepuluh pesanan yang diproses bersamaan sulit diurai tanpa konteks. Crate tracing menjawab dengan dua bangunan utama — event yang membawa data terstruktur, dan span yang membungkus rentang eksekusi menjadi konteks yang menempel pada setiap event di dalamnya. Seperti halnya log, instrumentasi tracing juga terpisah dari komponen pencetaknya: event dan span baru tampil setelah program memasang subscriber, dan pemilihan serta konfigurasi subscriber tersebut menjadi materi Chapter terakhir section ini.

Dari Pesan Teks ke Structured Logging #

Bedah mekanismenya dimulai dari bentuk paling mendasar: event. Macro tracing::info!, tracing::warn!, dan kawannya menerima pasangan field = nilai sebelum teks pesan, sehingga data direkam sebagai pasangan kunci-nilai, bukan sebagai potongan kalimat yang sudah dilebur ke dalam string. Pendekatan ini disebut structured logging: nilai pesanan_id = 42 tetap berupa data bernama pesanan_id dengan nilai 42, bukan sekadar potongan teks "42" yang menempel di kalimat. Keuntungannya ada di sisi pembaca — subscriber bebas memformat ulang pasangan tersebut menjadi teks rapi, berkas JSON, atau apa pun tanpa kehilangan struktur aslinya.

Pembagian kerja kedua meniru pola facade dari Chapter Crate log. Kode aplikasi cukup bergantung pada crate tracing dan memanggil macro-nya, sementara crate tracing-subscriber — komponen yang benar-benar membaca dan mencetak — hanya ditambahkan oleh binary yang ingin melihat outputnya. Ketika binary belum memasang subscriber, event dan span tidak mengirimkan apa pun ke mana pun; instrumentasi tetap aman ditinggali di dalam library tanpa memaksa biaya pencetakan pada pemakainya.

Proyek uji kita membutuhkan dua dependency, dengan satu catatan: feature attributes pada crate tracing mengaktifkan attribute macro #[instrument] yang akan kita pakai di paruh kedua Chapter.

toml
[package]
name = "myapp"
version = "0.1.0"
edition = "2024"

[dependencies]
tracing = { version = "0.1", features = ["attributes"] }
tracing-subscriber = "0.3"

Event Tanpa Subscriber: Senyap #

Kita buktikan dulu klaim pemisahan tersebut dengan program yang penuh event namun tanpa subscriber:

rust
use tracing::{info, warn};

fn main() {
    info!(pesanan_id = 42, "pesanan diterima");
    warn!("sisa stok rendah");
}

Jalankan programnya:

bash

cargo run

Output yang Dihasilkan:

text

Blok output di atas memang kosong — program berakhir dengan kode keluar 0 tanpa mencetak apa pun, persis seperti program crate log yang belum memasang logger. Macro info! dan warn! tetap dieksekusi, tetapi dispatcher global tracing belum menerima subscriber, sehingga setiap event berhenti di tempat yang sama. Perilaku senyap ini bukan kelemahan; perilaku ini yang membuat instrumentasi boleh ditanam di dalam library tanpa membebani pemakainya.

Melihat Output dengan Subscriber Minimal #

Sekarang kita pasang subscriber paling sederhana dari tracing-subscriber — pemanggilan fmt() dengan ambang level INFO, yang detail konfigurasinya kita bedah tuntas pada Chapter berikutnya. Program yang sama ditambah tiga baris pemasangan:

rust
use tracing::info;

fn main() {
    tracing_subscriber::fmt()
        .with_max_level(tracing::Level::INFO)
        .init();

    info!(pesanan_id = 42, pelanggan = "Budi", "pesanan diterima");

    let keranjang: Vec<&str> = vec!["buku", "pensil"];
    info!(?keranjang, "isi keranjang diperiksa");

    let pelanggan = String::from("Budi");
    info!(?pelanggan, "pelanggan direkam dengan Debug");
    info!(%pelanggan, "pelanggan direkam dengan Display");
}

Output yang Dihasilkan:

text
2026-10-13T23:05:11.328537Z  INFO myapp: pesanan diterima pesanan_id=42 pelanggan="Budi"
2026-10-13T23:05:11.328561Z  INFO myapp: isi keranjang diperiksa keranjang=["buku", "pensil"]
2026-10-13T23:05:11.328566Z  INFO myapp: pelanggan direkam dengan Debug pelanggan="Budi"
2026-10-13T23:05:11.328570Z  INFO myapp: pelanggan direkam dengan Display pelanggan=Budi

Mari kita bedah program dan outputnya:

Baris 4-6 (tracing_subscriber::fmt() ... .init();): rantai ini membangun subscriber format bawaan dengan level maksimum INFO lalu memasangnya sebagai dispatcher global; setelah baris ini, semua event mencapai pencetak.
Baris 8 (info!(pesanan_id = 42, pelanggan = "Budi", "pesanan diterima");): dua field bernama direkam sebelum teks pesan; pada output, kedua field muncul setelah pesan sebagai pesanan_id=42 pelanggan="Budi" — pesan dan data tetap terpisah.
Baris 10-11 (let keranjang ...; info!(?keranjang, ...)): sigil ? sebelum nama field memaksa perwujudan Debug, sehingga Vec<&str> tercetak sebagai keranjang=["buku", "pensil"] — utuh dengan tanda kutipnya.
Baris 13-15 (info!(?pelanggan, ...) dan info!(%pelanggan, ...)): dua baris sengaja membandingkan dua sigil pada data yang sama — ?pelanggan menghasilkan pelanggan="Budi" karena trait Debug milik String menambahkan kutip, sedangkan %pelanggan menghasilkan pelanggan=Budi karena sigil % memaksa trait Display.

Perhatikan pula format barisnya: pola bawaan subscriber fmt() adalah timestamp LEVEL target: pesan field=nilai, dengan timestamp UTC berketelitian mikrodetik dan level yang ditata rata kanan dalam lima karakter. Nilai timestamp pada output di atas berasal dari satu eksekusi di mesin penulis dan akan berbeda di setiap eksekusi Anda — sama seperti env_logger, waktu yang dicatat adalah saat event terjadi.

Span: Konteks yang Dibawa Antar Event #

Event menjawab “apa yang terjadi”, span menjawab “di dalam kegiatan apa hal tersebut terjadi”. Sebuah span adalah objek bernama yang membuka rentang eksekusi, membawa field sendiri, dan menutup dirinya saat rentang selesai. Cara membukanya ada dua: memanggil span! lalu enter() untuk mendapatkan guard, atau menempelkan attribute #[instrument] pada sebuah fungsi. Selama guard span masih hidup, setiap event yang dicatat dari titik manapun di bawahnya otomatis membawa nama serta field span tersebut.

rust
use tracing::{info, instrument, span, Level};

#[instrument]
fn hitung_pajak(nominal: u64) -> u64 {
    info!(nominal, "menghitung pajak");
    nominal / 10
}

fn main() {
    tracing_subscriber::fmt()
        .with_max_level(Level::INFO)
        .init();

    info!(pesanan_id = 42, "pesanan diterima");

    let span = span!(Level::INFO, "proses_pesanan", pesanan_id = 42);
    let _guard = span.enter();
    info!("mulai memproses pesanan");

    let pajak = hitung_pajak(150_000);
    info!(pajak, "pajak selesai dihitung");
}

Output yang Dihasilkan:

text
2026-10-13T23:05:11.488952Z  INFO myapp: pesanan diterima pesanan_id=42
2026-10-13T23:05:11.489011Z  INFO proses_pesanan{pesanan_id=42}: myapp: mulai memproses pesanan
2026-10-13T23:05:11.489027Z  INFO proses_pesanan{pesanan_id=42}:hitung_pajak{nominal=150000}: myapp: menghitung pajak nominal=150000
2026-10-13T23:05:11.489041Z  INFO proses_pesanan{pesanan_id=42}: myapp: pajak selesai dihitung pajak=15000

Mari kita bedah bagian-bagian kuncinya:

Baris 16 (let span = span!(Level::INFO, "proses_pesanan", pesanan_id = 42);): span bernama proses_pesanan dibuat dengan satu field; span sendiri belum mencetak apa pun — span hanya mulai berbicara lewat event di dalamnya.
Baris 17 (let _guard = span.enter();): enter() mengembalikan guard bertanda _ yang menandai rentang aktif; guard memakai pola RAII yang kita kenal dari smart pointer — saat guard keluar scope dan di-drop, span ditutup otomatis.
Baris 18 (info!("mulai memproses pesanan");): event pertama di dalam rentang span; pada output, nama span muncul sebagai proses_pesanan{pesanan_id=42} di antara level dan target.
Baris 20 (let pajak = hitung_pajak(150_000);): pemanggilan fungsi beratribut #[instrument] membuka span hitung_pajak di dalam span yang masih aktif — output memperlihatkan rantai proses_pesanan{pesanan_id=42}:hitung_pajak{nominal=150000}.
Baris 21 (info!(pajak, "pajak selesai dihitung");): event ini dicatat setelah guard hitung_pajak selesai, sehingga rantai konteksnya kembali hanya proses_pesanan — span fungsi menutup diri tepat saat pemanggilannya usai.

Relasi event dan span pada program di atas tergambar sebagai berikut:

flowchart TD A["span proses_pesanan<br/>pesanan_id=42"] --> B["event: mulai memproses pesanan"] A --> C["span hitung_pajak<br/>nominal=150000"] C --> D["event: menghitung pajak"] A --> E["event: pajak selesai dihitung"]

Diagram di atas menegaskan beda keduanya: event adalah titik kejadian, sedangkan span adalah wadah yang membentang dari titik buka hingga titik tutup. Tanpa span, keempat event pada output akan menjadi baris-baris setara yang tidak bisa dibedakan alurnya; dengan span, sekali baca pun kita tahu bahwa perhitungan pajak terjadi di dalam pemrosesan pesanan 42.

Anotasi Fungsi dengan #[instrument] #

Attribute #[instrument] pada baris 3 adalah jalan pintas untuk pola span manual. Attribute tersebut membungkus seluruh tubuh fungsi dengan span bernama sesuai nama fungsi, lalu mengubah setiap parameter fungsi menjadi field span secara otomatis — parameter nominal pada hitung_pajak muncul sebagai field nominal=150000 tanpa kita menulisnya lagi. Span atribut terbuka saat fungsi dipanggil dan tertutup saat fungsi kembali, jadi konteksnya selalu tepat selingkup tubuh fungsi. Ketika ada parameter yang bukan data — misalnya koneksi atau handle — kita dapat mengecualikannya dari field dengan #[instrument(skip(koneksi))] agar tracing tidak berusaha merekam nilainya.

Ringkasan #

Crate tracing menggeser logging dari baris teks menjadi data terstruktur: event membawa field kunci=nilai yang direkam utuh, sigil ? dan % mengatur perwujudan Debug atau Display, dan span membungkus rentang eksekusi menjadi konteks yang menempel pada setiap event di dalamnya. Attribute #[instrument] membungkus fungsi dengan span otomatis dan mengubah parameter menjadi field. Instrumentasi tetap senyap tanpa subscriber, sama seperti facade log tanpa logger. Subscriber fmt() yang kita pakai masih berupa kotak hitam bernama with_max_level — Chapter berikutnya membuka kotak tersebut: filter RUST_LOG lewat EnvFilter, anatomi format bawaan, dan penyesuaian tampilannya.