Wednesday, March 23, 2016

Java Uygulamalarının İzlenmesi (1. Bölüm)

   Çalıştırdığımız Java uygulamalarının planlanan kapasitede ve başarımda çalıştığından emin olmak için çalışma zamanındaki davranışını izliyoruz. İzlemeyi farklı seviyelerde gerçekleştirebiliriz:
  • Donanım
  • İşletim Sistemi
  • Java Sanal Makinası (JSM) 
  • Uygulama
Bu yazıda ilk üç seviyede Java uygulamalarını izlemek için kullanılabilecek araçları tanıyacağız. İşletim sistemi seviyesindeki çalışmamızı, Oracle Enterprise Linux 6 üzerinde gerçekleştireceğiz. 
   Uygulamalar çalışabilmek için donanıma ihtiyaç duyarlar. Donanımı basitlik açısından işlemci, bellek, disk ve bilgisayar ağı olarak düşüneceğiz. Yazılımların bazıları yoğun hesaplama gerektirir ve bu nedenle işlemciyi yoğun olarak kullanılır. Uygulamaların çalışma zamanındaki davranışları iki farklı kip ile modellenebilir: 
  • Merkezi İşlem Birimini (MİB) yoğun olarak kullanan uygulamalar 
  • Yoğun Giriş/Çıkış işleminde bulunan uygulamalar
   Genel olarak, bir prosesin çalışma zamanındaki davranışı, bu iki kip arasında gidip gelecektir. Bu durum Şekil-1’de gösterilmiştir. Şekil-1’de, A uygulaması, vaktinin tamamında işlemciyi kullanırken, H uygulaması, vaktinin tamamında Giriş/Çıkış (G/Ç) işlemi yapmaktadır. G/Ç işlemi dosyaya ya da bilgisayar ağına erişimden kaynaklanmış bulunabilir. A uygulaması, işlemciyi yoğun olarak kullandığından, işlemciye bağımlı uygulama olarak adlandırılır. H uygulaması ise G/Ç sistemini yoğun olarak kullandığı için G/Ç bağımlı uygulama olarak adlandırılır. Şekil-1’deki diğer uygulamaların ise çalışma zamanlarının farklı bölümlerinde hem işlemciyi hem de G/Ç sistemini kullandıklarını görüyoruz. Bazı problemlerin çözümü yoğun olarak işlemciyi kullanmayı gerektirir. Örneğin bilimsel hesaplama gerektiren bir problemin çözümünü yapan proses işlemci bağımlı olarak çalışır. Web sunucusu (örneğin, Apache web sunucusu, httpd) ise ağırlıklı olarak G/Ç sistemini (hem dosya sistemini hem de bilgisayar ağını) yoğun olarak kullanır. Bu nedenle G/Ç bağımlı bir uygulamadır.
Şekil-1 Uygulamaların çalışma zamanında işlemciyi ve G/Ç sistemini kullanım davranışı
Günümüzde işlemci başarımları, dosya sistemlerinin ve bilgisayar ağlarının başarımına göre daha hızlı artmaktadır. Bu nedenle MİB bağımlı çalışan prosesler bu iyileşmeden daha fazla yararlanırlar. Üstelik son dönemde, çok çekirdekli sistemler sayesinde, eğer prosesler çok çekirdekli sistemlerin bilgi işleme yeteneklerinden yararlanacak şekilde tasarlanmışlar ise bu hızlanmanın işlemci bağımlı prosesler yönünde daha da açıldığı söylenebilir.
Donanım seviyesinde ilk göz atacağımız bileşen işlemci olacaktır. Sistemdeki işlemcilerin listesini ve yeteneklerini doğrudan /proc/cpuinfo dosyasına bakarak öğrenebiliriz:
[oracle@host01 ~]$ cat /proc/cpuinfo 
processor : 0
vendor_id : GenuineIntel
cpu family : 6
model  : 58
model name : Intel(R) Core(TM) i7-3630QM CPU @ 2.40GHz
stepping : 9
cpu MHz  : 2394.570
cache size : 6144 KB
physical id : 0
siblings : 2
core id  : 0
cpu cores : 2
apicid  : 0
initial apicid : 0
fpu  : yes
fpu_exception : yes
cpuid level : 13
wp  : yes
flags  : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts mmx fxsr sse sse2 ss ht syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts nopl xtopology tsc_reliable nonstop_tsc aperfmperf pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 popcnt aes xsave avx hypervisor lahf_lm ida arat epb pln pts dts
bogomips : 4789.14
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management:

processor : 1
vendor_id : GenuineIntel
cpu family : 6
model  : 58
model name : Intel(R) Core(TM) i7-3630QM CPU @ 2.40GHz
stepping : 9
cpu MHz  : 2394.570
cache size : 6144 KB
physical id : 0
siblings : 2
core id  : 1
cpu cores : 2
apicid  : 1
initial apicid : 1
fpu  : yes
fpu_exception : yes
cpuid level : 13
wp  : yes
flags  : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts mmx fxsr sse sse2 ss ht syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts nopl xtopology tsc_reliable nonstop_tsc aperfmperf pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 popcnt aes xsave avx hypervisor lahf_lm ida arat epb pln pts dts
bogomips : 4789.14
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management:

processor : 2
vendor_id : GenuineIntel
cpu family : 6
model  : 58
model name : Intel(R) Core(TM) i7-3630QM CPU @ 2.40GHz
stepping : 9
cpu MHz  : 2394.570
cache size : 6144 KB
physical id : 1
siblings : 2
core id  : 0
cpu cores : 2
apicid  : 2
initial apicid : 2
fpu  : yes
fpu_exception : yes
cpuid level : 13
wp  : yes
flags  : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts mmx fxsr sse sse2 ss ht syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts nopl xtopology tsc_reliable nonstop_tsc aperfmperf pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 popcnt aes xsave avx hypervisor lahf_lm ida arat epb pln pts dts
bogomips : 4789.14
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management:

processor : 3
vendor_id : GenuineIntel
cpu family : 6
model  : 58
model name : Intel(R) Core(TM) i7-3630QM CPU @ 2.40GHz
stepping : 9
cpu MHz  : 2394.570
cache size : 6144 KB
physical id : 1
siblings : 2
core id  : 1
cpu cores : 2
apicid  : 3
initial apicid : 3
fpu  : yes
fpu_exception : yes
cpuid level : 13
wp  : yes
flags  : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts mmx fxsr sse sse2 ss ht syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts nopl xtopology tsc_reliable nonstop_tsc aperfmperf pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 popcnt aes xsave avx hypervisor lahf_lm ida arat epb pln pts dts
bogomips : 4789.14
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management:
Çalıştığımız sistemde, hepsi de aynı özellikte olmak üzere 4 fiziksel işlemci bulunuyor. Daha özet bir bilgi için lscpu komutunu kullanabilirsiniz:
[oracle@host01 ~]$ lscpu
Architecture:          x86_64
CPU op-mode(s):        32-bit, 64-bit
Byte Order:            Little Endian
CPU(s):                4
On-line CPU(s) list:   0-3
Thread(s) per core:    1
Core(s) per socket:    2
CPU socket(s):         2
NUMA node(s):          1
Vendor ID:             GenuineIntel
CPU family:            6
Model:                 58
Stepping:              9
CPU MHz:               2394.570
BogoMIPS:              4789.14
L1d cache:             32K
L1i cache:             32K
L2 cache:              256K
L3 cache:              6144K
NUMA node0 CPU(s):     0-3
Saat frekansı işlemcinin başarımı için her şey demek olmasa da birim zamanda çıkardığı iş açısından önemli bir parametredir. Günümüz işlemcileri uygulamaların işlemci gereksinimlerine göre saat frekanslarını değiştirebilmektedir. Saat frekansını canlı olarak aşağıdaki gibi bir komutla izleyebilirsiniz:
[oracle@host01 ~]$ watch -n1 "lscpu | grep "MHz" | gawk '{print $1}'"
Sistemde işlemcilerin, belleğin ve G/Ç sistemlerinin ne kadar kullanıldığını vmstat komutu ile izleyebilirsiniz. vmstat komutuna parametre olarak örnekleme periyotunu veriyoruz. Periyotun birimi  saniyedir. Sistemden her beş saniyede bir örnekleme almak için vmstat komutunu aşağıdaki gibi çalıştırabilirsiniz:
[oracle@host01 ~]$ vmstat 5
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0    300 1168840  25888 2430188    0    0    19   129   51   47  0  1 99  0  0 
 1  0    300 1117484  26076 2432980    0    0  1496    20 2410 2589  7  5 88  0  0 
 8  0    300 786108  26080 2433064    0    0    12     0 8264 7616 46 15 38  0  0 
 1  0    300 648528  26120 2448160    0    0    58   186 5708 2964 60 14 26  0  0 
 1  0    300 654356  26128 2448160    0    0     0    12  219  123  4  0 96  0  0 
 0  0    300 650136  26128 2448160    0    0     0     0  167  205  1  0 99  0  0 
İşlemci kullanımını us(er), sy(stem) ve id(le) sütunlarından izleyebilirsiniz. Yüzde olarak verilen bu değerlerin toplamı 100'dür. user time (us) uygulamaların ne kadarlık bir zamanını işlemciyi kullanmak için geçirdiğini gösterir. System time (sy) ise uygulamaların ne oranda işletim sisteminin çekirdeğinden hizmet aldığını gösterir. İşletim sistemi servisleri normalde biz onlardan istekte bulunmadığımız sürece bir iş yapmazlar. Diskten ıskalanan verilerin tampon belleğe taşınması, dolan tamponların diske yazılması gibi işlemlerde çekirdek servisleri araya girer uygulamanın işlemci zamanından çalar. Eğer uzun süre system time (sy) %10'un üzerinde gidiyorsa araştırılması gereken bir durum var demektir. Genellikle üretim ortamlarından sistemleri yarı dolu çalıştırırız. Genel olarak ise sistemin %80'in üzerinde çalıştırılmaması uygun olur. Her zaman ek yükler ve anlık ihtiyaçlar için bir boşluk (idle time) bırakılmalıdır. Sistemin kapasitesinin üzerinde çalıştığını ise r etiketli birinci sütundan anlayabilirsiniz. Kapasitesinin üzerinde kullanılan her sistemde kuyruk oluşur. Eğer kuyruğun boyu (r), işlemci sayısının karesine karşılık gelen değeri uzun süre aşıyorsa, sistem kapasitesinin üzerinde kullanılıyor demektir.
   swpd sütunu takas bellek kullanımını göstermektedir. Fiziksel bellek uygulamaların sanal bellek ihtiyaçlarını karşılayamaz hale geldiğinde takas bellek kullanılmaya başlanacaktır. Sıkışık bellekli sistemlerde, fiziksel belleğin uygulamaların ihtiyaçlarını ancak karşıladığı sistemlerde fiziksel bellek ile diskte oluşturulan takas bellek arasında taşıma işlemi başlayacaktır. Bu taşıma işlemlerini si (swap-in) ve so (swap-out) sütunlarından izleyebilirsiniz. Eğer si ve so değerleri uzun süre yüksek giderse artık sistemde bellek arttırımına gitme vakti gelmiş demektir. 
   Bellekte sakladığımız verilere uygulama sona erdiğinde ya da makinayı kapattığımızda tekrar ulaşamayız. Bellek kalıcı bir depolama ortamı değildir. Verileri kalıcı olarak saklamak istediğimizde dosya sisteminden yararlanıyoruz. Dosya sistemini ayrıca uygulamaları biri birleri ile tümleştirmek için de kullanabiliriz. Bir uygulama aktarmak istediği veriyi dosyaya yazar, diğer uygulama ise bu verileri aynı dosyadan okur. Ancak dosyaları sakladığımız fiziksel diskler yavaşlar. Bu yavaşlığı kullanıcılardan ve uygulamalardan gizlemek için tampon belleklerden yararlanıyoruz. Veriler fiziksel diskte bloklar olarak organize edilmiştir. Siz diskten bir sekizlik okumak isterseniz, okumaya çalıştığınız sekizliğin yer aldığı blok, bellekte tampon olarak tanımlanan  bir alana getirilecektir. Blok içinde yaptığınız tüm okumalar bellekte gerçekleşecektir. Benzer durum yazma işlemi için de geçerlidir. bi (block-in) ve bo (block-out) sütunlarından bu aktarımları izleyebilirsiniz. Blokları disk ile tampon arasındaki taşıma işleminde çekirdek içindeki G/Ç servisi organize edecektir. O nedenle diskten kaynaklı G/Ç işlemlerin sy(stem time) değerinin artmasına neden olur. Bu aktarım sırasında uygulama bloke olur. b etiketli ikinci sütundan bu tür uygulamaların sayısını izleyebilirsiniz. Uzun süre b sütunu yüksek gidiyorsa, disk üzerinde bir dar boğaz yaşanıyor demektir. Özellikle veritabanı koşan sistemlerde bu durum irdelenmelidir.
   Bir uygulamanın bloke olmasının tek nedeni yoğun G/Ç işlemleri değildir. Bazen uygulamalar ya da uygulamayı oluşturan iplikler (=threads) biri birlerini beklemeleri gerekebilir. Bunu işletim sisteminde monitor dediğimiz yapılar aracılığı ile organize edebiliyoruz. Disk dışındaki kaynakların paylaşımında monitorlerden yararlanıyoruz. wa etiketli sütunda uygulamaların wa(it time) değerlerinin izleyebilirsiniz. Eğer uzun süre bu sütun yüksek gidiyorsa kilit/kaynak çekişmesine (=lock contention) işaret eder ve mutlaka hangi uygulamadan kaynaklığı olduğu bulunması ve uygulama geliştiricileri tarafından incelenmesi gerekir.
   vmstat komutu sistemin geneli hakkında bir bilgi verir. Bellek, işlemci ve G/Ç kullanım yüküne hangi uygulamaların ne kadar katkı yaptığını izlemek için ise top komutundan yararlanıyoruz:
top -M komutunun ekran görünümü
   top komutu, sistemin son 1 dakika, 5 dakika ve 15 dakika boyunca ortalama yükünü, sağ üst köşede "load average" başlıklı bölgede gösterir. Gerçek yükü makinadaki sanal işlemci sayısına göre yorumlamanız gerekir. Dört (4)  sanal işlemcili bir makinada, yük dördün (4) üzerinde ise sistem kapasitesinin üzerinde kullanılıyor demektir. Yukarıdaki örnekte, işlemci ve bellek yükünü 10064 proses kimlik numarasına sahip Java prosesi yaratıyor. Java uygulamaları çok iplikli uygulamalardır. İpliklerden hangisinin işlemciye gereksinim duyduğunu ise top -H -p 10064 komutu ile izlemek mümkündür:
top -H -p 10064
İşlemciye en fazla gereksinim duyan iplikleri ve bunların kimliklerini saptadık. Peki, bu iplikler şu an ne yapıyorlar, hangi metodu çalıştırıyorlar? Bunu nasıl saptayacağız? Sorunun cevabı için JSM seviyesinde uygulamayı izlememiz gerekir. Buna daha sonra bakacağız. Çok çekirdekli sistemlerde çekirdeklerin kullanım oranlarını bilmek isteriz. Eğer uygulamanın yavaşlığından şikayet ediliyorsa ve çekirdeklerin çoğu boşta ise yazılım çekirdekleri dolu tutacak şekilde problemi çekirdeklere paylaştıramamış, paralel programlama yapamamış demektir. İşlemcilerin kullanımlarını mpstat ve sar komutlarını kullanarak izleyebiliriz. Her iki komutta parametre olarak örnekleme periyodunu saniye cinsinden alır:
[oracle@host01 ~]$ mpstat -P ALL 5
Linux 2.6.39-200.24.1.el6uek.x86_64 (host01.example.com)  03/21/2016  _x86_64_ (4 CPU)

03:13:21 PM  CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest   %idle
03:13:26 PM  all    0.10    0.00    0.15    0.00    0.00    0.00    0.00    0.00   99.75
03:13:26 PM    0    0.20    0.00    0.20    0.00    0.00    0.00    0.00    0.00   99.60
03:13:26 PM    1    0.20    0.00    0.00    0.00    0.00    0.00    0.00    0.00   99.80
03:13:26 PM    2    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00
03:13:26 PM    3    0.20    0.00    0.20    0.00    0.00    0.00    0.00    0.00   99.60

03:13:26 PM  CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest   %idle
03:13:31 PM  all    0.30    0.00    0.20    0.00    0.00    0.00    0.00    0.00   99.50
03:13:31 PM    0    1.20    0.00    0.00    0.00    0.00    0.00    0.00    0.00   98.80
03:13:31 PM    1    0.00    0.00    0.20    0.00    0.00    0.00    0.00    0.00   99.80
03:13:31 PM    2    0.00    0.00    0.20    0.00    0.00    0.00    0.00    0.00   99.80
03:13:31 PM    3    0.00    0.00    0.40    0.00    0.00    0.00    0.00    0.00   99.60

03:13:31 PM  CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest   %idle
03:13:36 PM  all    0.70    0.00    0.40    0.05    0.00    0.00    0.00    0.00   98.85
03:13:36 PM    0    2.63    0.00    0.40    0.20    0.00    0.00    0.00    0.00   96.77
03:13:36 PM    1    0.00    0.00    0.40    0.20    0.00    0.00    0.00    0.00   99.40
03:13:36 PM    2    0.20    0.00    0.20    0.00    0.00    0.00    0.00    0.00   99.60
03:13:36 PM    3    0.00    0.00    0.60    0.00    0.00    0.00    0.00    0.00   99.40
sr komutu ile çok farklı türde istatistikler toplamak mümkündür. -S seçeneği ile swap disk kullanımı,  -b seçeneği ile disk g/ç başarımı, -P seçeneği ile çekirdeklerin kullanım oranları, -q ile işlemcilerde çalışmak için bekleyen proseslerin oluşturduğu kuyruk uzunlukları -d seçeneği ile g/ç cihazı bazında kullanım bilgilerine ve -w seçeneği ile bağlam anahtarlama bilgilerine erişilebilinir:
[oracle@host01 ~]$ sar -S 1 3
Linux 2.6.39-200.24.1.el6uek.x86_64 (host01.example.com)  03/21/2016  _x86_64_ (4 CPU)

03:21:57 PM kbswpfree kbswpused  %swpused  kbswpcad   %swpcad
03:21:58 PM   8189400      2596      0.03       400     15.41
03:21:59 PM   8189400      2596      0.03       400     15.41
03:22:00 PM   8189400      2596      0.03       400     15.41
Average:      8189400      2596      0.03       400     15.41
[oracle@host01 ~]$ sar -b 1 3
Linux 2.6.39-200.24.1.el6uek.x86_64 (host01.example.com)  03/21/2016  _x86_64_ (4 CPU)

03:22:18 PM       tps      rtps      wtps   bread/s   bwrtn/s
03:22:19 PM      0.00      0.00      0.00      0.00      0.00
03:22:20 PM      0.00      0.00      0.00      0.00      0.00
03:22:21 PM     19.00      0.00     19.00      0.00    224.00
Average:         6.33      0.00      6.33      0.00     74.67
[oracle@host01 ~]$ sar -P ALL 1 3
Linux 2.6.39-200.24.1.el6uek.x86_64 (host01.example.com)  03/21/2016  _x86_64_ (4 CPU)

03:23:03 PM     CPU     %user     %nice   %system   %iowait    %steal     %idle
03:23:04 PM     all      0.25      0.00      0.25      0.00      0.00     99.49
03:23:04 PM       0      0.00      0.00      0.00      0.00      0.00    100.00
03:23:04 PM       1      0.99      0.00      0.99      0.00      0.00     98.02
03:23:04 PM       2      0.00      0.00      1.00      0.00      0.00     99.00
03:23:04 PM       3      0.00      0.00      0.00      0.00      0.00    100.00

03:23:04 PM     CPU     %user     %nice   %system   %iowait    %steal     %idle
03:23:05 PM     all      0.00      0.00      0.50      0.00      0.00     99.50
03:23:05 PM       0      0.00      0.00      0.98      0.00      0.00     99.02
03:23:05 PM       1      0.00      0.00      1.00      0.00      0.00     99.00
03:23:05 PM       2      0.00      0.00      0.00      0.00      0.00    100.00
03:23:05 PM       3      0.00      0.00      0.99      0.00      0.00     99.01

03:23:05 PM     CPU     %user     %nice   %system   %iowait    %steal     %idle
03:23:06 PM     all      0.25      0.00      0.25      0.00      0.00     99.50
03:23:06 PM       0      0.00      0.00      0.00      0.00      0.00    100.00
03:23:06 PM       1      0.00      0.00      1.00      0.00      0.00     99.00
03:23:06 PM       2      0.00      0.00      0.00      0.00      0.00    100.00
03:23:06 PM       3      0.00      0.00      0.00      0.00      0.00    100.00

Average:        CPU     %user     %nice   %system   %iowait    %steal     %idle
Average:        all      0.17      0.00      0.33      0.00      0.00     99.50
Average:          0      0.00      0.00      0.33      0.00      0.00     99.67
Average:          1      0.33      0.00      1.00      0.00      0.00     98.67
Average:          2      0.00      0.00      0.33      0.00      0.00     99.67
Average:          3      0.00      0.00      0.33      0.00      0.00     99.67
[oracle@host01 ~]$ sar -q 1 3
Linux 2.6.39-200.24.1.el6uek.x86_64 (host01.example.com)  03/21/2016  _x86_64_ (4 CPU)

03:24:07 PM   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15
03:24:08 PM         0       342      0.00      0.01      0.05
03:24:09 PM         0       342      0.00      0.01      0.05
03:24:10 PM         0       342      0.00      0.01      0.05
Average:            0       342      0.00      0.01      0.05
[oracle@host01 ~]$ sar -d 1 3
Linux 2.6.39-200.24.1.el6uek.x86_64 (host01.example.com)  03/21/2016  _x86_64_ (4 CPU)

03:24:24 PM       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
03:24:25 PM    dev2-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
03:24:25 PM    dev8-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
03:24:25 PM  dev252-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
03:24:25 PM  dev252-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
03:24:25 PM  dev252-2      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00

03:24:25 PM       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
03:24:26 PM    dev2-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
03:24:26 PM    dev8-0      5.05      0.00     64.65     12.80      0.00      0.00      0.00      0.00
03:24:26 PM  dev252-0      8.08      0.00     64.65      8.00      0.00      0.00      0.00      0.00
03:24:26 PM  dev252-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
03:24:26 PM  dev252-2      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00

03:24:26 PM       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
03:24:27 PM    dev2-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
03:24:27 PM    dev8-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
03:24:27 PM  dev252-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
03:24:27 PM  dev252-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
03:24:27 PM  dev252-2      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00

Average:          DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
Average:       dev2-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
Average:       dev8-0      1.68      0.00     21.55     12.80      0.00      0.00      0.00      0.00
Average:     dev252-0      2.69      0.00     21.55      8.00      0.00      0.00      0.00      0.00
Average:     dev252-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
Average:     dev252-2      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
[oracle@host01 ~]$ sar -w 1 3
Linux 2.6.39-200.24.1.el6uek.x86_64 (host01.example.com)  03/21/2016  _x86_64_ (4 CPU)

03:24:40 PM    proc/s   cswch/s
03:24:41 PM      0.00    551.58
03:24:42 PM      0.00    542.57
03:24:43 PM      0.00    444.55
Average:         0.00    512.12

JSM Seviyesinde Uygulamaların İzlenmesi

Java platformunun en güçlü bileşeni Java Sanal Makinasıdır (JSM). Java uygulamaları JSM üzerinde çalışır. JSM satın alabileceğiniz, üretebileceğiniz bir işlemci tanımlar. Bu işlemcinin bir komut kümesi, yığın temelli adresleme kipleri, saklayıcı kümesi, yığın göstergesi, program sayacı, bellek modeli vardır. Çoğu zaman JSM'yi yazılımsal olarak ediniriz. Oracle, hemen hemen tüm işletim sistemleri için bir JSM yayınlıyor. Bu adresten elinizdeki işletim sistemi için bir JRE ya da JDK indirebilirsiniz. Eğer amacınız sadece Java uygulamalarını çalıştırmak ise Java Runtime Environment (JRE) yeterli olacaktır. Eğer uygulama geliştirmek isterseniz Java Geliştirme Çantasını (Java Development Kit, JDK) indirmeniz gerekir. Bu alet çantasının içerisinden bir derleyici (javac), Java'da geliştirdiğiniz uygulamayı yayınlamak için bir paketleyici (jar) ve nihayet java uygulamasını çalıştırmak için bir araç (java) çıkmaktadır. Bu çantada başka pek çok araç daha bulabilirsiniz:
  • javap
  • rmic
  • rmiregistry
  • serialver
  • xjc
  • wsgen
  • wsimport
  • keytool
  • jstatd
  • jstat
  • jps
  • jcmd
  • jstack
  • jmap
  • jhat
  • jconsole
  • jvisualvm
  • jmc
Bu araçlardan bir kısmı çalışan Java uygulamalarını izlemek için kullanılabilir:
jps: İşletim sisteminde çalışan Java uygulamalarının listesini verir. 
[oracle@host01 ~]$ jps -l
10064 /opt/jboss-eap-6.4/jboss-modules.jar
21799 sun.tools.jps.Jps
[oracle@host01 ~]$ jps -v
10064 jboss-modules.jar -D[Standalone] -XX:+UseCompressedOops -verbose:gc -Xloggc:/opt/jboss-eap-6.4/standalone/log/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=3M -XX:-TraceClassUnloading -Xms1303m -Xmx1303m -XX:MaxPermSize=256m -Djava.net.preferIPv4Stack=true -Djboss.modules.system.pkgs=org.jboss.byteman -Djava.awt.headless=true -Djboss.modules.policy-permissions=true -Dorg.jboss.boot.log.file=/opt/jboss-eap-6.4/standalone/log/server.log -Dlogging.configuration=file:/opt/jboss-eap-6.4/standalone/configuration/logging.properties
21815 Jps -Dapplication.home=/opt/jdk1.8.0_74 -Xms8m
[oracle@host01 ~]$ jps -m
10064 jboss-modules.jar -mp /opt/jboss-eap-6.4/modules -jaxpmodule javax.xml.jaxp-provider org.jboss.as.standalone -Djboss.home.dir=/opt/jboss-eap-6.4 -Djboss.server.base.dir=/opt/jboss-eap-6.4/standalone -Djboss.bind.address.management=host01.example.com -Djboss.bind.address=host01.example.com --server-config=standalone.xml
21833 Jps -m
[oracle@host01 ~]$ jps -q
10064
21882
jcmd: İşletim sisteminde çalışan Java uygulamalarının durumu ve başarımını listeler. jdk7u40 sürümünden itibaren kullanabilirsiniz.
[oracle@host01 ~]$ jcmd
10064 /opt/jboss-eap-6.4/jboss-modules.jar -mp /opt/jboss-eap-6.4/modules -jaxpmodule javax.xml.jaxp-provider org.jboss.as.standalone -Djboss.home.dir=/opt/jboss-eap-6.4 -Djboss.server.base.dir=/opt/jboss-eap-6.4/standalone -Djboss.bind.address.management=host01.example.com -Djboss.bind.address=host01.example.com --server-config=standalone.xml
22119 sun.tools.jcmd.JCmd
[oracle@host01 ~]$ jcmd 10064 help
10064:
The following commands are available:
JFR.stop
JFR.start
JFR.dump
JFR.check
VM.native_memory
VM.check_commercial_features
VM.unlock_commercial_features
ManagementAgent.stop
ManagementAgent.start_local
ManagementAgent.start
GC.rotate_log
Thread.print
GC.class_stats
GC.class_histogram
GC.heap_dump
GC.run_finalization
GC.run
VM.uptime
VM.flags
VM.system_properties
VM.command_line
VM.version
help
jcmd ile ipliklerin listesini alabiliriz:
[oracle@host01 ~]$ jcmd 10064 Thread.print
10064:
2016-03-22 08:43:36
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.74-b02 mixed mode):

"Attach Listener" #126 daemon prio=9 os_prio=0 tid=0x00007feb9c03c800 nid=0x562a waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"ServerService Thread Pool -- 52" #98 prio=5 os_prio=0 tid=0x00007feb88366000 nid=0x27b9 waiting on condition [0x00007febb485f000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000aea574b0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
        at org.jboss.threads.JBossThread.run(JBossThread.java:122)

"ServerService Thread Pool -- 51" #97 prio=5 os_prio=0 tid=0x00007feb50023800 nid=0x27b6 waiting on condition [0x00007febbf7f8000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000aea574b0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
        at org.jboss.threads.JBossThread.run(JBossThread.java:122)

. . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . .

"VM Thread" os_prio=0 tid=0x00007febd813e800 nid=0x2757 runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007febd801f000 nid=0x2753 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007febd8020800 nid=0x2754 runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007febd8022800 nid=0x2755 runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007febd8024000 nid=0x2756 runnable 

"VM Periodic Task Thread" os_prio=0 tid=0x00007febd8192000 nid=0x275f waiting on condition 

JNI global references: 205
jcmd ile heap dökümünü alabiliriz:
[oracle@host01 ~]$ jcmd 10064 GC.heap_dump hd1
10064:
Heap dump file created
Uygulamanın ne kadar süredir çalışır durumda olduğunu öğrenebiliriz:
[oracle@host01 ~]$ jcmd 10064 VM.uptime
10064:
41760.605 s
Çöp toplayıcıyı çalıştırabiliriz:
[oracle@host01 ~]$ jcmd 10064 GC.run
10064:
Command executed successfully
Nesnelerin sınıflara dağılımını öğrenebiliriz:
[oracle@host01 ~]$ jcmd 10064 GC.class_histogram
10064:

 num     #instances         #bytes  class name
----------------------------------------------
   1:         71034        6272304  [C
   2:         78756        2520192  java.util.HashMap$Node
   3:         56572        2461488  [Ljava.lang.Object;
   4:         70845        1700280  java.lang.String
   5:         11703        1335832  java.lang.Class
   6:          9676        1174216  [Ljava.util.HashMap$Node;
   7:         48360        1160640  java.util.ArrayList
   8:          1442         790624  [B
   9:          4676         689384  [I
  10:         11215         538320  java.util.HashMap
  11:             3         393264  [Ljava.net.Socket;
  12:          4021         386016  java.util.jar.JarFile$JarFileEntry
  13:          9429         377160  java.util.LinkedHashMap$Entry
  14:            46         265960  [J
  15:          6014         192448  java.util.RegularEnumSet
  16:          2129         187352  java.lang.reflect.Method
  17:          7353         176472  org.jboss.dmr.ModelNode
  18:          4389         140448  org.jboss.jandex.DotName
  19:          2492         139552  java.util.LinkedHashMap
  20:          4188         134016  org.jboss.vfs.spi.JavaZipFileSystem$ZipNode
jmap:  Java uygulamasının JSM bilgisine ulaşmak, çöp toplayıcı seyir defterini okumak ve heap dökümü almak için kullanılabilir.
[oracle@host01 ~]$ jmap 10064
Attaching to process ID 10064, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.74-b02
0x0000000000400000 7K /opt/jdk1.8.0_74/bin/java
0x0000003409400000 153K /lib64/ld-2.12.so
0x0000003409800000 22K /lib64/libdl-2.12.so
0x0000003409c00000 1873K /lib64/libc-2.12.so
0x000000340a000000 142K /lib64/libpthread-2.12.so
0x000000340a400000 45K /lib64/librt-2.12.so
0x000000340a800000 584K /lib64/libm-2.12.so
0x0000003415400000 91K /lib64/libgcc_s-4.4.6-20120305.so.1
0x00007febb50bd000 250K /opt/jdk1.8.0_74/jre/lib/amd64/libsunec.so
0x00007febc4582000 90K /opt/jdk1.8.0_74/jre/lib/amd64/libnio.so
0x00007febc4a03000 113K /opt/jdk1.8.0_74/jre/lib/amd64/libnet.so
0x00007febc4e1a000 49K /opt/jdk1.8.0_74/jre/lib/amd64/libmanagement.so
0x00007febddc77000 121K /opt/jdk1.8.0_74/jre/lib/amd64/libzip.so
0x00007febdde92000 64K /lib64/libnss_files-2.12.so
0x00007febde0af000 220K /opt/jdk1.8.0_74/jre/lib/amd64/libjava.so
0x00007febde2db000 64K /opt/jdk1.8.0_74/jre/lib/amd64/libverify.so
0x00007febde5eb000 16522K /opt/jdk1.8.0_74/jre/lib/amd64/server/libjvm.so
0x00007febdf5ce000 100K /opt/jdk1.8.0_74/lib/amd64/jli/libjli.so
jmap ile heap dökümü alabilirsiniz:
[oracle@host01 ~]$ jmap -dump:file=/tmp/hd2 10064
Dumping heap to /tmp/hd2 ...
Heap dump file created
Heap dökümünü jvisualvm ve jhat araçları ile açabilmek için format bilgisi vermeniz gerekir:
[oracle@host01 ~]$ jmap -dump:format=b,file=/tmp/hd3 10064
Dumping heap to /tmp/hd3 ...
Heap dump file created
jmap ile nesnelerin sınıflara dağılımını öğrenebilirsiniz:
[oracle@host01 ~]$ jmap -histo 10064

 num     #instances         #bytes  class name
----------------------------------------------
   1:        306149       25446904  [Ljava.util.HashMap$Node;
   2:        307550       24858880  [I
   3:        485732       17098168  [Ljava.lang.Object;
   4:        417225       16689000  java.util.LinkedHashMap$Entry
   5:        380523       12176736  java.util.HashMap$Node
   6:        208433       10004784  java.util.HashMap
   7:        151360        9687040  java.util.regex.Matcher
   8:        401669        9640056  org.jboss.dmr.ModelNode
   9:        129817        9331000  [C
  10:        290389        6969336  java.util.ArrayList
jmap ile çöp toplayıcı davranışını izleyebilirsiniz:
[oracle@host01 ~]$ jmap -heap 10064
Attaching to process ID 10064, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.74-b02

using thread-local object allocation.
Parallel GC with 4 thread(s)

Heap Configuration:
   MinHeapFreeRatio         = 0
   MaxHeapFreeRatio         = 100
   MaxHeapSize              = 1367343104 (1304.0MB)
   NewSize                  = 455606272 (434.5MB)
   MaxNewSize               = 455606272 (434.5MB)
   OldSize                  = 911736832 (869.5MB)
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 0 (0.0MB)

Heap Usage:
PS Young Generation
Eden Space:
   capacity = 389545984 (371.5MB)
   used     = 7536928 (7.187774658203125MB)
   free     = 382009056 (364.3122253417969MB)
   1.9347980237424294% used
From Space:
   capacity = 32505856 (31.0MB)
   used     = 0 (0.0MB)
   free     = 32505856 (31.0MB)
   0.0% used
To Space:
   capacity = 31981568 (30.5MB)
   used     = 0 (0.0MB)
   free     = 31981568 (30.5MB)
   0.0% used
PS Old Generation
   capacity = 911736832 (869.5MB)
   used     = 26046416 (24.839797973632812MB)
   free     = 885690416 (844.6602020263672MB)
   2.8567910262947454% used

21812 interned Strings occupying 2100808 bytes.
jhat: Heap dökümünü tarayıcı üzerinden incelemek için geliştirilmiş bir web uygulamasıdır. Java 9'da JDK'dan çıkarılacaktır.
[oracle@host01 ~]$ jhat -port 7001 /tmp/hd3 
Reading from /tmp/hd3...
Dump file created Tue Mar 22 09:10:22 EET 2016
Snapshot read, resolving...
Resolving 4682904 objects...
Chasing references, expect 936 dots........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................
Eliminating duplicate references........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................
Snapshot resolved.
Started HTTP server on port 7001
Server is ready.
7001 numaralı porttan bir web tarayıcı aracılığı ile uygulamaya bağlanabilirsiniz:
http://host01.example.com:7001 adresinden uygulamaya bağlanabilirsiniz
Asıl menü sayfanın alt tarafında yer alıyor.
Menülerden ilgimizi çeken en önemli başlık "Execute Object Query Language (OQL) query". Burada heap'deki nesneler arasında sorgu çalıştırarak arama yapabiliyoruz.
OQL ile ilgili örnekleri bu adresten inceleyebilirsiniz.

jstack: jstack komutu ile ipliklerin dökümünü alabilirsiniz.

[oracle@host01 ~]$ jstack 10064
2016-03-22 10:21:52
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.74-b02 mixed mode):

"Attach Listener" #126 daemon prio=9 os_prio=0 tid=0x00007feb9c03c800 nid=0x562a waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"ServerService Thread Pool -- 52" #98 prio=5 os_prio=0 tid=0x00007feb88366000 nid=0x27b9 waiting on condition [0x00007febb485f000]
   java.lang.Thread.State: WAITING (parking)
 at sun.misc.Unsafe.park(Native Method)
 - parking to wait for  <0x00000000aea440b0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
 at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
 at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
 at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
 at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
 at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
 at java.lang.Thread.run(Thread.java:745)
 at org.jboss.threads.JBossThread.run(JBossThread.java:122)

 . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . 

"VM Thread" os_prio=0 tid=0x00007febd813e800 nid=0x2757 runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007febd801f000 nid=0x2753 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007febd8020800 nid=0x2754 runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007febd8022800 nid=0x2755 runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007febd8024000 nid=0x2756 runnable 

"VM Periodic Task Thread" os_prio=0 tid=0x00007febd8192000 nid=0x275f waiting on condition 

JNI global references: 213

jstat: Çalışan Java uygulaması ile ilgili farklı türde bilgiler almak ve izlemek için kullanılır. Aşağıda kullanımına ilişkin örnekler verilmiştir. 
Çöp toplayıcı davranışına ve heap kullanımına ilişkin 1000 mili saniye aralıklarla 10 tane örnek almak istiyoruz:
[oracle@host01 ~]$ jstat -gc 10064 1000 10
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT   
31232.0 30208.0 224.0   0.0   383488.0 272898.9  890368.0   25436.0   78284.0 64323.3 10700.0 7729.8     30    1.436   9      2.804    4.240
31232.0 30208.0 224.0   0.0   383488.0 272898.9  890368.0   25436.0   78284.0 64323.3 10700.0 7729.8     30    1.436   9      2.804    4.240
31232.0 30208.0 224.0   0.0   383488.0 272898.9  890368.0   25436.0   78284.0 64323.3 10700.0 7729.8     30    1.436   9      2.804    4.240
31232.0 30208.0 224.0   0.0   383488.0 272898.9  890368.0   25436.0   78284.0 64323.3 10700.0 7729.8     30    1.436   9      2.804    4.240
31232.0 30208.0 224.0   0.0   383488.0 272900.9  890368.0   25436.0   78284.0 64323.3 10700.0 7729.8     30    1.436   9      2.804    4.240
31232.0 30208.0 224.0   0.0   383488.0 272900.9  890368.0   25436.0   78284.0 64323.3 10700.0 7729.8     30    1.436   9      2.804    4.240
31232.0 30208.0 224.0   0.0   383488.0 272900.9  890368.0   25436.0   78284.0 64323.3 10700.0 7729.8     30    1.436   9      2.804    4.240
31232.0 30208.0 224.0   0.0   383488.0 272900.9  890368.0   25436.0   78284.0 64323.3 10700.0 7729.8     30    1.436   9      2.804    4.240
31232.0 30208.0 224.0   0.0   383488.0 272900.9  890368.0   25436.0   78284.0 64323.3 10700.0 7729.8     30    1.436   9      2.804    4.240
31232.0 30208.0 224.0   0.0   383488.0 272900.9  890368.0   25436.0   78284.0 64323.3 10700.0 7729.8     30    1.436   9      2.804    4.240
Çöp toplayıcı ve heap kullanım oranlarını listelemek için jstat kullanılabilir:
[oracle@host01 ~]$ jstat -gcutil 10064 1000 10
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  0.00   0.00  33.31   3.77  91.83  81.85      5    0.159     3    0.302    0.461
  0.00   0.00  33.31   3.77  91.83  81.85      5    0.159     3    0.302    0.461
  0.00   0.00  33.54   3.77  91.83  81.85      5    0.159     3    0.302    0.461
  0.00   0.00  33.54   3.77  91.83  81.85      5    0.159     3    0.302    0.461
  0.00   0.00  33.54   3.77  91.83  81.85      5    0.159     3    0.302    0.461
  0.00   0.00  33.54   3.77  91.83  81.85      5    0.159     3    0.302    0.461
  0.00   0.00  33.54   3.77  91.83  81.85      5    0.159     3    0.302    0.461
  0.00   0.00  33.77   3.77  91.83  81.85      5    0.159     3    0.302    0.461
  0.00   0.00  33.77   3.77  91.83  81.85      5    0.159     3    0.302    0.461
  0.00   0.00  33.77   3.77  91.83  81.85      5    0.159     3    0.302    0.461
JIT derleyeci davranışını izlemek için jstat kullanılabilir:
[oracle@host01 ~]$ jstat -compiler  10064 1000 10
Compiled Failed Invalid   Time   FailedType FailedMethod
    2684      0       0     8.19          0             
    2684      0       0     8.19          0             
    2684      0       0     8.19          0             
    2716      0       0     8.22          0             
    2716      0       0     8.22          0             
    2716      0       0     8.22          0             
    2716      0       0     8.22          0             
    2716      0       0     8.22          0             
    2748      0       0     8.23          0             
    2748      0       0     8.23          0  
Sınıf yükleyici (=class loader) davranışını izlemek için jstat kullanılabilir:
[oracle@host01 ~]$ jstat -class  10064 1000 10
Loaded  Bytes  Unloaded  Bytes     Time   
 10825 21886.4        1     1.6      17.18
 10825 21886.4        1     1.6      17.18
 10825 21886.4        1     1.6      17.18
 10825 21886.4        1     1.6      17.18
 10825 21886.4        1     1.6      17.18
 10825 21886.4        1     1.6      17.18
 10825 21886.4        1     1.6      17.18
 10825 21886.4        1     1.6      17.18
 10825 21886.4        1     1.6      17.18
 10825 21886.4        1     1.6      17.18
JIT'lenen metodları izlemek için jstat kullanılabilir:
[oracle@host01 ~]$ jstat -printcompilation 10064 1000 10
Compiled  Size  Type Method
    4489    995    1 org/jboss/as/controller/operations/validation/ModelTypeValidator matches
    4489    995    1 org/jboss/as/controller/operations/validation/ModelTypeValidator matches
    4489    995    1 org/jboss/as/controller/operations/validation/ModelTypeValidator matches
    4498      5    1 org/jboss/as/server/deployment/scanner/FileSystemDeploymentService$ScanContext access$2000
    4498      5    1 org/jboss/as/server/deployment/scanner/FileSystemDeploymentService$ScanContext access$2000
    4498      5    1 org/jboss/as/server/deployment/scanner/FileSystemDeploymentService$ScanContext access$2000
    4498      5    1 org/jboss/as/server/deployment/scanner/FileSystemDeploymentService$ScanContext access$2000
    4498      5    1 org/jboss/as/server/deployment/scanner/FileSystemDeploymentService$ScanContext access$2000
    4502     64    1 java/util/AbstractSet hashCode
    4502     64    1 java/util/AbstractSet hashCode

jstatd: İzleme komutlarının hemen hemen hepsi (jcmd hariç) uzaktaki bir sistemdeki Java uygulamasını izlemek için kullanılabilir. Bunun mümkün olabilmesi için uzaktaki sistemde jstatd servisinin çalıştırılması gerekir. host02.example.com'da jstatd servisini 8001 numaralı portu dinlemek üzere çalıştırıyoruz:
[oracle@host02 ~]$ cat security.policy 
grant codebase "file:${java.home}/../lib/tools.jar" {
 permission java.security.AllPermission;
};
[oracle@host02 ~]$ jstatd -p 8001 -J-Djava.security.policy=security.policy 
Şimdi, host01.example.com makinasından host02.example.com makinasındaki Java uygulamalarının listesini alalım:
[oracle@host01 ~]$ jps host02.example.com:8001
19953 jboss-modules.jar
19970 jboss-modules.jar
19579 Jstatd
20036 jboss-modules.jar
[oracle@host01 ~]$ jps -lv host02.example.com:8001
19953 /opt/jboss-eap-6.4/jboss-modules.jar -D[Process Controller] -Xms64m -Xmx512m -XX:MaxPermSize=256m -Djava.net.preferIPv4Stack=true -Djboss.modules.system.pkgs=org.jboss.byteman -Djava.awt.headless=true -Djboss.modules.policy-permissions=true -Dorg.jboss.boot.log.file=/opt/jboss-eap-6.4/domain/log/process-controller.log -Dlogging.configuration=file:/opt/jboss-eap-6.4/domain/configuration/logging.properties
19970 /opt/jboss-eap-6.4/jboss-modules.jar -D[Host Controller] -Dorg.jboss.boot.log.file=/opt/jboss-eap-6.4/domain/log/host-controller.log -Dlogging.configuration=file:/opt/jboss-eap-6.4/domain/configuration/logging.properties -Xms64m -Xmx512m -XX:MaxPermSize=256m -Djava.net.preferIPv4Stack=true -Djboss.modules.system.pkgs=org.jboss.byteman -Djava.awt.headless=true -Djboss.modules.policy-permissions=true
20082 /opt/jboss-eap-6.4/jboss-modules.jar -D[Server:server-two] -XX:PermSize=256m -XX:MaxPermSize=256m -Xms1000m -Xmx1000m -Djboss.modules.system.pkgs=org.jboss.byteman -Djava.awt.headless=true -Djava.net.preferIPv4Stack=true -Djboss.home.dir=/opt/jboss-eap-6.4 -Djboss.modules.policy-permissions=true -Djboss.server.log.dir=/opt/jboss-eap-6.4/domain/servers/server-two/log -Djboss.server.temp.dir=/opt/jboss-eap-6.4/domain/servers/server-two/tmp -Djboss.server.data.dir=/opt/jboss-eap-6.4/domain/servers/server-two/data -Dorg.jboss.boot.log.file=/opt/jboss-eap-6.4/domain/servers/server-two/log/server.log -Dlogging.configuration=file:/opt/jboss-eap-6.4/domain/configuration/default-server-logging.properties
19579 sun.tools.jstatd.Jstatd -Dapplication.home=/opt/jdk1.8.0_74 -Xms8m -Djava.security.policy=security.policy
20036 /opt/jboss-eap-6.4/jboss-modules.jar -D[Server:server-one] -XX:PermSize=256m -XX:MaxPermSize=256m -Xms1000m -Xmx1000m -Djboss.modules.system.pkgs=org.jboss.byteman -Djava.awt.headless=true -Djava.net.preferIPv4Stack=true -Djboss.home.dir=/opt/jboss-eap-6.4 -Djboss.modules.policy-permissions=true -Djboss.server.log.dir=/opt/jboss-eap-6.4/domain/servers/server-one/log -Djboss.server.temp.dir=/opt/jboss-eap-6.4/domain/servers/server-one/tmp -Djboss.server.data.dir=/opt/jboss-eap-6.4/domain/servers/server-one/data -Dorg.jboss.boot.log.file=/opt/jboss-eap-6.4/domain/servers/server-one/log/server.log -Dlogging.configuration=file:/opt/jboss-eap-6.4/domain/configuration/default-server-logging.properties
Uzaktaki bir makinadaki bir Java prosesinin çöp toplayıcı davranışını jstat komutu ile izleyelim:
[oracle@host01 ~]$ jstat -gcutil 19953@host02.example.com:8001 1000 5
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  0.00  99.98   8.80   3.08  94.49  89.91      1    0.007     0    0.000    0.007
  0.00  99.98   8.80   3.08  94.49  89.91      1    0.007     0    0.000    0.007
  0.00  99.98   8.80   3.08  94.49  89.91      1    0.007     0    0.000    0.007
  0.00  99.98   8.80   3.08  94.49  89.91      1    0.007     0    0.000    0.007
  0.00  99.98   8.80   3.08  94.49  89.91      1    0.007     0    0.000    0.007

jconsole

Java uygulamalarının davranışını izlemek için kullanılabilecek grafik arayüze sahip bir uygulamadır. jconsole ile aşağıdaki yapabilirsiniz:
  • Uygulamanın JSM parametreleri okunabilir,
  • İpliklerin davranışı izlenebilir
  • İpliklerin dökümü alınabilir
  • Heap kullanımı izlenebilir
  • Heap dökümü alınabilir
  • JMX üzerinden MBean'lere uzaktan erişerek uygulama yönetilebilir
jconsole, Java 9 ile birlikte artık JDK içinden çıkmayacak. Şimdi jconsole ekranlarını inceleyelim:
Hem yerel makinadaki hem de uzaktaki bir makinadaki Java proseslerini seçip izleyebilirsiniz.
Özetçe ekranında, Heap ve işlemci kullanımını, İplik ve yüklenen sınıf sayılarını izleyebilirsiniz.
Heap tek düze bir bellek alanı değildir. Eden, Survivor, Tenure gibi farklı alanlardan oluşur. Bu alanların ayrı ayrı kullanımlarını Bellek ekranından izleyebilirsiniz. İsterseniz bu ekranda "Perform GC" butonuna basarak tam çöp toplama işlemini başlatabilirsiniz.
İpliklerin sayısını ve listesini bu ekrandan izleyebilirsiniz. İsterseniz listeden bir iplik seçip şu an hangi metodu çalıştırdığını ve çağrı yığınına bakabilirsiniz. 
Sınıf yükleyici tarafından yüklenen sınıfların sayılarını bu ekrandan izleyebilirsiniz.
JSM özet bilgilerine bu ekrandan ulaşabilirsiniz: JSM versiyonu. çalıştırma parametreleri, heap kapasitesi, iplik sayıları, işletim sistemi özelliklerini okumak mümkündür.
jconsole uygulamasını kullanmaya değecek ekran MBeans ekranıdır. Bu ekrandan JMX aracılığı ile MBean'lere ulaşıp anlık olayları izlemek ve uygulamayı yönetmek mümkündür. Bu örnekte, jconsole ile bir JBoss EAP 6 sunucusuna bağlıyız ve uygulama yayınlamak ya da kaldırmak gibi bir işlemi gerçekleştirebiliriz.



jvisualvm

jvisualvm Java uygulamalarının davranışını  ve başarımını izlemek, kesitini çıkarmak (=profiling), sorunun türünü tespit etmek ve kaynağını belirlemek için kullanılabilecek JDK içinden çıkan görsel bir araçtır. jvisualvm, jconsole gibi hem yerel hem de uzaktaki bir makinadaki Java uygulamaları için kullanılabilir. Şimdi jvisualvm ekranlarını inceleyelim:
Hem yerel makinadaki hem de uzaktaki bir makinadaki (örneğin host02.example.com makinasındaki) Java proseslerini seçip izleyebilirsiniz. 
Yerel makinadaki hem de uzaktaki bir makinadaki 25192 kimlik numarasına sahip Java uygulamasına bağlandık. JSM özet bilgilerine bu ekrandan ulaşabilirsiniz: JSM versiyonu. çalıştırma parametreleri ve sistemi özelliklerini okumak mümkündür.
Monitor ekranında, Heap ve işlemci kullanımını, İplik ve yüklenen sınıf sayılarını izleyebilirsiniz.
İpliklerin sayısını ve listesini bu ekrandan izleyebilirsiniz. İsterseniz listeden bir iplik seçip şu an hangi metodu çalıştırdığını ve çağrı yığınına bakabilirsiniz. 
Örnekleme yaparak üretim ortamındaki bir sunucudan uygulama başarımını fazla etkilemeden uygulamanın vaktini hangi metodlarda geçirdiğini ve hangi sınıftan ne kadar nesne yaratıldığını izleyebilirsiniz.
Uygulamanın kendisine ayrılan işlemci zamanında bu zamanı hangi metodlarda geçirdiğini öğrenebilirsiniz. Bir uygulamayı hızlandırmak istiyorsanız ilk bakacağınız yer bu listenin tepesindeki metodlar olmalıdır.

Uygulama en fazla hangi sınıftan nesne yaratıyor ? Bu nesneler bellekte ne kadar yer kaplıyor? sorularına yanıt alabilirsiniz.
Heap kullanımını grafiksel olarak bu ekrandan görsel olarak izleyebilirsiniz.
jvisualvm kullanarak uygulamanın kesitini çıkarmak mümkündür. Problemin nedenine yönelik kesin teşhis koyabilmek için kesitini almamız gerekebilir. Bu maliyetli bir işlemdir ve çoğu zaman üretim ortamındaki bir uygulamada bunu yapmak mümkün olmaz. jvisualvm kullanarak kesit almak ile ilgili detayları bu yazının ikinci bölümünde ele alacağız.



jmc

Oracle'ın Sun'ı satın almazdan önce jRockit isimli bir JSM'si bulunuyordu. Genellikle üretim ortamında çalıştırılacak Oracle orta katman uygulamalarını bu JSM üzerinde çalıştırıyorduk. OracleSun'ı satın satın aldıktan sonra ise Sun'ın geliştirdiği HotSpot ile devam etmeye karar verdi ve jRockit'in geliştirilmesini durdurdu. jRockit'in Mission Control ve Flight Recorder gibi jRockit üzerinde çalışan Java uygulamalarını izlemek için kullanıldığımız gelişmiş araçları bulunuyor. Oracle şimdi bu araçları, JDK 7u40 sürümünden itibaren JDK ile birlikte dağıttığını görüyoruz. jmc'nin ticari kullanımının ücretli olduğunu bilmelisiniz. HotSpot'u varsayılan ayarlar ile çalıştırdığınızda Flight Recorder özelliğinin kapalı olduğunu belirtmeliyim. jmc ile Flight Recorder özelliğini kullanabilmek için uygulamayı aşağıdaki HotSpot seçenekleri ile başlatmalısınız:
[oracle@host01 ~]$ export JAVA_OPTS="-XX:+UnlockCommercialFeatures -XX:+FlightRecorder"
jmc detaylarını yazının ikinci bölümünde inceleyeceğiz. Şimdi jmc'nin yeteneklerini ekran görüntüleri üzerinden inceleyelim:

Java Mission Control (jmc) karşılama ekranı
Makinadaki Java uygulamalarının bir listesini solda görebilirsiniz. İzlemek istediğiniz uygulama altındaki MBean Server başlığına çift tıklayarak JMX üzerinden uygulamaya bağlanabilirsiniz. 
Ortadaki alanda gelişmiş grafiklerde Heap, İşlemci ve bellek kullanımı izleyebilirsiniz. Bu alanı izlemek istediğiniz JSM özelliklerini seçerek siz de ihtiyaçlarınıza göre tasarlayabilirsiniz.
Soldaki ağaçtaki Flight Recorder başlığından kara kutunu kaydını başlatabilirsiniz.
Kara kutunun neleri kayıt edeceğinin seçimi hem sorunu açıklayabilmek hem de uygulama başarımını fazla etkilememek için önemlidir. Flight Recorder'ı bir uçağın kara kutusuna benzetebiliriz. Uçağın düşmesini arzu etmeyiz. Ama uçak düştüğünde, uçağın neden düştüğünü açıklamak, aynı hatayı tekrarlamamak için önemlidir.
Yazının ikinci bölümünde jvisualvm, jmc ve mat (Eclipse memory analyzer) kullanarak örnek sorunlu uygulamalar üzerinde, bu araçların nasıl kullanılabileceğini, uygulamalı olarak inceleyeceğiz.

2 comments:

  1. Binnur bey merhaba,

    Yazınız çok güzel, tebrik ederim.
    Yazının ikinci kısmını bulamadım blog'unuzda, yazmış mıydınız acaba?

    Teşekkürler

    ReplyDelete
  2. Henüz yazmadım. Bu yıl öncelikli olarak yazacağım yazılardan biri olacak.

    ReplyDelete