omeryanbas.com

Ömer Yanbaş

Genel Müdür, Ticofab Yazılım

OperasyonYöntem

Log’ları okunmaya değer kılan üç alan

Çoğu log, olay anında sorulan tek soruya cevap veremez. Bir correlation id, işlenen kaydın kimliği ve sebebiyle birlikte sonuç bunu çözer.

Üretimde bir şey ters gider ve log'ları açarsınız. Son bir saatten dört yüz bin satır vardır, çoğu Processing item ya da Error: failed to send der ve hiçbiri hangi kayıt olduğunu veya neden düştüğünü söylemez. Müşteriye cevap vermek için gereken bilgi teknik olarak oradadır, üç servise dağılmıştır ve birbirine bağlayan hiçbir şey yoktur. Log yazılmıştır, sadece okunmak üzere yazılmamıştır.

Tek bir satırın cevaplaması gerekenler

Log satırı, bir programın sonradan bir soruyla gelecek bir insan için tuttuğu nottur. Soru neredeyse her zaman aynı üçünün bir hali olur: bu hangi istekti, hangi kayıt üzerinde çalışıyordu ve o kayda ne oldu. Üçüne birden cevap veren satır saklanmaya değer. Hiçbirine cevap vermeyen satır, disk ve dikkat harcayan gürültüdür.

Buradan hemen her satırda bulunması gereken üç alan çıkıyor.

Correlation id: iş sisteme girdiğinde bir kez üretilir ve her yere taşınır. Tek bir istek web sürecinde, bir queue worker'ında ve dışarıya giden bir çağrıda satır üretir. Ortak bir id olmadan bunlar birbiriyle ilgisiz üç yığındır.

Konu, tür ve id olarak. "subject_type": "message", "subject_id": "84213" yazmak, tek bir sipariş hakkındaki şikâyeti aranabilir bir şeye çevirir. Zaman damgasından başlamak ise o dakikada olan her şeyi okumak demektir.

Sonuç, sebebiyle birlikte. Cümle değil, sabit bir kümeden kısa bir kod: "outcome": "rejected", "reason": "quota_exceeded". Kod sayılabilir, gruplanabilir, grafiğe dökülebilir. Cümle yalnızca okunabilir.

Aynı olayın iki türlü yazılmış hali:

{"level":"error","msg":"Failed to send message to recipient, giving up"}

{"time":"2026-04-23T09:12:44.118Z","level":"error","service":"sender",
 "request_id":"01HXQ8R4M2","subject_type":"message","subject_id":"84213",
 "event":"dispatch","outcome":"rejected","reason":"invalid_recipient",
 "attempt":3,"duration_ms":412}

İlk satır size bir yerde kötü bir şey olduğunu söyler. İkincisi hangi mesaj, hangi istek, kaçıncı denemeden sonra ve neden sorularını cevaplar, üstüne bugün aynı sebeple kaç mesajın düştüğünü saymanıza izin verir.

Serbest metin neden çürür

Log mesajındaki cümle bir kez yazılır ve sonra sonsuza kadar düzenlenir. Biri refactor sırasında ifadeyi değiştirir, bir başkası ortasına bir değişken ekler, üçüncüsü Failed to send yerine Send failed yazar. O cümlenin üzerine kurulmuş her dashboard, alarm ve kayıtlı arama sessizce bozulur ve bunu, çalması gereken alarm çalmadığında öğrenirsiniz.

Alan adı bir arayüzdür. Çevresindeki kod baştan yazıldığında reason anlamını korur, içine yeni bir değer girmesi kırılma değil ekleme olur. Alan adları ayrıca cümlelerin asla beceremediği şeyi başarır: toplulaştırma. Bir günlük log üzerinde group by reason, bir backend mühendisinin elindeki en hızlı ürün araştırmasıdır ve düz metin üzerinde imkânsızdır.

Log seviyeleri de aynı türden bir sözleşmedir ve her birini bir cümleyle bir kez tanımlamaya değer:

  • error: bir insanın bir şey yapması gerekir, bu satırın birini uyandırmaya hakkı vardır.
  • warn: sistem durumu idare etti ama tekrarlarsa bir insan ilgilenmeli.
  • info: sonradan yeniden kurmanız gerekebilecek bir durum değişikliği, iş birimi başına bir satır.
  • debug: geliştirici ayrıntısı, tek bir istek için açılmadıkça üretimde kapalı.

Buradaki bozulma enflasyondur. Rutin reddedilmeler error olarak yazılmaya başlandığında error seviyesi anlamını kaybeder, alarm susturulur ve gerçek bir hata kimsenin okumadığı bir kanala düşer. Geçersiz alıcı yüzünden reddedilen bir mesaj olay değil, sıradan iş akışıdır; yeri sebep koduyla birlikte info veya warn'dır.

Pratik bir ölçü şu: bir seviyeyi, o seviyede bir gecede kaç satır geldiğinde rahatsız olacağınızı düşünerek seçin. Error seviyesine gecede üç satır düşüyorsa üçüne de bakarsınız. Üç yüz satır düşüyorsa hiçbirine bakmazsınız ve seviye artık sadece bir süs olur.

Gerçek bir olayı bir dakikanın altında ayıklamak

Bir log kurulumunun sınavı, sizi şikâyetten sebebe ne kadar hızlı götürdüğüdür. Üç alan yerindeyse bu iki komuttur. Müşterinin bildiği tek şeyden, kayıt numarasından başlayın:

# 1. bu kayda dokunan isteği bul
rg '"subject_id":"84213"' /var/log/app/*.jsonl | jq -r .request_id | head -1
# 01HXQ8R4M2

# 2. o isteğin her serviste yaptığı her şeyi sırayla oynat
rg '"request_id":"01HXQ8R4M2"' /var/log/app/*.jsonl \
  | jq -c '{t:.time, svc:.service, ev:.event, out:.outcome, r:.reason}'
{"t":"09:12:41.004","svc":"api",    "ev":"accept",   "out":"ok",      "r":null}
{"t":"09:12:41.120","svc":"api",    "ev":"enqueue",  "out":"ok",      "r":null}
{"t":"09:12:42.660","svc":"worker", "ev":"dispatch", "out":"retry",   "r":"provider_timeout"}
{"t":"09:12:43.900","svc":"worker", "ev":"dispatch", "out":"retry",   "r":"provider_timeout"}
{"t":"09:12:44.118","svc":"sender", "ev":"dispatch", "out":"rejected","r":"invalid_recipient"}

Beş satır ve hikâyenin tamamı ortada: asıl sebep görünmeden önce iki timeout yaşandığı dahil. Üçüncü komut ise anekdotu karara çeviren komuttur:

rg '"outcome":"rejected"' /var/log/app/*.jsonl | jq -r .reason | sort | uniq -c | sort -rn
#  1842 invalid_recipient
#   311 quota_exceeded
#    27 content_blocked

Artık elinizde tek bir mutsuz müşteri mi yoksa veri kalitesi sorunu olan bin sekiz yüz kayıt mı olduğunu bilirsiniz. Aynı biçimdeki soru kayıttan önce gelen teslim raporu yazısında da karşımıza çıkıyor: orada hangi id'nin önce geldiğini bilmek teşhisin kendisidir.

Log'a asla girmemesi gerekenler

Log'lar başka sistemlere taşınır, ticket'lara kopyalanır, sohbete yapıştırılır ve aylarca saklanır. Oraya yazılan her şeyi şirket içinde herkese açık ve kalıcı kabul edin.

  • Parola, token, anahtar, çerez veya authorization başlığı yok. Serileştirilmiş hata nesnesinin içi dahil, sızıntı genelde tam oradan olur.
  • Tam istek ve yanıt gövdesi yok. Boyutu, content type'ı ve iki paketi karşılaştırmanız gerekiyorsa bir hash yazın.
  • Satırın ihtiyacı olmayan kişisel veri yok. Telefon numarasının veya e-posta adresinin cevaplayacağı hemen her operasyonel soruyu hesap id'si de cevaplar.
  • Mesaj içeriği yok. Ne gönderildiğini kanıtlayabilmeniz gerekiyorsa bunu erişim kontrollü olarak veritabanında tutun, log'a kayıt id'sini yazın.

Maskeleme çağrı yerlerinde değil logger'ın içinde olmalı, çünkü gelecek ay eklenecek çağrı yeri kuralı hatırlamayacak. Alan adlarından oluşan kısa bir izinli liste ve geri kalan her şeyin düşürülmesi, şu ana kadar aklınıza gelmiş sırlardan oluşan bir yasaklı listeden güvenlidir.

Çalıştığını nasıl doğrularsınız

Kural, ancak onu zorlayan bir şey varsa gerçektir. İki kontrol neredeyse her şeyi yakalar: zorunlu alanı eksik bir olay loglandığında düşen bir test ve dün üretilen çıktıda izi sürülemeyen satırları arayan bir tarama.

# üç alandan biri eksik olarak en az bir kez görünmüş her olay
cat /var/log/app/*.jsonl \
  | jq -r 'select(.request_id == null or .subject_id == null or .outcome == null) | .event' \
  | sort | uniq -c | sort -rn
#   914 cache_refresh
#     3 webhook_receive

Boş sonuç, üretimdeki her olayın bir id'den yola çıkılarak izlenebildiği anlamına gelir. Uzun bir liste ise, boşluğun ne sıklıkta canınızı yakacağına göre sıralanmış bir yapılacaklar listesidir. Yukarıdaki çıktıda cache_refresh için konu gerçekten yok, dürüst çözüm ona sahte bir id uydurmak değil, istisnayı açıkça yazmaktır.

Nelere dikkat etmeli

  • Hacim hem maliyet hem tehlikedir. Beklediğinizden hızlı büyüyen log'lar diski doldurur ve servisi de yanında götürür. Bu, log rotasyonu ve dolan diskin sessiz maliyeti yazısındaki arızanın ta kendisi.
  • Retry'da değişen id, correlation id değildir. Bir iş üç kez çalışıyorsa üç çalışma da orijinal isteğin id'sini taşımalı; bu aynı zamanda onları idempotent işler olarak izlenebilir kılan şeydir.
  • Sebep kodlarının bir evi olmalı. Kümeyi tek bir dosyada union tip olarak tutun ki yeni bir kod eklemek yazım hatası değil code review olsun.
  • Makineler arasındaki saat farkı sıralı oynatmayı yalancı yapar. Tek biçimde ve zaman dilimi farkıyla loglayın, iki servis saniyelerle çelişiyorsa sıralamaya güvenmeden önce saatleri düzeltin.

Çıta aslında alçak ve neredeyse kimse geçemiyor: kodu hiç görmemiş bir insan, destek mesajından aldığı tek bir kimlikle sistemin ne yaptığını yeniden kurabilmeli. Bunun için üç alan, sabit bir sebep sözlüğü ve geri kalan her şeyi dışarıda bırakma disiplini yeter. Karşılığını kötü bir günde alırsınız: beş dakikalık cevapla iki saatlik aramanın arasındaki fark, birinin o id'yi yazmış olup olmamasıdır.

Sorular ve cevaplar

Log'da correlation id ne işe yarar?
Bir istek sisteme girdiğinde üretilen ve o isteği işlerken üretilen her log satırına, diğer servisler ve arka plan işleri dahil, iliştirilen tek bir kimliktir. Tek bir filtreyle o isteğin bütün hikâyesini çıkarmanızı sağlar. Girişte üretin, çağıran taraf zaten gönderdiyse onu kabul edin ve yanıtta geri dönün ki destek ekibi müşteriden numarayı alabilsin.
Log JSON mu olmalı düz metin mi?
Bir makinenin filtreleyeceği veya sayacağı her şey için yapısal satırlar, genelde satır başına bir JSON nesnesi. Düz metin yerel geliştirme konsolu için yeterlidir. Asıl mesele değerlerin cümlenin içinde değil adlandırılmış alanlarda durması, çünkü alan adları yeniden yazımdan sağ çıkar, cümleler çıkmaz.
Log'a asla ne yazılmamalı?
Her türden kimlik bilgisi, session token, API anahtarı, tam istek ve yanıt gövdeleri, kart verisi ve o satırın cevapladığı soru için gerekmeyen kişisel veri. Değerin kendisi yerine bir id veya hash yazın. Log'lar başka sistemlere taşınır ve aylarca saklanır, oraya düşen her şeyin yayılacağını varsayın.
Bir istek kaç log satırı üretmeli?
Info seviyesinde, anlamlı her durum değişikliği için bir satır; normal bir istekte bu genelde bir ile beş arasıdır. Daha ince ayrıntı debug seviyesine aittir ve tek bir istek için açmadıkça üretimde kapalı kalır. İstek başına yirmi info satırı yazan bir servis hem kendi log'unu okunmaz yapar hem de disk faturasını büyütür.