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

一、背景

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

二、现象

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

三、排查思路

1. 调用外部接口耗时过长?

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

2. 程序问题?

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

3. pprof

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

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

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


pprof-4.png

(3).输入上述http地址

  • 查看cpu profiler


    pprof-1.png
> 没有什么太大异常,只有少许执行逻辑消耗一秒多
  • 查看了top/flame graph都没有查看到什么异常


    pprof-3.png
pprof-2.png

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类似,感兴趣的同学可自行尝试

4. 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,造成后面花了几个小时仔细排查。其实也是情有可原吧,这个采集模块代码细节我并不熟悉,对golang语言也不熟悉,只因负责这个模块开发的同学束手无策,我是这个项目的负责人,只能赶鸭子上架了😃。一遇到问题,我就有一种莫名的小激动,因为遇到了我未知的领域,又有机会对技术有更深入的了解了。

参考

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 203,271评论 5 476
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,275评论 2 380
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,151评论 0 336
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,550评论 1 273
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,553评论 5 365
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,559评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,924评论 3 395
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,580评论 0 257
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,826评论 1 297
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,578评论 2 320
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,661评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,363评论 4 318
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,940评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,926评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,156评论 1 259
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 42,872评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,391评论 2 342

推荐阅读更多精彩内容