一次现网redis CPU使用率异常定位

背景

618大促前，运维对系统做巡检时发现redis cpu利用率白天基本保持在72%左右，夜里也在60%以上。担心618流量比平时大，导致redis超负荷，因此找开发进行优化，降低redis的负载。
在这里插入图片描述

定位思路

其实资源使用率过高定位都是一个模式，不管是cpu使用率高还是内存使用率高甚至是磁盘使用率高。我们要做的就是找到明确的问题点（有bug导致不正常或者说过多的使用了资源），如果没有明确的问题点，那只能找出资源使用的分布，从高到底逐步分析代码，确认优化空间，优先对优化空间大的代码进行优化，这样才能达到小投入高回报。

如果有明显的问题点，那还是很好定位的（或者说问题很容易捕捉）。比如java代码定位cpu使用率高时，通过top命令找到cpu占用高的线程，然后查看堆栈基本上就可以确认问题了。但并不是所有时候都有明显的问题点；这个时候，通过一些命令去观察时，捕捉到的数据并不是集中分布，那就不好直接确认问题。还是以java为例，使用top命令时，发现cpu占用率高的线程并不稳定，这个时候通过瞬间捕捉的高cpu使用率的线程去查看堆栈已经没太大意义了。这个时候要做的就是上述所说的找到cpu耗时的分布（像cpu可以使用火焰图），由高到底去逐个找优化空间了。

排查过程

初步观察监控，找到疑点

首先我是先看一下半夜的各项观察指标，确认可疑点。因为半夜用户数几乎可以忽略不计，用户的操作在系统整体占比非常低，这样不管去排查问题代码，还是看数据监控，都能更聚焦（对代码来说，关注后台异步操作；对监控来说，使用系统资源的指令更集中），相对容易找到问题所在。或者换个说法，半夜基本没有用户操作，能够基本消除用户操作对数据的干扰，使问题点更明显。
从监控上看，半夜使用率依然很高（超过60%），而且注意到半夜里执行的命令数下降了2/3。此处可大致推断出，半夜里面执行的操作是问题所在。
在这里插入图片描述

确认半夜执行的命令分布，是否有明显的问题点

因为监控并不支持查看执行命令的分布，因此只能委托运维在业务最底的时候，使用redis的命令去导出redis执行的命令（使用的monitor指令）。
导出后发现大部分指令是session（系统用了spring session）的相关操作，这就跟实际业务情况有点矛盾了，spring session只有人操作系统时才会触发相关代码执行，半夜几乎没有用户，哪里来的人机接口调用。遂使用调用链查看半夜到底有啥接口被调用。通过调用链系统发现半夜主要就一个接口在被调用（占总体调用量的95%以上），不仅调用间隔低，而且间隔固定。于是找接口负责人确认业务场景（我是临时过来支援问题定位的，并不清楚他们的业务），他告诉我这个接口是给第三方集成用的机机接口，于是乎问题基本明了。

我们去api平台注册接口给第三方用时，把接口url写错了，本应该填机机接口的，填成人机接口了。人机接口调用时会校验session，每次都会调用request.getSession获取session然后校验前端传相关认证信息。因为机机调用时没有cookie，因此每次都会创建新的session，然后半个小时候过期。

备注：从我的角度来讲，找到redis的问题命令后，就能够快速的找到问题接口以及问题，是因为我本身对系统使用的框架非常熟悉。因此，虽然定位资源利用率高的问题，有套路。但是如果对整个系统不了解（不仅是业务代码，系统使用的框架细节也要非常清楚），找到直接问题点后，很难往下一步找到问题根因。比如本问题中，该系统负责人，顺着我的思路找到有问题的redis的命令，但到了这一步后他就分析不下去了，他不知道这些redis命令是什么地方用的。