Masalah paling berbahaya pada backend agent/AI workflow sering bukan request yang gagal total, melainkan sistem yang terlihat sehat sementara jejak eksekusinya rusak. Job selesai, status database tampak benar, bahkan metrik throughput normal. Namun saat ditelusuri, log step agen hilang, sebagian ganda, atau urutannya tidak masuk akal. Dalam sistem seperti ini, log adalah sumber kebenaran perilaku agent: tanpa log yang utuh dan konsisten, retry bisa salah sasaran, audit menjadi lemah, dan debugging berubah menjadi tebakan.

Artikel ini membahas studi kasus debugging backend untuk gejala tersebut. Fokusnya bukan pada model AI, melainkan pada lapisan eksekusi async: worker paralel, buffering log, dan penulisan non-atomik yang memicu race condition. Tujuannya adalah memberi pola investigasi yang bisa dipakai di sistem nyata, lengkap dengan contoh pseudocode, pola log yang salah vs benar, langkah perbaikan, dan checklist pencegahan.

Studi kasus: sistem sehat, tetapi jejak eksekusi kacau

Bayangkan sebuah backend yang menjalankan workflow agen sebagai rangkaian step:

  • menerima task baru,
  • memanggil planner,
  • menjalankan tool,
  • menyimpan hasil intermediate,
  • melakukan retry jika tool gagal,
  • menutup workflow dengan status final.

Arsitekturnya umum: API menulis task ke queue, beberapa worker memproses step secara asynchronous, lalu event log dikirim ke sink terpusat atau disimpan ke database/stream.

Secara operasional, dashboard menunjukkan semuanya normal:

  • queue tetap terproses,
  • tingkat error rendah,
  • waktu respons masih masuk akal,
  • status akhir job banyak yang sukses.

Tetapi gejala di lapangan mulai muncul:

  • step tool_started ada, tetapi tool_finished hilang, padahal hasil final tersedia,
  • event retry_scheduled muncul dua kali untuk attempt yang sama,
  • urutan log menunjukkan workflow_completed tercatat sebelum step_started,
  • beberapa trace memiliki request_id yang benar tetapi tidak lengkap dari awal sampai akhir.

Ini bukan sekadar masalah kenyamanan observability. Pada sistem agen, log sering dipakai untuk:

  • retry yang aman: menentukan step terakhir yang benar-benar selesai,
  • audit: membuktikan tool apa yang dipanggil, kapan, dan dengan input apa,
  • debugging: memahami mengapa agen memilih aksi tertentu,
  • billing atau usage tracking: menghitung konsumsi step atau tool execution.

Saat log tidak dapat dipercaya, semua proses di atas ikut goyah.

Mengapa log adalah sumber kebenaran perilaku agent

Pada backend CRUD biasa, kehilangan satu-dua log mungkin masih bisa ditutup oleh status akhir di database. Pada agent workflow, itu jauh lebih sulit karena perilakunya berbentuk rangkaian keputusan dan transisi state. Status akhir success tidak menjelaskan:

  • apakah agen sempat gagal lalu retry,
  • tool mana yang dipanggil lebih dulu,
  • apakah ada step yang dieksekusi dua kali,
  • apakah hasil intermediate sempat ditimpa worker lain.

Karena itu, event log untuk agen idealnya diperlakukan seperti execution ledger: catatan berurutan yang menggambarkan apa yang benar-benar terjadi, bukan sekadar pesan debug bebas. Ketika ledger ini rusak oleh race condition, sistem tetap bisa menyelesaikan pekerjaan, tetapi tim kehilangan kemampuan menjelaskan perilakunya secara akurat.

Gejala nyata dan dampaknya di backend

1. Retry menjadi tidak deterministik

Misalnya worker A menulis step_started, worker B menulis retry_scheduled, lalu worker A terlambat mengirim step_finished karena buffer baru di-flush. Sistem recovery yang membaca log bisa salah menyimpulkan bahwa step gagal sebelum selesai, lalu menjadwalkan retry yang seharusnya tidak perlu.

2. Audit tidak dapat diandalkan

Jika log event ditulis non-atomik atau sebagian tertimpa, auditor hanya melihat snapshot yang tidak utuh. Dalam sistem yang memakai tool eksternal, ini berbahaya karena catatan siapa memanggil apa dan kapan menjadi ambigu.

3. Debugging salah arah

Urutan log yang kacau sering membuat engineer mengejar root cause yang salah. Contoh klasik: terlihat seolah callback datang sebelum request awal, padahal sebenarnya timestamp dan flush order dari beberapa worker tidak konsisten.

4. Duplikasi efek samping

Saat log dipakai sebagai dasar idempotensi lemah, event ganda bisa memicu eksekusi ganda. Contohnya, sink downstream menganggap setiap tool_finished sebagai sinyal finalisasi dan menulis hasil dua kali.

Root cause: race condition, buffering, dan penulisan log non-atomik

Race condition pada async worker

Masalah inti biasanya muncul ketika beberapa worker atau coroutine menangani workflow yang sama tanpa kontrak urutan yang jelas. Mereka berbagi trace_id, tetapi tidak berbagi mekanisme serialisasi event. Akibatnya:

  • event untuk workflow yang sama keluar dari lebih dari satu proses,
  • urutan wall-clock tidak sama dengan urutan log yang diterima sink,
  • update state dan penulisan log tidak terjadi dalam satu unit kerja yang konsisten.

Buffering di logger, stdout, collector, atau network client

Bahkan jika kode aplikasi memanggil logger sesuai urutan, hasil akhirnya belum tentu sama. Buffer pada runtime, agent log collector, sidecar, atau client network dapat menunda flush sebagian event. Jika proses mati, restart, atau timeout, event terakhir bisa hilang. Jika beberapa buffer flush di waktu berbeda, urutan yang diterima agregator juga berubah.

Penulisan log non-atomik

Pola berbahaya yang sering ditemui adalah menyusun catatan log sebagai operasi terpisah:

  • membaca record lama,
  • menambahkan event ke array di memori,
  • menulis seluruh array kembali ke storage.

Jika dua worker melakukan hal yang sama hampir bersamaan, salah satu update bisa menimpa yang lain. Ini adalah bentuk lost update. Pada storage berbasis file atau dokumen JSON, gejalanya sangat nyata: event hilang atau urutan berubah setelah write terakhir menang.

Alur investigasi: dari gejala ke root cause

1. Mulai dari satu trace yang rusak

Jangan mulai dari agregat error rate. Ambil satu trace_id atau workflow_id yang jelas menunjukkan keanehan, lalu kumpulkan seluruh event dari:

  • aplikasi utama,
  • worker queue,
  • sink log terpusat,
  • database status workflow,
  • jika ada, message broker atau event bus.

Tujuannya adalah membandingkan apa yang diklaim oleh status akhir dengan apa yang terekam sebagai jejak eksekusi.

2. Bedakan tiga urutan waktu

Saat menganalisis log agen AI yang hilang, penting membedakan:

  1. waktu kejadian di kode — saat fungsi memanggil logger,
  2. waktu event ditulis/di-flush — saat event benar-benar keluar dari proses,
  3. waktu event diterima sink — saat agregator menyimpannya.

Banyak investigasi gagal karena hanya melihat satu timestamp dari sink log, lalu menganggapnya sama dengan urutan eksekusi.

3. Cari pola “tidak mungkin”

Beberapa pola yang hampir selalu menunjukkan race condition atau write non-atomik:

  • completed muncul sebelum started untuk step yang sama,
  • dua event memiliki attempt=1 tetapi payload berbeda,
  • counter step meloncat, misalnya dari 3 ke 5 tanpa event 4,
  • status database menyatakan sukses tetapi event final tidak pernah ada,
  • event ada di stdout lokal worker tetapi tidak ada di sink terpusat.

4. Cocokkan dengan model konkurensi aplikasi

Tanyakan hal-hal ini:

  • apakah satu workflow bisa diproses paralel oleh lebih dari satu worker,
  • apakah retry dapat berjalan sebelum attempt sebelumnya benar-benar selesai flush log-nya,
  • apakah logger memakai buffer asinkron,
  • apakah event ditulis ke file, dokumen, stream append-only, atau tabel relasional,
  • apakah update status workflow dan insert log dilakukan dalam transaksi yang sama.

Biasanya root cause mulai terlihat saat hubungan antara mekanisme konkurensi dan media penyimpanan log dipetakan dengan jelas.

Pseudocode pola yang salah

Contoh berikut menunjukkan antipola umum: status workflow dan log event ditulis terpisah, lalu event log disimpan sebagai array yang ditimpa ulang.

// worker memproses satu step workflow yang sama dari beberapa proses paralel
async function runStep(workflowId, stepName) {
  logger.info({ workflowId, stepName, event: "step_started" })

  const workflow = await db.getWorkflow(workflowId)
  workflow.logs.push({ stepName, event: "step_started", ts: now() })
  await db.saveWorkflow(workflow) // overwrite seluruh dokumen/record

  const result = await executeTool(stepName)

  workflow.status = "running"
  workflow.lastStep = stepName
  await db.saveWorkflow(workflow)

  workflow.logs.push({ stepName, event: "step_finished", ts: now(), result })
  await db.saveWorkflow(workflow)

  logger.info({ workflowId, stepName, event: "step_finished" })
}

Ada beberapa masalah sekaligus:

  • workflow.logs.push(...) dilakukan pada salinan state yang mungkin sudah stale,
  • saveWorkflow menimpa versi terbaru dari worker lain,
  • status dan log tidak ditulis atomik,
  • logger aplikasi dan storage log memiliki urutan yang berbeda,
  • jika proses berhenti setelah update status tetapi sebelum log final tersimpan, jejak menjadi bolong.

Pola log yang salah vs benar

Pola yang salah

10:00:01 workflow=wf-17 step=tool_search event=step_started attempt=1
10:00:03 workflow=wf-17 event=workflow_completed status=success
10:00:02 workflow=wf-17 step=tool_search event=step_finished attempt=1
10:00:02 workflow=wf-17 step=tool_search event=retry_scheduled attempt=1

Masalahnya bukan hanya timestamp yang acak. Ada kontradiksi semantik: workflow selesai sebelum step selesai, dan retry dijadwalkan untuk attempt yang tampaknya juga selesai.

Pola yang lebih benar

seq=101 workflow=wf-17 step=tool_search event=step_started attempt=1
seq=102 workflow=wf-17 step=tool_search event=step_finished attempt=1 outcome=success
seq=103 workflow=wf-17 event=workflow_completed status=success

Perbedaannya penting:

  • ada sequence number per workflow,
  • event bersifat append-only, bukan overwrite snapshot log lama,
  • state final konsisten dengan transisi event sebelumnya.

Langkah perbaikan yang efektif

1. Jadikan log event append-only

Untuk jejak eksekusi agen, hindari model “simpan array log di dalam satu record workflow lalu overwrite”. Lebih aman menulis satu event per baris/record/pesan. Ini mengurangi risiko lost update dan memudahkan deduplikasi.

Pilihan implementasi yang umum:

  • tabel event terpisah dengan satu row per event,
  • stream append-only,
  • message log yang kemudian diindeks oleh sistem observability.

2. Tambahkan sequence number per workflow

Timestamp saja tidak cukup untuk mengurutkan event lintas worker. Gunakan nomor urut monoton per workflow_id atau trace_id. Nomor ini bisa dihasilkan oleh komponen yang memiliki kontrol serial terhadap workflow, atau lewat mekanisme penyimpanan yang mendukung increment atomik.

Catatan: sequence number tidak harus global. Per-workflow biasanya cukup dan lebih sederhana untuk reasoning.

3. Satukan commit state dan event penting

Jika event tertentu sangat penting untuk recovery, upayakan agar perubahan state dan pencatatan event terjadi dalam satu batas konsistensi. Dalam database relasional, ini sering berarti satu transaksi untuk:

  • update status step/workflow,
  • insert event log,
  • opsional: update sequence counter.

Dengan begitu, sistem tidak akan mengklaim step selesai tanpa event yang menyertainya.

4. Gunakan operasi atomik atau kontrol konkurensi

Beberapa opsi yang lazim:

  • row-level lock atau penguncian per workflow saat mengubah state sensitif,
  • optimistic concurrency control dengan version field,
  • atomic append jika storage mendukung,
  • single-writer pattern untuk event workflow tertentu.

Pilih sesuai kebutuhan throughput dan kompleksitas. Single-writer paling mudah dipahami, tetapi bisa menjadi bottleneck. Lock lebih aman, tetapi berisiko menambah latency dan deadlock jika desain buruk. Optimistic concurrency cocok jika konflik relatif jarang dan retry murah.

5. Flush log di titik kritis, jangan hanya mengandalkan buffer default

Untuk event yang menentukan recovery atau audit, pertimbangkan mekanisme flush yang lebih disiplin. Ini bukan berarti semua log harus sinkron dan memblokir, tetapi Anda perlu membedakan:

  • log debug biasa,
  • event eksekusi yang menjadi sumber kebenaran sistem.

Event kategori kedua pantas mendapat jalur yang lebih andal, misalnya insert langsung ke event store atau pengiriman ke stream yang memiliki konfirmasi penyimpanan.

6. Tambahkan idempotency key pada event

Jika worker bisa retry atau memproses ulang pesan, event seperti step_finished perlu memiliki identitas stabil, misalnya kombinasi:

  • workflow_id,
  • step_name,
  • attempt,
  • event_type.

Dengan begitu, insert ganda bisa ditolak atau diabaikan secara aman.

Pseudocode pola yang lebih aman

async function runStep(workflowId, stepName, attempt) {
  await db.transaction(async (tx) => {
    const seq = await tx.nextWorkflowSequence(workflowId)
    await tx.insertEvent({
      workflowId,
      seq,
      stepName,
      attempt,
      eventType: "step_started",
      ts: now()
    })

    await tx.updateWorkflowStepState({
      workflowId,
      stepName,
      attempt,
      state: "running"
    })
  })

  const result = await executeTool(stepName)

  await db.transaction(async (tx) => {
    const seq = await tx.nextWorkflowSequence(workflowId)
    await tx.insertEvent({
      workflowId,
      seq,
      stepName,
      attempt,
      eventType: "step_finished",
      outcome: "success",
      ts: now()
    })

    await tx.updateWorkflowStepState({
      workflowId,
      stepName,
      attempt,
      state: "completed",
      resultRef: result.id
    })
  })
}

Pola ini bekerja lebih baik karena:

  • event tidak ditimpa, melainkan di-append,
  • urutan dijaga lewat seq,
  • state dan event ditulis konsisten dalam satu transaksi,
  • debugging tidak bergantung penuh pada urutan flush logger eksternal.

Verifikasi setelah fix

Perbaikan race condition tidak cukup diverifikasi dengan “kelihatannya log sudah rapi”. Anda perlu membuktikan bahwa invariannya terpenuhi di bawah beban dan retry.

1. Uji konkurensi terkontrol

Jalankan beberapa worker yang sengaja memproses workflow yang sama atau step berdekatan dengan delay acak. Tujuannya memancing interleaving yang sebelumnya memicu bug.

for i in 1..N workers:
  process same workflow with random sleep before write
  inject retry on selected attempts
  sometimes delay log flush or simulate worker restart

2. Definisikan invariant yang harus selalu benar

  • setiap step_started maksimal memiliki satu step_finished untuk pasangan workflow_id + step + attempt,
  • workflow_completed tidak boleh muncul sebelum semua step wajib selesai,
  • sequence number per workflow harus unik dan monoton,
  • status final workflow harus dapat direkonstruksi dari event log tanpa kontradiksi.

3. Bandingkan event store dengan sink observability

Jika Anda tetap mengirim log ke agregator terpusat, perlakukan event store internal sebagai sumber kebenaran utama. Lalu ukur selisih antara keduanya: apakah ada event yang hilang di pipeline observability, apakah urutan di sink berbeda, dan apakah hal itu hanya masalah presentasi atau benar-benar kehilangan data.

4. Uji skenario crash

Bug seperti ini sering baru terlihat saat proses mati di tengah jalan. Simulasikan:

  • worker berhenti setelah update status namun sebelum emit log,
  • restart saat buffer belum flush,
  • timeout jaringan ke sink log.

Hasil yang diinginkan: sistem recovery tetap bisa menentukan state sebenarnya dari workflow tanpa bergantung pada event yang mungkin hanya ada di memori proses.

Trade-off desain yang perlu dipahami

Append-only event store menambah volume data

Ini harga yang wajar untuk auditability dan debugging yang baik. Anda mungkin perlu strategi retensi, kompaksi, atau pemisahan antara event penting dan log verbose.

Transaksi dan locking bisa menambah latency

Benar, terutama pada workflow dengan throughput tinggi. Namun biaya ini sering lebih murah dibanding biaya operasional akibat retry yang salah, audit yang gagal, dan waktu debugging berjam-jam.

Sequence number butuh otoritas urutan

Begitu Anda ingin urutan yang tegas, harus ada mekanisme yang menjaminnya. Ini bisa berarti ketergantungan pada database, coordinator, atau partisi single-writer. Tidak gratis, tetapi jauh lebih jelas daripada mengandalkan timestamp semata.

Kesalahan umum yang sering terlewat

  • Menganggap timestamp sink log sama dengan urutan eksekusi aktual.
  • Menyimpan seluruh log workflow dalam satu field JSON lalu overwrite berkali-kali.
  • Menggunakan logger async untuk event kritis tanpa memikirkan flush dan crash.
  • Tidak membedakan log observability biasa dengan execution event yang dipakai untuk recovery.
  • Tidak memberi identitas unik pada event, sehingga duplikasi sulit dideteksi.
  • Mengizinkan retry membaca state yang belum konsisten karena commit state dan event terpisah.

Checklist pencegahan untuk developer backend

  • Gunakan append-only event untuk jejak eksekusi agent.
  • Tambahkan workflow_id, step_name, attempt, dan event_type pada setiap event.
  • Tambahkan sequence number per workflow jika urutan penting.
  • Jangan overwrite array log bersama dari beberapa worker.
  • Satukan update state penting dan insert event dalam satu transaksi atau batas konsistensi yang jelas.
  • Terapkan idempotency untuk event yang bisa diproduksi ulang saat retry.
  • Uji kondisi crash, restart, dan delay flush sebagai bagian dari test plan.
  • Pisahkan antara log debug biasa dan event ledger yang dipakai untuk audit/recovery.
  • Monitor anomali seperti event out-of-order, missing finish, dan duplicate attempt.
  • Dokumentasikan invariant workflow agar tim tahu pola log mana yang valid dan mana yang mustahil.

Penutup

Dalam debugging backend untuk sistem agen, masalah paling sulit sering muncul saat semuanya tampak baik-baik saja. Queue jalan, status sukses, metrik hijau, tetapi jejak log agen AI hilang karena race condition. Begitu log rusak, Anda kehilangan sumber kebenaran perilaku agent: retry menjadi spekulatif, audit melemah, dan debugging tidak lagi berbasis fakta.

Perbaikan utamanya bukan sekadar “menambah lebih banyak log”, melainkan memperlakukan log eksekusi sebagai data yang harus konsisten: append-only, berurutan, dapat dideduplikasi, dan ditulis dengan batas atomik yang masuk akal. Jika sistem agent Anda bergantung pada jejak langkah untuk menjelaskan keputusan, maka kualitas logging bukan fitur tambahan. Ia adalah bagian dari correctness backend itu sendiri.