Linux performans analiz araçları / perf-tools

Bir Sistem/Network Yöneticisi için, performans anlamında sistemde o an neler olup bittiğini bilmek ve sistemin sağlığını izlemek, sistemin kendisi ve sistemde koşan servisin sürekliliği için hayati derecede önem taşır. Sistemden alınan her bilgi sistemdeki mevcut veya daha sonra oluşabilecek sorunlar hakkında ipucu verir. Sistem/Network Yöneticisi için sistem performansını izlemek, sistemi monitör etmek ve ortaya çıkan verileri analiz edip sorunun kaynağına inebilmek bazı durumlarda içinden çıkılmaz bir duruma dönüşebilir. Sistem kaynaklarının anlık kullanım oranları, hangi komutların ve proseslerin çalıştığı, CPU, Ram, Disk I/O ve Network kaynak tüketimleri gibi bilgiler ile sistemde oluşan darboğazların (bottleneck) önüne geçilebilir, sorunun derinlemesine analizi yapılabilir.

Bu konular ile ilgili klasik araçların dışında sistemi daha da derinlemesine inceleyen, sistem performans analiz araçları koleksiyonu olan perf-tools‘u incelemeye karar verdim. Perf-Tools, Brendan Gregg (Kıdemli Sistem Performans Mimarı @Netflix) tarafından USENIX LISA 2014 konferansında   “Linux Performance Analysis: New Tools and Old Secrets” adlı sunumunda duyurulmuştur. Gregg, bu araç setinin Netflix sistem altyapısındaki geniş ölçekli sunucuların performans dizaynı, analizi ve tuning işlemleri için sıklıkla kullanıldığını belirtmiştir. Gayet kullanışlı ve el altında bulundurulması gereken araçlar.

perf-tools_2016.png

https://github.com/brendangregg/perf-tools

Araçları kullanabilmek için Github reposunu aşağıdaki komut ile kendi sistemimize klonlayalım.


git clone --depth 1 https://github.com/brendangregg/perf-tools

Kopyalama sonrası, bu araç setine /perf-tools/bin dizini itibarı ile erişebilirsiniz.


root@ubase00:/home/hakan/gitRepos/perf-tools/bin# ls -alh
total 8,0K
drwxr-xr-x  2 root root 4,0K Tem 14 13:49 .
drwxr-xr-x 16 root root 4,0K Tem 14 13:49 ..
lrwxrwxrwx  1 root root   16 Tem 14 13:49 bitesize -> ../disk/bitesize
lrwxrwxrwx  1 root root   15 Tem 14 13:49 cachestat -> ../fs/cachestat
lrwxrwxrwx  1 root root   12 Tem 14 13:49 execsnoop -> ../execsnoop
lrwxrwxrwx  1 root root   19 Tem 14 13:49 funccount -> ../kernel/funccount
lrwxrwxrwx  1 root root   19 Tem 14 13:49 funcgraph -> ../kernel/funcgraph
lrwxrwxrwx  1 root root   20 Tem 14 13:49 funcslower -> ../kernel/funcslower
lrwxrwxrwx  1 root root   19 Tem 14 13:49 functrace -> ../kernel/functrace
lrwxrwxrwx  1 root root   12 Tem 14 13:49 iolatency -> ../iolatency
lrwxrwxrwx  1 root root   10 Tem 14 13:49 iosnoop -> ../iosnoop
lrwxrwxrwx  1 root root   12 Tem 14 13:49 killsnoop -> ../killsnoop
lrwxrwxrwx  1 root root   16 Tem 14 13:49 kprobe -> ../kernel/kprobe
lrwxrwxrwx  1 root root   12 Tem 14 13:49 opensnoop -> ../opensnoop
lrwxrwxrwx  1 root root   22 Tem 14 13:49 perf-stat-hist -> ../misc/perf-stat-hist
lrwxrwxrwx  1 root root   21 Tem 14 13:49 reset-ftrace -> ../tools/reset-ftrace
lrwxrwxrwx  1 root root   11 Tem 14 13:49 syscount -> ../syscount
lrwxrwxrwx  1 root root   17 Tem 14 13:49 tcpretrans -> ../net/tcpretrans
lrwxrwxrwx  1 root root   16 Tem 14 13:49 tpoint -> ../system/tpoint
lrwxrwxrwx  1 root root   14 Tem 14 13:49 uprobe -> ../user/uprobe
root@ubase00:/home/hakan/gitRepos/perf-tools/bin#
root@ubase00:/home/hakan/gitRepos/perf-tools/bin#

Ben ilk olarak anlık disk I/O metrikleri hakkında detaylı bilgi veren 2 önemli araç ile başlamak istiyorum. iosnoop ve iolatency. Sonra diğer yaygın olarak kullanılan execsnoop ve opensnoop ile devam edeceğim.

iosnoop

iosnoop, disk I/O trafik durumunu, gecikme (latency) metrikleri ile birlikte raporlar. Aracı hemen bir demo ile örnekleyelim; sistemimde yapay bir I/O trafiği üretmek için diskimde bulunan sıkıştırılmış bir CentOS ISO dosyasını “tar” komutu ile “extract” etmeye karar verdim.

tar_centos

“tar” komutu ile dosyayı “extract” etmeye başladığımda diskte oluşan I/O trafiğini “iosnoop” aracı ile gözlemleyelim.

root@ubase00:/home/hakan/gitRepos/perf-tools# ./iosnoop
Tracing block I/O. Ctrl-C to end.
COMM         PID    TYPE DEV      BLOCK        BYTES     LATms
tar          9247   R    8,0      33527232     131072     1.15
tar          9247   R    8,0      33527488     131072     1.30
tar          9247   R    8,0      33527744     131072     0.92
tar          9247   R    8,0      33528000     131072     0.84
tar          9247   R    8,0      33528256     131072     0.90
tar          9247   R    8,0      33528512     131072     1.38
tar          9247   R    8,0      33528768     131072     1.24
tar          9247   R    8,0      33529024     131072     0.98
tar          9247   R    8,0      33529280     131072     1.00
tar          9247   R    8,0      33529536     131072     0.92
tar          9247   R    8,0      33529792     131072     0.94
tar          9247   R    8,0      33530048     131072     0.90
tar          9247   R    8,0      33530304     131072     0.89
tar          9247   R    8,0      33530560     131072     0.94
tar          9247   R    8,0      33530816     131072    60.84
tar          9247   R    8,0      33531072     131072    68.03
tar          9247   W    8,0      36505600     1044480     7.44

Gözlemlenen “tar” I/O trafiği görünüşe göre 131072 Byte’lık veriler şeklinde Read (TYPE = R) işlemi yapmakta. Latency 0.80 ile 68 ms. arasında geziyor. Diskim Solid State olmadığı için bu gecikmeler normal. Solid State Disk (SSD) teknolojisinde bu değerler ortalama 0.10 – 0.30 ms civarında gezmektedir.


firefox      9360   R    8,0      5847648      8192      10.97
jbd2/sda1-30 300    WS   8,0      29760104     81920      0.76
jbd2/sda1-30 300    WS   8,0      29760264     4096       0.29
kworker/1:1H 327    WS   8,0      37657024     36864      1.85
jbd2/sda1-30 300    WS   8,0      29760272     36864      0.64
jbd2/sda1-30 300    WS   8,0      29760344     4096       0.36
kworker/1:1H 327    WS   8,0      37635976     524288     2.99
kworker/1:1H 327    WS   8,0      8886168      4096       2.78
kworker/1:1H 327    WS   8,0      37645312     163840  1027.78
jbd2/sda1-30 300    WS   8,0      29760352     12288      0.89
jbd2/sda1-30 300    WS   8,0      29760376     4096       0.55
kworker/1:1H 327    W    8,0      21538376     32768      0.67
jbd2/sda1-30 300    WS   8,0      29760384     45056      1.46
jbd2/sda1-30 300    WS   8,0      29760472     4096       0.47
kworker/1:1H 327    W    8,0      9005360      32768      0.90
jbd2/sda1-30 300    WS   8,0      29760480     45056      0.64
jbd2/sda1-30 300    WS   8,0      29760568     4096       0.54
kworker/1:1H 327    WS   8,0      37624384     65536      2.17
kworker/1:1H 327    WS   8,0      8886192      32768      1.09
jbd2/sda1-30 300    WS   8,0      29760576     20480      0.72
jbd2/sda1-30 300    WS   8,0      29760616     4096       0.58
kworker/0:1H 275    W    8,0      9005424      32768      1.14
firefox      9360   R    8,0      7283144      131072    38.09
firefox      9360   R    8,0      7278240      131072     6.95
firefox      9360   R    8,0      6111784      131072    12.28
firefox      9360   R    8,0      6105776      131072     9.70

Yukarıdaki alıntıda, Firefox’un  9360 PID ile Read (TYPE = R) işlemi yaptığını görüyoruz. jbd2/sda1-30 isimli proses (Journalling Block Device Driver) ise 300 PID ile Senkron yani eş zamanlı yazma işlemi (TYPE = WS) yapmakta.

iolatency

iolatency aracı ise CLI üzerinden disk I/O gecikme durumunu bir histogram şeklinde özetler.

Aşağıda, 7200 RPM hızına sahip bir diskin üzerinde oluşan I/O trafiği örneği gösterilmiştir. Sistem, 0 ve 1 ms arasında sistem 10 IOPS yaparken, 8 ile 16 ms arasında 22 IOPS yapabilmiş.

 >=(ms) ..  1       : 10       |##################                    |
       1 -> 2       : 1        |##                                    |
       2 -> 4       : 0        |                                      |
       4 -> 8       : 21       |##################################### |
       8 -> 16      : 22       |######################################|
      16 -> 32      : 21       |##################################### |
      32 -> 64      : 14       |#########################             |
      64 -> 128     : 13       |#######################               |

  

SSD diskli sistemin verilerine bakalım. Sistem 0 ile 1 ms arası 1400K IOPS yapabilmekte.


>=(ms) ..  1       : 1427     |######################################|
       1 -> 2       : 5        |#                                     |
       2 -> 4       : 3        |#                                     |

  >=(ms) ..  1       : 1409     |######################################|
       1 -> 2       : 6        |#                                     |
       2 -> 4       : 1        |#                                     |
       4 -> 8       : 1        |#                                     |

  >=(ms) ..  1       : 1478     |######################################|
       1 -> 2       : 6        |#                                     |
       2 -> 4       : 5        |#                                     |
       4 -> 8       : 0        |                                      |
       8 -> 16      : 2        |#                                     |

  >=(ms) ..  1       : 1437     |######################################|
       1 -> 2       : 5        |#                                     |
       2 -> 4       : 7        |#                                     |
       4 -> 8       : 0        |                                      |
       8 -> 16      : 1        |#                                     |

execsnoop

execsnoop, bir uygulamanın başlangıç aşamasını anlamak için kullanışlıdır. Kısa zamanlı anlık çalışıp duran prosesleri yakalamak için birebirdir. Özellikle de periyodik başlayıp duran prosesleri analiz etmek için kullanılabilir. Anlık açılıp kapanan proseslerin neden olduğu performans sorunlarını takip etmek için geliştirilmiştir. Anlık çalışan prosesler CPU tüketir ama “top” komutunda görülmezler.

Klasik olarak parametresiz olarak çalıştırıldığında start olan prosesi ve PID numarasını listeler.


root@ubase00:/home/hakan/gitRepos/perf-tools# ./execsnoop
Tracing exec()s. Ctrl-C to end.
Instrumenting sys_execve
   PID   PPID ARGS
 10952  10948 mawk -W interactive -v o=1 -v opt_name=0 -v name= [...]
 10953  10951 cat -v trace_pipe
 10954   9891 ping
 10955   9891 ping 8.8.8.8
 10959   9891 tar -czvf centos.tar.gz CentOS-7-x86_64-Minimal-1708.iso
 10960  10959 gzip

<span id="mce_SELREST_start" style="overflow:hidden;line-height:0;"></span>

Kısa zamanlı çalışan bir prosesin hangi zaman aralıklarında (Unix Timestamp) çalıştığını listeleyen bir kullanım. Aşağıdaki liste incelendiğinde bir “supervise” edilmiş prosesin varlığı görülebilir.


# ./execsnoop -t
Tracing exec()s. Ctrl-C to end.
TIMEs               PID   PPID ARGS
7419756.154031     8185   8181 mawk -W interactive -v o=1 -v opt_name=0 -v name= [...]
7419756.154131     8186   8184 cat -v trace_pipe
7419756.245264     8188   1698 ./run
7419756.245691     8189   1696 ./run
7419756.246212     8187   1689 ./run
7419756.278993     8190   1693 ./run
7419756.278996     8191   1692 ./run
7419756.288430     8192   1695 ./run
7419756.290115     8193   1691 ./run
7419756.292406     8194   1699 ./run
7419756.293986     8195   1690 ./run
7419756.294149     8196   1686 ./run
7419756.296527     8197   1687 ./run
7419756.296973     8198   1697 ./run
7419756.298356     8200   1685 ./run
7419756.298683     8199   1688 ./run
7419757.269883     8201   1696 ./run
[...]

opensnoop

open() sistem çağrılarını izleyen performans aracıdır. İlk çalıştırıldığında kendi başlangıç sürecini listeler, daha sonra sistemde oluşan open() çağrılarını raporlar.

root@ubase00:/home/hakan/gitRepos/perf-tools# ./opensnoop
Tracing open()s. Ctrl-C to end.
COMM             PID      FD FILE
opensnoop        12835   0x3
            12840   0x3 /etc/ld.so.cache
            12839   0x3 /etc/ld.so.cache
            12839   0x3 /usr/lib/x86_64-linux-gnu/libsigsegv.so.2
            12840   0x3 /lib/x86_64-linux-gnu/libc.so.6
            12839   0x3 /lib/x86_64-linux-gnu/libreadline.so.6
            12839   0x3 /usr/lib/x86_64-linux-gnu/libmpfr.so.4
            12839   0x3 /usr/lib/x86_64-linux-gnu/libgmp.so.10
            12839   0x3 /lib/x86_64-linux-gnu/libdl.so.2
            12839   0x3 /lib/x86_64-linux-gnu/libm.so.6
            12840   0x3 /usr/lib/locale/locale-archive
            12839   0x3 /lib/x86_64-linux-gnu/libc.so.6
            12840   0x3 trace_pipe
            12839   0x3 /lib/x86_64-linux-gnu/libtinfo.so.5
gawk             12839   0x3 /proc/self/maps
gawk             12839   0x3 /usr/lib/locale/locale-archive
gawk             12839   0x3 /usr/lib/x86_64-linux-gnu/gconv/gconv-modules.cache
irqbalance       1209    0x3 /proc/interrupts
irqbalance       1209    0x3 /proc/stat

Firefox açılışından kısa bir “opensnoop” raporu şu şekildedir. Firefox çalışırken hangi prosesleri çağırdığı listede görülebilir.

firefox          13135  0x24 /proc/cpuinfo
firefox          13135    -1 /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq
firefox          13135  0x24 /sys/devices/system/cpu/cpu0/cache/index2/size
firefox          13135  0x24 /sys/devices/system/cpu/present
firefox          13135  0x24 /etc/ld.so.cache
firefox          13135  0x24 /usr/lib/x86_64-linux-gnu/libpulse.so.0
firefox          13135    -1 /usr/lib/x86_64-linux-gnu/pulseaudio/tls/x86_64/libjson-c.so.2
firefox          13135    -1 /usr/lib/x86_64-linux-gnu/pulseaudio/tls/libjson-c.so.2
firefox          13135    -1 /usr/lib/x86_64-linux-gnu/pulseaudio/x86_64/libjson-c.so.2
firefox          13135    -1 /usr/lib/x86_64-linux-gnu/pulseaudio/libjson-c.so.2
firefox          13135  0x24 /lib/x86_64-linux-gnu/libjson-c.so.2
firefox          13135  0x24 /usr/lib/x86_64-linux-gnu/pulseaudio/libpulsecommon-8.0.

Bu araçlar kernel versiyon 3.2 ve üzeri için tasarlanmışlardır. 2.6 serisi kernel ile kullanım için şurada yayınlanan uyarılar dikkate alınmalıdır.

Hakan ORCAN

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google photo

You are commenting using your Google account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s