İzleme ve Uyarı

Önceki dersteki her karar bir ölçüme dayanıyordu: bağlantı maliyeti, kuyruk süresi, eşzamanlı işlem sayısı, zaman aşımına uğrayan istek oranı. Bunların hiçbiri kendiliğinden görünmez. Havuz doygunluğu, uygulama tarafında yalnız “veritabanı yavaş” olarak fark edilir ve genellikle yanlış yerde aranır.

İzlemenin işi bu boşluğu doldurmaktır: sistemin durumunu, arıza anında değil sürekli olarak sayılara çevirmek. Bu ders hangi sayıların toplanacağını, nasıl okunacağını ve bir uyarının ne zaman anlamlı olduğunu ele alıyor.

Bir Sorgunun Süresi Neyi Ölçer

En temel büyüklük bir deyimin ne kadar sürdüğüdür; ama “süre” tek bir sayı değildir. Aşağıdaki blok aynı tablo üzerinde iki sorguyu ölçüyor. Süreler makineye ve dosya sistemine bağlıdır; sizde farklı çıkacaktır.

rm -f olcum.db

sqlite3 olcum.db <<'SQL'
CREATE TABLE odunc(id INTEGER PRIMARY KEY, kitap_id INT NOT NULL, uye_id INT NOT NULL,
                   sube_id INT NOT NULL, alis TEXT NOT NULL, iade TEXT);
WITH RECURSIVE s(n) AS (SELECT 1 UNION ALL SELECT n+1 FROM s WHERE n<400000)
INSERT INTO odunc(id,kitap_id,uye_id,sube_id,alis)
SELECT n,(n%400)+1,(n%900)+1,(n%3)+1,'2025-06-01' FROM s;
CREATE INDEX odunc_uye ON odunc(uye_id);
SQL

sqlite3 olcum.db <<'SQL'
.header on
.timer on
SELECT COUNT(*) AS dizinli FROM odunc WHERE uye_id=42;
SELECT COUNT(*) AS taramali FROM odunc WHERE alis LIKE '2025-06-01';
SQL

dizinli
445
Run Time: real 0.000 user 0.000060 sys 0.000036
taramali
400000
Run Time: real 0.014 user 0.012269 sys 0.001597

Üç sayı üç ayrı şeyi söylüyor. Duvar saati süresi (real) sorgunun başlangıcı ile bitişi arasında geçen zamandır — kullanıcının beklediği süre budur. İşlemci süresi (user ve sys) o sorgu için gerçekten hesaplama yapılan zamandır.

İkinci sorguda duvar saati süresi işlemci süresine yakındır: sorgu dört yüz bin satırı okurken hep meşguldü, hiçbir şey beklemedi. Bu, izlemenin en yararlı tek kuralını verir: duvar saati süresi işlemci süresinden belirgin biçimde büyükse, aradaki fark beklemedir. Bekleme; diskten veri gelmesi, bir kilidin bırakılması, günlüğün diske yazılması ya da ağdan yanıt gelmesi olabilir. Yalnız işlemci süresine bakan bir izleme, en sık rastlanan yavaşlık nedenlerini göremez.

Motorların çoğu bunu daha ayrıntılı sunar: her oturumun o anda hangi olayı beklediği kayıt altındadır. Bekleme olayları sınıflara ayrılır — kilit beklemesi, veri dosyasından okuma, günlüğün diske yazılması, istemcinin veri göndermesini bekleme. Bu sınıfların dağılımı, darboğazın adını doğrudan verir; ölçmeden yapılan tahminler genellikle yanlış çıkar.

Ortalama, Dağılım ve Toplam Etki

Tek bir çalıştırmanın süresi bir sayıdır; işletimde gereken şey binlerce çalıştırmanın dağılımıdır. Aşağıdaki blok bir günün iş yükünü canlandırıyor: dört farklı sorgu biçimi, farklı çağrı sayılarıyla çalışıyor ve her çalıştırmanın süresi kaydediliyor.

Üye dağılımı kasıtlı olarak çarpıktır: bir numaralı üye, kütüphanenin toplu ödünç hesabıdır ve çok sayıda kaydı vardır. Süreler ortama bağlıdır; anlamlı olan sütunlar arasındaki ilişkidir.

rm -f izleme.db

node - <<'EOF'
const { DatabaseSync } = require("node:sqlite");
const db = new DatabaseSync("izleme.db");
db.exec(`CREATE TABLE odunc(id INTEGER PRIMARY KEY, kitap_id INT NOT NULL, uye_id INT NOT NULL,
                            sube_id INT NOT NULL, alis TEXT NOT NULL, iade TEXT)`);
// Uye dagilimi carpik: 1 numarali uye kutuphanenin toplu odunc hesabidir.
const ekle = db.prepare("INSERT INTO odunc(kitap_id,uye_id,sube_id,alis) VALUES(?,?,?,?)");
db.exec("BEGIN");
for (let i = 1; i <= 200000; i++)
  ekle.run(i % 400 + 1, i % 12 === 0 ? 1 : (i % 900) + 2, (i % 3) + 1, "2025-06-01");
db.exec("COMMIT");
db.exec("CREATE INDEX odunc_uye ON odunc(uye_id)");

const kutuk = [];   // her calistirma icin (imza, sure)
const calistir = (imza, deyim, ...p) => {
  const t = process.hrtime.bigint();
  deyim.all(...p);
  kutuk.push([imza, Number(process.hrtime.bigint() - t) / 1e6]);
};
const uyeSorgu = db.prepare("SELECT id,kitap_id,alis FROM odunc WHERE uye_id=?");
const anahtarSorgu = db.prepare("SELECT kitap_id,uye_id FROM odunc WHERE id=?");
const subeSorgu = db.prepare("SELECT COUNT(*) c FROM odunc WHERE sube_id=? AND iade IS NULL");
const raporSorgu = db.prepare(
  "SELECT sube_id, COUNT(*) c FROM odunc WHERE alis>=? GROUP BY sube_id");

for (let i = 0; i < 2000; i++) calistir("uye kayitlari", uyeSorgu, i % 12 === 0 ? 1 : i % 900 + 2);
for (let i = 0; i < 20000; i++) calistir("anahtarla arama", anahtarSorgu, i % 200000 + 1);
for (let i = 0; i < 200; i++) calistir("sube sayimi", subeSorgu, (i % 3) + 1);
for (let i = 0; i < 20; i++) calistir("gunluk rapor", raporSorgu, "2025-01-01");

const dilim = (a, p) => a[Math.min(a.length - 1, Math.floor(a.length * p))];
const toplamSure = kutuk.reduce((t, k) => t + k[1], 0);
console.log("imza            | cagri | ortalama | p50   | p95   | p99   | toplam  | pay");
console.log("----------------|-------|----------|-------|-------|-------|---------|------");
for (const imza of [...new Set(kutuk.map((k) => k[0]))]) {
  const s = kutuk.filter((k) => k[0] === imza).map((k) => k[1]).sort((a, b) => a - b);
  const toplam = s.reduce((t, v) => t + v, 0);
  console.log(imza.padEnd(15) + " | " + String(s.length).padStart(5) + " | " +
    (toplam / s.length).toFixed(3).padStart(8) + " | " + dilim(s, 0.5).toFixed(2).padStart(5) +
    " | " + dilim(s, 0.95).toFixed(2).padStart(5) + " | " + dilim(s, 0.99).toFixed(2).padStart(5) +
    " | " + (toplam.toFixed(0) + " ms").padStart(7) + " | %" +
    (100 * toplam / toplamSure).toFixed(1).padStart(4));
}
const ESIK = 10;
const yavas = kutuk.filter((k) => k[1] > ESIK);
const yavasSure = yavas.reduce((t, k) => t + k[1], 0);
console.log();
console.log("toplam calistirma: " + kutuk.length + ", toplam sure: " +
            toplamSure.toFixed(0) + " ms");
console.log(ESIK + " ms esigini asan: " + yavas.length + " calistirma, " +
            yavasSure.toFixed(0) + " ms (%" + (100 * yavasSure / toplamSure).toFixed(1) + ")");
EOF

imza            | cagri | ortalama | p50   | p95   | p99   | toplam  | pay
----------------|-------|----------|-------|-------|-------|---------|------
uye kayitlari   |  2000 |    0.570 |  0.08 |  5.69 |  5.96 | 1140 ms | %45.8
anahtarla arama | 20000 |    0.003 |  0.00 |  0.00 |  0.00 |   62 ms | % 2.5
sube sayimi     |   200 |    4.512 |  4.19 |  5.35 |  5.48 |  902 ms | %36.2
gunluk rapor    |    20 |   19.267 | 19.26 | 19.51 | 19.51 |  385 ms | %15.5

toplam calistirma: 22220, toplam sure: 2490 ms
10 ms esigini asan: 20 calistirma, 385 ms (%15.5)

Tablo, izlemenin üç ayrı dersini aynı anda veriyor.

Ortalama dağılımı anlatmaz. Üye kayıtları sorgusunun ortalaması yarım milisaniyenin biraz üzerinde; ortanca değeri ise bunun yedide biri. Aradaki fark, çağrıların on ikide birinin toplu ödünç hesabına gitmesinden geliyor. Ortalama, bu iki ayrı davranışı tek bir sayıya karıştırır ve ikisini de doğru anlatmaz. Yüzdelik dilimler (percentile) ayrımı korur: p50 sıradan kullanıcının gördüğü süredir, p95 ve p99 kuyruğu tarif eder.

Yavaş olan ile pahalı olan aynı şey değildir. Günlük rapor tek çalıştırmada en yavaş sorgudur; toplam yükün altıda birini üretir. Üye kayıtları sorgusu her çalıştırmada hızlıdır ve toplam yükün neredeyse yarısını üretir. Sistemi hızlandırmak için ilk bakılacak yer, ortalama süresi en yüksek sorgu değil, çağrı sayısı ile süresinin çarpımı en yüksek olandır.

Eşiğe dayalı yavaş sorgu kütüğü yalnız bir dilimi görür. On milisaniyelik eşik, iş yükünün yüzde on beşini yakaladı; kalan yüzde seksen beş görünmez kaldı. Eşik, tek başına patolojik olan deyimleri bulmak için değerlidir; iş yükünün nereye gittiğini söylemez. Bunun için her çalıştırmanın sorgu imzasına (query fingerprint) göre toplanması gerekir — parametreleri soyulmuş deyim metni, aynı biçimin bütün çalıştırmalarını tek satırda toplar.

Beklemenin Ölçülmesi

Sorgunun kendi süresi, yanıt süresinin tamamı değildir. Aşağıdaki blok bunu doğrudan ölçüyor: aynı güncelleme deyimi önce boş bir sistemde, sonra başka bir sürecin aynı tabloyu kilitli tuttuğu sırada çalışıyor. İkinci süre, kilidi tutan işlemin ne kadar sürdüğüne bağlıdır.

rm -f bekleme.db kilit.isaret

node - <<'EOF'
const { DatabaseSync } = require("node:sqlite");
const { spawn } = require("node:child_process");
const fs = require("node:fs");
const bekle = (ms) => Atomics.wait(new Int32Array(new SharedArrayBuffer(4)), 0, 0, ms);

const db = new DatabaseSync("bekleme.db");
db.exec("PRAGMA busy_timeout=5000");
db.exec("CREATE TABLE odunc(id INTEGER PRIMARY KEY, kitap_id INT, uye_id INT, iade TEXT)");
const ekle = db.prepare("INSERT INTO odunc(kitap_id,uye_id) VALUES(?,?)");
db.exec("BEGIN");
for (let i = 1; i <= 5000; i++) ekle.run(i % 400, i % 250);
db.exec("COMMIT");

const yaz = () => {
  const t = process.hrtime.bigint();
  db.exec("BEGIN IMMEDIATE");
  db.prepare("UPDATE odunc SET iade='2025-06-30' WHERE id=?").run(7);
  db.exec("COMMIT");
  return Number(process.hrtime.bigint() - t) / 1e6;
};
const serbest = yaz();

// Ikinci bir surec ayni tabloyu 1200 ms boyunca kilitli tutar.
const cocukKod = `
const { DatabaseSync } = require("node:sqlite");
const fs = require("node:fs");
const db = new DatabaseSync("bekleme.db");
db.exec("PRAGMA busy_timeout=5000");
db.exec("BEGIN IMMEDIATE");
db.prepare("UPDATE odunc SET iade='2025-06-29' WHERE id=?").run(9);
fs.writeFileSync("kilit.isaret", "1");
Atomics.wait(new Int32Array(new SharedArrayBuffer(4)), 0, 0, 1200);
db.exec("COMMIT");
`;
spawn(process.execPath, ["-e", cocukKod], { stdio: "ignore" });
while (!fs.existsSync("kilit.isaret")) bekle(10);

const kilitli = yaz();
console.log("cakismasiz yazma        : " + serbest.toFixed(1) + " ms");
console.log("kilit altinda ayni yazma: " + kilitli.toFixed(1) + " ms");
console.log("beklemenin payi         : %" +
            (100 * (kilitli - serbest) / kilitli).toFixed(2));
fs.rmSync("kilit.isaret", { force: true });
EOF

cakismasiz yazma        : 0.3 ms
kilit altinda ayni yazma: 1306.3 ms
beklemenin payi         : %99.98

Aynı deyim, aynı satır, aynı veri; süre dört mertebe büyüdü ve büyümenin tamamı beklemeden geldi. Deyimin kendisi hakkında toplanan hiçbir ölçüm bunu açıklayamaz: sorgu planı aynı, okunan satır sayısı aynı, işlemci süresi aynı. Açıklama yalnız “bu oturum ne bekliyordu” sorusunun yanıtındadır.

İşletimde bu fark şöyle görünür: uygulama tarafında ölçülen yanıt süresi büyür, veritabanı tarafında sorgu süreleri normaldir. İki taraf birbirini işaret eder. Bekleme olaylarının izlenmesi bu tartışmayı bitirir — süre, kilidi bekleyen tarafta değil, kilidi tutan uzun işlemde harcanmaktadır.

Uyarının Anlamlı Olması

Toplanan her sayı bir uyarıya dönüştürülemez. İşleyen bir uyarı üç koşulu sağlar.

Bir eşiği vardır ve eşik taban çizgisinden türetilmiştir. “Sorgu süresi yüksek” bir uyarı değildir; “p95 değeri son bir saat boyunca normal değerinin üç katında” bir uyarıdır. Taban çizgisi, sistemin sağlıklı olduğu bilinen dönemde ölçülerek elde edilir.

Süreklilik koşulu vardır. Anlık bir sıçrama uyarı üretmez; belirli bir pencerede sürmesi gerekir. Bu, önceki dersteki devralma ayarıyla aynı ödünleşimdir: duyarlılık arttıkça yanlış uyarı sayısı artar.

Bir eyleme karşılık gelir. Karşılığında yapılacak bir iş yoksa, uyarı yalnız gürültü üretir ve zamanla bakılmaz hâle gelir. Uyarı yorgunluğu, izleme kurulumlarının en sık görülen başarısızlık biçimidir: yüzlerce uyarı arasında gerçek olan fark edilmez.

Uyarılacak büyüklüklerin seçiminde işe yarayan bir ayrım, belirti ile neden arasındaki farktır. Belirti, kullanıcının hissettiği şeydir: yanıt süresi, hata oranı, başarısız ödünç işlemi sayısı. Neden, o belirtiyi üreten iç durumdur: çoğaltma gecikmesi, havuz doygunluğu, disk doluluğu, uzun süren işlem. Uyarılar belirtiler üzerine kurulur — kullanıcı etkilenmediğinde kimse uyandırılmaz. Nedenler ise gösterge panolarında tutulur; uyarı geldiğinde bakılacak yer orasıdır.

Bu ayrımın dışında kalan bir sınıf vardır: kullanıcı henüz etkilenmediği hâlde uyarı gerektiren durumlar. Diskin dolmasına iki gün kalması, yedeklemenin üç gündür çalışmaması, çoğaltma gecikmesinin kurtarma noktası hedefini aşması. Bunlar tükenmekte olan bir kaynağı gösterir ve etki oluşmadan önce ele alınması gerekir.

Son olarak izlemenin kendisinin de kapsamı vardır. Bu konudaki her ders bir izlenecek büyüklük bıraktı: yedeğin yaşı ve doğrulanma tarihi, kurtarma tatbikatının süresi, çoğaltma gecikmesi, küme üyelerinin durumu, havuzdaki boş bağlantı sayısı ve kuyruk süresi. İzlenmeyen bir güvence, güvence değildir.

Özet

• Duvar saati süresi ile işlemci süresi arasındaki fark beklemedir; yalnız işlemci süresine bakan izleme, yavaşlığın en sık nedenlerini göremez.
• Ortalama, çarpık dağılımları gizler; p50 sıradan durumu, p95 ve p99 kuyruğu anlatır.
• İş yükünün nereye gittiği, çağrı sayısı ile süre çarpımının sorgu imzasına göre toplanmasıyla bulunur; en yavaş sorgu genellikle en pahalı sorgu değildir.
• Eşiğe dayalı yavaş sorgu kütüğü tek başına patolojik deyimleri yakalar, toplam yükün büyük bölümünü görmez.
• Kilit beklemesi deyimin kendi ölçümlerinde hiç görünmez; süre, kilidi tutan işlemde harcanır ve ancak bekleme olayları izlenerek bulunur.
• Anlamlı uyarı, taban çizgisinden türetilmiş bir eşiğe, bir süreklilik koşuluna ve karşılık gelen bir eyleme sahiptir; uyarılar belirtiler üzerine, gösterge panoları nedenler üzerine kurulur.

Sonraki Adım

İzleme, sistemin olağan yükü altında ne yaptığını gösterir. Bazı işler ise olağan yükün dışındadır ve sistemi bilerek zorlar: bir arşivin içeri aktarılması, başka bir kurumdan gelen üye listesinin yüklenmesi, yıllık ödünç kayıtlarının dışarı çıkarılması. Bu işler milyonlarca satırı tek seferde taşır ve satır satır yazma alışkanlığıyla yapıldığında saatler sürer. Sonraki ders toplu veri yüklemeyi ele alıyor: işlem sınırının süreye etkisi, dizinlerin yükleme sırasındaki maliyeti, hazır deyim ile içe aktarım komutunun karşılaştırılması ve bozuk satırların yüklemeyi durdurmadan ayıklanması.