logging: profesyonel kayıt tutma

Neden önemli?

Gece 03.00'te Anadolu Market'in ödeme servisi bazı siparişleri reddetmeye başlıyor. Nöbetçi geliştiricinin elinde yalnız loglar var. Kod print("hata oldu") yazıyorsa elinde ne zaman, hangi modülde, hangi siparişte, hangi önem derecesinde olduğu bilinmeyen bir satır vardır. logging ile yazılmışsa her satırda zaman, seviye, modül adı ve sipariş numarası durur; hata satırının altında tam traceback vardır; hassas veriler maskelenmiştir ve loglar hem ekrana hem dönen (rotating) dosyalara akar.

Hata tasarımı dersinde basicConfig, getLogger(__name__) ve exception() ile tanıştın. Bu derste logging'in mimarisini öğreneceksin: logger → filter → handler → formatter boru hattı (pipeline), hiyerarşi ve yayılım (propagation), dictConfig, JSON log, kütüphane kodunun kuralları ve KVKK uyumlu maskeleme.

print yerine logging: ne kazanırsın?

Seviyeler

Her seviye bir sayıdır. Logger ve handler bir eşik taşır; eşiğin altındaki kayıtlar atılır.

Kök logger'ın (root) varsayılan seviyesi WARNING'dir. Bu yüzden hiç yapılandırmadan yazılan logging.info(...) görünmez; yeni başlayanların en sık şaşırdığı durum budur.

Boru hattı: logger, handler, formatter, filter

1. Logger: koddan çağırdığın nesne (log.info(...)). Seviyesine bakar, bir LogRecord oluşturur, kendi filtrelerini uygular.
2. Handler: kaydı bir hedefe gönderir (StreamHandler: akış, FileHandler: dosya, RotatingFileHandler: boyutla dönen dosya). Kendi seviyesi ve filtreleri vardır.
3. Formatter: kaydı metne çevirir: "%(asctime)s %(levelname)s %(name)s: %(message)s".
4. Filter: kaydı geçirir ya da düşürür; kaydı değiştirebilir de (maskeleme).

Bu derste ekran çıktısının her çalıştırmada aynı olması için handler'ları sys.stdout'a bağlayacak ve formata zaman koymayacağız. Tarayıcıdaki Python oturumu çalıştırmalar arasında yaşadığı için, her örnekte logger'ın handler'larını temizleyip propagate = False yapacağız; yoksa aynı mesaj iki, üç kez basılır.

import logging, sys

log = logging.getLogger("anadolu.siparis")
log.handlers.clear()                 # önceki çalıştırmadan kalanları sil
log.propagate = False                # kök logger'a iletme
log.setLevel(logging.DEBUG)          # logger eşiği

ekran = logging.StreamHandler(sys.stdout)
ekran.setLevel(logging.INFO)         # handler eşiği: DEBUG bu kapıdan geçmez
ekran.setFormatter(logging.Formatter("%(levelname)-8s %(name)s | %(message)s"))
log.addHandler(ekran)

log.debug("Sepet ara toplamı: %s", 1249.9)     # görünmez
log.info("Sipariş %s oluşturuldu", "AM-101")
log.warning("Stok azaldı: %s (kalan %d)", "Termos", 3)
log.error("Ödeme reddedildi: %s", "AM-102")
print(log.getEffectiveLevel(), ekran.level)

Logger hiyerarşisi ve yayılım

Logger adları noktayla ayrılmış bir ağaç kurar: anadolu → anadolu.odeme → anadolu.odeme.kart. Her modülün başında log = logging.getLogger(__name__) yazarsan ağaç, paket yapını kendiliğinden yansıtır. İki kural:

• Etkin seviye: seviyesi ayarlanmamış (NOTSET) logger, ilk ayarlı atasının seviyesini kullanır.
• Yayılım: propagate True ise (varsayılan) kayıt, atalarının handler'larına da gönderilir. Atanın logger seviyesine bakılmaz, yalnız handler seviyelerine bakılır.

import logging, sys

def ekran(etiket):
    h = logging.StreamHandler(sys.stdout)
    h.setFormatter(logging.Formatter(etiket + " %(name)s: %(message)s"))
    return h

ana = logging.getLogger("anadolu")
ana.handlers.clear(); ana.propagate = False
ana.setLevel(logging.INFO)
ana.addHandler(ekran("[ANA]"))

odeme = logging.getLogger("anadolu.odeme")
odeme.handlers.clear(); odeme.propagate = True; odeme.setLevel(logging.NOTSET)
odeme.info("Kart doğrulandı")                 # kendi handler'ı yok: ata yazar
odeme.addHandler(ekran("[ODEME]"))
odeme.info("Tahsilat tamam")                  # İKİ kez: kendi + ata
odeme.propagate = False
odeme.info("Yalnız bir kez")
print(odeme.parent.name, logging.getLevelName(odeme.getEffectiveLevel()))

Tekrarlanan log satırlarının bir numaralı nedeni budur: hem alt logger'a hem köke handler eklemek. Yaygın düzen: handler'ları yalnız en üstte (kök ya da uygulama logger'ı) tanımla, alt logger'lara hiç handler ekleme, yalnız getLogger(__name__) ile kullan.

Filter: kaydı süz ya da değiştir

logging.Filter'dan türeyen bir sınıfın filter(self, kayit) metodu True dönerse kayıt geçer. Kaydın alanlarını değiştirmek de serbesttir. Bu, KVKK ve PCI-DSS gereği TC kimlik ve kart numaralarını logdan silmenin en sağlam yoludur: geliştirici unutsa bile filtre yakalar.

import logging, sys, re

KART = re.compile(r"\b(?:\d[ -]?){12}(\d{4})\b")
TC = re.compile(r"\b[1-9]\d{8}(\d{2})\b")

def maskele(metin):
    metin = KART.sub(lambda m: "**** **** **** " + m.group(1), metin)
    return TC.sub(lambda m: "*" * 9 + m.group(1), metin)

class MaskeFiltresi(logging.Filter):
    def filter(self, kayit):
        kayit.msg = maskele(kayit.getMessage())
        kayit.args = ()
        return True

log = logging.getLogger("anadolu.kvkk")
log.handlers.clear(); log.propagate = False; log.setLevel(logging.INFO)
h = logging.StreamHandler(sys.stdout)
h.setFormatter(logging.Formatter("%(levelname)s %(message)s"))
h.addFilter(MaskeFiltresi())
log.addHandler(h)

log.info("Ödeme alındı kart=%s tutar=%.2f", "4543 1234 5678 9012", 1499.9)
log.warning("Müşteri %s için adres eksik", "12345678946")

Filtreyi handler'a eklemek, o handler'a giden her kaydı (alt logger'lardan yayılanlar dahil) kapsar. Logger'a eklenen filtre ise yalnız o logger'da doğrudan oluşturulan kayıtlara uygulanır.

exception(): traceback'i kaybetme

log.exception("mesaj") yalnız except bloğunda çağrılır, ERROR seviyesinde yazar ve formatter traceback'i mesajın altına ekler. Başka bir seviyede traceback istersen exc_info=True ver.

import logging, sys

log = logging.getLogger("anadolu.kur")
log.handlers.clear(); log.propagate = False; log.setLevel(logging.INFO)
h = logging.StreamHandler(sys.stdout)
h.setFormatter(logging.Formatter("%(levelname)s %(message)s"))
log.addHandler(h)

def birim_fiyat(toplam, adet):
    try:
        return round(toplam / adet, 2)
    except ZeroDivisionError:
        log.exception("Birim fiyat hesaplanamadı: toplam=%s adet=%s", toplam, adet)
        return None

print(birim_fiyat(100, 0))
try:
    int("on iki")
except ValueError:
    log.warning("Adet sayıya çevrilemedi", exc_info=True)

Yapılandırılmış (JSON) log

Üretimde loglar Elasticsearch, Loki, Datadog gibi sistemlerde aranır. Her satırın bir JSON nesnesi olması, "tutarı 10.000 TL üstü ve seviyesi ERROR olan kayıtlar" gibi sorguları mümkün kılar. Kendi Formatter'ını yazmak kolaydır; ek alanlar extra= ile kayda eklenir.

import logging, sys, json

class JsonFormatter(logging.Formatter):
    def format(self, kayit):
        veri = {"seviye": kayit.levelname, "logger": kayit.name, "mesaj": kayit.getMessage()}
        for alan in ("siparis_id", "tutar"):
            if hasattr(kayit, alan):
                veri[alan] = getattr(kayit, alan)
        if kayit.exc_info:
            veri["hata"] = self.formatException(kayit.exc_info).splitlines()[-1]
        return json.dumps(veri, ensure_ascii=False)

log = logging.getLogger("anadolu.json")
log.handlers.clear(); log.propagate = False; log.setLevel(logging.INFO)
h = logging.StreamHandler(sys.stdout)
h.setFormatter(JsonFormatter())
log.addHandler(h)

log.info("Sipariş onaylandı", extra={"siparis_id": "AM-101", "tutar": 1499.9})
try:
    {}["kargo"]
except KeyError:
    log.exception("Kargo bilgisi yok", extra={"siparis_id": "AM-102"})

Dosyaya log ve RotatingFileHandler

FileHandler tek dosyaya yazar ve dosya sonsuza dek büyür. RotatingFileHandler dosya maxBytes'a ulaşınca onu .1 olarak yeniden adlandırır, eskileri kaydırır ve en fazla backupCount yedek tutar. Zamana göre döndürmek için TimedRotatingFileHandler (ör. her gece) vardır.

import logging, os
from logging.handlers import RotatingFileHandler

for f in os.listdir("."):
    if f.startswith("stok.log"):
        os.remove(f)

log = logging.getLogger("anadolu.stok")
log.handlers.clear(); log.propagate = False; log.setLevel(logging.INFO)
dosya = RotatingFileHandler("stok.log", maxBytes=120, backupCount=2, encoding="utf-8")
dosya.setFormatter(logging.Formatter("%(levelname)s %(message)s"))
log.addHandler(dosya)

for i in range(1, 13):
    log.info("Ürün U%02d sayıldı", i)
dosya.close()
log.removeHandler(dosya)

print(sorted(f for f in os.listdir(".") if f.startswith("stok.log")))
with open("stok.log", encoding="utf-8") as f:
    print(f.read().strip())

dictConfig: yapılandırmayı koddan ayır

Gerçek uygulamada yapılandırma tek yerde, çoğu zaman bir YAML/JSON dosyasında durur ve logging.config.dictConfig ile yüklenir. Ortama (geliştirme/üretim) göre seviyeyi değiştirmek kod değişikliği gerektirmez.

import logging, logging.config

AYAR = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {"sade": {"format": "%(levelname)s:%(name)s:%(message)s"}},
    "handlers": {
        "ekran": {"class": "logging.StreamHandler", "stream": "ext://sys.stdout",
                  "formatter": "sade", "level": "INFO"},
    },
    "loggers": {
        "anadolu": {"handlers": ["ekran"], "level": "DEBUG", "propagate": False},
    },
}
logging.config.dictConfig(AYAR)
logging.getLogger("anadolu.iade").info("İade talebi alındı")
logging.getLogger("anadolu.iade").debug("ekran handler'ı INFO, bu görünmez")

"ext://sys.stdout" yapılandırma anında sys.stdout nesnesine çözülür. disable_existing_loggers: False unutulursa, dictConfig'ten önce oluşturulmuş tüm logger'lar sessizce kapanır: klasik bir üretim sürprizi.

Kütüphane kodunda NullHandler

Bir paket (ör. anadolu_odeme) yazıyorsan logging'i yapılandırma: basicConfig çağırma, handler ekleme, seviye ayarlama. Bu kararlar uygulamanındır. Paketin __init__.py'sine yalnız şunu yaz:

import logging
logging.getLogger(__name__).addHandler(logging.NullHandler())

NullHandler hiçbir şey yapmaz; yalnız "handler bulunamadı" durumunda Python'un son çare (last resort) olarak stderr'e WARNING basmasını önler. Uygulama kendi handler'larını köke eklediğinde paketin logları yayılım sayesinde oraya akar.