Java线程发生大量的睡眠，没有GC干扰和低机器负载 [英] Large oversleep in Java thread occurs without GC interference and with low machine load

问题描述

在一个相当复杂的应用程序中，我开发我在一个线程中有以下代码：

  long T = System.currentTimeMillis （）; 
 Thread.sleep（waitNow）; 
 T = System.currentTimeMillis（） -  T; 
 if（T> waitNow * 5）{
 System.out.println（Overslept+ T +>+ waitNow）; 
} 
  

此线程在某些情况下会过载并产生如下输出：

  Overslept 10010> 10 
  

请注意：我知道主题的合同。睡眠方法允许它睡过头，然而这种行为是奇怪的给定的睡眠的大小（10秒而不是10毫秒）。

线程主要睡眠接近指定时间（11-15毫秒）的量，然而由于某种原因，当应用程序运行时，它将睡眠更长时间（10秒+）和可以在几分钟内进行多次（可能一分钟两次或三次）。

线程是正常优先级线程。

在应用程序中总共有大约35个线程。

我使用jconsole并验证垃圾收集器在这些休眠期间没有运行，当GC运行时它非常快（jconsole报告它占用大约30- 50ms）。

应用程序分配了256m内存（-Xmx），但是堆没有使用接近这个数量（可能大约30m）和测试应用程序专门推送内存限制，同时有另一个线程尝试睡眠不会遇到同样的问题。

这个特定的线程发送UDP消息，但是它发送这些相对低速率（大约每秒20×510字节的消息 - 10k /秒）。

线程不会中断，因为它继续完成计时并打印出消息

JRE是1.7.0_45 build 18，运行在2013年的Retina Macbook pro 13运行OSX Mavericks。

由于我的测试应用程序也不会在同一时间这个应用程序睡眠（实际上测试应用程序没有睡过头）这将建议它不是一个时钟更新问题，是这个应用程序的特别的/ JVM，但是我不能想到会导致这种情况的任何东西，事实上除了在机器上消耗大量的资源，我不能想到任何方式对于Java中的一个线程影响另一个线程睡眠的时间量对我有用[0]丢个板砖[0]引用|举报|编辑删除管理jvb取消关注

有谁知道什么是线程可能的原因睡眠？

应用程序（或其他任何东西）可能不会涉及在JVM中使用高内存或高CPU使用率，可能会影响这个？ / p>

解决方案

我在实践中遇到了类似的情况，原来是JVM的一个问题安全点。

对于诊断您可以使用以下选项：

• -XX：+ PrintGCApplicationStoppedTime STW暂停不仅与GC相关


• -XX：+ PrintSafepointStatistics - 打印安全点详细信息


• -XX：PrintSafepointStatisticsCount = 1 - 使JVM报告每个安全点

在我的情况下，根本原因是在应用程序代码（可能代码已触发一些错误在JIT）。

In a fairly complex application I am developing I have the following code in a thread:

long T = System.currentTimeMillis();
Thread.sleep(waitNow);
T = System.currentTimeMillis()-T;
if (T > waitNow*5) {
    System.out.println("Overslept "+T+" > "+waitNow);
}

This thread oversleeps on some occasions and produces output like this:

Overslept 10010 > 10

PLEASE NOTE: I am aware that the contract of the Thread.sleep method allows it to oversleep however this behaviour is strange given the size of the oversleep (10 seconds instead of 10 milliseconds).

The thread mostly sleeps an amount close to the specified time (11-15ms) however for some reason when the application is running it will sleep much longer (10 seconds+) and may do this a number of times over a few minutes (maybe as much as twice or three times a minute).

The thread is a normal priority thread.

There are about 35 threads in total in the application.

I have used jconsole and verified that the garbage collector is not running during these sleeps and that when the GC does run it is very fast (jconsole reports it taking around 30-50ms).

The app is allocated 256m of memory (-Xmx) but the heap is not using close to that amount (maybe around 30m) and a test app that specifically pushes the memory limit of the VM and at the same times has another thread trying to sleep does not hit the same issue.

This particular thread sends UDP messages however it sends these at a relatively low rate (around 20x 510 byte messages per second - 10k/sec).

The thread isn't interrupted since it continues on to finish the timing and print out the message about oversleeping.

The JRE is 1.7.0_45 build 18 running on a 2013 Retina Macbook pro 13" running OSX Mavericks.

Since my test app doesn't also oversleep at the same time this app does (in fact the test app doesn't oversleep at all) this would suggest it is not a clock update issue and is something particular to this app / JVM however I can't think of anything that would cause this, in fact aside from consuming a large amount of resources on the machine I can't think of any way for one thread inside Java to affect the amount of time another thread sleeps for which leads me to suspect it is something odd within the JVM or OS.

The question is:

Does anyone know what are the possible causes of the thread oversleeping?

What could the app (or anything else) be doing that wouldn't involve high memory using in the JVM or high CPU usage on the machine that might affect this?

解决方案

I had similar situation in my practice, it turned out to be a problem with JVM safe points.

For diagnostic you can use following options:

• -XX:+PrintGCApplicationStoppedTime - it prints all STW pauses not only related to GC
• -XX:+PrintSafepointStatistics - prints safe points details
• -XX:PrintSafepointStatisticsCount=1 - make JVM report every safe point

In my case, root cause was in application code (probably code have been triggering some bug in JIT).

这篇关于Java线程发生大量的睡眠，没有GC干扰和低机器负载的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！