活动项目访问量异常的排查笔记

问题描述

最近有个活动放出去后，发现访问量非常大，导致服务器负载很高
和产品确认后，得知推送的用户并不多，大约6W，而nginx日志中的记录却有96W

排查流程

2015.12.23

1.top查看负载、cpu和内存
如果发现高负载、低cpu和内存，那么可能是请求量过大的问题

2.查看近几分钟的并发量，和上一日进行对比：
cat /usr/local/nginx/logs/activity.access.log|awk '($4>="[23/Dec/2015:09:00:00" && $4 <= "[23/Dec/2015:09:50:00"){x++}END{print x/(50*60)}'
cat /usr/local/nginx/logs/activity.access.log.1|awk '($4>="[22/Dec/2015:09:00:00" && $4 <= "[22/Dec/2015:09:50:00"){x++}END{print x/(50*60)}'
如果发现并发量异常，需要统计异常的用户和IP

3.统计每个uri的请求量：
php statFlow.php -f /usr/local/nginx/logs/activity.access.log -t /home/zhouchangju/statFlow/ -s n -p
通过这一步，定位到异常的uri，比如这次是/cfxf/egg2016/index/

4.统计异常的用户(cookie userid):
(sort性能消耗极大，千万别在盘中使用。可以将日志文件拷贝到测试服务器查看)：
cat /usr/local/nginx/logs/activity.access.log|awk '($7~/cfxf\/egg2016\/index/){print $12}'|sort |uniq -c|sort -nrk1|more

5.统计异常的IP:
(sort性能消耗极大，千万别在盘中使用。可以将日志文件拷贝到测试服务器查看)：
cat /usr/local/nginx/logs/activity.access.log|awk '($7~/cfxf\/egg2016\/index/){print $(NF-1)}'|sort |uniq -c|sort -nrk1|more

6.临时添加IP黑名单，并增加squid缓存：
if ($http_x_forwarded_for ~ '172.20.1.91|172.20.1.205') {
     return 403;
}

2015.12.24

针对这次的问题，分析了异常请求的特点，发现：
1.请求首页6次以上的IP有4500多个
2.异常请求的$http_referer都是首页自身
3.$user_agent中，近99%的异常请求都来自Chrome浏览器
4.异常请求中，也包含极少的砸金蛋请求，说明是有用户在操作的
从日志来看，不像是人为发起的请求，更像是我们的程序在部分使用Chrome的用户电脑上出现问题，导致了页面不断刷新。

按照时间顺序观察了部分异常用户的请求，发现一个规律：用户都是正常进入页面，执行登录操作，然后正常砸金蛋，再经过一个时间空隙后，就开始不停发送首页请求了，详见附件图片。

猜测这里可能有两个原因：
1.用户手动刷新了页面，然后sso登录出问题
2.用户点击了页面上某个功能(从日志中来看，一旦循环请求，除了首页请求之外，就没有其他的url了，因此这里点击的，一定是项目之外的功能，即登录或者手机验证)后出问题

目前尚未确定具体原因，针对这两个问题，先做如下处理：
1.修改登录流程
目前的登录流程：
活动首页没登录
弹出iframe登录窗，url中传入http://activity.10jqka.com.cn/reloadroot.html
登录成功后，iframe内的登录页面会跳转到http://activity.10jqka.com.cn/reloadroot.html
http://activity.10jqka.com.cn/reloadroot.html触发父窗口刷新
父页面刷新后，会调用sso，如cookie写入失败，会再次触发sso，调用http://activity.10jqka.com.cn/reloadroot.html，触发父窗口刷新，然后进入死循环
(由于reloadroot.html有缓存，因此日志中统计到的reloadroot.html请求很少，统计到的首页请求非常多)

现在已由李晓栋更改为：
活动首页没登录
弹出iframe登录窗，url中传入http://activity.10jqka.com.cn/reloadroot.html
登录成功后，iframe内的登录页面会跳转到http://activity.10jqka.com.cn/reloadroot.html
http://activity.10jqka.com.cn/reloadroot.html执行sso操作，sso操作不执行任何回调
活动首页有一个定时器，会每隔一段时间会从cookie中查询用户ID，获取成功后，即请求我们这边的数据，渲染页面

2.修改了对于手机验证框的事件监听，去掉刷新功能


明天盘中推送活动时，我们再关注下，看看是否能够定位到具体原因。

2015.12.24

经过代码检查和日志分析，最终头儿定位到问题是js中的setInterval没有clearInterval，每隔100毫秒会请求一次，在用户网速较慢的情况下，就会不断发送请求。

总结

1.活动首页，一定要将动态数据独立出去，并设置squid缓存
2.活动项目的存储方案，需要考虑下，是否应该改为nosql
3.运维工具需要实践学习，以提升解决问题的速度
4.耐心分析日志，从共性中寻找原因
5.先从自身找原因