32-一条SQL引发的系统卡死(上)-数据分析

欢迎关注公众号OpenCoder,来和我做朋友吧~😍😊😘

今天给大家分享一个真实的案例,这是我之前一个朋友公司的项目在开发完毕后上线发现整个项目在线上的体验非常不好,有明显的频繁卡顿,后来经过一连串的排查、定位、分析和优化才发现原来是一条SQL引发的问题,而且该SQL语句是一位刚入职不久的工程师所写。

通过这次事故的教训也让这个团队在后续的开发中更加注重了JVM参数的设置以及GC的监控。

该案例肯定涉及到整个项目的代码关联,无法给到大家具体代码的展示,我们本案例还是通过画图的方式给大家进行讲解。对于该案例的分析和优化的过程大家如果能理解透彻,举一反三,对于大家以后在自己公司的项目以及遇到类似的情况,能够结合我们讲解的Jvm知识和掌握的工具自己去进行排查和优化肯定是有帮助的。

JVM性能分析-找问题

那么针对类似这种系统上线后就比较卡顿的问题,我们应该如何下手去进行排查呢?

我们之前已经介绍过 jstat工具了,这个工具是非常好用、实用的一个工具,希望大家重视起来。

由于很多中小型公司其实都没有可视化的监控平台,没法直接可视化的看到JVM各个区域的内存变化,GC次数和GC耗时。

当然,如果有办法的话,我建议大家可以给自己所在公司推荐一下类似Zabbix、Ganglia、Open-Falcon、Prometheus之类的可视化监控平台,其实接入都非常简单,如果把线上系统接入了这些平台,可以直接图形化看到JVM的表现。

但是哪怕你有了可视化监控平台,有时候直接对线上系统进行分析的时候,还是jstat更加好用和直接。

OK,具体如何通过 jstat工具进行数据分析和打印,请查看或回顾:28-虚拟机性能监控&故障处理工具

jstat排查后的数据统计

  • 机器配置:2核4G
  • JVM堆内存大小:2G
  • 系统运行时间:3天
  • 系统运行3天内发生的Full GC次数和耗时:125次,30多秒
  • 系统运行3天内发生的Young GC次数和耗时:1.3万次,700秒

该系统通过jstat工具监测三天后得到的数据统计如上,我们发现基本上每天就会发生40多次Full GC,每一个小时大概2次Full GC,每次Full GC耗时300ms左右; 每天发生4000多次Yong GC,基本每分钟就发生3次,每次GC 50ms左右。

根据以上数据分析我们可以看出这个系统的性能是相当的差了,不管是Yong GC还是Full GC的频率太频繁了!必须进行优化。

未优化前的线上JVM参数

下面是未优化前的线上JVM参数,大致如下:

-Xms1536M -Xmx1536M -Xmn512M -Xss256K 
-XX:SurvivorRatio=5 -XX:+UseParNewGC 
-XX:+UseConcMarkSweepGC 
-XX:CMSInitiatingOccupancyFraction=68
-XX:+CMSParallelRemarkEnabled 
-XX:+UseCMSInitiatingOccupancyOnly
-XX:+PrintGCDetails 
-XX:+PrintGCTimeStamps
-XX:+PrintHeapAtGC

可以看到,4G的机器,给JVM内存分配了1.5G,新生代分配了512M,老年代1G。

这里关键的是“-XX:SurvivorRatio”设置为了5,也就是说,Eden:Survivor1:Survivor2的比例是5:1:1。

那么可以推出:Eden区域大致为 366M,每个Survior区域大致为 70M。

如下图所示:

image

系统运行推导

1.新生代每秒分配对象的大小

由之前的统计分析可知:每分钟3次Yong GC,那么大概20s就会发生一次Yong GC,那么也就是20秒Eden区域基本就满了,20S共产生300多MB的对象,每秒大概产生 20MB的对象进Eden.

2.老年代分配对象时间
每一个小时大概2次Full GC,那么半小时就是一个Full GC,要想触发Full GC,需要达到老年代触发的阈值,而上述JVM参数中有一个

-XX:CMSInitiatingOccupancyFraction=68

参数的设置,那么也就是老年代空间大概在达到600多MB的时候就直接触发Full GC了。

总结下如下图所示:

image

那么分析到这儿,可能有多同学就会立马给出解决方案了:

  • 换机器:换成4核8G
  • 增大Survior区域的大小

请注意:并不是所有的问题都是可以通过增大机器内存,增大JVM内存,增大新生代内存,增大Survior区域大小就可以解决了,我们一定要先分析清楚到底是什么原因导致我们的系统会发生卡顿,是不是由于我们自己的代码问题所导致? 特别是在机器内存小的物理机上更容易检测出来我们代码的质量问题,这类问题如果不解决,而是一味的增大机器内存,根本是解决不了本质问题的!

这里真正的Full GC是真的由于Survior区域太小,导致每次Yong GC后剩余存活对象直接进入到了老年代?

还是有很多长时间存活对象,始终存活在老年代,导致无法回收?加上老年代触发Full GC的阈值只有68%,导致速度更快?

分析到这里,绝不能轻易草率的给出结论和解决方案!

那么我们到底应该如何继续分析以及排查问题,请大家积极思考可以在我们的技术交流群中给出自己的答案和分析计划。我们下篇文章再继续给出问题所在和解决方案。

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

推荐阅读更多精彩内容