从师父那里接了个服务,每天单机的流量并不大,峰值tips也并不高,但是CPU却高的异常。由于,服务十分重要,这个服务最高时占用了100个docker节点在跑,被逼无奈开始了异常曲折的查因和优化过程。
一般情况下,服务的主要性能瓶颈都在cpu和内存,关于内存的瓶颈之前遇到过一次,这次是第一次遇到Cpu的瓶颈。首先介绍下背景,浏览器的插件服务主要服务与QQ浏览器和所有tbs终端,每天的日活超过5亿,而服务的每天流量超过30亿。
这个服务非常重要,从师父那里接过来后一直没有任何改变,直到又一次告警才意外发现这个服务已经自动扩容了100个docker节点了。。。而且每台的负载都还很高(峰值超过70%),然后迫于运维的压力和服务的稳定性考虑,就开始了曲折的查因过程。值得注意的是,这个服务虽然日活很高(因为包含TBS),但是整体的流量不算太多,尤其平分到每个节点上流量并不大。那么问题来了,cpu到底跑哪里了。
一、perf跑火焰图
分析CPU瓶颈,最直接的方法就是用perf看看服务的Cpu到底跑哪里去了,跑的结果也很诡异:
结果显示,CPU并没有耗费在服务的具体某个函数上(火焰图也没看出来),从上面来看服务的主要消耗在int和string的构造和析构上,也就是内存的频繁申请和释放?我把这个结果在组里同步下,组里的各位大神提出了一些建议。其中,bj大神认为,既然都在内存的申请和释放上,建议我把tcmalloc编译进去用于代替libc中内存回收,说对于小内存的频繁释放用tcmalloc会好很多。ok,于是我就照做了,然而吧tcmalloc静态编进去之后,依然没用,所以,应该不是回收机制原因,所以,fail。
二、性能分析
用perf跑出来的东西并没有帮我找到瓶颈,那么只能尝试着换换方法。
于是乎:(1)尝试着查下这个进程在用户态和系统态的cpu时间比,然后想通过strace和time等分析下是不是系统调用等方面的问题,然而我分析了半天和其他服务比较了下,依然没有收获。
(2)这个时候,偶然想到可以看看服务的线程cpu占比是否均衡或者都耗在哪些线程上了。
这个时候就发现诡异的事情了,这个服务的核心线程有30个,其中20个imp主线程,10个异步回调线程,还有些其他的日志线程等。然后,其中有10个线程cpu占比是其他的7到8倍,然后用gstack打了堆栈之后,发现这10个线程居然是回调线程!!!这就奇怪了,为啥回调线程会占这么高的CPU,这个时候结合服务本身的特性,对回调后的插件过滤部分做了和主线程一样的缓存,发到线上,cpu有一定程度的降低,然而,还是没有发现根本原因。因为在单机流量并不大的情况下,服务的CPU到底跑哪里了?按照同等流量下,这个服务的CPU应该是在40%以下,然后实际是80%。而这10个异步线程为啥会这么耗CPU,我review了n遍代码,还是没能解决。。。
三、服务自身优化
这个时候,春节将至,而我查了半个月,发了4个线上版本都没有根本性改变。运维要缩容,服务由很重要,真的头疼。这个时候,就请组里的大佬(xianyi)向他们请教类似的经历和优化方法。这个时候,我们认为,虽然服务的流量不大,但是插件服务没有做任何的缓存和控制,每次请求都会做完整的计算。于是,希望通过和终端联合改版,通过其他方式把服务的计算次数降下来。然而,终端改版要时间,服务的cpu快满了,看来春节是不好过了。。。
四、找到问题or真相
万般无奈下,xianyi告诉我了他们之前关于染色debug日志优化的事情,让我试试改改说不定可以降低很多,于是乎就是下面这段代码: