Slow Log Analizi ile Redis Performans Sorunlarını Tespit Etme

yazar

Redis cluster’ınızda bir şeyler ters gidiyor. Uygulamanız yavaşladı, kullanıcılar şikayet ediyor ve siz de gecenin köründe terminale bakıyorsunuz. “Redis mi yavaş, uygulama mı?” sorusunu sormak yerine, Redis’in size sunduğu en değerli araçlardan biri olan Slow Log mekanizmasını kullanarak sorunu doğrudan kaynağından tespit edebilirsiniz.

Redis Slow Log Nedir?

Redis, belirli bir sürenin üzerinde çalışan komutları otomatik olarak kaydeden dahili bir loglama mekanizmasına sahiptir. Bu mekanizmaya Slow Log denir. Bir veritabanı sorgusunu yavaş sorgu logu ile analiz etmek nasıl bir şeyse, Redis Slow Log da tam olarak aynı mantıkla çalışır.

Slow Log’un en güzel tarafı, disk I/O yapmadan bellekte tutulmasıdır. Bu sayede performansa ek yük bindirmeden yavaş komutları yakalayabilirsiniz. Loglar dairesel bir buffer’da tutulur, yani yapılandırdığınız maksimum kayıt sayısına ulaşıldığında en eski kayıtlar silinir ve yenileri eklenir.

Her slow log kaydı şu bilgileri içerir:

  • ID: Sıralı benzersiz tanımlayıcı
  • Timestamp: Komutun çalıştığı zaman damgası (Unix timestamp)
  • Execution Time: Mikrosaniye cinsinden çalışma süresi
  • Command: Çalıştırılan komut ve argümanları
  • Client IP/Port: Komutu gönderen istemcinin adresi
  • Client Name: Varsa istemci adı

Slow Log Yapılandırması

Temel Parametreler

Redis Slow Log’u yapılandırmak için iki temel parametre vardır:

slowlog-log-slower-than: Mikrosaniye cinsinden eşik değeri. Bu değerin üzerinde çalışan komutlar loglanır. Varsayılan değer 10.000 mikrosniye, yani 10 milisaniyedir.

slowlog-max-len: Buffer’da tutulacak maksimum kayıt sayısı. Varsayılan değer 128’dir.

Bu değerleri redis.conf dosyasında kalıcı olarak ayarlayabilirsiniz:

# /etc/redis/redis.conf dosyasını düzenle
sudo nano /etc/redis/redis.conf

# Şu satırları bul ve ayarla:
slowlog-log-slower-than 5000
slowlog-max-len 256

Ya da çalışan Redis instance’ında dinamik olarak değiştirebilirsiniz:

# Redis CLI'a bağlan
redis-cli -h 127.0.0.1 -p 6379

# Eşik değerini 5ms olarak ayarla
CONFIG SET slowlog-log-slower-than 5000

# Buffer boyutunu artır
CONFIG SET slowlog-max-len 256

# Mevcut ayarları kontrol et
CONFIG GET slowlog-log-slower-than
CONFIG GET slowlog-max-len

Geçici Olarak Tüm Komutları Loglama

Sorun tespiti sırasında geçici olarak tüm komutları loglamak isteyebilirsiniz. Bu durumda eşik değerini 0 veya negatif yapabilirsiniz:

# Tüm komutları logla (dikkatli kullan, buffer hızla dolar)
redis-cli CONFIG SET slowlog-log-slower-than 0

# Slow log'u devre dışı bırak
redis-cli CONFIG SET slowlog-log-slower-than -1

Üretim ortamında bu ayarı uzun süre aktif bırakmayın. Buffer dolduğunda eski kayıtlar silinir ve gerçekten önemli bilgileri kaçırabilirsiniz.

Slow Log Verilerini Okuma ve Analiz

Temel Komutlar

# Son 10 slow log kaydını getir
redis-cli SLOWLOG GET 10

# Tüm slow log kayıtlarını getir
redis-cli SLOWLOG GET

# Toplam kayıt sayısını öğren
redis-cli SLOWLOG LEN

# Slow log'u temizle (yeni analiz başlatmadan önce)
redis-cli SLOWLOG RESET

SLOWLOG GET komutunun çıktısı şöyle görünür:

127.0.0.1:6379> SLOWLOG GET 3
1) 1) (integer) 14          # Log ID
   2) (integer) 1699876543  # Unix timestamp
   3) (integer) 18523        # Mikrosaniye cinsinden süre
   4) 1) "KEYS"             # Komut
      2) "user:*"           # Argüman
   5) "127.0.0.1:52341"     # İstemci adresi
   6) ""                     # İstemci adı
2) 1) (integer) 13
   2) (integer) 1699876501
   3) (integer) 12841
   4) 1) "SMEMBERS"
      2) "large:set:key"
   5) "10.0.0.5:44213"
   6) "worker-3"

İnsan Tarafından Okunabilir Format

Unix timestamp’leri elle çevirmek zahmetlidir. Şu bash scripti ile daha okunabilir bir çıktı elde edebilirsiniz:

#!/bin/bash
# redis_slowlog_parser.sh

REDIS_HOST=${1:-127.0.0.1}
REDIS_PORT=${2:-6379}
LIMIT=${3:-20}

echo "=== Redis Slow Log Analizi ==="
echo "Host: $REDIS_HOST:$REDIS_PORT"
echo "Son $LIMIT kayıt gösteriliyor"
echo "================================"

redis-cli -h $REDIS_HOST -p $REDIS_PORT SLOWLOG GET $LIMIT | 
while read line; do
    echo "$line"
done

echo ""
echo "Toplam slow log kaydı: $(redis-cli -h $REDIS_HOST -p $REDIS_PORT SLOWLOG LEN)"

Python ile Gelişmiş Analiz

Gerçek dünyada slow log verilerini daha sofistike şekilde analiz etmek isteyebilirsiniz:

#!/usr/bin/env python3
# redis_slowlog_analyzer.py

import redis
from datetime import datetime
from collections import Counter

def analyze_slowlog(host='127.0.0.1', port=6379, password=None, limit=100):
    client = redis.Redis(host=host, port=port, password=password, decode_responses=True)
    
    entries = client.slowlog_get(limit)
    
    if not entries:
        print("Slow log boş veya kayıt yok.")
        return
    
    command_stats = Counter()
    total_time = 0
    
    print(f"{'ID':<6} {'Tarih':<22} {'Süre(ms)':<12} {'Komut':<50}")
    print("-" * 90)
    
    for entry in entries:
        log_id = entry['id']
        timestamp = datetime.fromtimestamp(entry['start_time'])
        duration_ms = entry['duration'] / 1000
        command_parts = entry['command']
        command_str = ' '.join(str(c) for c in command_parts[:3])
        
        # İlk kelime komut adı
        cmd_name = str(command_parts[0]).upper() if command_parts else 'UNKNOWN'
        command_stats[cmd_name] += 1
        total_time += entry['duration']
        
        # Uzun komutları kırp
        if len(command_str) > 47:
            command_str = command_str[:47] + "..."
        
        print(f"{log_id:<6} {str(timestamp):<22} {duration_ms:<12.2f} {command_str:<50}")
    
    print("n=== Komut İstatistikleri ===")
    for cmd, count in command_stats.most_common():
        print(f"  {cmd}: {count} kez")
    
    print(f"nOrtalama yavaş komut süresi: {(total_time / len(entries)) / 1000:.2f} ms")
    print(f"En yavaş komut: {max(e['duration'] for e in entries) / 1000:.2f} ms")

if __name__ == '__main__':
    analyze_slowlog()

Gerçek Dünya Senaryoları

Senaryo 1: KEYS Komutu Felaketi

Bir e-ticaret uygulamasında her ürün güncellemesinde aşağıdaki pattern kullanılıyordu:

# Geliştirici bu kodu yazmıştı:
# KEYS product:*:cache

# Slow log bunu gösteriyordu:
1) (integer) 89
   3) (integer) 340000   # 340ms! Ürün sayısı arttıkça bu değer büyüyordu
   4) 1) "KEYS"
      2) "product:*:cache"

KEYS komutu O(N) karmaşıklığıyla tüm keyspace’i tarar ve Redis’i bloklar. 500.000 key olan bir veritabanında bu komut 300-400ms sürebilir. Çözüm SCAN komutunu kullanmaktır:

# Kötü yöntem - asla production'da kullanma
KEYS product:*

# İyi yöntem - SCAN ile cursor tabanlı iterasyon
SCAN 0 MATCH product:* COUNT 100

# Tüm eşleşenleri bulmak için bash döngüsü
cursor=0
while true; do
    result=$(redis-cli SCAN $cursor MATCH "product:*" COUNT 100)
    cursor=$(echo "$result" | head -1)
    keys=$(echo "$result" | tail -n +2)
    echo "$keys"
    [ "$cursor" -eq 0 ] && break
done

Senaryo 2: Büyük Set Operasyonları

Bir kullanıcı segmentasyon sistemi, milyonlarca kullanıcı ID’si içeren setleri birleştiriyordu:

# Slow log kaydı:
4) 1) "SUNIONSTORE"
   2) "temp:segment:result"
   3) "segment:18-25:male"
   4) "segment:18-25:female"
   5) "segment:26-35:male"

# Süre: 2.3 saniye!

Bu tür büyük set operasyonlarını tespit ettikten sonra çözüm, operasyonu parçalara bölmek ve arka planda çalıştırmaktı:

# Büyük set boyutlarını kontrol et
redis-cli SCARD segment:18-25:male
redis-cli SCARD segment:18-25:female

# Memory kullanımını da kontrol et
redis-cli MEMORY USAGE segment:18-25:male
redis-cli MEMORY USAGE segment:26-35:male

Senaryo 3: Büyük Hash Yapıları

Bir CRM uygulaması, kullanıcı profillerini tek bir hash içinde saklıyordu ve her profil 500’den fazla alan içeriyordu:

# Sorunlu komut
redis-cli HGETALL user:profile:123456

# Slow log bu kaydı sürekli gösteriyordu
3) (integer) 8500   # 8.5ms
4) 1) "HGETALL"
   2) "user:profile:123456"

Çözüm olarak HGETALL yerine sadece ihtiyaç duyulan alanları HMGET ile çekmek:

# Kötü - tüm 500 alanı çekiyor
HGETALL user:profile:123456

# İyi - sadece ihtiyaç duyulan 3 alanı çekiyor
HMGET user:profile:123456 name email last_login

Otomatik Slow Log İzleme

Cron ile Düzenli Raporlama

#!/bin/bash
# /usr/local/bin/redis_slowlog_monitor.sh

REDIS_CLI="redis-cli -h 127.0.0.1 -p 6379"
LOG_FILE="/var/log/redis/slowlog_report.log"
ALERT_THRESHOLD=5  # 5'ten fazla slow log varsa uyar
MAIL_TO="[email protected]"

SLOW_COUNT=$($REDIS_CLI SLOWLOG LEN)
TIMESTAMP=$(date '+%Y-%m-%d %H:%M:%S')

echo "[$TIMESTAMP] Slow log kayıt sayısı: $SLOW_COUNT" >> $LOG_FILE

if [ "$SLOW_COUNT" -gt "$ALERT_THRESHOLD" ]; then
    REPORT=$($REDIS_CLI SLOWLOG GET 10)
    echo "[$TIMESTAMP] UYARI: $SLOW_COUNT adet yavaş komut tespit edildi" >> $LOG_FILE
    echo "[$TIMESTAMP] Son 10 kayıt:" >> $LOG_FILE
    echo "$REPORT" >> $LOG_FILE
    
    # Mail gönder (mailutils kurulu olmalı)
    echo -e "Redis Slow Log UyarısınnTespit edilen yavaş komut sayısı: $SLOW_COUNTnnSon 10 kayıt:n$REPORT" | 
        mail -s "Redis Slow Log Uyarısı - $(hostname)" $MAIL_TO
    
    # Log'u temizle, yeni dönem başlat
    $REDIS_CLI SLOWLOG RESET
fi
# Crontab'a ekle - her 5 dakikada bir çalıştır
crontab -e
# Şu satırı ekle:
# */5 * * * * /usr/local/bin/redis_slowlog_monitor.sh

Slow Log ile Birlikte Kullanılacak Diğer Araçlar

Redis INFO Komutu ile Korelasyon

Slow log analizini INFO komutuyla desteklemek, sorunun tam resmini görmenizi sağlar:

# Genel istatistikler
redis-cli INFO stats | grep -E "rejected_connections|evicted_keys|keyspace_hits|keyspace_misses"

# Memory durumu
redis-cli INFO memory | grep -E "used_memory_human|mem_fragmentation_ratio|maxmemory"

# İstemci bağlantı bilgileri
redis-cli INFO clients

# Keyspace bilgisi
redis-cli INFO keyspace

# Persistence durumu
redis-cli INFO persistence | grep -E "rdb_last_bgsave_status|aof_last_write_status"

MONITOR Komutu ile Anlık İzleme

Kısa süreli anlık izleme için MONITOR kullanabilirsiniz. Dikkat edin, bu komut ciddi performans etkisi yaratır:

# Sadece 10 saniye izle ve kaydet (production'da dikkatli kullan!)
timeout 10 redis-cli MONITOR > /tmp/redis_monitor.log 2>&1

# En çok kullanılan komutları bul
cat /tmp/redis_monitor.log | awk '{print $3}' | sort | uniq -c | sort -rn | head -20

Latency Monitoring

Redis 2.8.13+ ile gelen latency monitoring özelliği, slow log’u tamamlar:

# Latency izlemeyi aktif et
redis-cli CONFIG SET latency-monitor-threshold 1

# Latency geçmişini görüntüle
redis-cli LATENCY HISTORY event

# Son latency olaylarını listele
redis-cli LATENCY LATEST

# Latency grafiği (ASCII)
redis-cli LATENCY GRAPH event

Yaygın Sorunlar ve Çözüm Kalıpları

Slow log analizinde en sık karşılaşılan sorunlar ve çözümleri:

  • KEYS, SMEMBERS, HGETALL ile büyük veri yapıları: Bu komutlar O(N) karmaşıklığındadır. SCAN, SSCAN, HSCAN ile cursor tabanlı alternatiflere geçin.
  • Büyük değerler (Large Values): 1MB üzerindeki değerler ağ gecikmesine ve serialization süresine yol açar. Veriyi parçalara bölün veya sıkıştırın.
  • Bağlantı havuzu yetersizliği: Her istek için yeni bağlantı açmak overhead yaratır. Connection pooling kullanın.
  • Uygunsuz veri yapısı seçimi: Liste ile yapılan üyelik sorguları Set ile yapılandan çok daha yavaştır. Kullanım senaryonuza uygun veri yapısı seçin.
  • Pipeline kullanmamak: Çok sayıda ayrı komut yerine pipeline ile toplu işlem yapın.
  • Büyük Lua scriptleri: Uzun çalışan Lua scriptleri Redis’i bloklar. Scriptleri optimize edin veya bölün.

Slow Log Analiz Metodolojisi

Sistematik bir yaklaşım için şu adımları takip edin:

  • Baseline oluşturun: Normal yük altında slow log’u birkaç gün boyunca izleyin. Ne sıklıkta ve hangi komutlar görünüyor?
  • Eşik değerini kademeli düşürün: 10ms’den başlayın, 5ms, 2ms, 1ms şeklinde azaltarak sorunların nerede kümelendiğini görün.
  • Komut dağılımını analiz edin: Hangi komutlar en sık slow log’a düşüyor? Bu komutların kodda nereden çağrıldığını bulun.
  • Zaman korelasyonu yapın: Slow log timestamp’leri ile uygulama loglarını, sistem metriklerini ve kullanıcı şikayetlerini karşılaştırın.
  • Değişiklik sonrası doğrulama: Optimizasyon yaptıktan sonra slow log’u sıfırlayın ve yeni verileri izleyin.

Sonuç

Redis Slow Log, performans sorunlarını tespit etmek için sahip olduğunuz en değerli araçlardan biridir. Sıfır ek yapılandırma gerektirmesi ve minimal performans etkisi ile her Redis kurulumunda aktif olmalıdır.

Özetlemek gerekirse: eşik değerini üretim ortamınıza göre ayarlayın (genellikle 5-10ms iyi bir başlangıç noktasıdır), buffer boyutunu yeterince büyük tutun (256-1024 arası), ve slow log verilerini düzenli olarak analiz eden otomatik scriptler kurun. KEYS, SMEMBERS, HGETALL gibi O(N) komutların büyük veri setlerinde ortaya çıkması en yaygın sorun kaynağıdır ve bunların cursor tabanlı alternatifleri genellikle sorunu hızlıca çözer.

Gece yarısı pager’ınızın çalması yerine, sabah kahvenizi içerken slow log raporunuzu gözden geçirmeyi tercih ederseniz, bu yazıdaki adımları takip etmek sizi o noktaya götürecektir.

Yorum yapın