Logging untuk Debugging

Setelah program berjalan di mesin lain atau di tengah malam, debugger tidak lagi bisa menolong: prosesnya sudah selesai dan kondisinya sudah lenyap. Log adalah satu-satunya saksi yang tersisa, sehingga kualitas log menentukan seberapa cepat kita menemukan akar masalah. Package log/slog (dibaca structured logging) mencatat kejadian sebagai pasangan kunci–nilai, bukan kalimat bebas, sehingga mesin bisa memfilter dan mengurutkannya. Pada chapter ini kita akan membangun logger terstruktur, menyaring pesan berdasarkan level, lalu memakainya untuk melacak jalur eksekusi sebuah proses bisnis.

Logger Terstruktur dengan slog #

Inti slog ada tiga komponen: slog.Logger sebagai pintu pencatatan, slog.Handler sebagai pemformat output, dan opsi slog.HandlerOptions untuk mengatur level serta atribut. Berkas contoh.go di bawah halaman membangun dua handler dengan level berbeda untuk membuktikan cara kerja filter level:

package main

import (
	"log/slog"
	"os"
)

// buangWaktu menghapus atribut waktu agar log stabil dan mudah dibandingkan.
func buangWaktu(groups []string, a slog.Attr) slog.Attr {
	if a.Key == slog.TimeKey {
		return slog.Attr{}
	}
	return a
}

func prosesPembayaran(logger *slog.Logger, user string, jumlah int) {
	logger.Info("mulai proses pembayaran", "user", user, "jumlah", jumlah)
	logger.Debug("rute server terpilih", "rute", "kantor-cabang-2")
	logger.Info("pembayaran selesai", "user", user)
}

func main() {
	// Handler level Info: pesan Debug disembunyikan.
	handlerInfo := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
		Level:       slog.LevelInfo,
		ReplaceAttr: buangWaktu,
	})
	logger := slog.New(handlerInfo)

	logger.Info("mode level Info: pesan Debug tidak tampil")
	prosesPembayaran(logger, "Budi", 150000)

	// Handler level Debug: pesan Debug ikut tampil.
	handlerDebug := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
		Level:       slog.LevelDebug,
		ReplaceAttr: buangWaktu,
	})
	loggerDebug := slog.New(handlerDebug)

	loggerDebug.Debug("detail koneksi dibuka", "user", "Siti", "attempt", 1)
}

Output yang Dihasilkan:

level=INFO msg="mode level Info: pesan Debug tidak tampil"
level=INFO msg="mulai proses pembayaran" user=Budi jumlah=150000
level=INFO msg="pembayaran selesai" user=Budi
level=DEBUG msg="detail koneksi dibuka" user=Siti attempt=1

Filter Level untuk Menyelaraskan Detail #

Empat level bawaan slog — Debug, Info, Warn, Error — membentuk hierarki dari detail teknis hingga kegagalan kritis. Handler dengan Level: slog.LevelInfo menolak semua pesan di bawah Info, sehingga baris logger.Debug("rute server terpilih", ...) di dalam prosesPembayaran tidak pernah tercetak pada sesi pertama. Handler kedua dibuat dengan Level: slog.LevelDebug, dan mendadak pesan Debug dari user Siti muncul di layar. Pola ini persis cara kerja filter di production: level naik ke Warn saat sistem sehat (log minim, biaya kecil), dan diturunkan ke Debug saat insiden menyala (semua detail ikut tercatat).

Tabel berikut merangkum keempat level beserta tempatnya dalam alur diagnosis:

Membaca Jejak Saat Debugging #

Perhatikan baris kedua output: level=INFO msg="mulai proses pembayaran" user=Budi jumlah=150000. Ketika Budi mengeluh uangnya terpotong dua kali, kita memfilter log dengan user=Budi, lalu mengurutkan sisanya — dua kejadian mulai proses pembayaran untuk transaksi yang sama berarti ada dobel submit, bukan bug pada modul pembayaran. Itulah kekuatan atribut terstruktur: pertanyaan dijawab oleh filter, bukan oleh mata yang membaca ribuan baris satu per satu.

Mari kita telaah baris demi baris program di atas:

1. Baris 9–14 (buangWaktu): ReplaceAttr menerima setiap atribut sebelum dicetak; mengembalikan slog.Attr{} untuk kunci time membuat atribut itu dibuang.
2. Baris 16–20 (prosesPembayaran): fungsi menerima *slog.Logger sebagai parameter, bukan memakai logger global, sehingga setiap pemanggil bisa menyetel level dan handler sendiri.
3. Baris 18: pesan Debug di tengah fungsi adalah contoh detail yang hanya relevan saat penyelidikan — tersembunyi pada level Info, muncul pada level Debug.
4. Baris 24–28: handler pertama dibangun dengan slog.NewTextHandler, level Info, dan ReplaceAttr.
5. Baris 34–40: handler kedua memakai konfigurasi identik kecuali level Debug; logger dari handler inilah yang membuat baris keempat output muncul.

Log menjawab “apa yang sudah terjadi”, tetapi untuk pertanyaan “di fungsi mana waktu CPU habis” kita membutuhkan profiler — dimulai dari pprof pada chapter berikutnya.

Referensi #

• Package log/slog — dokumentasi resmi Logger, Handler, dan HandlerOptions.
• Blog resmi: structured logging with slog — desain dan motivasi slog oleh tim Go.

package main

import (
	"log/slog"
	"os"
)

// buangWaktu menghapus atribut waktu agar log stabil dan mudah dibandingkan.
func buangWaktu(groups []string, a slog.Attr) slog.Attr {
	if a.Key == slog.TimeKey {
		return slog.Attr{}
	}
	return a
}

func prosesPembayaran(logger *slog.Logger, user string, jumlah int) {
	logger.Info("mulai proses pembayaran", "user", user, "jumlah", jumlah)
	logger.Debug("rute server terpilih", "rute", "kantor-cabang-2")
	logger.Info("pembayaran selesai", "user", user)
}

func main() {
	// Handler level Info: pesan Debug disembunyikan.
	handlerInfo := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
		Level:       slog.LevelInfo,
		ReplaceAttr: buangWaktu,
	})
	logger := slog.New(handlerInfo)

	logger.Info("mode level Info: pesan Debug tidak tampil")
	prosesPembayaran(logger, "Budi", 150000)

	// Handler level Debug: pesan Debug ikut tampil.
	handlerDebug := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
		Level:       slog.LevelDebug,
		ReplaceAttr: buangWaktu,
	})
	loggerDebug := slog.New(handlerDebug)

	loggerDebug.Debug("detail koneksi dibuka", "user", "Siti", "attempt", 1)
}