软件开发 系统开发 网站开发服务,机票网站手机版建设,资源下载wordpress,wordpress通过id调用文章目录标题 问题描述分析过程查看监控数据系统监控指标JVM监控指标Redis监控指标分析应用异常单机异常规律集群异常规律统计超时的key 初步结论验证结论访问Redis链路slowlogRedis单节点info all定位redis节点定位异常keybigkeystcpdump定位大key影响 经验总结 问题描述
某产品线… 目录标题 问题描述分析过程查看监控数据系统监控指标JVM监控指标Redis监控指标分析应用异常单机异常规律集群异常规律统计超时的key 初步结论验证结论访问Redis链路slowlogRedis单节点info all定位redis节点定位异常keybigkeystcpdump定位大key影响 经验总结 问题描述
某产品线应用访问Redis出现超时超时时间配置的是2000ms异常信息
分析过程
查看监控数据
通过监控数据了解应用运行状态以确定应用出现问题时间点、是否过载、依赖服务是否过载等基本信息。
系统监控指标 JVM监控指标 FullGC过于频繁及耗时较长的情况下会造成应用阻塞住从图中看FullGC发生的频次是正常的一次FullGC耗时也是正常的所以FullGC不是造成SocketTimeoutException的原因。
Redis监控指标 从Redis控制台及阿里云杜康上该Redis实例的CPU使用率、内存使用率等指标都是正常的。
分析应用异常
分析异常日志首先需要弄明白的是应用抛异常时候执行的业务逻辑及异常本身含义异常在本机出现的频次情况是否存在规律性及异常在该应用的集群上的规律性。 除了访问Redis异常应用依赖得其他服务没有超时情况。
单机异常规律
分析了每小时、每分钟及每秒钟异常出现的次数发现异常具有一定周期性每个小时在固定的几个时间点会集中出现出现的时候会集中在相邻的几秒钟内。
集群异常规律
统计了应用集群中其他机器的异常规律每台机器出现异常的规律是一致的不出现都不出现要出现一起出现。
统计超时的key
我们统计了异常日志中所有超时的key然后单独访问这些key并没有任何发生超时的情况。
初步结论
通过上面的分析很有可能是应用侧在相对集中的时间点访问了同一个Redis节点在该Redis节点产生了慢查询进而阻塞掉了正常的请求Redis的命令。
验证结论
访问Redis链路 slowlog
最先想到是Redis慢查询有些应用卡慢的场景到这里可以找到线索遗憾的是slowlog并没有看到应用端发过来的命令。 Redis单节点info all
接着是Redis单节点的监控指标一些CPU高、卡慢的场景在这里找到线索经过对比确实有个节点avgRT比其他节点高很多。下面是两个不同节点的数据 avgRT45的是节点8初步判定节点8是问题节点。
定位redis节点
我们初步判定节点8是问题节点超时的key是否打到了这个节点呢阿里云redis自研了info key指令查询key所属的slot和db。 可惜的是这个版本的Redis返回的node_index跟控制台上实例拓扑图的node index不一致。 我们只好去每个Redis节点通过tcpdump抓包对抓包里的key执行info key biz_key来核对node_index:5到底是哪个节点最终定位到了超时key都是打在了节点13.
定位异常key
是对哪些key的访问阻塞住了Redis进而造成其他命令的超时呢首先想到的是大key的影响。
bigkeys tcpdump定位大key影响
在redis节点132进行tcpdump抓包且过滤大key
tcpdump -i any tcp and dst port 3048 -A -nn | grep -E 大key1|大key2|大key3|......在应用侧过滤日志中的异常信息
tail -f error.log | grep SocketTimeoutException
当应用侧出现SocketTimeoutException的时候redis节点上的key是需要我们引起关注的最后将定位的key提供给研发。
经验总结
排查此类问题几个需要关注的点
统计超时key及key对应的redis节点Redis slowlog 慢查询Redis单节点info all指标对比不同节点服务情况Redis bigkeys还有一个注意的点是Redis hotkeys
