grafana 线上排查

grafana 线上排查

现象

基于grafana v6.3.4魔改过的版本,在生产环境上,偶发大量的401错误,导致页面重定向到了登录页。

分析

现象还是比较明显的,通过分析grafana前端的代码,可以看到逻辑是之后后端接口返回401, 前端就会重定向到登录页面,那么后端什么情况向会产生401错误呢?通过分析整个部署的架构以及grafana后端的代码可以确定有这么几种情况

  1. 前端发请求的试试根本没有带grafana session
  2. 请求到达公司接入层nginx之后,nginx把session丢了
  3. 接入层没有丢, 但是自己的实例上那层nginx把session搞丢了
  4. 请求session打到了实例上,但是代码逻辑问题,导致没有通过session解析出用户ID,返回401
  5. 数据库问题导致,解析请求失败返回401

追踪

可能的情况大概就是这么几种。 最开始,我不太认为会是代码上的问题,所以一直把经历放在了2,3上。 主要是任务nginx这层会把session丢掉。
由于问题还是偶发的, 所以日志真的很难抓取到完整的链路,这里我也是跟了很久,才把整个链路的日志搞到,从而分析,排除了1,2,3

客户端

image

可以看到返回401时, grafana_session是带过去的,所以我们排除1

公司接入层&源站nginx

这块是最不好排查的, 因为这层的日志不在我自己手里,而且也不是全量采集的(可以理解,毕竟这个集群量太大了)。所以我直接把域名绑定到了源站的nginx ip上,如果还是出现问题,那么就可以排除2,接着排查3了。 让人失望的是, 问题真的依然出现了;我们在nginx日志的session打开,抓取到日志的情况是session还是带过来的
image

实例代码问题

问题困扰了我2周,还是频繁出现,而且在被迫添加了定时重启之后,还是会不定期的出现,由于我们的grafana支持着公司所有的业务,所以这个问题必须的尽快解决。没办法,只能再撸一下代码,看看到底会是哪里的问题。

image

grafana 用了这个中间件来判断用户登录的情况, 每个请求会一次执行switch中的几个方法判断,只要有一个满足,下面的逻辑就不执行了(这块代码值得借鉴);我们的代码主要走红框中的逻辑

image

跟到红框这里我又发现一些蛛丝马迹, 查看源站实例日志,再出现问题的时候确实发现了Failed to look up user based on cookie的日志

image

可以看到是在链接DB的时候报错了,当时第一反应肯定是DB有问题,导致连不上DB, 无法根据session解出用户ID;导致我又联系DBA,同事自己查看DB的监控,但是并没有看出当时的数据库有任何问题;

在仔细看上面的日志,发现端口后面是缺了的,最开始我认为的问题是日志库把日志截断了,但是看报connect: connection refused说明什么? 说明的是IP层是通的,真的是端口也就是进程层面不同,但是数据库的3306端口当时不可能有问题的,难道真的是端口错了吗? 可是端口是在实例初始化的时候,依赖consul服务发现解出来的,怎么会出错呢?

到这个时候,我已经开始怀疑是依赖的底层consul库有问题了,所有我进一步看了依赖库的代码逻辑。由于涉及到公司的底层代码,源码不方便贴出来,而且当时跟进到这一步之后,我没有发现明显的问题(有一处逻辑,当时大概会觉得有问题,但是我也没有做测试,所以当时没有再深入下去,最后的原因其实就是这里),线索到此又断了,抱着试一试的心态,只能去golang大群里请教群里的大神。

峰回路转的是, 真的有人遇到了同样的问题,并且提过fatal,经过群里的讨论, 问题终于清楚了!

image

模拟问题

源码不能贴,但是我写了测试代码, 实现大概是这个样子

image

通过go race 能看到在并发做rand.Shuffle操作的时候是存在race condition的

image

这导致的结果就是在并发 swap 的时候出现竞态,结果得到了一个 string 的 data 和另一个 string 的 length,最终出现日志中端口那段的字符串缺失,或者错误

总结

  1. 还是要相信日志
  2. 仔细,不放过任何的细节
  3. 对我自己来说,对于并发情况下,竞态的分析不够敏锐
  4. 总有大神比你牛逼