在產品中有碰到過使用LinkedBlockingQueue.poll時超時很不準的現象，關鍵是這不是一般的不準，如果只是一點點不準的話也就勉強接受了，例如指定poll的超時時間為100ms，但最終執行.poll這段代碼就花費了8000ms的現象，這篇blog就是展示下通過一段小小的代碼來重現這樣的現象，畢竟沒有重現是無法證明為什么會出現這樣的現象的。
由于在出現這個現象的時候有看到過OutOfMemory的錯，雖然java進程沒退出，但猜想可能是這個原因造成的，于是寫了下面這段代碼：
public static void main(String[] args) throws Exception{
long beginTime=System.currentTimeMillis();
Map<String, byte[]> cache=new HashMap<String, byte[]>();
for (int i = 0; i < 1000000; i++) {
cache.put(String.valueOf(i),new byte[500]);
}
CountDownLatch latch=new CountDownLatch(25);
for (int i = 0; i < 5; i++) {
for (int j = 0; j < 5; j++) {
Thread thread=new Thread(new TestThread(latch));
thread.start();
}
}
latch.await();
long endTime=System.currentTimeMillis();
System.out.println("總共執行時間："+(endTime-beginTime));
}
static class TestThread implements Runnable{
private CountDownLatch latch;
public TestThread(CountDownLatch latch){
this.latch=latch;
}
public void run(){
BlockingQueue<String> queue=new LinkedBlockingQueue<String>(1);
try{
for (int i = 0; i < 5; i++) {
long beginTime=System.currentTimeMillis();
queue.poll(100, TimeUnit.MILLISECONDS);
long endTime=System.currentTimeMillis();
long consumeTime=endTime-beginTime;
if(consumeTime>200)
System.out.println("獲取queue的時間為："+consumeTime);
@SuppressWarnings("unused")
byte[] bytesNew=new byte[25506000];
}
}
catch(Exception e){
;
}
latch.countDown();
}
}
啟動上面程序時，將jvm參數設置為-Xms640M -Xmx640M，運行后，應該會看到有很多queue.poll執行超過200ms的現象，甚至會出現8000ms的現象。
上面整段程序的寫法就是用大量的小對象占據old generation，然后啟動多個線程，每個線程運行的時候new一個大的對象，讓其產生有可能直接從new generation分配到old generation，從而導致Full GC頻繁執行，里面的byte數組的大小的原則為：塞滿內存，產生Full GC，但又盡量不讓應用出現OutOfMemory，或者說不出現過于頻繁的OutOfMemory，避免jvm crash。
從上面程序的運行效果來看，當jvm內存消耗的很嚴重的情況下，poll的超時是沒法準的，其實分析下原因，還是挺正常的：
1、jvm內存消耗嚴重的情況下，Minor GC和Full GC瘋狂執行，導致了應用的執行不斷的被暫停，因此當線程已經進入poll等待后，這個線程沒有機會被執行，導致當其有機會執行時，早就超過了指定的超時時間，因此其超時不準并不是本身的機制導致的，而是jvm GC造成的多次暫停；
2、多次暫停的情況下，jvm需要不斷的調度恢復線程，這需要消耗很多的資源，而且切換多了Swap空間很容易不夠用，最終導致jvm crash。