一段好玩的測(cè)試LinkedBlockingQueue.poll超時(shí)的程序

          在產(chǎn)品中有碰到過(guò)使用LinkedBlockingQueue.poll時(shí)超時(shí)很不準(zhǔn)的現(xiàn)象,關(guān)鍵是這不是一般的不準(zhǔn),如果只是一點(diǎn)點(diǎn)不準(zhǔn)的話也就勉強(qiáng)接受了,例如指定poll的超時(shí)時(shí)間為100ms,但最終執(zhí)行.poll這段代碼就花費(fèi)了8000ms的現(xiàn)象,這篇blog就是展示下通過(guò)一段小小的代碼來(lái)重現(xiàn)這樣的現(xiàn)象,畢竟沒(méi)有重現(xiàn)是無(wú)法證明為什么會(huì)出現(xiàn)這樣的現(xiàn)象的。

          由于在出現(xiàn)這個(gè)現(xiàn)象的時(shí)候有看到過(guò)OutOfMemory的錯(cuò),雖然java進(jìn)程沒(méi)退出,但猜想可能是這個(gè)原因造成的,于是寫(xiě)了下面這段代碼:
          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(
          "總共執(zhí)行時(shí)間:"+(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的時(shí)間為:"+consumeTime);
                              @SuppressWarnings(
          "unused")
                              
          byte[] bytesNew=new byte[25506000];
                          }
                      }
                      
          catch(Exception e){
                          ;
                      }
                      latch.countDown();
                  }
                  
              }

          啟動(dòng)上面程序時(shí),將jvm參數(shù)設(shè)置為-Xms640M -Xmx640M,運(yùn)行后,應(yīng)該會(huì)看到有很多queue.poll執(zhí)行超過(guò)200ms的現(xiàn)象,甚至?xí)霈F(xiàn)8000ms的現(xiàn)象。

          上面整段程序的寫(xiě)法就是用大量的小對(duì)象占據(jù)old generation,然后啟動(dòng)多個(gè)線程,每個(gè)線程運(yùn)行的時(shí)候new一個(gè)大的對(duì)象,讓其產(chǎn)生有可能直接從new generation分配到old generation,從而導(dǎo)致Full GC頻繁執(zhí)行,里面的byte數(shù)組的大小的原則為:塞滿(mǎn)內(nèi)存,產(chǎn)生Full GC,但又盡量不讓?xiě)?yīng)用出現(xiàn)OutOfMemory,或者說(shuō)不出現(xiàn)過(guò)于頻繁的OutOfMemory,避免jvm crash。

          從上面程序的運(yùn)行效果來(lái)看,當(dāng)jvm內(nèi)存消耗的很?chē)?yán)重的情況下,poll的超時(shí)是沒(méi)法準(zhǔn)的,其實(shí)分析下原因,還是挺正常的:
          1、jvm內(nèi)存消耗嚴(yán)重的情況下,Minor GC和Full GC瘋狂執(zhí)行,導(dǎo)致了應(yīng)用的執(zhí)行不斷的被暫停,因此當(dāng)線程已經(jīng)進(jìn)入poll等待后,這個(gè)線程沒(méi)有機(jī)會(huì)被執(zhí)行,導(dǎo)致當(dāng)其有機(jī)會(huì)執(zhí)行時(shí),早就超過(guò)了指定的超時(shí)時(shí)間,因此其超時(shí)不準(zhǔn)并不是本身的機(jī)制導(dǎo)致的,而是jvm GC造成的多次暫停;
          2、多次暫停的情況下,jvm需要不斷的調(diào)度恢復(fù)線程,這需要消耗很多的資源,而且切換多了Swap空間很容易不夠用,最終導(dǎo)致jvm crash。

          posted on 2009-03-12 16:52 BlueDavy 閱讀(7809) 評(píng)論(4)  編輯  收藏 所屬分類(lèi): Java

          評(píng)論

          # re: 一段好玩的測(cè)試LinkedBlockingQueue.poll超時(shí)的程序 2009-03-12 20:23 lizongbo

          這個(gè)應(yīng)該和jdk的具體版本有關(guān),不知道你們用的具體哪個(gè)版本的jdk。
          我剛才試了一下用不同版本jdk運(yùn)行的效果:
          各版本的耗時(shí)不一樣:
          1.7.0-nio2 ,基本都在359左右。
          1.6.0_11 ,基本都在453左右。
          1.5.0_14,基本在2359左右。


          前段時(shí)間我們就是因?yàn)閖dk的gc問(wèn)題,對(duì)所有的服務(wù)器都進(jìn)行了jdk升級(jí)到j(luò)dk1.6.0_12。

            回復(fù)  更多評(píng)論   

          # re: 一段好玩的測(cè)試LinkedBlockingQueue.poll超時(shí)的程序 2009-03-12 20:28 lizongbo

          漏了補(bǔ)充說(shuō)明,只在jdk1.5的時(shí)候運(yùn)行出現(xiàn)了java.lang.OutOfMemoryError,而jdk1.6和jdk1.7都沒(méi)出現(xiàn)OutOfMemoryError.
            回復(fù)  更多評(píng)論   

          # re: 一段好玩的測(cè)試LinkedBlockingQueue.poll超時(shí)的程序 2009-03-12 20:34 BlueDavy

          @lizongbo
          多謝,:),我之前還只在1.5.0_10上跑過(guò),看來(lái)越新的java版本,性能確實(shí)越好,呵呵  回復(fù)  更多評(píng)論   

          # re: 一段好玩的測(cè)試LinkedBlockingQueue.poll超時(shí)的程序 2009-03-12 22:50 岑文初

          觀察過(guò),1.5肯定是不回收的,它的一個(gè)鎖信號(hào)量,1.6回收比較慢,要到一定的內(nèi)存占用比例才會(huì)去Gc。SIP最早時(shí)候的內(nèi)存泄露就是這個(gè)問(wèn)題。  回復(fù)  更多評(píng)論   

          公告

           









          feedsky
          抓蝦
          google reader
          鮮果

          導(dǎo)航

          <2009年3月>
          22232425262728
          1234567
          891011121314
          15161718192021
          22232425262728
          2930311234

          統(tǒng)計(jì)

          隨筆分類(lèi)

          隨筆檔案

          文章檔案

          Blogger's

          搜索

          最新評(píng)論

          閱讀排行榜

          評(píng)論排行榜

          主站蜘蛛池模板: 腾冲县| 页游| 满洲里市| 望城县| 中江县| 光泽县| 喀什市| 监利县| 阿克陶县| 宝应县| 丰县| 潜山县| 建昌县| 德安县| 绥滨县| 阿尔山市| 芜湖县| 阿巴嘎旗| 辛集市| 咸阳市| 抚州市| 巨鹿县| 康乐县| 梧州市| 依安县| 乌什县| 绍兴市| 芒康县| 彭泽县| 元朗区| 东丰县| 神农架林区| 赣榆县| 绥宁县| 太白县| 山阳县| 科技| 浑源县| 扎兰屯市| 浦江县| 稷山县|