一次线上java应用响应时间过长问题的排查

最近接手一个老java应用，没多久接到响应时间太长的报警，整个排查过程还是挺有意思的，记录一下。
整个过程中，设计到cpu，内存，垃圾回收，引用，spring, 单例 等等知识，整个下来，心情愉悦。

接到报警

吃完晚饭回来，接到报警短信，服务响应时间太长，达到2s以上。
第一反应，怎么可能，这个应用很简单，就提供了几个查询接口，QPS单机也就10左右，居然响应时间2s以上，这不科学。

看监控

看监控平台，有问题的机器，cpu占用很高，这。。。更不科学了。理论上，这应用cpu能到1%就不错了，现在居然80%，吓得我赶紧跑到机器上，top了一把，确实是java应用占用cpu很高。

找出占用cpu的线程

ps -mp pid -o THREAD,tid,time

发现cpu几乎全被一个线程占用了，将线程id转换成16进制

printf "%x\n" tid

打印线程堆栈信息

jstack pid |grep tid -A 30

看到的结果居然是，CMS垃圾收集器的线程。。。
这，这，这不科学。

垃圾回收

看垃圾回收日志，发现一直在进行Full GC，但是几乎没啥效果，GC完了，老年代依然是几乎占满的状态。
即使是CMS，也不能避免传说中的stop the world，所以响应时间变长了。
但是，现在问题来了，Full GC回收不掉的对象都是啥啥啥？

分析java堆内存

先把线上流量从这台机器切走，然后dump，分析后发现，一共160多万个PoolHttpConnectionManager对象占领了绝大多数内存。
会议了一下代码，和http请求有关的只有oss存储的client了。
猜测是new oss client时的问题

oss client 源码

看了一下应用中的代码，发现每次使用oss时都会 new OssClient，用完之后没有shutdown。
但是，new是在方法内部的，方法内的局部变量按道理说，方法结束后直接就可以回收的啊，这不科学，肯定是ossClient的源码中搞了鬼。于是直接去源码中看了一下。
发现在new OssClient时，源码中会新建上面提到的PoolHttpConnectionManager，然后调用ossClient存取数据时，PoolHttpConnectionManager会从内部维护的http连接池中找到可用连接，进行操作。
这没问题，大多是框架都是这么设计的。
既然JVM 堆内存中有160多万个PoolHttpConnectionManager对象，说明肯定是有地方把内次new OssClient时新建的PoolHttpConnectionManager给缓存起来了，导致垃圾回收无能为力。
继续看源码，发现确实和我想的一样。给存起来了,只有显式调用ossClient的shutdown，才会清理掉缓存。
想想这样设计也没问题，这和线程池的思想是一样的，我们使用线程池时，肯定不会每次都new 一个新的，只不过这个ossClient隐藏的比较深。。。

解决

解决办法很简单，把OssClient改成单例就行了。
但是，集团封网期间不允许上线，这。。。
没办法，把应用重启一遍，JVM内存满血复活，清醒QPS很低，重启后可以撑过封网的时间断了

Spring的Controller是单例的

突然想到，其他应用也使用了这个OssClient，一直没问题，想必是单例吧，忍不住上去瞅了瞅代码，发现，是在一个Controller中使用了成员变量，像这样：

@RestController
@RequestMapping("/sdk/map/styles")
public class MyController {
    private OSSClient ossClient = new OSSClient();

    public put(Object o) {
	ossClient.put(0);
    }

我记得上学那会儿，捣腾Struts的时候，Action并不是单例的啊，单里会有问题，难道Spring是单例了？
查了一下，确实，Spring的Controller，默认是单例。
想了想，单例也没啥问题，只要不在方法中去操作成员变量就可以了。

后记

你所学的知识，都是有用的，认为没用，也许只是时候未到而已。