Gözlemlenebilirlik: log, metrik, iz ve SLO

Neden önemli?

Cuma akşamı Lezzet Kurye'ye "siparişim bir saattir gelmedi" şikâyetleri yağıyor. Sunucular ayakta, CPU normal, hata logu yok. Sorun nerede: restoranın onayında mı, kurye atamasında mı, ödeme servisinin yavaşlamasında mı? İzleme (monitoring) önceden bildiğin soruları sorar: "CPU %90'ı geçti mi?". Gözlemlenebilirlik (observability) ise sistemin dışarı verdiği sinyallerle önceden düşünmediğin soruları da cevaplayabilmektir: "Bu akşam Kadıköy'deki nakit ödemeli siparişlerde kurye atama adımı neden 4 kat yavaş?". Bu dersin sonunda bir servisin log, metrik ve izlerini tasarlayabilecek, "iyi çalışıyor"u bir SLO ile sayıya dökebilecek ve gürültüsüz alarm kurabileceksin.

Üç sütun ve aralarındaki ilişki

Üçü birbirine bağlandığında güçlenir: metrik panelinde p95'in sıçradığını görürsün, o andaki yavaş bir isteğin trace_id'sine (exemplar) tıklarsın, izde ödeme servisinin 3 saniye beklediğini görürsün, aynı trace_id ile loglarda hata mesajını bulursun. Bu bağı kuran şey korelasyon kimliğidir. Logging dersinde yapılandırılmış (JSON) log ve Filter ile bağlam eklemeyi görmüştün; şimdi o bağlamı istek boyunca taşıyacağız.

Korelasyon ve istek kimliği: contextvars

Her gelen isteğe bir kimlik (request id) verilir; istemci X-Request-ID başlığıyla gönderdiyse o kullanılır, yoksa üretilir. Bu kimliği her fonksiyona parametre olarak geçirmek yerine contextvars.ContextVar kullanılır: asyncio'da her görev kendi bağlam kopyasında çalıştığı için aynı anda işlenen iki isteğin kimlikleri karışmaz (global değişkende karışır). Bir logging filtresi de kimliği her log kaydına ekler.

import asyncio, contextvars, io, logging

istek_kimligi = contextvars.ContextVar("istek_kimligi", default="-")

class KimlikFiltresi(logging.Filter):
    def filter(self, kayit):
        kayit.istek_kimligi = istek_kimligi.get()
        return True

akim = io.StringIO()
h = logging.StreamHandler(akim)
h.setFormatter(logging.Formatter("%(istek_kimligi)s %(message)s"))
h.addFilter(KimlikFiltresi())
log = logging.getLogger("lezzet.siparis")
log.handlers[:] = [h]
log.setLevel(logging.INFO)
log.propagate = False

async def siparis_al(kimlik, siparis_id):
    istek_kimligi.set(kimlik)                 # middleware bunu yapar
    log.info("sipariş alındı %s", siparis_id)
    await asyncio.sleep(0.001)                # bu arada diğer istek çalışır
    log.info("kurye atandı %s", siparis_id)

async def main():
    await asyncio.gather(siparis_al("req-a1", 1), siparis_al("req-b2", 2))

asyncio.run(main())
print(akim.getvalue(), end="")
print("ana bağlamda:", istek_kimligi.get())

İki istek iç içe geçerek çalıştı ama her log satırı doğru kimliği taşıyor; ana bağlam etkilenmedi. Senkron web çatılarında (Django, Flask) middleware token = istek_kimligi.set(...) ile değeri koyar ve yanıt bitince istek_kimligi.reset(token) ile geri alır; iş parçacığı havuzunda bir sonraki istek eski kimliği görmesin diye bu reset önemlidir.

Metrik türleri ve yüzdelikler

# pip install prometheus-client   ->  http://localhost:8000/metrics
from prometheus_client import Counter, Gauge, Histogram, start_http_server

SIPARIS = Counter("siparis_toplam", "Alınan siparişler", ["sehir", "odeme"])
KUYRUK = Gauge("bildirim_kuyrugu", "Bekleyen bildirim sayısı")
TESLIM = Histogram("teslim_suresi_dakika", "Sipariş -> teslim süresi",
                   buckets=[15, 20, 30, 40, 45, 60, 75, 90])

start_http_server(8000)
SIPARIS.labels(sehir="İstanbul", odeme="kart").inc()
KUYRUK.set(12)
TESLIM.observe(36.8)

Gecikmeyi ortalama ile izlemek yanıltır: birkaç çok yavaş istek ortalamayı az etkiler ama o kullanıcılar çok mutsuzdur. Bunun yerine yüzdelik (percentile) kullanılır: p50 (medyan) tipik deneyimi, p95 ve p99 kuyruğu (en kötü %5 ve %1) gösterir. Lezzet Kurye'nin gerçek teslim sürelerine bakalım:

import datetime as dt
import veri

def teslim_sureleri():
    """Teslim edilen siparişlerin sipariş -> teslim süresi (dakika)."""
    sonuc = []
    for s in veri.kayitlar("lezzet_kurye", "lk_orders"):
        if s["status"] == "teslim":
            a = dt.datetime.fromisoformat(s["placed_at"])
            b = dt.datetime.fromisoformat(s["delivered_at"])
            sonuc.append((b - a).total_seconds() / 60)
    return sonuc

import math, statistics

def yuzdelik(degerler, p):                     # en yakın sıra (nearest-rank) yöntemi
    s = sorted(degerler)
    k = max(1, math.ceil(p / 100 * len(s)))
    return s[k - 1]

sureler = teslim_sureleri()
print("teslim edilen sipariş:", len(sureler))
print(f"ortalama = {statistics.mean(sureler):.1f} dk")
for p in (50, 95, 99):
    print(f"p{p} = {yuzdelik(sureler, p):.1f} dk")
print(f"60 dk içinde teslim oranı = %{100 * sum(x <= 60 for x in sureler) / len(sureler):.2f}")

Medyan müşteri siparişini 37 dakikada alıyor, ama her 20 müşteriden biri 57 dakikadan fazla bekliyor. Yüzdelik hesaplamanın birden çok yöntemi vardır (en yakın sıra, doğrusal ara değer; statistics.quantiles ve numpy farklı varsayılanlar kullanır); panolarda hangi yöntemin kullanıldığını bil ve yüzdelikleri asla ortalamasını alarak birleştirme: iki sunucunun p95'lerinin ortalaması toplam p95 değildir. Birleştirilebilir olan histogram kovalarıdır.

RED ve USE yöntemleri

Google SRE kitabındaki "dört altın sinyal" (gecikme, trafik, hata, doygunluk) da bu ikisinin birleşimidir. Her servisin ilk panosu RED olmalı; doygunluk ise sorunun nedenini (veritabanı bağlantı havuzu dolu) gösterir.

Dağıtık iz: span, trace, örnekleme

Bir sipariş isteği API ağ geçidinden geçer, sipariş servisi restoran servisini ve ödeme servisini çağırır, sonra kuyruğa bildirim bırakır. Trace bu yolculuğun tamamıdır ve bir trace_id taşır; her adım bir span'dir (ad, başlangıç, bitiş, üst span kimliği, öznitelikler). Servisler arasında bağlam HTTP başlığıyla taşınır; W3C standardı traceparent: 00-<trace_id 32 hex>-<span_id 16 hex>-01 biçimindedir (son bayt örneklenme bayrağı).

# pip install opentelemetry-sdk opentelemetry-instrumentation-fastapi
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor, ConsoleSpanExporter
from opentelemetry.sdk.trace.sampling import ParentBased, TraceIdRatioBased

saglayici = TracerProvider(sampler=ParentBased(TraceIdRatioBased(0.1)))   # izlerin %10'u
saglayici.add_span_processor(BatchSpanProcessor(ConsoleSpanExporter()))    # gerçekte OTLP -> Jaeger/Tempo
trace.set_tracer_provider(saglayici)
izci = trace.get_tracer("lezzet.siparis")

def siparis_ver(s):
    with izci.start_as_current_span("siparis_ver") as span:
        span.set_attribute("siparis.sehir", s.sehir)
        with izci.start_as_current_span("odeme_al"):
            odeme.tahsil(s)
        with izci.start_as_current_span("kurye_ata"):
            kurye.ata(s)

Aşağıdaki simülasyon aynı fikri contextvars ile kuruyor: etkin span bir bağlam değişkeninde durur, yeni span onu üst (parent) olarak alır; saat enjekte edildiği için süreler deterministiktir.

import contextvars, itertools
from contextlib import contextmanager

etkin = contextvars.ContextVar("etkin_span", default=None)
saat = {"t": 0}
sayac = itertools.count(1)
spanlar = []

@contextmanager
def span(ad):
    ust = etkin.get()
    s = {"ad": ad, "id": next(sayac), "ust": ust["id"] if ust else None, "bas": saat["t"]}
    token = etkin.set(s)
    try:
        yield s
    finally:
        s["sure"] = saat["t"] - s["bas"]
        etkin.reset(token)
        spanlar.append(s)

with span("POST /siparis"):
    saat["t"] += 5
    with span("odeme_al"):
        saat["t"] += 120
    with span("kurye_ata"):
        saat["t"] += 40
        with span("sql: SELECT kurye"):
            saat["t"] += 35

def yaz(ust=None, girinti=0):
    for s in sorted((x for x in spanlar if x["ust"] == ust), key=lambda x: x["bas"]):
        print("  " * girinti + f"{s['ad']:{24 - 2 * girinti}} {s['sure']:4} ms")
        yaz(s["id"], girinti + 1)

yaz()

Bütün izleri saklamak pahalıdır; bu yüzden örnekleme yapılır. Baştan örnekleme (head sampling) kararı istek başında verir (ör. %10) ve ucuzdur ama nadir hatalı istekleri kaçırabilir. Kuyruktan örnekleme (tail sampling) iz bittikten sonra karar verir: tüm hatalı ve yavaş izleri, normallerin ise küçük bir kısmını saklar; OpenTelemetry Collector'da yapılır.

SLI, SLO ve hata bütçesi

SLI (Service Level Indicator) kullanıcı deneyimini ölçen bir orandır: iyi olaylar / tüm olaylar. SLO (Objective) bu oran için hedeftir: "Bir ay içinde teslim edilen siparişlerin %95'i 60 dakika içinde teslim edilmeli." SLA ise müşteriyle yapılan, cezası olan sözleşmedir ve SLO'dan gevşek tutulur. Hata bütçesi = (1 - hedef) × toplam olay: hedefin izin verdiği "kötü" olay sayısıdır. Bütçe varken yeni özellik çıkarılır; bütçe bitince ekip güvenilirliğe odaklanır. Bu, "hiç hata olmasın" yerine ölçülebilir bir risk dengesi kurar.

import datetime as dt
import veri

def teslim_sureleri():
    """Teslim edilen siparişlerin sipariş -> teslim süresi (dakika)."""
    sonuc = []
    for s in veri.kayitlar("lezzet_kurye", "lk_orders"):
        if s["status"] == "teslim":
            a = dt.datetime.fromisoformat(s["placed_at"])
            b = dt.datetime.fromisoformat(s["delivered_at"])
            sonuc.append((b - a).total_seconds() / 60)
    return sonuc

from collections import defaultdict

ay = defaultdict(lambda: [0, 0])                    # ay -> [iyi, toplam]
for s in veri.kayitlar("lezzet_kurye", "lk_orders"):
    if s["status"] != "teslim":
        continue
    sure = (dt.datetime.fromisoformat(s["delivered_at"]) - dt.datetime.fromisoformat(s["placed_at"])).total_seconds() / 60
    a = ay[s["placed_at"][:7]]
    a[0] += sure <= 60
    a[1] += 1

HEDEF = 0.95
for k in ("2024-10", "2024-11", "2024-12"):
    iyi, toplam = ay[k]
    butce = (1 - HEDEF) * toplam
    harcanan = (toplam - iyi) / butce
    print(f"{k}: SLI=%{100 * iyi / toplam:.2f}  bütçe={butce:.0f} kötü olay  harcanan=%{100 * harcanan:.0f}")

Gürültüsüz alarm: yanma hızı (burn rate)

"Hata oranı %5'i geçti" gibi anlık eşikler ya her küçük dalgalanmada çalar ya da yavaş sızan sorunu kaçırır. SRE yaklaşımı yanma hızına bakar: yanma = gözlenen hata oranı / (1 - hedef). Yanma 1 ise bütçe tam dönem sonunda biter; 14.4 ise 30 günlük bütçenin %2'si 1 saatte yanar. Önerilen desen çok pencereli alarmdır: uzun pencere (1 saat) ve kısa pencere (5 dakika) birlikte eşiği aşınca sayfa (page) at; uzun pencere ciddiyeti, kısa pencere sorunun hâlâ sürdüğünü kanıtlar ve düzelince alarmın çabuk susmasını sağlar. Her alarmın bir runbook'u (ne yapılacağı) olmalı; eyleme dönüşmeyen alarm silinmeli.

Hata takibi ve sağlık uç noktaları

Sentry gibi hata takip araçları yakalanmamış istisnaları yığın izi, istek bağlamı, sürüm ve kullanıcı sayısıyla toplar; aynı hatayı tek bir "sorun" altında gruplar ve yeni sürümle gelen hatayı ilk dakikada bildirir. Kişisel veriyi göndermemek için send_default_pii=False ve before_send ile maskeleme yapılır.

# pip install "sentry-sdk[fastapi]"
import sentry_sdk
sentry_sdk.init(dsn=os.environ["SENTRY_DSN"], release="lezzet-api@2.4.1", environment="prod",
                traces_sample_rate=0.1, send_default_pii=False)

@app.get("/saglik/canli")        # liveness: süreç yanıt veriyor mu? (bağımlılıklara BAKMA)
def canli():
    return {"durum": "ok"}

@app.get("/saglik/hazir")        # readiness: trafik alabilir mi? (veritabanı, Redis)
def hazir():
    sorunlar = [ad for ad, kontrol in (("db", db_ping), ("redis", redis_ping)) if not kontrol()]
    if sorunlar:
        raise HTTPException(503, {"durum": "hazir_degil", "sorunlar": sorunlar})
    return {"durum": "ok"}

Docker ve dağıtım dersinde HEALTHCHECK'i görmüştün. Kubernetes iki ayrı sonda kullanır: liveness başarısız olursa konteyner yeniden başlatılır; readiness başarısız olursa yalnız trafik kesilir. Veritabanı çökünce liveness'ı da başarısız yaparsan tüm podlar sürekli yeniden başlar ve sorun büyür; bağımlılık kontrolleri readiness'a aittir.

Veri hattı gözlemlenebilirliği

Veri mühendisliğinde "servis ayakta" yetmez: gece çalışan ETL hatasız bitip boş tablo yazabilir. Veri hatları için beş temel sinyal izlenir: tazelik (son kayıt ne kadar eski?), hacim (bugünkü satır sayısı olağan aralıkta mı?), şema (sütun eklendi/silindi/tipi değişti mi?), dağılım (boş değer oranı, değer aralığı) ve soy (lineage: bu tablo hangi kaynaktan besleniyor?). Orkestrasyon dersindeki görevlerin sonuna bu kontrolleri eklemek, bozuk verinin panolara ulaşmasını engeller.

import datetime as dt, statistics
from collections import Counter
import veri

siparisler = veri.kayitlar("lezzet_kurye", "lk_orders")
simdi = dt.datetime(2025, 1, 1, 2, 0)

son = max(dt.datetime.fromisoformat(s["placed_at"]) for s in siparisler)
print("tazelik:", round((simdi - son).total_seconds() / 60, 1), "dk önce son sipariş")

gunluk = Counter(s["placed_at"][:10] for s in siparisler)
son7 = [gunluk[(dt.date(2024, 12, 31) - dt.timedelta(days=i)).isoformat()] for i in range(1, 8)]
ort, sapma = statistics.mean(son7), statistics.stdev(son7)
print(f"31 Aralık hacmi: {gunluk['2024-12-31']} (önceki 7 gün ort. {ort:.1f}, z = {(gunluk['2024-12-31'] - ort) / sapma:.2f})")

beklenen = {"order_id", "customer_id", "restaurant_id", "courier_id", "placed_at", "picked_at",
            "delivered_at", "status", "payment", "delivery_fee", "discount", "tip"}
print("şema farkı:", set(siparisler[0]) ^ beklenen or "yok")