GC 永久代溢出导致服务宕机

现象

今天, 生产上的springboot 应用cpu 达到200%, 即占用了2核, 线上应用奔溃, 应用无法访问。在立刻重启应用后,应用恢复正常, 奇怪的是, 在一段时间后, 服务又出现无法访问的情况。

问题分析

该问题可以大致上看成2类, 可能也可能没有直接关联

  1. 服务宕机
  2. 应用占用CPU很高

排查思路及手段

因为不同的问题排查思路及方式会不同, 针对本次服务宕机的排查问题追溯如下:
通过jps查看应用是否运行 > 通过Top查看系统运行状况 > 查看错误日志 >

排查细节:

1、 使用jps查看是哪个进程编号pid 对应哪个应用

jps: Java Virtual Machine Process Status Tool

[root@localhost ~]#  jps             
26610 Bootstrap
28877 jar
18039 TSDMain
26091 Kafka
19456 Jps

如果发现应用不在列表中, 则本次服务无法访问则是因为应用未启动造成, 则需要排查是什么原因造成服务未启动。
可能原因:

  1. linux oom killer 将应用杀死
  2. 人为杀死(可能性很小)
  3. 操作系统宕机等原因(如果操作系统在云服务上,可能性极小)

此时, 我发现应用还在列表中。

2. 查看错误日志

java 应用在线上会以文件的形式记录warn级别及以上的错误日志, 发现有大量以下内容的错误日志:

   "Cannot serialize; nested exception is 
   org.springframework.core.serializer.support.SerializationFailedException: Failed to 
   serialize object using DefaultSerializer; nested exception is java.lang.OutOfMemoryError: 
   PermGen space"

以上错误很明显了: 内存溢出, 永久代内存空间不足。

2.1查看应用永久代内存空间大小
 >   jstat -gcpermcapacity pid                      #perm对象的信息及其占用量
  PGCMN      PGCMX       PGC         PC      YGC   FGC    FGCT     GCT   
   21504.0    83968.0    83968.0    83968.0   361     2    0.906   39.789

# 同时我们可以通过jstat -gcutil来动态查看gc的状态
> jstat -gcutil pid 
大致情况如下:
  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT   
  0.00  11.13  11.97  40.61  33.67   5508   44.783    22   10.686   55.469
(以上是jvm参数加入后的状态, 之前看到P是99%以上)

经过换算, 发现perm代的最大容量才81M。

本次解决办法:

设置jvm参数, 增大永久代内存的大小
(java -XX:MaxPermSize=512M -jar xxxx.jar &)
之后服务不再出现无法提供服务的问题。

事后回顾及思考:

应用通过jenkins发布, 构建后执行脚本运行springboot的应用, 采用的是java -jar xxx.jar , 故采用默认配置, 从而忽略了生产对于内存要求的苛刻性。
所以对于生产环境的配置, 往往要结合并分析实际业务场景, 选择适合的配置, 当然有时候不能盲目加入硬件配置, 也可以通过一定的逻辑优化来解决问题。

知识补充:(针对该现象)

  1. 内存中什么对象是永久代
    有时候把永生代和方法区对等, 方法区是多个线程共享的区域, 存储常量信息,类信息,方法信息。
截取自《深入理解java虚拟机 JVM高级特性与最佳实践》2.2.5
  1. JVM性能调优监控工具 使用
    往往大多数程序员忽视了这方面的知识, 对关于jvm的问题束手无策, 其实jdk中为我们提供了大量的jvm调优及监控工具, 比如jps、jstack、jmap、jhat、jstat。
    在本次我们使用了jps和jstat来查看问题, 当然这些命令还有其他参数,如果感兴趣的话可以在网上搜索。

针对CPU占用高的问题

系统CPU占用高曾经也出现过,所以很快能够排查出大致问题所在。

大致思路

1. 检查是哪个进程占用了高cpu

>  top              # top命令经常用来监控linux的系统状况
top命令示意图

有时候会看到mysql进程占用很高cpu
一般mysql的配置dba会配置好,往往不是mysql配置的问题, 所以 对于开发人员来说, 首先看慢sql日志。如果此时发现有大量慢sql日志产生, 则需要结合实际业务场景进行相应的sql及逻辑优化, 有必要的话可以通过一些缓存手段来解决问题。

如果是java 应用占用很高cpu

2 java应用CPU占用高

这时候我们开始对具体的应用进行分析了, 我们可以借用一些工具来分析java进程。如
jstack、jmap、jhat、hprof。

我的做法是首先定位占用高cpu的线程:
步骤如下:

  1. 通过jps获取进程id
  2. 通过jstack 查找线程dump
>  ps -mp pid  -o THREAD,tid,time
线程
将线程id转换为16进制(以方便找到dump中对应的线程)
> printf "%x\n" tid
>  jstack pid |grep tid -A 60      这里的tid为转换的16进制, grep -A  n 为匹配的行数后n条

查询结果大致如下:

"container-0" prio=10 tid=0x00007f9a14e1e800 nid=0x465a waiting on condition [0x00007f9a6dc57000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at org.apache.catalina.core.StandardServer.await(StandardServer.java:427)
    at org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedServletContainer$1.run(TomcatEmbeddedServletContainer.java:177)
"VM Thread" prio=10 tid=0x00007f9a7812f800 nid=0x45ec runnable 
"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007f9a7801e000 nid=0x45dd runnable 

如果定位发现cpu高的线程为GC, 很有可能是GC出现了问题。
如果线程dump中执行的是某业务代码, 可能是发生了死循环之类的。

参考:
[1] jstat 命令详解
[2] Java SE Specifications Chapter 2. The Structure of the Java Virtual Machine
[3] 《深入理解java虚拟机 JVM高级特性与最佳实践》

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

推荐阅读更多精彩内容

  • R:创建共同目的 总而言之,当你感到对方和你的目的不一致时,应当这样做:暂停充满争议的对话内容,关注对方的真正目的...
    涵妈秀秀阅读 504评论 0 0
  • 意念这个东西是真的讲究配得的,今天就有一个感受,本来计划的目标是两个店共同达成1.5万的销售,后来我想尝试着向三万...
    马骏辉阅读 322评论 0 1
  • 人生要敢爱、敢恨、感悟人生、感悟经历、感悟伤痛。点点滴滴成就永恒,累积成就记忆!
    一梦一醒阅读 139评论 0 0
  • 继去年走进博物馆参加《永恒之城—古罗马的辉煌》展览后,尼采读书会第二次走进博物馆看展览《山东历史文化展》。 有人说...
    苏步哲阅读 1,401评论 0 0