对opentsdb业务进行迁移,迁移到新集群之后,查询每天有200多次的timeout,时间超过10秒,检查日志看了一下ResponsetooSlow的processtime,一般在10-40秒之间。由于迁移之前没有这个问题,而且新集群之前的业务也没有问题,因此需要调查到底发生什么问题导致查询timeout.
经过对新集群老业务的梳理,以前的架构采用了redis作为缓存,如果redis没有数据才去opentsdb直接查询数据。经过与开发沟通,让他们去对老业务也做压测,不使用redis,看是否会出现timeout,测试结果是不管新业务还是老业务,在新集群如果没有使用redis都会出现timeout.
由此可以基本判断,新集群应该是哪里有问题,因为老集群没有使用redis,直接访问opentsdb并没有这个问题。
分析:
1. 老集群使用的sas盘,新集群使用的是sata盘,从磁盘性能来看,sas盘肯定比sata盘快,最开始怀疑不是不是因为磁盘不同,导致性能不行。
2. 联系开发进行压测,对磁盘io等进行监控,发现磁盘io还好,高的使用率也是40%,低的一半就0-20之间,读写也就100m/s,低的就几m几十m。 所以觉得磁盘应该不是主要问题,先放一边。
3. 查询region server的日志,发现responsetooslow日志大概30分钟左右出现一次,这个时间和opentsdb timeout的时间是一致的.
到此为此基本可以判断,opentsdb出现timeout的时候,的确是因为那个时间点region server比较慢,但是问题是,timeout并不是断断续续出现,而是30分钟左右出现一次。这么有规律的timeout是为什么?
4. 检查region server的监控,包括gc, jvm内存使用等,从肉眼看,看不出什么问题,至少从监控图没有发现什么特别的异常。
5. region server打印了2种日志,一种是resonsetooslow,另外一个是FSWal slow sync的日志,因此对dn的监控也进行了查看,发现dn gc有明显的特点,每天有4根柱子,6小时发生一次,也就是那4次gc时间较长。对比timeout时间,发现时间完全吻合。
到现在基本可以基本认为,dn gc的时间点就是查询timeout的时间点。那么什么原因导致dn gc时间长呢? 查询老集群的dn gc没有发现这个问题。
为了进一步确认dn gc的确和timeout有关系,让开发继续压测,打开dn gc监控图,可以百分百确定,只要dn在gc,就出现timeout。
按照原理,dn每6个小时会向nn汇报block,难道是因为block数量太多,导致上报的时间拉长,进而出现gc? 通过nn webui查看block数量,数字是2700w左右,对比老集群的400w block引起了我的注意,检查新集群为什么block数量会如此之多,毕竟业务差不多,不应该有如此大的差距。最后发现是之前flink读kafka落地到hdfs很多小文件,大概有2700w多,删除那些小文件,最后的block数量只有87000个。
等待将近12个小时,也就是2轮dn汇报之后,dn的gc正常了。 这里解释一下为什么要等待将近12个小时,因为dn每6小时汇报一次,删除block之后,要等下一轮汇报结束才会正常。由于dn汇报时间并不是同时的,那么多dn要汇报完整体肯定要超过6个小时。
这里提示一下,修改jvm的-XX:SurvivorRatio=3参数也是ok的,这么做的原因是减少新生代的大小,让他能尽快移走,而不是导致积累大量数据至少再移走而增加gc的时间。简而言之,就是让他ygc频率增加,但是每次gc时间很短,这样在dn汇报的时候不会造成一次性大量内存占用,而影响ygc时间.