Yavaş MySQL sorgusunu slow query log ile bulma

Site Linux hosting üzerinde yavaşladı, TTFB 200 milisaniyeden 3 saniyeye çıktı ve bunu hangi sorgunun yaptığını hâlâ bilmiyorsunuz. Sadece CPU ve RAM'e bakarsanız, asla cevap alamazsınız. Doğru araç slow query log'dur; yani MySQL'in kendisinin yazdığı ve çoğu yöneticinin asla açmadığı şey.

Önce slow query log'un açık olup olmadığına bakın

my.cnf üzerinde herhangi bir değişiklik yapmadan önce, MySQL'in kendisine sorun:

SHOW VARIABLES LIKE 'slow_query_log%';
SHOW VARIABLES LIKE 'long_query_time';
SHOW VARIABLES LIKE 'log_output';

Eğer slow_query_log OFF ise, bugüne kadar hiç veriniz olmamış demektir ve sıfırdan başlamanız gerekir. long_query_time değeri de genellikle varsayılan olarak 10 saniyedir ki bu bir WordPress sitesi için pratikte işe yaramaz; hiçbir sorgu 10 saniye sürmez, ama binlerce 300 milisaniyelik sorgu siteyi çökertir.

Yeniden başlatmadan etkinleştirme

Hemen şimdi başlamak ve servisi kesmemek için:

SET GLOBAL slow_query_log = 'ON';
SET GLOBAL long_query_time = 0.5;
SET GLOBAL log_output = 'TABLE';

0.5 saniye iyi bir başlangıç noktasıdır. Eğer trafik yüksekse ve log patlıyorsa, 1'e çıkarın. Eğer site küçükse ve ayrıntı arıyorsanız, 0.2 de mantıklıdır. log_output = 'TABLE' ile çıktı mysql.slow_log tablosuna düşer ve SQL ile sorgulanabilir. Eğer FILE yaparsanız, log dosyasına yazar ki bu büyük hacimli analiz için daha iyidir ama okuması daha manueldir.

Bu ayarlar MySQL yeniden başlatıldığında silinir. Kalıcı hale getirmek için, yapılandırma dosyasının [mysqld] bölümüne yazın:

[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 0.5
log_queries_not_using_indexes = 0

O son satır önemlidir. log_queries_not_using_indexes'i çoğu kişi 1 yapar çünkü onlara göre "indekssiz her sorguyu yakala" demektir. Pratikte WordPress sitelerinde, wp_options gibi birkaç yüz satırlık küçük tabloları da loglar ve log dosyası birkaç saat içinde gigabaytlara ulaşır. Ben varsayılan olarak 0 bırakırım ve sadece belirli bir kalıp aradığımda açarım.

Çıktıyı okuma: hangi satır önemli

Her log girdisinde işinize yarayacak üç şey vardır: çalışma süresi, MySQL'in incelediği satır sayısı ve sorgunun kendisi. Gerçek bir örnek:

# Time: 2024-05-11T09:14:22.318471Z
# User@Host: wpuser[wpuser] @ localhost []
# Query_time: 4.812301  Lock_time: 0.000142  Rows_sent: 12  Rows_examined: 184320
SET timestamp=1715418862;
SELECT * FROM wp_postmeta WHERE meta_key = '_thumbnail_id' ORDER BY meta_value LIMIT 12;

Rows_examined: 184320 sayısının Rows_sent: 12 karşısındaki değeri tüm hikâyeyi anlatır. MySQL on iki satır vermek için yüz seksen bin satır okumuş. Asıl ölçüt çalışma süresi değil, bu orandır. Query_time'ı yarım saniye ama oranı 15000'e 1 olan bir sorgu, eşzamanlı yük altında 2'ye 1 oranlı iki saniyelik bir sorgudan çok daha hızlı siteyi çökertir.

Eğer çıktı tabloda ise, bu sıralama sorgusunu çalıştırın:

SELECT sql_text, query_time, rows_examined, rows_sent
FROM mysql.slow_log
ORDER BY rows_examined DESC
LIMIT 20;

query_time yerine rows_examined'e göre sıralamak, genellikle kök nedene daha hızlı ulaştırır.

EXPLAIN: indeks eklemeden önce bakın

Şüpheli sorguyu alın ve önüne EXPLAIN koyun:

EXPLAIN SELECT * FROM wp_postmeta
WHERE meta_key = '_thumbnail_id'
ORDER BY meta_value LIMIT 12;

Çıktıda type ve key sütunlarına bakın. Eğer type ALL ise, tam tablo taraması var demektir. Eğer key boşsa, hiçbir indeks kullanılmamış. rows sütunu kaç satır okunacağını tahmin eder ve eğer gerçek Rows_examined ile uyuşmuyorsa, tablo istatistikleri eskimiştir ve ANALYZE TABLE wp_postmeta; gerekir.

Doğru indeks, herhangi bir indeks değil

Yukarıdaki sorgu için, meta_key üzerinde tek sütunlu bir indeks yeterli değildir çünkü ORDER BY meta_value de var. Bileşik indeks cevap verir:

ALTER TABLE wp_postmeta ADD INDEX idx_key_value (meta_key, meta_value(20));

Bileşik indekste sütun sırası önemlidir. Eğer ters yazarsanız, MySQL bunu sıralama için kullanamaz ve tekrar filesort alırsınız. O (20) de bir önektir; longtext sütunu üzerinde önek olmadan indeks oluşturamazsınız ve ERROR 1170 (42000): BLOB/TEXT column used in key specification without a key length hatası alırsınız.

İşte burada hata yapıyorlar: indeks olmaması her zaman neden değildir

En sık gördüğüm hata şudur: site yöneticisi logu açar, Rows_examined'i yüksek bir sorgu görür, hemen indeks ekler ve site hâlâ yavaştır. İşareti de şudur: indeksten sonra EXPLAIN key'i dolu gösterir ama çalışma süresi değişmemiştir.

Bu durumun arkasındaki üç gerçek neden:

• Tabloda kilitlenme. Eğer logda Lock_time yüksekse, sorun okuma hızı değil kilit rekabetidir. Uzun bir işlem, diğerlerini kuyrukta tutuyor.
• N+1 sorgusu. Her biri long_query_time eşiğinin altında olan binlerce 5 milisaniyelik sorgu, loga asla girmez ama toplamları siteyi çökertir. Burada long_query_time'ı geçici olarak 0 yapmalı veya performance_schema kullanmalısınız.
• Diskten veri transferi. SELECT * yapan ve ağır sütunları döndüren bir sorgu, doğru indeksle bile disk IO'sunu doyurur. Eğer SATA diskli bir Linux hosting üzerindeyseniz ve iostat %util'in 90'ın üzerinde olduğunu gösteriyorsa, sorun indeks değildir.

İkinci noktayı ciddiye alın. 15 eklentili bir WordPress kurulumunda, bir sayfa render'ında 800 sorgu görmek tamamen normaldir ve hiçbiri slow query log'a girmez. Eğer log boşsa ama site yavaşsa, sorun başka bir yerdedir; WordPress wp-cron'u kontrol edin, çünkü cron'un kullanıcı isteğiyle eşzamanlı çalışması ani veritabanı piklerinin en yaygın nedenlerinden biridir.

Kabul etmeniz gereken maliyet

Slow query log'u açmak bedava değildir. Her sorgu zamanlanmalı ve I/O'ya yazılmalıdır. Ağır yük altında, log_output = 'FILE' ve yavaş disk ile logun kendisi throughput'un yüzde 5 ila 10'unu yiyebilir. Bu yüzden ben onu hiçbir zaman yüksek trafikli bir sunucuda kalıcı olarak açık bırakmam. Kalıp şudur: açın, 24 saat veri toplayın, analiz edin, kapatın. Gerekirse gelecek hafta tekrar.

Analiz için, Percona araç setinden pt-query-digest insan gözünden çok daha iyi çalışır:

pt-query-digest /var/log/mysql/slow.log > /tmp/report.txt

Çıktısı sorguları tek tek çalıştırmalara göre değil, toplam harcanan zamana göre sıralar. Bu tam olarak istediğiniz şeydir.

Sık sorulan sorular

Slow query log neden boş ama site yavaş?

Çünkü muhtemelen long_query_time çok yüksektir veya sorun sorgudan değildir. Değeri 0.2 yapın ve bir saat bekleyin. Eğer hâlâ boşsa, sorun başka bir katmandadır: tablo kilidi, N+1 sorguları veya disk I/O doygunluğu.

İndeks eklemek sorguyu her zaman hızlandırır mı?

Hayır. Düşük kardinaliteye sahip sütunlarda (üç değerli durum sütunu gibi) indeks neredeyse işe yaramaz ve sadece yazma maliyetini artırır. Ayrıca her ek indeks, INSERT ve UPDATE hızını düşürür. İndeksi tahminle değil, öncesi ve sonrasıyla EXPLAIN ile ölçün.

log_output'un TABLE ve FILE arasındaki farkı nedir?

TABLE modunda çıktı mysql.slow_log tablosuna düşer ve SQL ile filtrelenip sıralanabilir, ama ağır yük altında kendisi rekabet yaratır. FILE modunda yazma daha hafiftir ve pt-query-digest gibi araçlarla analiz için daha uygundur. Kısa süreli sorun giderme için TABLE daha rahattır, yüksek trafikli sunucu için FILE.

Yavaş sorgunun WordPress'in kendisinden mi yoksa bir eklentiden mi geldiğini nasıl anlarım?

Sorgudaki tablo adlarına bakın. wp_options ve wp_postmeta tabloları genellikle eklenti veya tema demektir. Emin olmak için, eklentileri tek tek devre dışı bırakın ve her değişiklikten sonra logu temizleyin ki hangi sorgunun kaybolduğunu görün. Hız testi ve sunucu durumunu kontrol etmek için hazır bir araç arıyorsanız, ServerNet ücretsiz araçları iyi bir başlangıç noktasıdır.

Eğer bu adımlardan sonra darboğazın sorgudan değil sunucunun kendisinden olduğu ortaya çıkarsa, daha uygun kaynaklara sahip Linux hosting düşünmenin zamanı gelmiştir. WordPress siteleri için de optimize edilmiş MySQL ayarlarına sahip WordPress hosting genellikle daha az sorun çıkarır.

Hemen şimdi bu iki satırı çalıştırın: SET GLOBAL slow_query_log = 'ON'; ve SET GLOBAL long_query_time = 0.5;. Yarın sabah logu açın ve Query_time'a değil, Rows_examined sütununa bakın.