PostgreSQL'de Yavaş Sorguyu Bulmak ve Planı Okumak: pg_stat_statements, EXPLAIN ANALYZE ve Planlayıcının Yanıldığı Yerler

Bir uygulama yavaşladığında ilk refleks çoğu zaman "şu sorguya indeks ekleyelim" olur. Sorun şu ki hangi sorgunun gerçekten pahalı olduğunu bilmeden eklenen indeks, yazma maliyetini artırır ve asıl darboğazı yerinde bırakır. PostgreSQL bu işin araçlarını zaten içinde taşıyor: toplam yükü gösteren pg_stat_statements, tek bir sorgunun içini açan EXPLAIN (ANALYZE, BUFFERS) ve üretimdeki yavaş planları kendiliğinden kaydeden auto_explain. Bu yazı üçünü hangi sırayla kullanacağınızı ve plan çıktısında nereye bakacağınızı anlatıyor.

Önce yükü ölçün, sonra sorguyu

Yavaş sorgu günlüğü (log_min_duration_statement) tek tek uzun süren sorguları yakalar, ama veritabanını asıl yoran şey çoğunlukla tek seferde 3 saniye süren rapor değil, saniyede yüzlerce kez çalışan 8 milisaniyelik sorgudur. Bunu görmek için toplama bakmak gerekir.

pg_stat_statements sabitleri ayıklayıp aynı biçimdeki sorguları tek satırda toplar. Sunucu başlarken yüklenmesi gerektiği için yeniden başlatma ister:

# postgresql.conf
shared_preload_libraries = 'pg_stat_statements'
track_io_timing = on

Yeniden başlattıktan sonra izlemek istediğiniz veritabanında:

CREATE EXTENSION IF NOT EXISTS pg_stat_statements;

SELECT calls,
       round(total_exec_time::numeric, 0) AS toplam_ms,
       round(mean_exec_time::numeric, 2)  AS ortalama_ms,
       rows,
       shared_blks_hit,
       shared_blks_read,
       left(query, 120) AS sorgu
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 20;

Sıralamayı total_exec_time ile yapın, mean_exec_time ile değil. Ortalamaya göre sıralarsanız gece bir kez çalışan bakım işini en üstte görürsünüz; toplama göre sıralarsanız veritabanının zamanını gerçekte nereye harcadığını görürsünüz. calls sütunu da ayrıca değerlidir: tek bir isteğin binlerce kez çalıştırdığı küçük bir sorgu, uygulamadaki N+1 deseninin en net izidir ve bunu hiçbir indeks düzeltmez.

İstatistikleri bir değişiklikten önce SELECT pg_stat_statements_reset(); ile sıfırlarsanız, değişikliğin etkisini temiz bir pencerede ölçebilirsiniz.

track_io_timing açıkken plan çıktısında ve istatistiklerde disk okumasına harcanan süre de görünür. Saat okumasının pahalı olduğu bazı sanal makinelerde ek yük getirebilir; açmadan önce pg_test_timing ile ölçmek iyi bir alışkanlıktır.

EXPLAIN ANALYZE ile planı okumak

Hedef sorguyu bulduktan sonra planına bakın:

EXPLAIN (ANALYZE, BUFFERS)
SELECT o.id, o.total
FROM orders o
WHERE o.customer_id = 4211
  AND o.status = 'open'
ORDER BY o.created_at DESC
LIMIT 50;

EXPLAIN tek başına yalnızca tahmini planı gösterir. ANALYZE sorguyu gerçekten çalıştırır ve her düğüm için gerçek satır sayısını ve süreyi ekler. Bu yüzden UPDATE ya da DELETE incelerken sorguyu bir işlem içine alıp geri alın:

BEGIN;
EXPLAIN (ANALYZE, BUFFERS) UPDATE orders SET status = 'closed' WHERE id = 10;
ROLLBACK;

Çıktıda bakılacak yerler şunlardır.

Tahmini ve gerçek satır sayısı. Her düğümde rows= iki kez geçer: ilki planlayıcının tahmini, actual kısmındaki gerçek sonuç. Aralarında on kat ya da daha fazla fark varsa planlayıcı yanlış bilgiyle karar vermiştir ve sonraki bütün seçimleri (birleştirme türü, indeks kullanımı, bellek) bu hatanın üstüne kurulur. Yavaş planlarda sorun çoğunlukla en yavaş düğümde değil, ilk yanlış tahminin yapıldığı düğümdedir.

loops. İç içe döngü birleştirmelerinde iç düğümün süresi ve satır sayısı tek tur içindir; gerçek maliyet için loops ile çarpmanız gerekir. 0,05 milisaniyelik bir indeks taraması 200.000 kez dönüyorsa tablonun en pahalı satırı odur.

Rows Removed by Filter. İndeks bulunmuş ama koşulun bir kısmı indekste olmadığı için satırlar okunup sonradan atılıyorsa burada görürsünüz. Büyük bir sayı, indeksin sütunlarının ya da sırasının sorguya uymadığını söyler.

Buffers. shared hit bellekteki sayfalar, read diskten okunanlardır. Aynı sorguyu iki kez çalıştırıp ikincisinin çok hızlı olduğunu görürseniz, ilk çalıştırmayı yavaşlatan şey planı değil soğuk önbellek olabilir. Optimizasyonu süreye değil okunan sayfa sayısına bakarak değerlendirmek daha güvenilirdir, çünkü süre makinenin o anki yüküne göre oynar, sayfa sayısı oynamaz.

Sort Method. external merge Disk: ... görüyorsanız sıralama work_mem sınırına sığmamış ve geçici dosyaya taşmıştır. work_mem değerini genel olarak büyütmek yerine sorunlu oturum ya da işlem için SET LOCAL work_mem kullanmak daha güvenlidir; bu değer bağlantı başına değil sıralama ve hash işlemi başına harcanır.

Planlayıcı neden yanılır

Yanlış tahminlerin büyük kısmı birkaç tanıdık sebepten gelir.

Eskimiş istatistik. Toplu yükleme ya da büyük silme sonrası autovacuum henüz ANALYZE çalıştırmamışsa planlayıcı tablonun eski hâline göre karar verir. Toplu işlerin sonuna elle ANALYZE tablo_adi; eklemek bu sınıfı tamamen kapatır.

Birbirine bağlı sütunlar. Planlayıcı varsayılan olarak her koşulun seçiciliğini bağımsız kabul edip çarpar. city = 'Ankara' AND country = 'TR' gibi biri diğerini belirleyen sütunlarda bu, satır sayısını çok düşük tahmin etmesine yol açar. Çok sütunlu istatistik bu ilişkiyi öğretir:

CREATE STATISTICS orders_city_country (dependencies) ON city, country FROM orders;
ANALYZE orders;

Çarpık dağılım. Bir sütunda değerlerin büyük kısmı birkaç değerde toplanıyorsa varsayılan örnek boyutu az kalabilir. Tek sütun için ALTER TABLE orders ALTER COLUMN status SET STATISTICS 1000; ve ardından ANALYZE ile daha ayrıntılı histogram toplanır.

İndeksi kullanılamaz hâle getiren ifade. WHERE lower(email) = $1 sorgusu email üzerindeki düz indeksi kullanamaz; ifade indeksine (CREATE INDEX ON users (lower(email));) ihtiyaç vardır. Aynı durum sütunu farklı bir türe dönüştüren karşılaştırmalarda da oluşur.

ORDER BY ile LIMIT. Planlayıcı, sıralama sütunundaki indeksi geriye doğru tarayıp koşula uyan ilk 50 satırı çabucak bulacağını varsayabilir. Koşula uyan satırlar tablonun sonunda değil başındaysa milyonlarca satır okunur. Planda Index Scan Backward ve büyük bir Rows Removed by Filter görürseniz çözüm genellikle filtre ve sıralama sütunlarını birlikte içeren bir indekstir, örneğin (customer_id, created_at).

Tuzaklar

Geliştirme veritabanında plan okumak. Planlayıcının kararı tablo boyutuna ve veri dağılımına bağlıdır. Birkaç bin satırlık bir tabloda sıralı tarama doğru seçimdir; aynı sorgu üretimde başka bir plan alır. Planı üretimde ya da üretimle aynı boyutta ve dağılımda bir kopyada okuyun.

Hazırlıklı deyimlerde genel plan. Sürücüler sorguları çoğunlukla hazırlıklı deyim olarak gönderir. PostgreSQL ilk birkaç çalıştırmada parametreye özel plan kurar, sonra maliyeti benzer görünürse parametreden bağımsız genel plana geçebilir. Çarpık veride bu genel plan bazı parametreler için felakettir ve elle EXPLAIN ile yeniden üretemezsiniz, çünkü elle yazdığınız sorgu sabit değerli olduğu için özel plan alır. Şüpheleniyorsanız plan_cache_mode = force_custom_plan ayarını oturum düzeyinde deneyip farkı ölçün.

Üretimde ANALYZE'ı her yerde açmak. auto_explain, belirli bir sürenin üstündeki sorguların planını günlüğe yazar ve üretimdeki planı görmenin en dürüst yoludur. Ancak auto_explain.log_analyze açıksa her sorgu için zamanlama toplanır ve bu, eşiğin altında kalan sorgular dahil ek yük getirir. Önce yalnızca auto_explain.log_min_duration ile tahmini planları toplayın, gerçek sayılara ihtiyaç olduğunda kısa bir süre için log_analyze açın.

Tek sorguyu düzeltip yükü unutmak. Bir sorgunun süresini yarıya indirmek, pg_stat_statements sıralamasında onuncu sıradaysa toplam yükü pek değiştirmez. Değişiklikten önce ve sonra toplamı karşılaştırın.

Bu yol ne zaman yanlış yoldur

Sorgunun kendisi hızlı ama calls sayısı istek başına yüzlerse sorun veritabanında değil uygulamadadır: toplu getirme ya da birleştirme gerekir. Bekleme süresi sorgu yürütmesinde değil kilit beklemesindeyse EXPLAIN hiçbir şey göstermez; pg_stat_activity içindeki wait_event_type ve pg_locks bakılacak yerdir. Bağlantı kurma ve havuz kuyruğu da sorgu süresine dahil edilmez. Kısacası EXPLAIN bir sorgunun neden yavaş olduğunu söyler; uygulamanın neden yavaş olduğunu söylemesi için önce o sorgunun gerçekten suçlu olduğunu ölçmüş olmanız gerekir.