Sean的吃喝玩樂+工作: t-442-1

顯示具有 t-442-1 標籤的文章。顯示所有文章

2011年4月1日星期五

收集系統information

#觀察系統一般參數
RH20 /home/cts>cat report1.sh
#!/bin/bash
LOG=~/report1.log
date > $LOG
echo "" >> $LOG
echo "=========================df==============================" >> $LOG
df >> $LOG
echo "" >> $LOG
echo "======================blockdev===========================" >> $LOG
blockdev --report /dev/sda >> $LOG
echo "" >> $LOG
echo "======================grub.conf==========================" >> $LOG
cat /etc/grub.conf >> $LOG
echo "" >> $LOG
echo "======================lsb_release========================" >> $LOG
lsb_release -a >> $LOG
echo "" >> $LOG
echo "=======================uname=============================" >> $LOG
uname -a >> $LOG
echo "" >> $LOG
echo "======================meminfo============================" >> $LOG
cat /proc/meminfo >> $LOG
echo "" >> $LOG
echo "======================cpuinfo============================" >> $LOG
cat /proc/cpuinfo >> $LOG
echo "" >> $LOG
echo "======================iostat=============================" >> $LOG
iostat -x >> $LOG
echo "" >> $LOG
echo "======================vmstat=============================" >> $LOG
vmstat -m >> $LOG
echo "" >> $LOG
vmstat -a >> $LOG
echo "" >> $LOG
vmstat -n >> $LOG
echo "" >> $LOG
vmstat -s >> $LOG
echo "" >> $LOG
vmstat -d >> $LOG

echo "" >> $LOG
echo "======================sysctl=============================" >> $LOG
sysctl -a | grep -e lowmem -e pressure -e page-cluster -e zone >> $LOG

#觀察系統io參數
RH20 /home/cts>cat report2.sh
#!/bin/bash
LOG=~/report2.log
date > $LOG
echo "" >> $LOG
echo "======================scheduler==========================" >> $LOG
cat /sys/block/sda/queue/scheduler >> $LOG
echo "" >> $LOG
echo "====================read_ahead_kb========================" >> $LOG
cat /sys/block/sda/queue/read_ahead_kb >> $LOG
echo "" >> $LOG
echo "====================nr_requests==========================" >> $LOG
cat /sys/block/sda/queue/nr_requests >> $LOG
echo "" >> $LOG
echo "===================antic_expire==========================" >> $LOG
cat /sys/block/sda/queue/iosched/antic_expire >> $LOG
echo "" >> $LOG
echo "===================read_expire===========================" >> $LOG
cat /sys/block/sda/queue/iosched/read_expire >> $LOG
echo "" >> $LOG
echo "===================write_expire==========================" >> $LOG
cat /sys/block/sda/queue/iosched/write_expire >> $LOG
echo "" >> $LOG
echo "=====================quantum=============================" >> $LOG
cat /sys/block/sda/queue/iosched/quantum >> $LOG
echo "" >> $LOG
echo "=====================queue===============================" >> $LOG
cat /sys/block/sda/queue/iosched/queue >> $LOG
echo "" >> $LOG
echo "=================front_merges============================" >> $LOG
cat /sys/block/sda/queue/iosched/front_merges >> $LOG
for pidd in $(pidof XGateway)
do
echo "" >> $LOG
top -n 1 -S -b -p $pidd >> $LOG
echo "" >> $LOG
ps -p $pidd -o comm,cmd,user,group >> $LOG
done

echo "" >> $LOG
top -S -b -n1 >> $LOG

#觀察2天的file fragmentation
RH20 /home/cts>cat report3.sh
#!/bin/bash
LOG=~/report3.log
date1="20110317"
date2="20110324"
date > $LOG
echo "" >> $LOG
echo "=========================KGIStkLog==============================" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/KGIStkLog/10.0.250.24.Ord >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/KGIStkLog/10.0.250.24.Ord >> $LOG
echo "" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/KGIStkLog/10.0.250.24.Rpt >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/KGIStkLog/10.0.250.24.Rpt >> $LOG
echo "" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/KGIStkLog/10.0.250.24.RptOth >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/KGIStkLog/10.0.250.24.RptOth >> $LOG
echo "" >> $LOG

echo "" >> $LOG
echo "=========================KStkSesLog=============================" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/KStkSesLog/192.168.248.92.Ord >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/KStkSesLog/192.168.248.92.Ord >> $LOG
echo "" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/KStkSesLog/192.168.248.93.Ord >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/KStkSesLog/192.168.248.93.Ord >> $LOG
echo "" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/KStkSesLog/192.168.248.93.PreRpt >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/KStkSesLog/192.168.248.93.PreRpt >> $LOG
echo "" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/KStkSesLog/192.168.248.93.Rpt >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/KStkSesLog/192.168.248.93.Rpt >> $LOG
echo "" >> $LOG

echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/KStkSesLog/All.inn >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/KStkSesLog/All.inn >> $LOG
echo "" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/KStkSesLog/All.preinn >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/KStkSesLog/All.preinn >> $LOG
echo "" >> $LOG

echo "" >> $LOG
echo "=========================orderlog===============================" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/orderlog/IvacMatch.rec >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/orderlog/IvacMatch.rec >> $LOG
echo "" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/orderlog/IvacOrder.rec >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/orderlog/IvacOrder.rec >> $LOG
echo "" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/orderlog/LocalIvacMatch.rec >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/orderlog/LocalIvacMatch.rec >> $LOG
echo "" >> $LOG

echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/orderlog/IvacStkLocalMat/0000 >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/orderlog/IvacStkLocalMat/0000 >> $LOG
echo "" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/orderlog/IvacStkLocalOrd/0000 >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/orderlog/IvacStkLocalOrd/0000 >> $LOG
echo "" >> $LOG
echo "" >> $LOG
echo "=========================OrderLog===============================" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/OrderLog/Stk/Deals.bin >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/OrderLog/Stk/Deals.bin >> $LOG
echo "" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/OrderLog/Stk/SysOrds.inn >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/OrderLog/Stk/SysOrds.inn >> $LOG
echo "" >> $LOG

echo "" >> $LOG
echo "=========================SyncLog================================" >> $LOG
echo "$date1" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date1/SyncLog/Stk.Sync >> $LOG
echo "$date2" >> $LOG
/usr/sbin/filefrag -v /xgw/XGW.Stk.K1/Logs/$date2/SyncLog/Stk.Sync >> $LOG
echo "" >> $LOG

2011年3月31日星期四

AP@Linux Disk IO 效能調校

針對本次的測試說明如下:
1.使用Bryan提供的測試程式(XGW.STK.K1，以下簡稱XGW)(內含56000多筆的資料)來進行測試,
   壓力測試程式在Windows 7(小黑nb,172.16.43.144)上執行
   同時也執行了模擬後端主機(dbs)接收的的程式
2.本次的XGW在3台機器上分別進行驗證,不過主要以驗證PC -1為主,硬體與作業系統規格如下


PC - 1 kernel 2.6.18-164.el5PAE
distribution RHEL5.4(172.16.43.99)
memory MemTotal: 3916364 kB
cpu Intel(R) Core(TM)2 Quad CPU Q8400 @ 2.66GHz
disk 500G 7200rpm(single)
PC - 2 kernel 2.6.18-92.el5
distribution RHEL5.2(172.16.43.171)
memory MemTotal: 3107452 kB
cpu Intel(R) Pentium(R) Dual CPU E2140 @ 1.60GHz
disk 160G 7200rpm(single)
PC - 3 kernel 2.6.18-194.el5 
distribution CentOS5.5(172.16.43.170)
memory MemTotal: 16411680 kB
cpu Intel(R) Xeon(R) CPU E5506 @ 2.13GHz(quard core * 2)
disk 7200 rpm(raid-5, 146G*3)

3.本次測試以上3台都同樣在172.16.43.0/24 網段上進行,所以應該不會有網路的堵塞問題
   曾經試過對172.16.53.20進行測試,都會莫名其妙增加很多時間,推測,可能是172.16.53.0/24上有人大量丟封包


測試方法說明:
1.先在PC - 1進行完整的測試
   (1)以作業系統剛安裝好的參數,先進行一次測試,當成參考值
   (2)針對Block Device的各項參數進行調整(依開發人員描述,主要為disk io所影響)
   (3)測試時,以相同的壓測步驟與XGW初始化環境一一進行驗證
   (4)測試期間收集送完56000筆的時間,XGW主機的整體cpu使用狀況,單一支XGW使用cpu狀況,系統wait io的狀況進行資料收集
2.從1.所測試出來的較佳幾個系統調整狀況,在PC-2及PC-3上面也進行驗證
   (1)在較老的機器上(PC-2)進行驗證
   (2)在較佳的機器上(PC-3, 有做raid-5)進行驗證
   (3)以上2個再跟PC-1進行對照驗證
3.在PC-1上安裝ramdisk同時驗證效能


測試結果如下:

黃色那一行是作業系統出廠的預設參數所測出來的結果(nr_requests 預設為128,預設為cfq)
土色那一行是調整後,得到較佳數據的2個結果, wa(wait for disk IO)的狀況有呈現較好的狀況,數據也反應在time欄位上
紫色是依據PC-1的結果,也同樣在PC-2 , PC-3上面驗證的結果


HDD nr_requests episode time(sec) min CPU idle% avg CPU idle% XGW useage% wa%(inc. in idle) PC2 time PC3 time
cfq 64 0c0101092 173 
128 0c0202092 157 44 68.09 45.66 19.2 168 82
512 0c01020c1 121 
1024 0c01030c1 85 
2048 0c0103092 86 115 66
4096 0c01010c1 93 35 63.26 56.06 18.65 116 65
anticipatory 64 0b0101012 159 
128 0b0202012 153 
2048 0b0103012 85 114 71
4096 0b01010c1 77 55 72.88 62.8 11.04 115 69
deadline 64 0a0101012 171 
128 0a0202012 159 
2048 0a0103012 101 121 121
noop 64 0d01010b1 163 
128 0d02020b1 171 
2048 0d01030b1 140 181 231




ramdisk nr_requests episode time diff
cfq 128 - 79
1024 - 79
2048 - 76
anticipatory 128 - 79

結論與建議
1. 從結果可以得知
     (1)nr_requests(queue length)增加,對系統disk io的效能確實有效果(nr_requests有助減少seek time)
     (2)ramdisk因為沒有磁頭,沒有seek time的issue,然而效能本身己經很好
     (3)raid-5 (pc-3)的效能,在經過調整後,在本案的情境下,可以比ramdisk更好
2. 建議
     (1)依以下調整參數(建議先使用"cfq" , nr_requests=4096)
        在/etc/rc.local上面新增一筆
         echo 4096 > /sys/block/[disk device]/queue/nr_requests
         上面[disk device]請置換上XGW所安裝與執行的device上,例如sda(如果我記得沒錯,GW15跟16應該都是sda)
         重新開機後啟動XGW
         注意,nr_requests的增加,在系統異常時,愈有機會發生資料未完全寫入硬碟裡
                  異常發生時,建議確認XGW是否有漏寫資料,如果有發生,需要實際操作補送與寫入的作業(XGW跟後台間回報序號倒回重補的作業)
      (2)使用raid-5
         從 PC-3的結果可以看出raid-5的IO throughput本身就己經很優秀,再經調整後,
         已可以比PC-1的預設情境好上很多
      (3)使用ramdisk(非SSD)
         ramdisk本身是效能己經很好,不過因為他對nr_requests的設定是沒幫助的,不過效能穩定性高上許多
         再者,坊間對Ramdisk己可以支援raid,所以加乘使用,效果應該會更佳
    以上的建議,請事先驗證過後,再行開放,
    若有發生效率沒有明顯改善時,請確認壓測過程是否有網路的干擾因素(如前所述,可能會有網路堵塞或者效率不佳的因素)
補充說明:
  1. file fragmentation
    上次在客戶XGW上收集回來的資料,有對於XGW flush機制換版前後進行log檔結構分析
    在換版前(2011/03/17)的每個log(大檔,尤其是Ord,Rpt,RptOth及Sync log等),其fragmentation(檔案的破碎程度)
     大概都在100~300以上
     在換上新版後(2011/03/24)每個log(尤其是剛才那3個檔),其fragmentation都降到大概在10之間
     該次換版效能的改善從中可以發現一斑
     檔案的fragment會嚴重影響IO的效能,
  2. elevator
    (1)noop
       不使用任何elevator機制
     (2)deadline
       使用one-way的作業,在執行disk read或write時會去merge目前queue裡的 requests(有助降低seek time),對於"read"的作業更甚於"write",為了避免resource starvation,系統提供了許多的expire機制.這個elevator配合TQC及效率較佳的Disk,很適合拿來做資料庫系統
     (3)anticipatory
       在kernel 2.6版之前,這個elevator是預設的.在執行disk read或write時會去merge目前queue裡的 requests(有助降低seek time),read或write作業是分批作業進行.在進行資料讀取時,會多預讀一些資料起來,系統的預期是,可能接下來的動作是要再繼續往下讀一些,如此在某些情境下,可以減少磁頭的移動.或許針對某些資料庫可以提供很好的效率(在某些特定條件下)
       前面在的測試,在某些情況下,anticipatory反而比cfq好,或許跟XGW.STK.K1在這次的案例裡,幾乎只有write動作有關,所以系統做request merge的效率很好
     (4)cfq
       Complete Fair Queueing Scheduler, 這是最中庸的elevator,因為它是round robin的處理作業,針對各process提供相同的device IO requests數量.這個elevator在kernel 2.6之後,就是預設的.提供read and write的requests merging.這種elevator適用在多使用者的環境下(筆者另外解讀,在multi-process或multi-file-IO下也蠻適合的).
       本例在XGW.STK.K1是multi-thread會同時開啟許多個檔案進行write作業,所以cfq的作業在預計的nr_requests=128或許效果沒那麼好,可是在nr_requests愈來愈大的情況下,merging效果愈好,約在2048~4096就有很好的成效

     本次的測試,覺得noop不好,因為系統沒那個條件不做elevator(有人建議,若disk device有很好的request 管理機制,可以用noop);deadline,為因read優先於write ,或許因為這樣測不出好數據(實際上的XGW.STK.K1應該有read也有write );anticipatory或許因為XGW.STK.K1在本例中幾乎都只有write,所以有好的數據;所以筆者覺得cfq配合高的nr_requests較保險,也較能預期對實際狀況(有read也有write)下能有不錯的效能提升
  
   3.system call的分析 
     一般系統調完了,大概也知道程式本身的一些特性,其實程式本身也可以進行分析,提供給開發人員,或者也能夠對系統效率有些改善

nr_requests=4096配合anticipatory
[root@HTS099 queue]# ps -ef | grep XG
root      5909     1 17 21:12 ?        00:00:02 ./XGateway -d
root      5937  4663  0 21:12 pts/2    00:00:00 grep XG
[root@HTS099 queue]# strace -p 5909 -c
Process 5909 attached - interrupt to quit
Process 5909 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 73.46    0.610550           0   5683975           write
 19.98    0.166032           1    112149         1 poll
  1.59    0.013212           0   1858339           gettimeofday
  1.37    0.011416           0    836665           lseek
  1.12    0.009291         107        87           close
  0.71    0.005923           0    154532      5137 read
  0.59    0.004914           0     56046           send
  0.58    0.004855           0    337399           time
  0.49    0.004064           0    112092     56047 recv
  0.06    0.000508           3       185        25 open
  0.02    0.000144           2        90           munmap
  0.02    0.000136           3        53        53 connect
  0.00    0.000036           0       542           brk
  0.00    0.000017           0        53           socket
  0.00    0.000013           0       152           getsockopt
  0.00    0.000000           0        10         8 mkdir
  0.00    0.000000           0         1         1 sigreturn
  0.00    0.000000           0         1           mremap
  0.00    0.000000           0        91           mmap2
  0.00    0.000000           0         1           madvise
  0.00    0.000000           0       110           fcntl64
  0.00    0.000000           0         2           futex
  0.00    0.000000           0         2           tgkill
  0.00    0.000000           0         4         2 accept
  0.00    0.000000           0         4           getsockname
  0.00    0.000000           0         4           getpeername
  0.00    0.000000           0        51           setsockopt
------ ----------- ----------- --------- --------- ----------------
100.00    0.831111               9152640     61274 total

nr_requests=4096配合cfq
[root@HTS099 queue]# strace -p 5552 -c
Process 5552 attached - interrupt to quit
Process 5552 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 87.57    1.342217           0   5684176           write
  8.93    0.136850           1    112181         1 poll
  0.85    0.012984           0   1858717           gettimeofday
  0.71    0.010894           0    836729           lseek
  0.58    0.008904          95        94           close
  0.42    0.006392           0    153624      4182 read
  0.35    0.005406           0     56046           send
  0.33    0.005123           0    337500           time
  0.21    0.003238           0    112092     56047 recv
  0.02    0.000311           2       189        29 open
  0.01    0.000132           2        60        60 connect
  0.01    0.000099          50         2           futex
  0.00    0.000075           1        88           munmap
  0.00    0.000026           0       524           brk
  0.00    0.000020           0        60           socket
  0.00    0.000012           0       167           getsockopt
  0.00    0.000000           0        10         8 mkdir
  0.00    0.000000           0         1         1 sigreturn
  0.00    0.000000           0         1           mremap
  0.00    0.000000           0        91           mmap2
  0.00    0.000000           0       124           fcntl64
  0.00    0.000000           0         2           tgkill
  0.00    0.000000           0         4         2 accept
  0.00    0.000000           0         4           getsockname
  0.00    0.000000           0         4           getpeername
  0.00    0.000000           0        57           setsockopt
------ ----------- ----------- --------- --------- ----------------
100.00    1.532683               9152547     60330 total

ramdisk配合anticipatory
[root@HTS099 queue]# ps -ef | grep XG
root      6260     1  7 21:18 ?        00:00:01 ./XGateway -d
root      6301  4663  0 21:18 pts/2    00:00:00 grep XG
[root@HTS099 queue]# strace -p 6260 -c
Process 6260 attached - interrupt to quit
Process 6260 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 42.12    0.495718           3    154737      5362 read
 38.00    0.447302           0   5683978           write
 15.87    0.186833           2    112153         1 poll
  1.20    0.014139           0   1858164           gettimeofday
  0.88    0.010348           0    836666           lseek
  0.74    0.008721         101        86           close
  0.48    0.005594           0     56046           send
  0.41    0.004834           0    337403           time
  0.28    0.003326           0    112092     56047 recv
  0.01    0.000118           1       186        26 open
  0.00    0.000033           1        53        53 connect
  0.00    0.000022           0       155           getsockopt
  0.00    0.000018           0        53           socket
  0.00    0.000009           0       523           brk
  0.00    0.000008           0        91           mmap2
  0.00    0.000004           0       110           fcntl64
  0.00    0.000000           0        10         8 mkdir
  0.00    0.000000           0        88           munmap
  0.00    0.000000           0         1         1 sigreturn
  0.00    0.000000           0         1           mremap
  0.00    0.000000           0         4           futex
  0.00    0.000000           0         2           tgkill
  0.00    0.000000           0         4         2 accept
  0.00    0.000000           0         4           getsockname
  0.00    0.000000           0         4           getpeername
  0.00    0.000000           0        50           setsockopt
------ ----------- ----------- --------- --------- ----------------
100.00    1.177027               9152664     61500 total


ramdisk配合cfq
[root@HTS099 queue]# ps -ef | grep XG
root      6608     1 13 21:24 ?        00:00:01 ./XGateway -d
root      6638  4663  0 21:24 pts/2    00:00:00 grep XG
[root@HTS099 queue]# strace -p 6608 -c
Process 6608 attached - interrupt to quit
Process 6608 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 41.36    0.354313           2    153443      4036 read
 32.29    0.276602           0   5683977           write
 20.06    0.171828           2    112155         1 poll
  1.79    0.015369           0    836666           lseek
  1.69    0.014454           0   1858390           gettimeofday
  1.04    0.008922         104        86           close
  0.68    0.005864           0     56046           send
  0.58    0.004947           0    337403           time
  0.38    0.003217           0    112092     56047 recv
  0.09    0.000764           4       186        26 open
  0.01    0.000094           1        88           munmap
  0.01    0.000094           2        53        53 connect
  0.00    0.000035           0       524           brk
  0.00    0.000027           0       155           getsockopt
  0.00    0.000012           0        91           mmap2
  0.00    0.000011           0       110           fcntl64
  0.00    0.000000           0        10         8 mkdir
  0.00    0.000000           0         1         1 sigreturn
  0.00    0.000000           0         1           mremap
  0.00    0.000000           0         1           futex
  0.00    0.000000           0         1           tgkill
  0.00    0.000000           0        53           socket
  0.00    0.000000           0         4         2 accept
  0.00    0.000000           0         4           getsockname
  0.00    0.000000           0         4           getpeername
  0.00    0.000000           0        50           setsockopt
------ ----------- ----------- --------- --------- ----------------
100.00    0.856553               9151594     60174 total

     
補充指令：
     sysctl -w vm.drop_caches=3
     filefrage -v /path to file
     cat /proc/[pid]/status (see "thread"), man 5 proc
     cat /proc/#/status
     cat /proc/interrupt
     cat /proc/partitions (major:minor)
     lspci -v查出硬體與IRQ
     SATA: smartctl -a /dev/sda查詢硬碟資訊
             smartctl -a /dev/sda -d ata"
     dmesg | more 也可以查出一些硬體資訊

     監控目前HDD有在IO作業的PROCESS是哪一支

     while true; do date; ps auxf | awk '{if($8=="D") print $0;}'; sleep 1; done

     sleep 1若改usleep 300000, 則0.3秒監控一次,可以更快反應

     其中,可以取得PID , 進一步透過/proc/PID/io 來找出相對應的read/write統計資料

       rchar => This is the total reads caused by the process in bytes. This includes bytes read from the disk or from console

wchar => The same as rchar but it accounts for bytes written instead of read

read_bytes => Actual number of bytes read from the storage

write_bytes => Actual bytes written to the storage

Here's the script that shows you the top 5 processes which are reading data from disk:

grep read_bytes /proc/[0-9]*/io | sort -nrk2 | head -5

writing data, execute the following:

grep write_bytes /proc/[0-9]*/io | sort -nrk2 | head -5

There's also an utility called "iotop" which does the same thing in real time and gives you better top-like output

yum install iotop

     /proc/PID/status, 則是方面的統計內容

參考資料:
http://yoshinorimatsunobu.blogspot.com/2009/04/linux-io-scheduler-queue-size-and.html

http://www.softpanorama.org/Commercial_linuxes/performance_tuning.shtml

2011年3月23日星期三

process用top監控的方便

一般用top監控,如果想要留記錄來比較,可能會覺得不太方便,以下是可以留一個時間跟資料內容來當成追蹤記錄
top -S -b -p $(pidof XGateway) grep -e XGateway -e average
[結果]
top - 16:13:11 up 42 days, 21:00, 4 users, load average: 1.11, 1.19, 1.17
31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:12.54 XGateway
top - 16:13:14 up 42 days, 21:00, 4 users, load average: 1.10, 1.18, 1.17
31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:12.54 XGateway
top - 16:13:17 up 42 days, 21:00, 4 users, load average: 1.41, 1.25, 1.19
31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:12.54 XGateway
top - 16:13:20 up 42 days, 21:00, 4 users, load average: 1.41, 1.25, 1.19
31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:12.54 XGateway
top - 16:13:23 up 42 days, 21:00, 4 users, load average: 1.46, 1.26, 1.20

[root@RH20 cts]# cat top.sh#!/bin/bash
pidd=$(pidof XGateway)
while [ 1 ]
do

#Solaris不適用
echo "$(date +%H:%M:%S) $(top -n1 -S -b -p $pidd | grep -e XGateway )"
usleep 500000
done

[結果]17:01:19 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway
17:01:20 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway
17:01:21 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway
17:01:22 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway
17:01:23 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway
17:01:24 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway
17:01:25 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway
17:01:26 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway
17:01:27 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway
17:01:28 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway
17:01:29 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway
17:01:30 31555 cts 15 0 227m 60m 8416 S 0.0 1.6 0:15.84 XGateway

[root@RH20 cts]# cat vmstat.sh#!/bin/bash
#pidd=$(pidof XGateway)
while [ 1 ]
do
str="$(vmstat 1 2| tail -n 1)"

#在solaris這行要改成 "$(vmstat 1 2 | tail -1l)"

echo "$(date +%H:%M:%S) $str"
done

[結果][root@RH20 cts]# ./vmstat.sh
20:21:02 0 0 896 1011492 325056 2152676 0 0 0 0 1006 4532 2 3 96 0 0
20:21:03 0 0 896 1011616 325056 2152676 0 0 0 260 1059 4558 1 2 97 0 0
20:21:04 0 0 896 1011616 325056 2152684 0 0 0 0 1004 4759 1 2 97 0 0
20:21:05 2 0 896 1011616 325056 2152684 0 0 0 0 1010 2977 1 1 98 0 0


[root@RH20 cts]# cat iostat.sh
#==================================================
# you must install sysstat-* rpm for iostat
#==================================================

#iostat有不同版本,取得字串的行數就會不一樣
iostatver=$(iostat -V &> /dev/stdout | grep sysstat)
if [ "$iostatver" != "" ]; then
ntail=2
nhead=1
else
ntail=1
nhead=1
fi 

if [ "$1" != "" ]; then
device="$1"
else
device="sda"
fi

while [ 1 ]
do
strdate=$(date +%H:%M:%S)
#strstr=$(iostat -x $1 $2 $3 $4 $5 1 2 | tail -n $ntail | head -n $nhead | awk 'NR==1{ printf " %s %s\n","########",$0} NR>=2{printf " %s %s\n","        ",$0}' | sed 's/########/'${strdate}'/')
strstr=$(iostat -x $device 3 2 | tail -n $ntail | head -n $nhead | awk 'NR==1{ printf " %s %s\n","########",$0} NR>=2{printf " %s %s\n","        ",$0}' | sed 's/########/'${strdate}'/')
echo "$strstr"

done

[結果]RH20 /home/cts>./iostat.sh sda
 13:58:58 sda        0     1    0.0    3.0     0.0    16.0    5.3   0.0    0.0   0.0   0
 13:58:59 sda        0     0    0.0    0.0     0.0     0.0    0.0   0.0    0.0   0.0   0
 13:59:00 sda        0    33    0.0   12.0     0.0   192.0   16.0   0.2   18.9   2.0   2

2010年12月13日星期一

process監控的問題與替代方法

在監控某一process時，常用
watch -n1 ps -p $(pidof 'process name' ) -o comm,pid,vss,rsz,pcpu,pri,cstime,cutime,utime
或者
while :; do date; ps -p $(pidof 'process name') -o comm,pid,vss.rsz,pcpu,pri,cstime,cutime,utime ;sleep 1; done
while :; do date; ps -oe comm,pid,vss,rsz,pcpu,pri,cstime,cutime,utime | grep 'process name' ;sleep 1; done
或者
for pidd in $(pidof 'process name')
do
top -n 1 -S -b -p $pidd >> $LOG
ps -p $pidd -o comm,cmd,user,group >> $LOG
done

但會發現pcpu(欄位%CPU)不會變,跟top指令比較，TOP確會變
於是修改指令如下，即可：
while :; do date; top -n 1 -S -b | grep vmware-vmx;sleep 1; done

[AIX]
ps -p 442584 -o args,pid,vsz,pcpu
ps -ef -o args,pid,vsz,pcpu

#!/usr/bin/ksh
if [ "$1" = "" ] ; then
echo "you need to entery the [pid] what you want to lookup."
echo "shell>./mon.sh [pid]"
exit 0;
else
# while :; do date >> ~/mon.log;ps -ef -o comm,pid,pcpu,vsz | grep $1 >> ~/mon.log ; sleep 5; done
while :; do date >> ~/mon.log;ps -efl | grep $1 >> ~/mon.log ; sleep 5; done
fi

[結果]
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
200003 A root 1 0 0 60 20 d8039000 756 Nov 24 - 0:21 /etc/init
240001 A root 98420 1 0 60 20 d0138400 496 * Nov 24 - 11:37 /usr/sbin/syncd 60
40401 A root 102602 1 0 60 20 e803f400 828 10a09d8 Nov 24 - 0:00 /usr/lib/errdemon

TIME
(all flags) The total execution time for the process.
TTY
(all flags) The controlling workstation for the process:
-
The process is not associated with a workstation.
?
Unknown.
Number
The TTY number. For example, the entry 2 indicates TTY2.
UID
(-f, -l, and l flags) The user ID of the process owner. The login name is printed under the -f flag.
WCHAN
(-l flag) The event for which the process or kernel thread is waiting or sleeping. For a kernel thread, this field is
blank if the kernel thread is running. For a process, the wait channel is defined as the wait channel of the sleeping
kernel thread if only one kernel thread is sleeping; otherwise STIME
(-f and u flags) The starting time of the process. The LANG environment variables control the appearance of this
field.
SZ
(-l and l flags) The size in 1KB units of the core image of the
NI
(-l and l flags) The nice value; used in calculating priority for the sched other policy.
PID
(all flags) The process ID of the process.
PGIN
(v flag) The number of disk I/Os resulting from references by the process to pages not loaded in core.
PPID
(-f, l, and -l flags) The process ID of the parent process.
PRI
(-l and l flags) The priority of the process or kernel thread; higher numbers mean lower priority.
S
(-l and l flags) The state of the process or kernel thread :(見man ps)
F
(-l and l flags) Some of the more important F field flags (hexadecimal and additive) associated with processes and
threads are shown in the following table:(見man ps)
CMD
(-f, -l, and l flags) Contains the command name. Under the -f flag, ps tries to determine the current command name and
arguments both of which may be changed asynchronously by the process. These are then displayed. Failing this, the
command name as it would appear without the option -f, is written in square brackets.

ADDR
(-l and l flags) Contains the segment number of the process stack, if normal; if a kernel process, the address of the
preprocess data area.
C
(-f, l, and -l flags) CPU utilization of process or thread, incremented each time the system clock ticks and the
process or thread is found to be running. The value is decayed by the scheduler by dividing it by 2 once per second.
For the sched_other policy, CPU utilization is used in determining process scheduling priority. Large values indicate
a CPU intensive process and result in lower process priority whereas small values indicate an I/O intensive process
and result in a more favorable priority.

訂閱：文章 (Atom)

Sean的吃喝玩樂+工作

2011年4月1日星期五

收集系統information

2011年3月31日星期四

AP@Linux Disk IO 效能調校

2011年3月23日星期三

process用top監控的方便

2010年12月13日星期一

process監控的問題與替代方法

文章分類

網誌存檔

關於我自己

PC - 1	kernel	2.6.18-164.el5PAE
	distribution	RHEL5.4(172.16.43.99)
	memory	MemTotal: 3916364 kB
	cpu	Intel(R) Core(TM)2 Quad CPU Q8400 @ 2.66GHz
	disk	500G 7200rpm(single)
PC - 2	kernel	2.6.18-92.el5
	distribution	RHEL5.2(172.16.43.171)
	memory	MemTotal: 3107452 kB
	cpu	Intel(R) Pentium(R) Dual CPU E2140 @ 1.60GHz
	disk	160G 7200rpm(single)
PC - 3	kernel	2.6.18-194.el5
	distribution	CentOS5.5(172.16.43.170)
	memory	MemTotal: 16411680 kB
	cpu	Intel(R) Xeon(R) CPU E5506 @ 2.13GHz(quard core * 2)
	disk	7200 rpm(raid-5, 146G*3)

HDD	nr_requests	episode	time(sec)	min CPU idle%	avg CPU idle%	XGW useage%	wa%(inc. in idle)	PC2 time	PC3 time
cfq	64	0c0101092	173
	128	0c0202092	157	44	68.09	45.66	19.2	168	82
	512	0c01020c1	121
	1024	0c01030c1	85
	2048	0c0103092	86					115	66
	4096	0c01010c1	93	35	63.26	56.06	18.65	116	65
anticipatory	64	0b0101012	159
	128	0b0202012	153
	2048	0b0103012	85					114	71
	4096	0b01010c1	77	55	72.88	62.8	11.04	115	69
deadline	64	0a0101012	171
	128	0a0202012	159
	2048	0a0103012	101					121	121
noop	64	0d01010b1	163
	128	0d02020b1	171
	2048	0d01030b1	140					181	231

ramdisk	nr_requests	episode	time diff
cfq	128	-	79
	1024	-	79
	2048	-	76
anticipatory	128	-	79

Sean的吃喝玩樂+工作

2011年4月1日 星期五

收集系統information

2011年3月31日 星期四

AP@Linux Disk IO 效能調校

2011年3月23日 星期三

process用top監控的方便

2010年12月13日 星期一

process監控的問題與替代方法

文章分類

網誌存檔

關於我自己

2011年4月1日星期五

2011年3月31日星期四

2011年3月23日星期三

2010年12月13日星期一