Yavaş Sorguları Tespit Etme: MySQL Slow Query Log Kullanımı

yazar

Veritabanı performans sorunlarıyla uğraşan her sistem yöneticisinin eninde sonunda karşılaştığı o klasik senaryo: Uygulama yavaşlamış, kullanıcılar şikayet ediyor, geliştirici ekip “bizim kodda sorun yok” diyor ve sen ortada kalıyorsun. İşte tam bu noktada MySQL ve MariaDB’nin Slow Query Log özelliği hayat kurtarıcı oluyor. Bu yazıda slow query log’u nasıl aktif edeceğimizi, nasıl okuyacağımızı ve elde ettiğimiz verilerle ne yapacağımızı gerçek dünya senaryolarıyla ele alacağız.

Slow Query Log Nedir ve Neden Önemlidir?

Slow query log, MySQL ve MariaDB’nin belirli bir sürenin üzerinde çalışan SQL sorgularını otomatik olarak kaydettiği bir loglama mekanizmasıdır. Varsayılan olarak devre dışı gelir ve aktif etmek için birkaç basit adım yeterlidir.

Neden bu kadar önemli? Çünkü bir production ortamında saniyede yüzlerce sorgu çalışıyor olabilir. Hangi sorgunun probleme yol açtığını tahmin etmeye çalışmak yerine, veritabanının bizzat işaret ettiği sorgulara odaklanmak çok daha verimli bir yaklaşım. Özellikle şu durumlarda slow query log olmadan iş yapmak neredeyse imkansız hale gelir:

  • Yüksek CPU kullanımı ama nedeni belirsiz
  • Spesifik saatlerde yavaşlayan uygulama (genellikle raporlama sorguları)
  • Yeni bir özellik deploy’undan sonra ortaya çıkan performans düşüşleri
  • Index eksikliğinden kaynaklanan full table scan’ler

Slow Query Log’u Aktif Etme

Çalışan Sistemde Dinamik Olarak Aktif Etme

Production ortamında MySQL’i restart etmeden slow query log’u açabilirsiniz. Bu, özellikle 7/24 çalışan sistemlerde büyük kolaylık sağlar.

mysql -u root -p -e "
SET GLOBAL slow_query_log = 'ON';
SET GLOBAL slow_query_log_file = '/var/log/mysql/slow-queries.log';
SET GLOBAL long_query_time = 1;
SET GLOBAL log_queries_not_using_indexes = 'ON';
"

Burada long_query_time parametresi saniye cinsinden eşik değerini belirler. 1 saniyenin üzerindeki sorgular loglanacak demektir. Bunu 0.5 veya hatta 0.1 olarak ayarlayabilirsiniz, ancak çok düşük değerler log dosyasını hızla şişirebilir.

Ayarların aktif olduğunu doğrulamak için:

mysql -u root -p -e "
SHOW VARIABLES LIKE 'slow_query_log%';
SHOW VARIABLES LIKE 'long_query_time';
SHOW VARIABLES LIKE 'log_queries_not_using_indexes';
"

my.cnf ile Kalıcı Yapılandırma

Dinamik ayarlar restart sonrasında sıfırlanır. Kalıcı yapılandırma için /etc/mysql/mysql.conf.d/mysqld.cnf veya /etc/my.cnf dosyasını düzenleyin:

# /etc/mysql/mysql.conf.d/mysqld.cnf
[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow-queries.log
long_query_time = 1
log_queries_not_using_indexes = 1
log_slow_admin_statements = 1
min_examined_row_limit = 100

Önemli parametreler:

  • slow_query_log: Log mekanizmasını açar/kapatır
  • slow_query_log_file: Log dosyasının tam yolu
  • long_query_time: Saniye cinsinden eşik değeri (ondalıklı da olabilir, örn: 0.5)
  • log_queries_not_using_indexes: Index kullanmayan sorgular 1 saniyenin altında olsa bile loglanır
  • log_slow_admin_statements: ALTER TABLE, ANALYZE TABLE gibi admin işlemlerini de loglar
  • min_examined_row_limit: Belirtilen satır sayısının altında incelenen sorgular loglanmaz

Log dizininin MySQL kullanıcısına ait olduğunu kontrol edin:

mkdir -p /var/log/mysql
chown mysql:mysql /var/log/mysql
chmod 750 /var/log/mysql

# MariaDB için restart
systemctl restart mariadb
# veya MySQL için
systemctl restart mysql

Log Dosyasını Manuel Okumak

Slow query log dosyası düz metin formatındadır ve doğrudan okunabilir. Tipik bir kayıt şu şekilde görünür:

tail -n 50 /var/log/mysql/slow-queries.log

Çıktı şuna benzer bir şey olacaktır:

# Time: 2024-01-15T14:23:45.123456Z
# User@Host: appuser[appuser] @ webapp-01 [10.0.1.15]
# Query_time: 4.523891  Lock_time: 0.000102  Rows_sent: 1  Rows_examined: 847293
SET timestamp=1705329825;
SELECT * FROM orders WHERE customer_email = '[email protected]' ORDER BY created_at DESC;

Bu çıktıyı okumayı bilmek çok önemli:

  • Query_time: Sorgunun toplam çalışma süresi (saniye)
  • Lock_time: Kilidi bekleme süresi
  • Rows_sent: İstemciye gönderilen satır sayısı
  • Rows_examined: Sorgunun taradığı toplam satır sayısı

Yukarıdaki örnekte 1 satır döndürmek için 847.293 satır taranmış. Bu neredeyse her zaman eksik bir index’e işaret eder.

mysqldumpslow ile Analiz

MySQL’in kendi araçlarından biri olan mysqldumpslow, ham log dosyasını parse ederek benzer sorguları gruplar ve özet bilgi sunar.

# En yavaş 10 sorguyu listele
mysqldumpslow -s t -t 10 /var/log/mysql/slow-queries.log

# En çok tekrar eden sorguları listele
mysqldumpslow -s c -t 10 /var/log/mysql/slow-queries.log

# En fazla satır okuyan sorguları listele
mysqldumpslow -s r -t 10 /var/log/mysql/slow-queries.log

# Belirli bir pattern için filtrele
mysqldumpslow -s t -t 5 -g "SELECT.*orders" /var/log/mysql/slow-queries.log

Sıralama seçenekleri:

  • -s t: Toplam süreye göre sırala
  • -s at: Ortalama süreye göre sırala
  • -s c: Çalışma sayısına göre sırala
  • -s r: İncelenen satır sayısına göre sırala
  • -s ar: Ortalama incelenen satır sayısına göre sırala

Örnek çıktı:

Count: 1523  Time=3.45s (5255s)  Lock=0.00s (0s)  Rows=10.0 (15230), appuser[appuser]@webapp-01
  SELECT * FROM products WHERE category_id = N AND active = N ORDER BY price LIMIT N, N

Bu çıktı bize şunu söylüyor: Bu sorgu 1523 kez çalışmış, toplamda 5255 saniye CPU zamanı tüketmiş ve ortalama 3.45 saniye sürüyor. Production ortamında bu türden bir bulgu, hemen aksiyon alınması gereken kritik bir durumdur.

pt-query-digest ile Daha Derin Analiz

Percona Toolkit’in bir parçası olan pt-query-digest, mysqldumpslow’dan çok daha detaylı analiz sunar. Gerçek production ortamlarında bu araç tercih sebebidir.

# Percona Toolkit kurulumu (Debian/Ubuntu)
apt-get install percona-toolkit

# CentOS/RHEL için
yum install percona-toolkit

# Temel kullanım
pt-query-digest /var/log/mysql/slow-queries.log

# Son 1 saatin loglarını analiz et
pt-query-digest --since 3600 /var/log/mysql/slow-queries.log

# Belirli bir zaman aralığı
pt-query-digest 
  --since "2024-01-15 10:00:00" 
  --until "2024-01-15 12:00:00" 
  /var/log/mysql/slow-queries.log

# Sonuçları dosyaya kaydet
pt-query-digest /var/log/mysql/slow-queries.log > /tmp/query-report.txt

pt-query-digest çıktısı çok daha zengindir. Her sorgu için yüzdelik dilim bazında süre dağılımı, varyans, standart sapma gibi istatistiksel bilgiler sunar. Özellikle “pct 95” değeri yani sorgular içindeki en yavaş %5’lik dilim, gerçek kullanıcı deneyimini anlamak için kritik önem taşır.

Gerçek Dünya Senaryosu: E-Ticaret Sitesinde Yavaşlama

Şimdi gerçekçi bir senaryoya bakalım. Bir e-ticaret platformunda gece 02:00-04:00 arası ciddi yavaşlama şikayetleri geliyor. Slow query log aktif ve analiz ediyoruz:

# Gece yarısı time range için analiz
pt-query-digest 
  --since "2024-01-15 02:00:00" 
  --until "2024-01-15 04:00:00" 
  /var/log/mysql/slow-queries.log | head -100

Log’da şu sorguyu buluyoruz:

SELECT p.*, c.name as category_name, b.name as brand_name,
       AVG(r.rating) as avg_rating, COUNT(r.id) as review_count
FROM products p
LEFT JOIN categories c ON p.category_id = c.id
LEFT JOIN brands b ON p.brand_id = b.id
LEFT JOIN reviews r ON r.product_id = p.id
WHERE p.created_at > DATE_SUB(NOW(), INTERVAL 30 DAY)
GROUP BY p.id
ORDER BY avg_rating DESC;

Query_time 45 saniye, Rows_examined 12 milyon. Bu büyük ihtimalle gecenin belirli bir saatinde çalışan bir raporlama sorgusu. EXPLAIN ile analiz edelim:

mysql -u root -p -e "
EXPLAIN SELECT p.*, c.name as category_name, b.name as brand_name,
       AVG(r.rating) as avg_rating, COUNT(r.id) as review_count
FROM products p
LEFT JOIN categories c ON p.category_id = c.id
LEFT JOIN brands b ON p.brand_id = b.id
LEFT JOIN reviews r ON r.product_id = p.id
WHERE p.created_at > DATE_SUB(NOW(), INTERVAL 30 DAY)
GROUP BY p.id
ORDER BY avg_rating DESCG" mydb

EXPLAIN çıktısında type: ALL ve rows: 4200000 görüyoruz. Products tablosunda created_at üzerinde index yok. Çözüm:

-- Eksik index'i ekle
ALTER TABLE products ADD INDEX idx_created_at (created_at);

-- Reviews tablosunda da index kontrolü
ALTER TABLE reviews ADD INDEX idx_product_id (product_id);

Bu değişiklikten sonra aynı sorgu 0.3 saniyeye düşüyor. 45 saniyeden 0.3 saniyeye, sihir değil sadece doğru index.

Log Rotasyonu ve Yönetimi

Production ortamında slow query log dosyası hızla büyüyebilir. Logrotate ile bunu yönetmek şart:

# /etc/logrotate.d/mysql-slow dosyasını oluştur
cat > /etc/logrotate.d/mysql-slow << 'EOF'
/var/log/mysql/slow-queries.log {
    daily
    rotate 14
    compress
    delaycompress
    missingok
    notifempty
    create 640 mysql mysql
    postrotate
        if [ -f /var/run/mysqld/mysqld.pid ]; then
            mysql -u root -p$(cat /root/.mysql_password) 
              -e "SELECT SLEEP(0)" 2>/dev/null || true
            kill -HUP $(cat /var/run/mysqld/mysqld.pid) 2>/dev/null || true
        fi
    endscript
}
EOF

Alternatif olarak MySQL’in kendi flush mekanizmasını kullanabilirsiniz:

# Log dosyasını flush et (yeni dosya açılır)
mysql -u root -p -e "FLUSH SLOW LOGS;"

# Veya runtime'da log'u geçici kapat, truncate et, tekrar aç
mysql -u root -p -e "SET GLOBAL slow_query_log = 'OFF';"
> /var/log/mysql/slow-queries.log
mysql -u root -p -e "SET GLOBAL slow_query_log = 'ON';"

Performance Schema ile Entegrasyon

MySQL 5.6 ve sonrasında Performance Schema, slow query log’u tamamlayan güçlü bir araçtır. Slow query log’da gördüğünüz sorguları Performance Schema üzerinden de doğrulayabilirsiniz:

mysql -u root -p << 'EOF'
-- En çok zaman tüketen sorguları listele
SELECT
    SCHEMA_NAME,
    DIGEST_TEXT,
    COUNT_STAR as execution_count,
    ROUND(AVG_TIMER_WAIT/1000000000, 3) as avg_time_sec,
    ROUND(MAX_TIMER_WAIT/1000000000, 3) as max_time_sec,
    ROUND(SUM_TIMER_WAIT/1000000000, 3) as total_time_sec,
    SUM_ROWS_EXAMINED as total_rows_examined,
    SUM_ROWS_SENT as total_rows_sent
FROM performance_schema.events_statements_summary_by_digest
WHERE SCHEMA_NAME IS NOT NULL
ORDER BY SUM_TIMER_WAIT DESC
LIMIT 10;
EOF

Bu sorgu size son restart’tan bu yana toplam maliyeti en yüksek sorguları verir. Slow query log anlık olarak yavaş sorguları yakalarken, Performance Schema kümülatif istatistik tutar. İkisini birlikte kullanmak en doğru yaklaşım.

Monitoring ile Entegre Etme

Slow query log’u manuel kontrol etmek kısa vadeli çözüm. Uzun vadede bu süreci otomatize etmek gerekiyor. Basit bir bash script ile slow query sayısını izleyebilirsiniz:

#!/bin/bash
# /usr/local/bin/check-slow-queries.sh

THRESHOLD=50
LOG_FILE="/var/log/mysql/slow-queries.log"
ALERT_EMAIL="[email protected]"

# Son 5 dakikadaki slow query sayısını hesapla
FIVE_MIN_AGO=$(date -d "5 minutes ago" "+%Y-%m-%dT%H:%M:%S")

COUNT=$(awk -v since="$FIVE_MIN_AGO" '
/^# Time:/ {
    gsub(/# Time: /, "")
    gsub(/..+/, "")
    if ($0 >= since) counting=1
}
/^# Query_time:/ && counting {count++}
END {print count+0}
' "$LOG_FILE")

echo "Son 5 dakikada slow query sayisi: $COUNT"

if [ "$COUNT" -gt "$THRESHOLD" ]; then
    echo "UYARI: Son 5 dakikada $COUNT slow query tespit edildi!" | 
    mail -s "[KRITIK] MySQL Slow Query Artisi - $(hostname)" "$ALERT_EMAIL"
    
    # En son 20 slow query'yi de raporla
    tail -n 200 "$LOG_FILE" | 
    mail -s "[DETAY] Son Slow Queries - $(hostname)" "$ALERT_EMAIL"
fi

Bu scripti cron’a ekleyin:

# Crontab'a ekle
echo "*/5 * * * * root /usr/local/bin/check-slow-queries.sh" >> /etc/cron.d/mysql-monitoring

Sık Yapılan Hatalar ve Dikkat Edilecekler

Slow query log kullanırken bazı tuzaklara düşmemek için şunlara dikkat edin:

  • long_query_time = 0 ayarlamayın: Bu tüm sorguları loglar ve disk I/O’yu patlatır. Önce 2-3 saniyeden başlayın, ardından 1 saniyeye indirin.
  • log_queries_not_using_indexes özelliğini geliştirme ortamında aktif edin: Production’da bu parametre ile dikkatli olun, bazı sistemlerde kasıtlı olarak index kullanmayan basit sorgular da olabilir ve log çok büyüyebilir.
  • Sadece Query_time’a bakmayın: Rows_examined/Rows_sent oranı çok daha bilgi verici. 1000 satır tarayan ve 1000 satır döndüren sorgu normal, 1 milyon satır tarayan ve 10 satır döndüren sorgu sorunlu.
  • EXPLAIN’i ihmal etmeyin: Slow log’da bir sorgu gördüğünüzde mutlaka EXPLAIN veya EXPLAIN ANALYZE ile inceleyin. Bazen sorun index yokluğu değil, yanlış index seçimi olabilir.
  • Log dosyası izinlerine dikkat edin: MySQL kullanıcısının log dosyasına yazma yetkisi olmadığında sessizce log tutmayı bırakır, hata vermez. Bunu periyodik olarak kontrol edin.

Sonuç

Slow query log, veritabanı performans mühendisliğinin temel taşlarından biri. Aktif etmesi dakikalar alan bu basit mekanizma, saatler sürecek debug süreçlerini ortadan kaldırabilir. Önemli olan sadece log açmak değil, elde edilen veriyi sistematik şekilde analiz etmek.

Pratik bir yol haritası şu şekilde özetlenebilir: Slow query log’u aktif et ve long_query_time = 1 ile başla. Haftada bir pt-query-digest veya mysqldumpslow ile rapor al. Raporda öne çıkan sorguları EXPLAIN ile analiz et. Eksik index’leri ekle, verimsiz sorguları geliştirici ekiple revize et. Periyodik olarak bu döngüyü tekrarla.

Veritabanı optimizasyonu tek seferlik bir iş değil, sürekli yapılan bir süreç. Uygulamanız büyüdükçe, veri hacmi arttıkça bugün hızlı olan sorgu yarın yavaşlayabilir. Slow query log’u bir alışkanlık haline getirmek, production’da sürprizlerle karşılaşma olasılığını ciddi ölçüde azaltır. Ve bir sonraki “neden yavaş?” sorusunu aldığınızda, cevabınız hazır olacaktır.

Yorum yapın