机器内存爆满问题排查

1 背景

两周前广告开屏服务突然503报警不断,先查看了各种业务监控没发现流量等有什么大变化,因为不久之前出过一次机器出问题的情况,马上去查看了机器是不是正常,果然内存几乎涨满了。大概十来分钟内存就会达到90%多,然后进程就重启了,但是从日志来看并没有什么异常情况,好在并没有将机器拖死。当时第一件事就是回滚代码,各种代码回滚到几天前,没什么效果。后来追查当时事发的一些修改改动,定位到是因为一个广告的上线导致,屏蔽该广告之后问题恢复了,但是当天还是没有查出最终问题。当时机器内存情况得截图:

image

2 复现问题

虽然当时定位到了由于一广告导致,但是看代码逻辑并没有发现有使用大内存的逻辑,线下用这广告尝试重现都没有出现类似情况,于是就尝试列出以下的可能: 1.线下环境跟线上不一致无法复现,用线上机器搭建复制服务环境 2.跟请求参数有关,有一些信息引发了这个问题,尝试用nginx的日志复放复现 3.请求Session信息有关,需要用线上流量复现

2.1 Nginx日志复放

因为大多数请求参数都在nginx日志里边有,除了一些用户信息外,所以就用线上nginx日志的在线下环境进行复现,但是并没有复现那出问题。 为了排除问题1的可能性,找了台线上机器环境基本一模一样,刚开始为了能快速复现问题,将uwsgi的work数调少了一些,发现并没有出现,后来调到一摸一样,还是没有复现。 复放流量用的代码:

image

线上环境也没法复现只好到正式服务改代码来进行,在代码中强制加入了出问题广告的处理,返回时再去掉,内存果然涨上来了。因为线上没法直接调试,没法定位具体问题,,所以得想办法在可随便整的环境上复现,把该代码原封不动的拷贝到复制好环境的线上机器上还是没法复现。 因为流量是用nginx日志进行重放,跟线上流量不一样的就是 请求没有带用户信息,所以需要尝试带上用户信息进行。

2.2 复制线上流量

想要尝试带上用户信息,刚开始先复制了一份cookie信息放到请求参数里,发现没法复现,设置cookie代码:

image

尝试无果后决定直接复制线上流量来进行复现,想到之前看过有人用gor试过,查了下资料可行,先说下gor的两种尝试: 1.保存出问题是的现场请求文件,gor可以原封不动的保存请求的所有信息 2.直接转发流量 先用方法1去录制了复现问题时的请求信息,然后在用gor进行复放,使用命令如下:

image

没有复现问题,直接在正式服务上启动了一个进程(为了方便调试)来进行,尝试方法2:

image

由于复制了1%的流量,虽然问题复现慢了些还是出现了,同时发现一个当时忽略的问题,并不是一个进程打满了所有内存,而是一个进程占用了1%左右内存(正常情况下只占用0.3%左右),由于线上机器进程数比较多才将内存打满了。
image

3 问题定位

问题复现了,可是无法用复放请求稳定复现,有随机性这个尴尬的场面使得无法调试问题,那只能尝试抓取问题复现时的现场信息了,找到了一个叫meliae的包,可以dump出python的内存使用信息,但是每次dump使用的时间太长,无法在每次请求的时候都dump一次,所以只能在问题复现后,快速dump一次,于是在代码中加了如下逻辑:

image

顺利拿到了问题出现时以及正常情况下的内存信息,然后用内存信息进行分析,发现了一个异常的dict对象占用50多兆内存,而它引用的字符串等对象占用也很大,有30多万条信息,用一下命令来解析内存dump文件:

image

正常
大于1m的dict没有

image

异常
大于1m的dict占用一个50多兆内存,item信息说明:

image
image

用脚本解析出该对象的一些字符串信息发现是一些pgc作者信息,感觉一头雾水想不出来哪里用加载这些信息。 虽然找到了对象信息,但是还是服务定位代码问题出在哪?用meliae能拿到对象ID以及它的父子对象信息,所以尝试用这些信息去定位: 1.对象ID查找变量信息,尝试未果行不通 2.用对象父信息查找相关信息,work 通过该对象的父父父..信息找到一个对象,定位到了相关代码:

image
image

找到了相关对象,然后搜索相关代码定义及使用的地方,顺藤摸瓜在相关调用出打印出堆栈信息,最终定位出了代码的调用逻辑及调用栈情况。

4 最终结论

最终问题是因为某对象的属性信息代码里加载了大量PGC作者相关信息,存储到本地的一个LRUCache占用了很多内存,由于使用python多进程的模式,每个进程都有一份自己的缓存,每个进程多占用了400M内存,100多个进程多占了四五十G内存,撑爆了机器内存。

5 解决方案

找了问题的原因,解决方案很简单,将需要的信息通过服务获取,避免子自身加载过多数据;数据服务已经是现成的,我们只需要接入新服务解决问题了。

6 总结

6.1 排查过程中的问题

问题复现走了很多弯路,说下复现时的一些疑问: 1.线上机器复制环境为什么复现不稳定:
没有group数据库访问权限(囧),中间复现过几次出现内存上涨是因为获取到了缓存数据 2.正式服务环境机器 重放请求时为什么不稳定复现(请求重放时这个请求一直是503也是见鬼了)

6.2 内存问题总结

1.如果能稳定复现的问题要好查很多,用memory_profile或者单步调试就能定位问题
2.对于这种不好复现的问题,最好能取到内存dump信息,分析内存信息来查找问题,过程就类似此文所述,线上环境都可以留这么一个用meliae来dump内存的接口或者零时添加来分析内存问题,这样面对内存保证问题就可以非常直接的分析了

6.3 涉及工具资料

gor:流量复制工具
使用Gor进行测试

meliae:内存分析工具,分析当前内存使用情况
https://pypi.python.org/pypi/meliae
http://blog.chinaunix.net/uid-16480950-id-103655.html

memoryprofile: 内存分析工具,分析内存增量情况,没法直观看出当前内存使用状况,有时候分析有些不准
https://pypi.python.org/pypi/memory
profiler

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

推荐阅读更多精彩内容