ftrace — Kernel Fonksiyon Tracing

00 ftrace nedir — tracefs ve Mcount

ftrace, Linux kernel'ın yerleşik tracing altyapısıdır. Kaynak değişikliği gerektirmeden, çalışan bir kernel'da fonksiyon düzeyinde izleme yapmanı sağlar.

ftrace, kernel derleme zamanında eklenen Mcount instrumentation mekanizmasına dayanır. Derleyici (gcc -pg veya -mfentry), her fonksiyonun girişine küçük bir çağrı talimatı yerleştirir. ftrace etkin olmadığında bu talimatlar NOP (no-operation) olarak çalışır — performans etkisi ihmal edilebilir düzeydedir. ftrace etkinleştirildiğinde ise bu NOP'lar, çalışma zamanında gerçek izleme koduna yönlendirilen call talimatlarına dönüşür.

tracefs — kontrol arayüzü

ftrace, tracefs dosya sistemi üzerinden kontrol edilir. Çoğu dağıtımda debugfs içine bağlanmıştır:

bash●

# tracefs mount durumunu kontrol et
mount | grep tracefs
# tracefs on /sys/kernel/debug/tracing type tracefs (rw,relatime)

# ya da doğrudan debugfs içinde:
ls /sys/kernel/debug/tracing/
# available_tracers  current_tracer  tracing_on  trace  set_ftrace_filter ...

# mount edilmemişse:
mount -t tracefs nodev /sys/kernel/tracing

Temel dosyalar

current_tracer

Aktif tracer'ın adı. nop (devre dışı), function, function_graph gibi değerler alır.

available_tracers

Kernel'da derlenmiş tüm tracer'ların listesi.

tracing_on

1 = tracing aktif, 0 = durduruldu. Ring buffer dolar endişesi olmadan hızlı durdurma için kullanılır.

trace

Ring buffer içeriği — okunabilir metin formatında.

trace_pipe

Ring buffer'dan canlı akış. cat trace_pipe ile gerçek zamanlı izle.

set_ftrace_filter

İzlenecek fonksiyon filtresi. Boşsa tüm fonksiyonlar izlenir.

set_ftrace_notrace

Bu dosyaya yazılan fonksiyonlar izlenmez — kara liste.

buffer_size_kb

Her CPU başına ring buffer boyutu (KB).

Gerekli kernel konfigürasyonu

Kconfig●

CONFIG_FTRACE=y
CONFIG_FUNCTION_TRACER=y
CONFIG_FUNCTION_GRAPH_TRACER=y
CONFIG_DYNAMIC_FTRACE=y          # NOP → call dönüşümü için gerekli
CONFIG_FTRACE_SYSCALLS=y         # sistem çağrısı tracepoint'leri
CONFIG_ENABLE_DEFAULT_TRACERS=y

GÜVENLIK

tracefs dosyalarına erişim için root veya CAP_SYS_ADMIN yetkisi gereklidir. Üretim sistemlerinde tracefs'i bağlamayı veya izinleri kısıtlamayı düşün: chmod 700 /sys/kernel/debug/tracing.

01 function tracer — temel kullanım

function tracer, her kernel fonksiyon çağrısını zaman damgasıyla birlikte kaydeder. En basit ve en kapsamlı tracer'dır.

bash●

# tracefs dizinine geç (root olarak)
cd /sys/kernel/debug/tracing

# mevcut tracer'ları listele
cat available_tracers
# blk function_graph preemptirq irqsoff function nop

# function tracer'ı aktifleştir
echo function > current_tracer

# tracing'i başlat
echo 1 > tracing_on

# ... birkaç saniye bekle ya da tetikleyici komutu çalıştır ...

# tracing'i durdur
echo 0 > tracing_on

# sonuçları oku
cat trace | head -50

Örnek çıktı

trace çıktısı●

# tracer: function
#
# entries-in-buffer/entries-written: 142521/142521   #P:4
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
          bash-1234  [001] .... 12345.678901: mutex_lock <-do_sys_open
          bash-1234  [001] .... 12345.678912: _raw_spin_lock <-mutex_lock
          bash-1234  [001] .... 12345.678923: do_sys_open <-__x64_sys_openat
          bash-1234  [001] .... 12345.678934: getname_flags <-do_sys_open

Her satır: görev adı ve PID, CPU numarası, flag'ler (interrupt/preempt durumu), zaman damgası (saniye.mikrosaniye) ve fonksiyon adı ile çağıran fonksiyon.

Ring buffer'ı temizle

bash●

# buffer'ı sil, yeni bir oturum başlat
echo > trace

# tracer'ı sıfırla
echo nop > current_tracer

DİKKAT — performans

Filtresiz function tracer, saniyede milyonlarca kayıt üretebilir. Ring buffer dolduğunda en eski kayıtların üzerine yazar. Uzun süreli izleme için mutlaka set_ftrace_filter kullan veya trace_pipe'ı bir dosyaya yönlendir.

02 function_graph tracer — çağrı grafiği

function_graph tracer, fonksiyon girişini ve çıkışını kaydeder; girintili çağrı grafiği ve her fonksiyonun süresini gösterir.

bash●

cd /sys/kernel/debug/tracing

echo function_graph > current_tracer
echo 1 > tracing_on
# ... test işlemi ...
echo 0 > tracing_on
cat trace | head -60

Örnek çıktı — girintili çağrı grafiği

trace çıktısı●

# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |
 1)               |  do_sys_open() {
 1)               |    getname_flags() {
 1)   0.842 us    |      kmem_cache_alloc();
 1)   1.205 us    |      strncpy_from_user();
 1) + 3.721 us    |    }
 1)               |    alloc_fd() {
 1)   0.543 us    |      _raw_spin_lock();
 1)   0.401 us    |      expand_fdtable();
 1)   1.802 us    |    }
 1) ! 102.34 us   |    path_openat();
 1) + 112.5 us    |  }

Süre göstergesi: + işareti 10 µs'den uzun, ! işareti 100 µs'den uzun, $ işareti 1 ms'den uzun fonksiyonları vurgular. Latency analizi için son derece kullanışlıdır.

İzleme derinliğini sınırla

bash●

# sadece 3 seviye derinliğe kadar izle (çıktıyı yönetilebilir tutar)
echo 3 > max_graph_depth

# belirli bir göreve göre filtrele (PID ile)
echo $$ > set_ftrace_pid   # mevcut shell'in PID'i

# tüm CPU'lar yerine sadece CPU 0'da izle
echo 0 > tracing_cpumask

KULLANIM ÖNERİSİ

function_graph tracer, bir fonksiyonun neden yavaş çalıştığını anlamak için idealdir. set_ftrace_filter ile giriş fonksiyonunu belirt, max_graph_depth ile derinliği sınırla — böylece gürültü olmadan net bir çağrı ağacı elde edersin.

03 set_ftrace_filter — belirli fonksiyonu izle

Tüm kernel fonksiyonlarını izlemek yerine, yalnızca ilgilendiğin fonksiyonları seçmek hem performans hem de okunabilirlik açısından kritiktir.

bash●

cd /sys/kernel/debug/tracing

# tek bir fonksiyon izle
echo 'do_sys_open' > set_ftrace_filter

# birden fazla fonksiyon (her satıra bir tane, ya da boşlukla ayır)
echo 'do_sys_open vfs_read vfs_write' > set_ftrace_filter

# wildcard ile — "i2c_" ile başlayan tüm fonksiyonlar
echo 'i2c_*' > set_ftrace_filter

# mevcut filtreye ekle (> yerine >>)
echo 'mutex_lock' >> set_ftrace_filter

# filtreyi görüntüle
cat set_ftrace_filter

# filtreyi temizle (tüm fonksiyonları izle)
echo > set_ftrace_filter

Mevcut kernel fonksiyonlarını listele

bash●

# izlenebilir tüm fonksiyonlar
cat available_filter_functions | wc -l
# 65432 (kernel versiyonuna göre değişir)

# i2c ile ilgili fonksiyonları bul
grep '^i2c_' available_filter_functions
# i2c_transfer
# i2c_master_send
# i2c_master_recv
# i2c_smbus_read_byte_data
# ...

# modül fonksiyonları da izlenebilir (modül adıyla)
grep '\[my_driver\]' available_filter_functions

set_graph_function — function_graph ile birlikte

bash●

# function_graph tracer'da yalnızca bu fonksiyondan başla
echo 'i2c_transfer' > set_graph_function
echo function_graph > current_tracer
echo 1 > tracing_on

İPUCU — modül yükleme

Kernel modülü içindeki fonksiyonlar, modül yüklendikten sonra available_filter_functions'a eklenir. Modülü yükle, filtreyi ayarla, sonra test et.

04 trace-cmd — kullanıcı dostu sarmalayıcı

trace-cmd, ftrace'in tracefs dosyalarını doğrudan yazmak yerine tek bir komutla kontrol etmeni sağlayan araçtır. Kaydı ikili formatta saklar ve raporlama yapabilir.

Kurulum

bash●

# Debian/Ubuntu
apt install trace-cmd

# Buildroot
BR2_PACKAGE_TRACE_CMD=y

# Yocto
IMAGE_INSTALL += "trace-cmd"

Temel kayıt ve rapor

bash●

# function tracer ile kayıt başlat (Ctrl+C ile durdur)
trace-cmd record -p function

# belirli fonksiyonu filtrele
trace-cmd record -p function -l 'i2c_transfer' -- i2cget -y 1 0x50 0x00

# function_graph ile derinlik sınırlı kayıt
trace-cmd record -p function_graph --max-graph-depth 4 -l 'do_sys_open' -- ls /tmp

# tracepoint kayıt (olay bazlı)
trace-cmd record -e 'i2c:*' -- i2cdetect -y 1

# kayıt sonucunu görüntüle (trace.dat dosyasından)
trace-cmd report

# başka makinede oluşturulan trace.dat dosyasını görüntüle
trace-cmd report -i /path/to/trace.dat

trace-cmd report çıktısı

bash çıktısı●

cpus=4
         i2cget-892   [001] 23456.789012: i2c_transfer: i2c-1 #1 a=050 f=0000 l=1 [W]
         i2cget-892   [001] 23456.789098: i2c_transfer: i2c-1 #2 a=050 f=0001 l=1 [R]
         i2cget-892   [001] 23456.789201: function:             i2c_transfer

Faydalı trace-cmd seçenekleri

-p <tracer>

Kullanılacak plugin: function, function_graph, nop.

-l <func>

Fonksiyon filtresi — set_ftrace_filter'a yazar. Wildcard destekler.

-e <event>

Tracepoint olayı etkinleştir: -e 'sched:*' veya -e 'irq:irq_handler_entry'.

-P <pid>

Yalnızca bu PID'i izle.

-b <size>

CPU başına ring buffer boyutu (KB).

-o <file>

Çıktı dosyası (varsayılan: trace.dat).

list -e

Mevcut tüm event'leri listele: trace-cmd list -e.

05 Tracepoint'lar — statik izleme noktaları

Tracepoint'lar, kernel kaynak koduna yerleştirilmiş statik izleme kancalarıdır. ftrace'in dinamik fonksiyon izlemesinden farklı olarak, tracepoint'lar belirli kernel olaylarını (schedule, irq, block I/O vb.) düşük overhead ile izler.

Mevcut tracepoint'ları keşfet

bash●

# tüm kullanılabilir olayları listele
cat /sys/kernel/debug/tracing/available_events | head -20
# block:block_rq_complete
# block:block_rq_insert
# i2c:i2c_read
# i2c:i2c_write
# irq:irq_handler_entry
# sched:sched_switch
# sched:sched_wakeup
# skb:kfree_skb

# alt sistem bazında ara
ls /sys/kernel/debug/tracing/events/
# block  ext4  i2c  irq  kmem  net  sched  skb  tcp  ...

Tracepoint etkinleştirme

bash●

cd /sys/kernel/debug/tracing

# sched_switch tracepoint'ini etkinleştir
echo 'sched:sched_switch' > set_event

# birden fazla olay
echo 'sched:sched_switch
i2c:i2c_read
i2c:i2c_write' > set_event

# alt sistem altındaki tüm olayları etkinleştir
echo 'i2c:*' > set_event

# doğrudan enable dosyasını kullanmak (daha seçici)
echo 1 > events/i2c/i2c_read/enable
echo 1 > events/i2c/i2c_write/enable

# tüm olayları devre dışı bırak
echo > set_event

Tracepoint event formatını incele

bash●

# i2c_read event'inin alan formatı
cat /sys/kernel/debug/tracing/events/i2c/i2c_read/format
# name: i2c_read
# ID: 312
# format:
#   field:int adapter_nr;  offset:8; size:4;
#   field:__u16 addr;      offset:12; size:2;
#   field:__u16 flags;     offset:14; size:2;
#   field:__u16 len;       offset:16; size:2;

# event'i filtrele — sadece adapter 1 ve adres 0x50
echo 'adapter_nr == 1 && addr == 0x50' > events/i2c/i2c_read/filter

TRACEPOINT vs FUNCTION

Tracepoint'lar, kernel geliştiricileri tarafından kasıtlı olarak yerleştirilen API kararlı izleme noktalarıdır. Kernel versiyonları arasında anlam değişmez. Fonksiyon izleme ise ham ve gelişigüzel — iç API'ler yeniden adlandırılabilir. Olay bazlı analiz için tracepoint'leri tercih et.

06 perf ile ftrace entegrasyonu

perf aracı, ftrace altyapısını kullanabilen ve buna ek olarak CPU PMU (Performance Monitoring Unit) sayaçlarına erişen güçlü bir performans analiz aracıdır.

perf ftrace komutu

bash●

# function tracer ile izle
perf ftrace -G do_sys_open ls /tmp

# function_graph tracer ile belirli fonksiyona odaklan
perf ftrace -T i2c_transfer -- i2cget -y 1 0x50 0x00

# tracepoint olaylarını kaydet
perf record -e 'i2c:*' -- i2cget -y 1 0x50 0x00
perf report

# sched olaylarıyla CPU göç analizi
perf record -e 'sched:sched_migrate_task' -a sleep 5
perf script

perf stat ile sayaç bazlı analiz

bash●

# temel CPU sayaçları
perf stat -e cycles,instructions,cache-misses,cache-references ./myprogram

# örnek çıktı:
#  Performance counter stats for './myprogram':
#    1,234,567,890  cycles
#    2,345,678,901  instructions    # 1.90 insn per cycle
#          123,456  cache-misses    # 2.34% of all cache refs
#        5,267,890  cache-references
#        0.456789123 seconds time elapsed

GÖMÜLÜ SISTEMLER

ARM tabanlı gömülü sistemlerde PMU sayaçlarına erişmek için kernel'ın CONFIG_HW_PERF_EVENTS=y ile derlenmiş olması ve platform PMU sürücüsünün yüklü olması gerekir. Bazı minimal kernel yapılandırmalarında bu özellikler devre dışıdır.

07 kernelshark — görsel analiz

kernelshark, trace-cmd'nin ürettiği trace.dat dosyalarını görsel olarak incelemek için bir Qt tabanlı GUI uygulamasıdır. Zaman çizelgesi ve CPU görünümleriyle karmaşık trace verilerini anlaşılır hale getirir.

Kurulum ve kullanım

bash●

# Debian/Ubuntu
apt install kernelshark

# trace kaydı al (hedef sistemde)
trace-cmd record -e 'sched:*' -e 'irq:*' sleep 2

# trace.dat dosyasını geliştirme makinesine kopyala
scp target:/tmp/trace.dat ./

# GUI'de aç
kernelshark trace.dat

kernelshark arayüzü

┌─────────────────────────────────────────────────────────┐
│  kernelshark                                            │
│  ┌───────────────────────────────────────────────────┐  │
│  │  CPU 0: ████░░░░████████░░░░░░███░░░░░░░░░░░░░   │  │
│  │  CPU 1: ░░░░████░░░░░░░░████████░░░░░████████░   │  │
│  │  CPU 2: ░░░░░░░░░░░░████░░░░░░░░████░░░░░░░░░░   │  │
│  │  CPU 3: ████░░░░░░░░░░░░░░░░░░░░░░░░████████░   │  │
│  └───────────────────────────────────────────────────┘  │
│  ┌───────────────────────────────────────────────────┐  │
│  │  Olaylar Listesi                 Filtre: [sched]  │  │
│  │  23456.789012  CPU1  sched_switch  bash→kworker   │  │
│  │  23456.789098  CPU0  irq_handler_entry  irq=32    │  │
│  └───────────────────────────────────────────────────┘  │
└─────────────────────────────────────────────────────────┘

Zaman çizelgesinde belirli bir CPU'ya veya göreve yakınlaşmak, olayları filtrelemek ve latency ölçmek için tıkla-sürükle arayüzü sunar. Hedef sistemde GUI olmasa bile trace.dat dosyasını geliştirme makinesine taşıyıp orada analiz edebilirsin.

GUI YOK MU?

trace-cmd report --cpu 0 | grep sched_switch ile komut satırından da etkili analiz yapılabilir. kernelshark yalnızca görselleştirme kolaylığı sağlar.

08 Pratik: I2C transfer latency izleme

Gerçek dünya senaryosu: bir I2C sensör sürücüsünün transfer gecikmesi beklentinin üzerinde. ftrace ile tam olarak nerede zaman harcandığını bul.

Senaryo

Bir BME280 basınç sensörü I2C-1 veri yolunda, adres 0x76'da. Her okuma ~5 ms sürüyor ama spec 1 ms altında olmasını söylüyor. Neyi araştırmalıyız?

Adım 1 — I2C tracepoint'lerini etkinleştir

bash●

cd /sys/kernel/debug/tracing

# I2C tracepoint'lerini etkinleştir
echo 1 > events/i2c/i2c_read/enable
echo 1 > events/i2c/i2c_write/enable
echo 1 > events/i2c/i2c_result/enable

# sadece adapter 1'i filtrele
echo 'adapter_nr == 1' > events/i2c/i2c_read/filter
echo 'adapter_nr == 1' > events/i2c/i2c_write/filter

# function_graph tracer ile i2c_transfer fonksiyonunu derinlemesine izle
echo 'i2c_transfer' > set_graph_function
echo function_graph > current_tracer
echo 1 > tracing_on

Adım 2 — Sensör okumasını tetikle

bash●

# BME280'den bir okuma tetikle
i2cget -y 1 0x76 0xF7
echo 0 > tracing_on

Adım 3 — Sonuçları analiz et

trace çıktısı●

i2cget-1847 [000] 67890.123456: i2c_write: i2c-1 #1 a=076 f=0000 l=1
i2cget-1847 [000] 67890.123460: function_graph:
 0)             |  i2c_transfer() {
 0)             |    __i2c_transfer() {
 0) + 15.2 us   |      i2c_smbus_xfer_emulated();
 0) ! 3821.5 us |      bcm2835_i2c_xfer();      /* ← burada gecikiyor */
 0) + 3840.1 us |    }
 0) + 3845.7 us |  }
i2cget-1847 [000] 67890.127301: i2c_read: i2c-1 #2 a=076 f=0001 l=3

Adım 4 — bcm2835_i2c_xfer'i daha derin incele

bash●

# bcm2835 I2C sürücüsüne odaklan
echo 'bcm2835_i2c_xfer' > set_graph_function
echo 6 > max_graph_depth
echo > trace
echo 1 > tracing_on
i2cget -y 1 0x76 0xF7
echo 0 > tracing_on
cat trace

Yorumlama ve sonuç

Fonksiyon	Süre	Yorum
`i2c_transfer`	3845 µs	Toplam süre
`bcm2835_i2c_xfer`	3821 µs	Donanım bekleme
`wait_for_completion_timeout`	3800 µs	IRQ gelene kadar bekleme — IRQ gecikme sorunu

Sorun I2C donanım hızında değil, IRQ işleme gecikmesinde. irq:irq_handler_entry tracepoint'i ile IRQ gecikmesini ayrıca izlemek bir sonraki adım olacaktır.

Hatırlanacaklar

echo function > current_tracer ve echo 1 > tracing_on — en temel ftrace kullanımı
function_graph tracer, fonksiyon sürelerini + / ! / $ ile vurgular
set_ftrace_filter ile odaklan, max_graph_depth ile gürültüyü azalt
trace-cmd record/report ile dosyaya kaydet, farklı makinede analiz et
Tracepoint'lar (i2c:*, sched:*) dinamik fonksiyon izlemesinden daha kararlı ve düşük overhead'lidir
kernelshark ile GUI'de görsel zaman çizelgesi analizi

Bir sonraki adım: kprobes rehberi — çalışan kernel'a dinamik probe ekleme.