系统故障定位

公司有监控组件cat,系统的所有信息在cat上面都可以看到,用久了平常的一些命令就忘完了

CPU

java应用cpu过高常见原因
1、死循环(线程一直不退出,所以占用cpu资源)
2、数据库慢查询(某个线程慢查询,一直占用cpu)、死锁
3、图片处理,切图操作

top命令
Mem中的free不是当前系统可用的最大物理内存,当前可用的物理内存数应该为Mem:free+Mem:buffers+Swap:cached

Load average
0.7 < load < 1: 此时是不错的状态,如果进来更多的汽车,你的马路仍然可以应付。
load = 1: 你的马路即将拥堵,而且没有更多的资源额外的任务,赶紧看看发生了什么吧。
load > 5: 非常严重拥堵,我们的马路非常繁忙,每辆车都无法很快的运行
load average:0.15, 0.16, 0.15
系统负载,即任务队列的平均长度。三个数值分别为 1分钟、5分钟、15分钟前到现在的平均值。

us:user_cpu,可以认为是 户进程占总cpu时间的百分,如果这个占比较高,多数是程序陷入死循环。(操作系统认为是正常逻辑)
sy:sys_cpu,运 内核及内核调 所占的cpu时间百分,如果这个占比较高,多数是死锁(卡在某些系统调 上)
ni:nice_cpu,修改过优先级的进程所占的cpu时间百分比,一般删log,压缩文件等io占CPU较多的进程推荐nice
id:idle_cpu,空闲cpu占比,越高代表cpu越闲
wa:wait_cpu,io等待所占的cpu时间 ,可能是硬盘,也可能是网络较慢
si:软件中断

mem_total 总物理内存
mem_used 被进程占
mem_free 空闲
mem_buffers:(数据块)缓冲区,硬盘块层面,准备刷新到硬盘上的数据
mem_cached:(文件)缓存区, 文件系统层面 ,从硬盘读取文件以备后面备使用
mem_swap:(内存页)缓存区,内存管理层面,物理内存不足时,用硬盘来模拟内存,一般占用量大后会导致性能急剧下降

 查询最耗CPU时的线程
 ps -mp pid -o THREAD,tid,time
 top -Hp pid

 jstack 28155 > test.txt 将当前java进程pid的栈信息打印到text.txt里面
 获取耗时大线程堆栈信息上下文
 grep `printf "%x\n" 28159` test.txt -A 30
 grep -n30 -E `printf "%x\n" 28159` a.txt

物理内存

查看系统当前可用内容
free -m

硬盘内存

查看系统磁盘剩余空间
df -h
du -h  --max-depth=1 /path:可以查看目录的大小,并控制子目录级别,找占用磁盘空间的文件是特别有用
如果日志不定时删除,会将硬盘空间写慢。

gc

dump出当前内存信息或者 启动时加入参数XX:+HeapDumpOnOutOfMemoryError, 在OOM触发时会自动dump日志
jmap -dump:format=b,file=/tmp/dump.dat 4813
来统计所有存活对象的个数
jmap -histo:live 20545 >>a.txt
打印出当前堆每个分区是使用详情,定位触发fullgc原因时特别有用,类似top的效果
jmap -heap pid
java当前gc信息
jstat -gcutil 1756 1000


jps -lv:加上lv可以列出启动类和启动参数,方便区别应用
jinfo pid:可以打印出进程生效的环境变量和参数的值

日志命令

grep -n -E 100
 less  xx.log, shift+g移动到最后一行,ctrl+b往前

FlameGraph火焰图

y 轴表示调用栈,每一层都是一个函数。调用栈越深,火焰就越高,顶部就是正在执行的函数,下方都是它的父函数。
x 轴表示抽样数,如果一个函数在 x 轴占据的宽度越宽,就表示它被抽到的次数多,即执行的时间长。
注意,x 轴不代表时间,而是所有的调用栈合并后,按字母顺序排列的。
火焰图就是看顶层的哪个函数占据的宽度最大。只要有"平顶"(plateaus),就表示该函数可能存在性能问题。

# 参考 http://www.brendangregg.com/FlameGraphs/cpuflamegraphs.html#Java

apt install linux-tools-generic
apt install linux-tools-common

export FLAMEGRAPH_DIR=/usr/java/code/FlameGraph
export JAVA_HOME=/usr/lib/jvm/java-8-openjdk-amd64

git clone  https://github.com/jrudolph/perf-map-agent
cd perf-map-agent
cmake .
make
bin/create-links-in /usr/bin

git clone https://github.com/brendangregg/FlameGraph.git

ps -ef|grep -v grep| grep 'webmagic'| awk '{print $2}' 获取到java 进程pid
perf-java-flames 19693
sz /usr/java/code/FlameGraph/flamegraph-19693.svg

参考:https://yq.aliyun.com/articles/710911
https://ichrisking.github.io/2018/03/08/FlameGraph/

案例

系统响应变慢

故障症状
系统登录页面都无法完全加载,客户端访问数据库也是响应特别慢,反正就是系统突然变得好慢
定位过程
ssh登录到系统之后,top看了下系统的load和内存使用状态都正常,
这时候想看下项目的日志,发现一堆超时,然后看了下Nginx的日志,一堆日志狂刷。
nginx日志格式:
    log_format main '$remote_addr - $remote_user [$time_local] '
                    'fwf[$http_x_forwarded_for] tip[$http_true_client_ip] '
                    '$upstream_addr $upstream_response_time $request_time '
                     '$http_host $request '
                     '"$status" $body_bytes_sent "$http_referer" '
                     '"$http_accept_language" "$http_user_agent" ';
随便抓取某行日志:
    139.199.30.109 - - [16/Sep/2018:06:01:52 +0800]
    fwf[-] tip[-]
    127.0.0.1:81 0.004 0.004
   kyfw.12306.cn GET /otn/leftTicket/queryA
  "302" 0 "https://kyfw.12306.cn/otn/leftTicket/init"
   "zh-CN,zh;q=0.8"
   "Mozilla/5.0 (Windows NT 6.3; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.80 Safari/537.36"
    然后根据关键字统计总爬虫数:
    cat host.access.log |grep 'kyfw.12306.cn' -c
    总共有2477947 接近250万请求。

    统计2018-09-16一天的请求数:
    cat host.access.log |grep 'kyfw.12306.cn'|grep '16/Sep/2018'  -c
    总共有1879513,接近190万

    统计2018-09-16 11点一个小时的请求数量:
    cat host.access.log |grep 'kyfw.12306.cn'|grep '16/Sep/2018:11'  -c
    总共有10万左右

    也就是说,100000/60/60=28 每秒的qps为28
    这个系统是给朋友做的一个自媒体稿件系统,单机的,线上机器配置是1核 2GB,带宽是1Mbps,因为爬虫访问的地址是/otn/leftTicket/queryA,
    这个地址会被shiro拦截,会302跳转到登录页面,没有涉及到任何db io操作
    因为线上的带宽很小就1M,所以考虑到会不会是带宽被打满导致的。

    根据命令iftop 可以很直观的看到流量数
    TX:发送流量
    RX:接收流量
    TOTAL:总流量
    Cumm:运行iftop到目前时间的总流量
    peak:流量峰值
    rates:分别表示过去 2s 10s 40s 的平均流量

也就是说我们的流量活活被爬虫打满了,导致其他正常请求无法及时响应。
解决方法
 根据特定场景,ngingx禁用user_agent和path
可以根据日志查询
tail -n 1000 /usr/local/nginx/logs/access.log | awk -F\" '{A[$(NF-1)]++}END{for(k in A)print A[k],k}' | sort -n
得到重复度最高的关键字
"Mozilla/5.0 (Windows NT 6.3; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.80 Safari/537.36"

Nginx的Location可以有以下几个匹配:
1. =   严格匹配这个查询。如果找到,停止搜索。
2. ^~ 匹配路径的前缀,如果找到,停止搜索。
3. ~   为区分大小写的正则匹配
4. ~* 为不区分大小写匹配
5.!~和!~*分别为区分大小写不匹配及不区分大小写不匹配

#拦截agent
    if ($http_user_agent ~ "^Mozilla/5\.0 \(Windows NT 6\.3; WOW64\) AppleWebKit/537\.36 \(KHTML, like Gecko\) Chrome/46\.0\.2490\.80 Safari/537\.36$") {
    return 403;
    }

location ~ /otn/leftTicket/ {
    deny all;
    }

/usr/local/nginx/sbin/nginx -s reload

拦截之后的日志:
82.61.143.135 - - [17/Sep/2018:18:43:12 +0800] fwf[-] tip[-] - - 0.000 kyfw.12306.cn GET /otn/leftTicket/queryA?leftTicketDTO
.train_date=2018-09-22&leftTicketDTO.from_station=GZQ&leftTicketDTO.to_station=WCN&purpose_codes=ADULT HTTP/1.1 "403" 570
"https://kyfw.12306.cn/otn/leftTicket/queryA?leftTicketDTO.train_date=2018-09-22&leftTicketDTO.from_station=GZQ&leftTicketDTO
.to_station=WCN&purpose_codes=ADULT" "zh-CN,zh;q=0.8" "Mozilla/5.0 (Windows NT 6.3; WOW64) AppleWebKit/537.36 (KHTML, like
Gecko) Chrome/46.0.2490.80 Safari/537.36"

可以看到响应变成了403
还是有日志狂刷,虽然带宽流量下来了,看了下日志,爬虫的机器ip就在几个网段,所以是必要加入黑名单才可以
#单个ip
iptables -I INPUT -s 81.241.219.171 -j DROP
 #封IP段ip
 iptables -I INPUT -s 106.12.1.0/16 -j DROP
优化前后带宽对比