一次排查事故纪录

服务器大范围报读超时，排查记录：
8月13日：
1 周一晚上根据op jmap的内存，发现老年代和年轻代都是百分之九十九。因为老年代满后会引起fullgc，检查gc日志证实频繁fullgc，但是fullgc几乎没有效果，导致jvm连续fullgc，所有线程等待，引起读超时现象。
2 op给出的jmap histo里面有大量keywordtype对象，怀疑有大量这种对象被引用没有释放
3 根据事故点的dump日志发现有大量log4j在争夺root时被blocked，同事给出优化建议，将lo4j的子日记不打到catalina.out里面。
8月14日：
3 同事排查代码未发现keywordtype有被map、list引用的情况
4 替换log4j，子log不打到catalina.out里面，并且将earth日志隔离出去，business层增加buffer，上线。解决log4j瓶颈问题，但是仍然大量读超时，并且发现dump出来的线程快照里面基本上都是runnable的线程，此时仍然频繁fullgc，且fullgc未果，大家怀疑heap里面到底有什么东西。另外发现了使用log4j的buffer的一个问题，发生业务日志丢失的情况，具体问题还没有排查出来结果。
5 要求op准备jmap事故现场的heap.bin来排查
8月15日：
6 早上有两台服务器重启后丢失业务日志，有一台服务器重启失败，十个小时左右无流量。
7 检查事故现场的heap.bin，这东西很大时，别直接jhat，开一个两倍或者三倍的内存在jhat -J-mx14g heap.bin。
8 检查heap.bin，同事发现大量的keywordtype最终没有被引用，而且这些keywordtype里面的内容大致相同。排查出这些keywordtype属于同一用户。检查访问日志，发现这个用户发送了一些大批量的查询请求，发送内容又大部分重复，发送的时间点和fullgc开始的时间点吻合。怀疑受到恶意攻击或者客户程序bug引起。
9 根据以上排查，让pm联系这个客户，得知这个客户在进行线上试验。
10 和qa、op协作，紧急上线。完成修复

评论

1 楼 lisongqiu168 2012-09-07  

888