同一份代码，虚机和Docker耗时差8倍，什么原因?

背景

公司有一个使用golang开发的采集模块，负责调用多个外部系统采集数据；最近做了一次架构上的调整，将采集模块分成api、job两个子模块，并部署到容器中，拆分前部署在虚机上。

现象

部分采集任务在容器中的执行时间比虚机中执行时间要长，8倍左右，本地测试无异常

排查思路

调用外部接口耗时过长？

只有部分任务执行时间长，怀疑容器调用那部分系统接口比较慢，于是在容器中curl外部接口接口，发现并不慢，排除这个可能。

程序问题？

将现有部署在虚机中的正常运行的应用，部署到容器中发现部分任务也会慢； 将部署在容器中的应用部署到虚机后恢复了正常；怀疑是容器本身或容器网络的问题，一时想不到是什么原因，于是开始了漫长的定位

pprof

pprof是golang提供的性能分析工具之一，采集模块已经引入pprof，首先使用它进行排查;

(1). 在容器中安装pprof/flamegraph¹

(2). 在容器中执行如下命令,开启pprof的http服务

(3).输入上述http地址

• 查看cpu profiler
  

没有什么太大异常，只有少许执行逻辑消耗一秒多

• 查看了top/flame graph都没有查看到什么异常
  

pprof中可以查看以下几类信息

• cpu（CPU Profiling): $HOST/debug/pprof/profile，默认进行 30s 的 CPU Profiling，得到一个分析用的 profile 文件
• block（Block Profiling）：$HOST/debug/pprof/block，查看导致阻塞同步的堆栈跟踪
• goroutine：$HOST/debug/pprof/goroutine，查看当前所有运行的 goroutines 堆栈跟踪
• heap（Memory Profiling）: $HOST/debug/pprof/heap，查看活动对象的内存分配情况
• mutex（Mutex Profiling）：$HOST/debug/pprof/mutex，查看导致互斥锁的竞争持有者的堆栈跟踪
• threadcreate：$HOST/debug/pprof/threadcreate，查看创建新OS线程的堆栈跟踪

由于跟网络有关系，所以想查看下io耗时，pprof无法实现我的需求，想到可以使用trace观察

期间又使用go-torch采集火焰图数据并查看，与pprof类似，感兴趣的同学可自行尝试

trace

trace也是go tool性能问题分析工具之一

(1) 打开trace

主要有以下几块：Goroutine、网络阻塞、同步锁、同步阻塞等

(2) 观察网络IO

一下子看到了60多秒，心里一阵窃喜，但从第一个节点开始已经是50多秒了，仍然不知道是什么原因造成的。又看了gorouting部分

看到network wait那一列耗时占比非常大，心里又是一阵窃喜，基本确定是网络的问题了，点击某一个gorouting进入grouting页面，再根据慢的任务名称找到相应gorouting，点击进入到trace页面

由于network占用大多数时间，连续点了靠后的几个绿条，发现最后一条语句一样，到代码中查看，发现是调用redis的代码，于是在容器中ping redis服务器，又在虚机中ping,发现容器ping的响应时间是虚机的26倍左右；想到公司的服务器分多地部署，于是又查虚机、redis、容器的部署地域，发现虚机和redis在同一地域，而容器和redis服务器不在同一地域，这时才恍然大悟，后面的解决办法就简单了，不在此赘述了；

总结

分析问题要从大到小，逐渐缩小范围，不能一上来就进入细节，这样会耗时较长。开始我怀疑是虚机网络问题，排查了外部系统接口，但遗漏了redis，造成后面花了几个小时仔细排查。其实也是情有可原吧，这个采集模块代码细节我并不熟悉，我的语言技术栈主要是Java,对golang语言不太熟悉，只因负责这个模块开发的同学束手无策，我是这个项目的负责人，只能赶鸭子上架了😃。一遇到问题，我就有一种莫名的小激动，因为遇到了我未知的领域，又有机会对技术有更深入的了解了。喜欢我文章的同学欢迎关注公众号哦，不定期分享干货！

参考

• [1]  Golang火焰图

• Go调优神器trace介绍

• 你的 pprof 暴露了

• Golang 大杀器之性能剖析 PProf