雄猫间歇性减速,反应迟钝,挂起

我一直在试图追查Tomcat服务器间歇性减速的原因。 我们每周都会放慢几次,Tomcat会停止响应,或者花费几分钟时间来处理请求,并且正常运行时间(Linux)上的CPU负载会从1-2左右增加到30多。然后,大概10分钟左右,事情就会慢慢恢复正常。

我们使用Apache作为前端,Postgres使用我们的数据库。 我一直在挖掘日志,试图找出可能导致问题的原因。 在减速的时代,我没有注意到任何明显的需求增长。

我发现的是,在多次放缓之前,Tomcat似乎只是睡了大约三分半钟。 在此期间的日志中没有条目,Tomcat也没有查询到数据库。 在小睡之后,Tomcat会醒来,并开始尝试处理所有备份的内容,导致数据库和CPU负载过重,响应时间慢。

为了试图弄清楚Tomcat在午睡时间里做了些什么,我设置了一个脚本来监视它的日志,并发送一个kill -3信号来获得一个线程转储,如果日志中没有活动三分钟的话。 不幸的是,信号没有唤醒Tomcat,所以线程转储不会发生,直到它自动唤醒并恢复了处理。

Apache和Postgres显然仍然在三分半钟的时间内保持清醒和活跃 – 他们的日志显示在这段时间内,与Tomcat相关的活动还在继续。

我们的Tomcat版本是5.0.28。

想法,build议? 我在与Tomcat合作方面很新,所以请不要假设太多的知识。


在根据Alex的build议激活详细的垃圾收集之后,我捕获了一对夫妇的问题,发现一个完整的GC是负责任的,在这两种情况下都花费了200秒,例如:

04:21:55.648491500 [GC 1035796K->933637K(1041984K), 0.3407580 secs] 04:21:56.012832500 [Full GC[Unloading class sun.reflect.GeneratedMethodAccessor633] 04:22:38.003920500 [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor39] 04:22:38.004051500 [Unloading class sun.reflect.GeneratedConstructorAccessor102] 04:22:38.004392500 [Unloading class sun.reflect.GeneratedConstructorAccessor98] 04:22:38.004533500 [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor40] 04:22:38.004716500 [Unloading class sun.reflect.GeneratedMethodAccessor634] 04:22:38.004808500 [Unloading class sun.reflect.GeneratedConstructorAccessor90] 04:22:38.004889500 [Unloading class sun.reflect.GeneratedConstructorAccessor95] 04:22:38.005044500 [Unloading class sun.reflect.GeneratedMethodAccessor632] 04:25:18.688916500 933637K->154281K(1041984K), 202.6760940 secs] 

现在我只需要弄清楚如何调整事情来防止这种情况发生。 (build议欢迎。)

感谢Alex和Mainguy的帮助。

如上所述,第一步是更改tomcat启动脚本进行添加
-verbose:gc -XX:+ PrintGCTimeStamps -XX:+ PrintGCDetails

当你的速度放缓的时候,在catalina.out中寻找像“FullGC”或许多GC一样的东西…

我会注意到,如果你还没有这样做的话,把tomcat堆的大小提高到1/2到3/4的可用内存,假设这个盒子只运行tomcat。 例如,要将最大堆设置为768 MB,可以将-Xmx768M添加到JAVA_OPTS

如果您使用的是Ubuntu 10.04,这些设置通常位于/ etc / default / tomcat6中。

当Java堆的“tenured”一代中的一大块内存已经被换出到磁盘上时,我们已经发生了这种情况,因为它是垃圾并且一段时间以后还没有被使用。 当需要完整收集时,必须将该内存重新换回。

在这种情况下,你的回答有点违反直觉:减lessJava堆的大小,或者找出其他东西正在使用引起交换的RAM。 在我们的情况中,一些夜间批量作业使用了一堆RAM,导致旧一代被换出到磁盘。 那么,第二天早上所需要的第一个完整的GC需要花费超过180秒(就像你看到的那样)。

您也可以尝试使用并发标记扫描收集器,通过并行执行大量工作来缩短完整的GC时间。 这是我见过的最好的文档。 关于这个问题也有一些很好的Sun博客: http : //www.oracle.com/technetwork/java/gc-tuning-5-138395.html

尝试激活详细的垃圾收集,看看它是否是一个垃圾收集暂停。 我想这是一个巨大的堆,大量的对象分配和交换可能会导致长时间的停顿,但是这个长时间听起来很不寻常。