奇怪的JVM线程挂起 - 建议排除故障?

问题描述:

在排除了JVM的一个在我们的生产环境挂着问题,我们遇到在于执行以下语句记录奇怪的JVM线程挂起 - 建议排除故障?

logger.debug("Loaded ids as " + ids + "."); 

一个线程被悬挂在这一步骤是可运行的线程状态。这里的ids是一个Set。还有另一个线程通过倒计数锁存器等待上述线程来完成其任务。该软件需要线程转储每15分钟和两个线程的踪迹看如下

Stack trace for [THREAD GROUP: Job_Executor] [THREAD NAME:main-Runner Thread][THREAD STATE: WAITING] 
    ...sun.misc.Unsafe.park(Native Method) 
    ...java.util.concurrent.locks.LockSupport.park(Unknown Source) 
    ...java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source) 
    ...java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(Unknown Source) 
    ...java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(Unknown Source) 
    ...java.util.concurrent.CountDownLatch.await(Unknown Source) 
    ...com.runner.MainRunner.stopThread(MainRunnerRunner.java:1334) 


Stack trace for [THREAD GROUP: Job_Executor] [THREAD NAME:task executor][THREAD STATE: RUNNABLE]  
    ...java.util.AbstractCollection.toString(Unknown Source)   
    ...java.lang.String.valueOf(Unknown Source)  
    ...java.lang.StringBuilder.append(Unknown Source)  
    ...com.runner.CriticalTaskExecutor.loadByIds(CriticalTaskExecutor.java:143) 

此JVM得到了挂了近24小时,最后我们不得不杀死它往前走。线程转储表明在RUNNABLE状态下有43个线程,包括上述线程。

上述线程在RUNNABLE状态下执行collection.toString()24小时的原因是什么?

关于如何进行的任何建议?

+3

你能告诉我们'的toString()'方法?任何延迟加载休眠字段或其他复杂? – Gray

+0

我会以此为忠告。感谢您指出。 –

这取决于被调用的方法toString()。当String的构建对于堆太大时,我见过AbstractCollection.toString。否则,问题可能出现在集合中对象的toString

为了弄清楚它是哪一个,需要更多的堆栈转储(大约10个)。卡住的螺纹通常可能在导致问题的toString中。

作为速战速决,与

logger.debug("Loaded ids as {}.", ids); 

更换

logger.debug("Loaded ids as " + ids + "."); 

(假设你正在使用SLF4J,否则查找适当的方式做你的框架参数记录)。

如果未启用调试,则会跳过toString。

+0

这是如何解决'toString()'方法的问题? – Gray

+1

@格雷它没有。但他们说这个问题是在生产中。 'toString'主要面向开发人员,通常不应该在生产IMHO中调用。 – artbristol

+0

真的吗? ''toString()'在我们的环境中被所有的时间调用生产日志。在渲染视图时,Web应用程序在容器对象的每个地方调用'toString()'。 – Gray

可能是什么原因,上述线程在RUNNABLE状态24个小时,只是在执行collection.toString()?

您尚未提供足够的信息来诊断问题。我只会挑战你不要假设这里发生了JVM问题。

如果我们看AbstractCollection.toString()方法的来源,我们会看到它遍历集合并大致吐出“[item0,item1,item2]”。调用每个item.toString()方法来显示该项目。

如果应用程序挂起在集合toString()那么我的猜测是集合上的迭代器存在一些问题。如果你的应用程序正在旋转,你可以告诉它 - 使用接近100%的CPU。 Set上的hasNext()方法总是返回true

如果应用程序挂在item.toString()的内部,那么我会确保您的项目只显示简单的字段。请注意,如果访问的字段使得RPC调用像延迟加载的ORM包装字段一样。

如果你提供有关问题的Set详细信息,并显示id.toString()代码,我们可以帮助更多。

现在听起来这是一套Integer对象。不知道为什么这会挂起你的应用程序。这里有一些其他的想法:

  • 你是否以非同步方式访问这个集合?多个线程是否可以对集合进行更改,以使其已损坏,从而导致其迭代器旋转?您可以尝试将其包装在Collections.synchronizedSet(...)中。
  • 任何机会Set巨大。你被淘汰的内存中运行密切和程序是颠簸?这不会挂起你的应用程序,但只是慢慢爬行。你会开始看到内存异常。
  • 是否有任何机会,toString()被称为一遍又一遍?不过,我认为你会在日志中看到。
+0

感谢您的输入。基础集合是一个HashSet 。只是为了让我明白,如果代码试图对一个延迟加载的集合进行RPC调用,那么堆栈跟踪是否会指示?我的意思是不会显示试图进行数据库调用的hibernate代码的痕迹? –

+0

你会这样想,是@安迪。我只是看不到一个'HashSet'悬挂任何东西,所以假设有其他事情正在进行。 – Gray

+0

AHA !! @AndyDufresne你正在同步这个集合?多线程以非同步的方式写入此集合并破坏它以使某些东西在旋转的任何机会? – Gray