一個ab壓測排查系統瓶頸的例子

時間  2019-12-04
標籤 一個 排查 系統 瓶頸 例子 简体版
原文   原文鏈接

ab添加 Cookie 參數

-Cjava

ab -C cookie1_name=cookie1_value -C cookie2_name=cookie2_value ....

或者能夠用 -H 參數實現mysql

ab -H "Cookie: cookie1_name=cookie1_value; cookie2_name=cookie2_value"

POST

ab -c 100 -n 1000 -p "loginData.txt" -T "application/x-www-form-urlencoded" "http://domainName/app/login"

ab測試命令

C:\Users\lenovo\Desktop\ab> ab -n 4000 -c 4000 -p "post.txt" http://192.168.238.58/app/info/getInfoDetail?Id=360270316a0960c4e05012ac24072db3 >> getInfoDetail.txt

查看服務器狀態

[root@appserver ~]# top
top - 17:57:50 up 53 days,  4:05,  6 users,  load average: 1.52, 0.40, 0.14
Tasks: 138 total,   1 running, 137 sleeping,   0 stopped,   0 zombie
Cpu0  : 14.0%us,  3.7%sy,  0.0%ni, 78.7%id,  3.0%wa,  0.0%hi,  0.7%si,  0.0%st
Cpu1  : 12.6%us,  2.7%sy,  0.0%ni,  6.3%id, 77.7%wa,  0.0%hi,  0.7%si,  0.0%st
Mem:   2056880k total,  2041824k used,    15056k free,   136564k buffers
Swap:  4095992k total,      424k used,  4095568k free,   497432k cached

  PID %MEM  VIRT SWAP  RES CODE DATA  SHR nFLT nDRT S  PR  NI %CPU COMMAND
22432 24.5 1328m 836m 492m    4 1.1g  13m   65    0 S  23   0  0.0 java
22363 18.1  815m 450m 364m  22m 763m  12m   55    0 S  15   0  5.3 mysqld
13387 16.4 1522m 1.2g 329m    4 1.3g  14m  137    0 S  25   0 17.6 java
 2082  1.1 28696 6152  22m  172  20m 1732    0    0 S   6 -10  0.0 iscsiuio
 2496  0.9 30276  11m  18m   12  17m  584    0    0 S  15   0  0.0 restorecond
 2748  0.9  240m 223m  17m    4  31m 5732   76    0 S  15   0  0.0 setroubleshootd
13882  0.6 24340  12m  11m 2596 9680 1928    0    0 S  15   0  1.3 nginx
13881  0.5 22608  12m 9696 2596 7948 1936    0    0 S  15   0  0.0 nginx
 6013  0.5  131m 121m 9420    4 6324 2980    0    0 S  16   0  9.6 iotop
 2975  0.3  151m 144m 6592    4 5476 1048    0    0 S  18   0  0.0 hpssd.py
19922  0.3 95420  86m 6540  388 3912 2696    0    0 S  15   0  0.0 sshd
 2861  0.2 31840  26m 4920  248 3296 1716    0    0 S  15   0  0.0 hald
19924  0.2 58056  52m 4104   52 2588 1588    0    0 S  15   0  0.0 sftp-server
 3172  0.2 92320  86m 3860  388  812 3056    0    0 S  15   0  0.0 sshd
 3667  0.2 92320  86m 3856  388  812 3056    0    0 S  15   0  0.0 sshd
 3170  0.2 93112  87m 3852  388 1604 3052    0    0 S  16   0  0.0 sshd
 3615  0.2 92320  86m 3852  388  812 3056    0    0 S  15   0  0.0 sshd
 6019  0.2 90252  84m 3768  388  812 3000    0    0 S  15   0  0.0 sshd

# 分析：
Cpu1的 %id 空閒僅6.3%，說明Cpu1佔用很高；另等待輸入輸出的CPU時間百分比 %wa 的值很高，說明IO等待比較嚴重，這可能因爲磁盤大量做隨機訪問形成，也有可能磁盤出現瓶頸（塊操做）。

 
 
[root@appserver ~]# iotop -o 
Total DISK READ: 0.00 B/s | Total DISK WRITE: 1442.33 K/s
  TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN     IO>    COMMAND
  466 be/3 root        0.00 B/s    0.00 B/s  0.00 % 60.25 % [kjournald]
    5 rt/3 root        0.00 B/s    0.00 B/s  0.00 % 13.64 % [migration/1]
22385 be/4 mysql       0.00 B/s    0.00 B/s  0.00 % 12.67 % mysqld --basedir=/usr/local/mysql --datadir=/~emall.pid --socket=/tmp/mysql.sock --port=3306
23850 be/4 mysql       0.00 B/s  155.93 K/s  0.00 %  6.17 % mysqld --basedir=/usr/local/mysql --datadir=/~emall.pid --socket=/tmp/mysql.sock --port=3306
13450 be/4 mysql       0.00 B/s   77.96 K/s  0.00 %  6.02 % mysqld --basedir=/usr/local/mysql --datadir=/~emall.pid --socket=/tmp/mysql.sock --port=3306
13349 be/4 root        0.00 B/s    0.00 B/s  0.00 %  2.92 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
22382 be/4 mysql       0.00 B/s    0.00 B/s  0.00 %  2.92 % mysqld --basedir=/usr/local/mysql --datadir=/~emall.pid --socket=/tmp/mysql.sock --port=3306
 5913 be/4 root        0.00 B/s    0.00 B/s  0.97 %  1.95 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
 5851 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.97 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
 5887 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.97 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
 5901 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.97 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
 5911 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.97 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
 5915 be/4 root        0.00 B/s    0.00 B/s  1.95 %  0.97 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
 5908 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.97 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
 5943 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.97 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
 5866 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.97 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
 5930 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.97 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
 5998 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.97 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
13335 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.97 % java -Djava.util.logging.config.file=/usr/loc~mp org.apache.catalina.startup.Bootstrap start
12125 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [pdflush]
22386 be/4 mysql       0.00 B/s    0.00 B/s  0.00 %  0.00 % mysqld --basedir=/usr/local/mysql --datadir=/~emall.pid --socket=/tmp/mysql.sock --port=3306
 1230 be/4 mysql       0.00 B/s    0.00 B/s  0.00 %  0.00 % mysqld --basedir=/usr/local/mysql --datadir=/~emall.pid --socket=/tmp/mysql.sock --port=3306
20213 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % nginx: master process nginx
 1081 be/3 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kedac]

# 分析：
根據io排序能夠看出，kjournald佔用很高，應該是ext3在狂寫數據

[root@appserver src]# vmstat 2
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  2    424  17236 136560 495228    0    0     1     6    0    2  0  0 100  0  0
 0  1    424  16988 136560 495344    0    0     0  1168 1826 13231 13  4 33 49  0
 0  1    424  16244 136560 495456    0    0     0  1260 1304 11291 14  4 32 50  0
 8  1    424  13236 136560 495560    0    0     0  1190 1830 10366 21  5 38 36  0
 0  2    424  17420 136560 495980    0    0     0  1310 1655 12075 21  8 36 35  0
 1  2    424  17420 136560 496120    0    0     0  1318 1462 11666 13  4 43 40  0
 0  2    424  17172 136560 496232    0    0     0  1204 1767 12308 13  4 43 40  0
 0  1    424  16924 136564 496332    0    0     0  1250 1319 12386 14  4 43 40  0
 0  1    424  16676 136564 496440    0    0     0  1188 1834 12372 13  4 43 40  0
 0  1    424  16428 136564 496568    0    0     0  1188 1619 12459 12  4 34 50  0
 0  1    424  16180 136564 496712    0    0     0  1312 1541 11072 12  4 33 50  0
 0  1    424  16056 136564 496820    0    0     0  1180 1843 12342 14  4 41 40  0
 5  2    424  15808 136564 496924    0    0     0  1188 1327 11523 11  4 44 40  0
 0  1    424  15552 136564 497036    0    0     0  1196 1873 11847 14  4 41 41  0
 0  1    424  15304 136564 497164    0    0     0  1150 1298 12873 15  4 43 39  0
 0  1    424  15180 136564 497308    0    0     0  1246 1893 12078 13  4 43 40  0
 1  1    424  15180 136564 497432    0    0     0  1182 1754 11549 12  4 39 45  0
 0  1    424  14932 136568 497516    0    0     0  1242 1465 11814 12  3 44 41  0
 0  1    424  14932 136572 497644    0    0     0  1218 1870 13324 15  4 39 42  0
 2  1    424  14684 136576 497748    0    0     0  1238 1316 11377 12  4 44 41  0
 0  1    424  12592 136576 498052    0    0     0  1290 2695 13277 15  5 42 39  0

# 分析：
procs（進程）的b列表示等待IO的進程數量
io的bo列（每秒寫入的塊數）較高（超出1024k），能夠看到CPU在IO等待的值也會越大
cpu的wa（IO等待時間百分比）比較高，說明IO等待比較嚴重


[root@appserver ~]# iostat -x 2
Linux 2.6.18-308.el5 (appserver)    01/25/2017

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
          14.21    0.00    4.24   38.40    0.00   43.14

Device:         rrqm/s   wrqm/s   r/s   w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await  svctm  %util
cciss/c0d0        0.00   139.00  0.00 170.50     0.00  2468.00    14.48     1.31    7.65   5.58  95.20
cciss/c0d0p1      0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d0p2      0.00   139.00  0.00 170.50     0.00  2468.00    14.48     1.31    7.65   5.58  95.20
dm-0              0.00     0.00  0.00 309.50     0.00  2476.00     8.00     2.53    8.11   3.08  95.20
dm-1              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
          15.54    0.00    4.26   39.35    0.00   40.85

Device:         rrqm/s   wrqm/s   r/s   w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await  svctm  %util
cciss/c0d0        0.00   116.50  0.00 171.00     0.00  2308.00    13.50     1.18    6.92   5.57  95.25
cciss/c0d0p1      0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d0p2      0.00   116.50  0.00 171.00     0.00  2308.00    13.50     1.18    6.92   5.57  95.25
dm-0              0.00     0.00  0.00 288.50     0.00  2308.00     8.00     2.15    7.50   3.31  95.35
dm-1              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
          13.72    0.00    4.74   39.40    0.00   42.14

Device:         rrqm/s   wrqm/s   r/s   w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await  svctm  %util
cciss/c0d0        0.00   119.50  0.00 178.00     0.00  2392.00    13.44     1.18    6.62   5.36  95.35
cciss/c0d0p1      0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d0p2      0.00   119.50  0.00 178.00     0.00  2392.00    13.44     1.18    6.62   5.36  95.35
dm-0              0.00     0.00  0.00 296.50     0.00  2372.00     8.00     2.13    7.21   3.21  95.30
dm-1              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

# 分析：
%util（一秒中I/O 操做的利用率）已經接近100%，能夠看出目前這臺服務器的IO已經到達瓶頸了。

登陸後取得cookie，測接口：

ab -n 1000 -c 1000 -H "Cookie:JSESSIONID=8B3E561233C3451206456CFB86DFA46E" -p "postfile" http://app.tomcatalina.com/app/mark/getMark

結果解釋：

Document Path: /app/mark/getMark
#測試的頁面
Document Length: 50797 bytes
#頁面大小

Concurrency Level: 1000
#測試的併發數
Time taken for tests: 11.846 seconds
#整個測試持續的時間
Complete requests: 1000
#完成的請求數量
Failed requests: 0
#失敗的請求數量
Write errors: 0
Total transferred: 204586997 bytes
#整個過程當中的網絡傳輸量
HTML transferred: 203479961 bytes
#整個過程當中的HTML內容傳輸量
Requests per second: 337.67 [#/sec] (mean)
#最重要的指標之一，至關於LR中的每秒事務數，後面括號中的mean表示這是一個平均值
Time per request: 2961.449 [ms] (mean)
#最重要的指標之二，至關於LR中的平均事務響應時間，後面括號中的mean表示這是一個平均值
Time per request: 2.961 [ms] (mean, across all concurrent requests)
#每一個鏈接請求實際運行時間的平均值
Transfer rate: 16866.07 [Kbytes/sec] received
#平均每秒網絡上的流量，能夠幫助排除是否存在網絡流量過大致使響應時間延長的問題
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 483 1773.5 11 9052
Processing: 2 556 1459.1 255 11763
Waiting: 1 515 1459.8 220 11756
Total: 139 1039 2296.6 275 11843
#網絡上消耗的時間的分解，各項數據的具體算法還不是很清楚

Percentage of the requests served within a certain time (ms)
50% 275
66% 298
75% 328
80% 373
90% 3260
95% 9075
98% 9267
99% 11713
100% 11843 (longest request)
#整個場景中全部請求的響應狀況。在場景中每一個請求都有一個響應時間，其中50％的用戶響應時間小於275毫秒，66％的用戶響應時間小於298毫秒，最大的響應時間小於11843毫秒。對於併發請求，cpu實際上並非同時處理的，而是按照每一個請求得到的時間片逐個輪轉處理的，因此基本上第一個Time per request時間約等於第二個Time per request時間乘以併發請求數。
相關文章
相關標籤/搜索
每日一句
    每一个你不满意的现在，都有一个你没有努力的曾经。
本站公眾號
   歡迎關注本站公眾號,獲取更多信息
聯繫我們 最近搜索 最新文章 沪ICP备13005482号-10 MyBatis教程 SQL 教程 MySQL教程 Java 教程 Thymeleaf 教程 Hibernate教程 Spring教程 Redis教程