Retrospeksi Bug Backend: Menelusuri Root Cause lewat Log Terabaikan menjawab langsung bagaimana tim produksi menemukan bug yang tidak terlihat saat kejadian pertama. Menggunakan kerangka “It’s Only When You Look Back”, artikel ini menunjukkan gejala, konteks, dan kenapa bug mengendap sampai analisis ulang.

Gejala dan Konteks Produksi

Dalam kasus yang kita analisa, endpoint /orders/checkout mengembalikan status 503 secara sporadis setelah deploy kedua pada minggu yang sama. Monitoring hanya menangkap lonjakan latency di service order-processor, tapi tidak ada error eksplisit. Alur produksi: trafik tinggi karena rilis kampanye loyalty, worker queue terbagi antar node, dan retry policy pada layanan payment diatur dari sisi konsumer.

Gejala lain: order tetap ada di database, tetapi pembayaran tidak selesai. Tim pertama hanya melihat metrik throughput turun, lalu kembali normal setelah restart service yang tidak menjelaskan akar masalah.

Kenapa Bug Tidak Langsung Terlihat?

Kita tahu bug tertangkap terlalu lambat karena:

  • Log penting ditulis hanya pada level debug dan hanya terjadi saat error recoverable, sehingga lengkap hanya ada pada lingkungan staging.
  • Sampling log elasticsearch/managed logging hanya menyertakan 10% pesan INFO, lalu peristiwa yang memicu queue delay tidak tercatat.
  • Tidak ada alert untuk long tail latency dari queue worker yang menunggu database lock.

Faktor lain adalah kepercayaan pada retries otomatis di beberapa layanan, yang membuat tim mengabaikan log partial failure yang tidak memicu error-level.

Langkah Diagnosa

Retrospeksi dimulai dengan melihat kembali data:

  • Logs: Periksa log worker yang memproses event payment_attempt.
  • Metrics: Lihat distribusi response time queue, jumlah rollback transaksi.
  • Tracing: Ikuti trace dari API gateway sampai worker agar terlihat di mana delay terjadi.

Memadukan Log, Metric, dan Trace

Observabilitas ideal di kasus ini menggabungkan log asynchronous, metric queue latency, dan trace dari starter request. Kita memerlukan data seperti:

  • Timestamp event payment_attempt masuk antrean, worker mulai proses, dan selesai.
  • Lock pada row order_transactions yang menyebabkan worker bertahan lama.
  • Apakah ada inbound request yang di-retire karena timeout gateway.

Dengan data tersebut, kita bisa menghubungkan backlog message queue ke kondisi database, bukan hanya ke service worker.

Contoh Query Log

{
  "query": {
    "bool": {
      "must": [
        {"match": {"service": "order-processor"}},
        {"match": {"log.level": "error"}},
        {"match": {"event": "payment_attempt"}}
      ],
      "filter": [
        {"range": {"@timestamp": {"gte": "now-1h"}}}
      ]
    }
  },
  "sort": [{"@timestamp": "asc"}]
}

Query sederhana ini memfokuskan pada log error dengan context event, sehingga mempermudah melihat apakah ada lock wait yang tidak terekam pada level info.

Root Cause dan Perbaikan

Setelah menelusuri log dan trace, akar masalahnya adalah transactional gap: worker queue mengambil event check-out, melakukan SELECT FOR UPDATE pada row order, lalu menunggu callback payment. Selama block ini, row tersebut dikunci; apabila callback terlambat, queue mengirim ulang event, namun log retry ditulis hanya setelah timeout 30 detik, sehingga observasi awal tidak mengindikasikan kegagalan.

Root cause: log retry dan timeout berada di layer yang berbeda dan tidak dijadikan satu alur observabilitas. Selain itu, deadlock terbentuk karena dua worker mengeksekusi event berbeda pada order yang sama tanpa backoff.

Perbaikan yang Dilakukan

  • Menambahkan log WARN untuk lock hold time dan retry_attempt sehingga insight muncul lebih awal.
  • Mengubah konfigurasi queue untuk mengirim event ke dead-letter setelah tiga retry, disertai metadata trace-id.
  • Mengimplementasikan backoff jitter dan optimistic locking agar worker tidak langsung berkompetisi di row yang sama.
  • Memperluas tracing ke callback payment agar tim dapat melihat berapa lama payment gateway menanggapi.

Trade-off: log tambahan meningkatkan volume, sehingga kita menambahkan sampling berdasarkan label order_id untuk event penting dan hanya menyimpan detail penuh selama 1 minggu.

Checklist Pemeriksaan Post-Mortem Backend

Setiap tim backend sebaiknya mengevaluasi contoh berikut setelah kejadian:

  • Apakah log yang cukup terdokumentasi untuk menelusuri eksekusi? (level, konteks, trace-id)
  • Apakah metrik latency/missing event menunjukan anomali sebelum alert manual?
  • Apakah ada data trace yang menghubungkan request awal ke dependensi?
  • Apakah ada alert atau dashboard yang mencakup retry/lock timeout?
  • Apakah terdapat proses dead-letter dan siapa yang bertanggung jawab memonitorinya?
  • Apakah runbook disesuaikan berdasarkan temuan terbaru?
  • Apakah perbaikan dijelaskan pada registri perubahan dan dijaga lewat observability baseline?

Kerangka “It’s Only When You Look Back” mengingatkan kita bahwa log yang diabaikan sering mengandung petunjuk kalau kita kembali menelusurinya. Dengan dokumentasi lengkap, observabilitas terintegrasi, dan checklist post-mortem, tim backend bisa menutup siklus debugging lebih cepat dan mencegah kejadian serupa.