捉虫记(二)GC导致的hang

开发 开发工具
这次的现象是,我正准备出去泡个茶,突然业务经理嗷嗷直叫(终于找到一个Bug,能不兴奋么),一边喊着处理不行了,一边喊着赶紧重新启动,我没有吱声,默默打开了性能计数器,看到处理程序的缓存的确是慢慢在增长。

本来第二篇早就该写的,都准备写一个while(true)导致高CPU的问题,但是那个dump不知道跑到哪里了,害得我这段时间一直在找,这次的现象是,我正准备出去泡个茶,突然业务经理嗷嗷直叫(终于找到一个Bug,能不兴奋么),一边喊着处理不行了,一边喊着赶紧重新启动,我没有吱声,默默打开了性能计数器,看到处理程序的缓存的确是慢慢在增长(这表示有积压了),而处理速度降到非常低了,几秒钟处理一个(平时情况下哥的程序每秒钟处理1000个Socket业务包是 没有问题的),说到这里建议大家在自己的程序中也加入一些自定义性能计数器,这东西太好用,当你把系统的一些值(比如说CPU的UserTime,还有Disk的DQL等)和你自己程序的一些值(比如说程序的缓存数,处理的并行进程数等)以文件方式记录下来的时候,做个Excel图表,这样你就能对整个系统的性能有了一个很直观的认识。

1. 首先对程序有个大概的了解。

内存1.2G,程序已经运行好几天了。

无标题

2. 既然是程序处理速度变慢,那么应该看看CPU,线程池的消耗情况等

看看线程如何

***个命令!runaway(如果你是Web程序,那么这个命令对你讲非常有用,但是这个From程序中,很多模块用了那种该死的While(true),基本上这个命令我们得不到什么东西)

无标题1

让我们看看线程池是什么样子吧(!tp这个命令可以看到线程池的情况):

无标题2

Wowowo…,看这个cpu很高啊。

3. 我们看看我们的处理线程在看什么吧(!thread能看到所有的线程)。

无标题3

。。。。。。

无标题4

哦,注意那个32号, GC Disabled,到这里我们大概猜测到是GC将处理线程阻塞掉了。

4.为了进一步验证我们的猜测,我们看看线程们到底在干什么吧(~*e !clrstack这个命令将打印所有线程栈,别着急,慢慢看,这个可以copy一下,贴到一个比较容易查看的编辑器里慢慢看)。为了看起来方便,我把打印结果copy出来用notepad++来看看,下面这个截图,我做过处理,不然太多了,看不过来的。

无标题5

5.我的处理函数是SchemeEntity.ProcessIMSIContext,并且开了十个线程处理(都是从线程池申请,最多同时允许十个线程处理,如果超过是个线程都没有处理完毕,那么分发线程将等待,新来的请求将在缓存队列中,就是上面所说的那个正在慢慢增长的的缓存),从这个可以看出,十个处理线程都在处理,那么我们看看他们都在干嘛,随机挑选两个37,38号看看吧。

clip_image016

clip_image018

6.哦,他们都在Monitor.Enter了,我们重点看一下32,切换过去吧(切换线程 ~线程号s)

clip_image020

7.哦哦~,看到了么,38,37都在等待,但是32在GC,我们看看32的堆栈吧,果然在GC。(kv显示非托管栈)

clip_image022

看看托管的吧(!clrstack),哦哦~List.set_Capacity(32) ,这几乎可以肯定是List在做copy的动作,List将申请自己现在长度的两倍的内存,应该是这个长度非常非常长,现有托管堆内存不大够,所以引起长时间的GC了。

clip_image024

8.我们直接去看看这行代码到底在干嘛吧,看到蓝色喷雾了吧,那个地方可以对应到代码的行数(我的截屏上只有D:\I 这个样子),屏幕太小了,我没法直接贴出来。但是上面显示是第64行。

clip_image026

我们可以看到iMsiDayCountDic是一个ConcurrentDictionary,但是用.Keys.Contains这个用法,额,我们可以想到, Key这个应该是一个ICollection,然后再上面调用Contains应该是新生成一个List<ulong>,然后把Dict里面的key全部copy到这个List<ulong>中,当Dict里面的数据非常多的时候,在生成List<ulong>的过程中,List<ulong>需要每次不断申请自身长度的2倍,于是慢慢就GC了,整个处理被阻塞了,其实Dict有另外的方法了

clip_image028

我们修改成这个样子,就OK了。

原文链接:http://www.cnblogs.com/StevenChennet/archive/2012/08/14/2638079.html

【编辑推荐】

  1. 捉虫记(一)GC堆中的“内存泄漏”
  2. Java程序员必须了解GC的工作原理
  3. JVM GC调整优化过程全揭秘
  4. 详解Java GC的工作原理
  5. JVM基础:GC策略&内存申请、对象衰老
责任编辑:张伟 来源: StevenChennet的博客
相关推荐

2012-08-15 14:44:53

GC

2014-03-26 11:15:26

Hive

2021-05-13 08:51:20

GC问题排查

2017-06-09 08:49:07

加载器Full GCJVM

2017-04-19 12:09:56

数组动态扩容GC

2017-06-27 08:41:04

JVM设计缺陷GC

2022-12-17 19:49:37

GCJVM故障

2020-11-16 07:19:17

线上函数性能

2023-10-11 22:24:00

DubboRedis服务器

2019-03-10 20:37:14

Python编程语言

2017-04-17 11:07:19

GC数组动态扩容

2020-08-12 08:25:43

数据库MySQL技术

2019-07-25 08:30:58

数据库服务器故障

2022-01-10 09:31:17

Jetty异步处理seriesbaid

2019-09-11 08:22:57

MySQL数据库远程登录

2022-05-11 08:22:54

IO负载NFSOS

2011-05-17 10:10:15

MySQLmysqld

2021-11-12 08:07:31

SQL缓存RabbitMQ

2014-05-08 14:13:00

Java面向GC

2019-10-10 15:40:17

redisbug数据库
点赞
收藏

51CTO技术栈公众号