Java HotSpot Virtual Machine

Hi All,

i am keep getting "concurrent mode failure" message. The output shows that JVM has plenty of free heap space..

Linux 2.6.10, 1 Celeron 1.4, 512Mb RAM, JRE 1.5.0_06-b05
At the time the app creates around 320 threads, each thread creates 2 sockets.

java -Xmx360M -server -XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode -XX:+UseParNewGC -XX:CMSInitiatingOccupancyFraction=30 -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps

The output:

2699.648: [CMS-concurrent-reset-start]
2700.377: [GC 2700.378: [DefNew: 3968K->0K(4032K), 0.0314280 secs] 61514K->59427K(156940K), 0.0324840 secs]
2700.543: [CMS-concurrent-reset: 0.820/0.894 secs]
2700.658: [GC 2700.659: [DefNew: 3962K->0K(4032K), 0.0250140 secs] 63390K->60823K(156940K), 0.0260200 secs]
2700.795: [GC [1 CMS-initial-mark: 60823K(152908K)] 62179K(156940K), 0.0073890 secs]
2700.813: [CMS-concurrent-mark-start]
2701.098: [GC 2701.099: [DefNew: 3965K->0K(4032K), 0.0199350 secs] 64789K->61808K(156940K), 0.0208500 secs]
2701.427: [CMS-concurrent-mark: 0.535/0.613 secs]
2701.428: [CMS-concurrent-preclean-start]
2701.428: [CMS-concurrent-preclean: 0.000/0.000 secs]
2701.515: [CMS-concurrent-abortable-preclean-start]
2701.515: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs]
2701.611: [GC 2701.612: [DefNew: 3968K->0K(4032K), 0.0242650 secs] 65776K->62852K(156940K), 0.0252370 secs]
2701.783: [GC[YG occupancy: 2613 K (4032 K)]2701.784: [Rescan (non-parallel) 2701.784: [grey object rescan, 0.0036770 secs]2701.788: [root rescan, 0.0244120 secs], 0.0285420 secs]2701.813: [weak refs processing, 0.0102910 secs] [1 CMS-remark: 62852K(152908K)] 65465K(156940K), 0.0394870 secs]
2701.867: [CMS-concurrent-sweep-start]
2701.909: [GC 2701.910: [DefNew: 3964K->0K(4032K), 0.0323430 secs] 66816K->64975K(156940K), 0.0334390 secs]
2702.038: [CMS-concurrent-sweep: 0.049/0.171 secs]
2702.038: [CMS-concurrent-reset-start]
2702.998: [GC 2702.998: [DefNew: 3962K->0K(4032K), 0.0210140 secs] 85186K->82343K(156940K), 0.0218790 secs]
2703.138: [CMS-concurrent-reset: 0.333/1.100 secs]
2703.791: [Full GC 2703.791: [DefNew: 3964K->0K(4032K), 0.0146410 secs] 86741K->83289K(156940K), 0.0156280 secs]
2704.392: [Full GC 2704.392: [DefNew: 3968K->0K(4032K), 0.0167490 secs] 87655K->84394K(156940K), 0.0177010 secs]
2704.469: [GC [1 CMS-initial-mark: 84394K(152908K)] 85388K(156940K), 0.0107350 secs]
2704.486: [CMS-concurrent-mark-start]
2704.765: [GC 2704.766: [DefNew: 3451K->0K(4032K), 0.0126570 secs]2704.779: [CMS2704.849: [CMS-concurrent-mark: 0.319/0.363 secs]
(concurrent mode failure): 84687K->60062K(152908K), 1.1223510 secs] 87846K->60062K(156940K), 1.1360330 secs]
2706.019: [GC [1 CMS-initial-mark: 69278K(152908K)] 70183K(156940K), 0.0072570 secs]
2706.027: [CMS-concurrent-mark-start]
2706.321: [GC 2706.321: [DefNew: 3932K->0K(4032K), 0.0477850 secs] 73210K->72517K(156940K), 0.0486530 secs]
2706.581: [CMS-concurrent-mark: 0.497/0.554 secs]
2706.581: [CMS-concurrent-preclean-start]
2706.581: [CMS-concurrent-preclean: 0.000/0.000 secs]
2706.629: [GC[YG occupancy: 1856 K (4032 K)]2706.629: [Rescan (non-parallel) 2706.629: [grey object rescan, 0.0035780 secs]2706.633: [root rescan, 0.0226330 secs], 0.0266790 secs]2706.656: [weak refs processing, 0.0169460 secs] [1 CMS-remark: 72517K(152908K)] 74374K(156940K), 0.0442060 secs]
2706.694: [CMS-concurrent-sweep-start]
2706.737: [CMS-concurrent-sweep: 0.042/0.042 secs]
2706.737: [CMS-concurrent-reset-start]
2706.965: [CMS-concurrent-reset: 0.228/0.228 secs]
2707.587: [Full GC 2707.587: [DefNew: 3882K->0K(4032K), 0.0415640 secs] 76510K->74975K(156940K), 0.0426500 secs]
2708.077: [GC 2708.077: [DefNew: 3957K->0K(4032K), 0.0388670 secs] 78932K->77482K(156940K), 0.0398290 secs]
2708.239: [GC [1 CMS-initial-mark: 77482K(152908K)] 78533K(156940K), 0.0079570 secs]
2708.255: [CMS-concurrent-mark-start]
2708.510: [CMS-concurrent-mark: 0.255/0.255 secs]
2708.510: [CMS-concurrent-preclean-start]
2708.510: [CMS-concurrent-preclean: 0.000/0.000 secs]
2708.521: [GC[YG occupancy: 1472 K (4032 K)]2708.522: [Rescan (non-parallel) 2708.522: [grey object rescan, 0.0034210 secs]2708.525: [root rescan, 0.0231900 secs], 0.0270310 secs]2708.549: [weak refs processing, 0.0106450 secs] [1 CMS-remark: 77482K(152908K)] 78954K(156940K), 0.0382120 secs]
2708.595: [CMS-concurrent-sweep-start]
2708.668: [GC 2708.668: [DefNew: 3953K->0K(4032K), 0.0450880 secs] 81435K->80075K(156940K), 0.0460180 secs]
2708.873: [CMS-concurrent-sweep: 0.023/0.276 secs]
2708.873: [CMS-concurrent-reset-start]
2709.031: [CMS-concurrent-reset: 0.157/0.157 secs]
2709.481: [GC 2709.481: [DefNew: 3967K->0K(4032K), 0.0326910 secs] 57801K->56142K(156940K), 0.0335990 secs]
2709.771: [GC [1 CMS-initial-mark: 56142K(152908K)] 57433K(156940K), 0.0099300 secs]
------

11858.058: [CMS-concurrent-mark-start]
11858.473: [CMS-concurrent-mark: 0.414/0.414 secs]
11858.473: [CMS-concurrent-preclean-start]
11858.473: [CMS-concurrent-preclean: 0.000/0.000 secs]
11858.581: [GC 11858.582: [DefNew: 3923K->0K(4032K), 0.0267420 secs] 49870K->47211K(196732K), 0.0277170 secs]
11858.693: [GC[YG occupancy: 1214 K (4032 K)]11858.694: [Rescan (non-parallel) 11858.694: [grey object rescan, 0.0043820 secs]11858.698: [root rescan, 0.0254650 secs], 0.0302840 secs]11858.724: [weak refs processing, 0.0090100 secs] [1 CMS-remark: 47211K(192700K)] 48425K(196732K), 0.0398400 secs]
11858.747: [CMS-concurrent-sweep-start]
11858.778: [CMS-concurrent-sweep: 0.031/0.031 secs]
11858.778: [CMS-concurrent-reset-start]
11859.050: [CMS-concurrent-reset: 0.271/0.271 secs]
11859.302: [GC 11859.303: [DefNew: 3968K->0K(4032K), 0.0478380 secs] 49415K->47923K(196732K), 0.0507320 secs]
11859.414: [GC [1 CMS-initial-mark: 47923K(192700K)] 48929K(196732K), 0.0079440 secs]
11859.449: [CMS-concurrent-mark-start]
11859.902: [GC 11859.903: [DefNew: 3968K->0K(4032K), 0.0369170 secs] 51891K->50022K(196732K), 0.0378410 secs]
11860.364: [GC 11860.364: [DefNew: 3968K->0K(4032K), 0.0359820 secs] 53990K->52063K(196732K), 0.0369700 secs]
11860.862: [CMS-concurrent-mark: 1.052/1.412 secs]
11860.862: [CMS-concurrent-preclean-start]
11860.862: [CMS-concurrent-preclean: 0.000/0.000 secs]
11860.986: [Full GC 11860.986: [DefNew: 3968K->0K(4032K), 0.0386790 secs] 57164K->55449K(196732K), 0.0397380 secs]
11861.062: [GC 11861.062: [DefNew: 775K->0K(4032K), 0.0229250 secs]11861.085: [CMS ([b]concurrent mode failure): 55910K->48406K(192700K), 0.9172030 secs] 56225K->48406K(196732K), 0.9411970 secs]
11862.041: [GC [1 CMS-initial-mark: 52448K(192700K)] 52452K(196732K), 0.0076810 secs]
11862.050: [CMS-concurrent-mark-start]
11862.396: [CMS-concurrent-mark: 0.347/0.347 secs]
11862.398: [CMS-concurrent-preclean-start]
11862.398: [CMS-concurrent-preclean: 0.000/0.000 secs]
11862.411: [GC[YG occupancy: 2024 K (4032 K)]11862.412: [Rescan (non-parallel) 11862.412: [grey object rescan, 0.0051080 secs]11862.417: [root rescan, 0.0268980 secs], 0.0324490 secs]11862.444: [weak refs processing, 0.0123470 secs] [1 CMS-remark: 52448K(192700K)] 54472K(196732K), 0.0453460 secs]
11862.487: [CMS-concurrent-sweep-start]
11862.560: [GC 11862.560: [DefNew: 3966K->0K(4032K), 0.0439570 secs] 56090K->54265K(196732K), 0.0485230 secs]
11862.632: [CMS-concurrent-sweep: 0.082/0.144 secs]
11862.632: [CMS-concurrent-reset-start]
11862.973: [CMS-concurrent-reset: 0.340/0.340 secs]
11863.026: [GC 11863.027: [DefNew: 3964K->0K(4032K), 0.0210200 secs] 57690K->54638K(196732K), 0.0220900 secs]
11863.243: [GC [1 CMS-initial-mark: 54638K(192700K)] 57264K(196732K), 0.0077380 secs]
11863.252: [CMS-concurrent-mark-start]
11863.391: [GC 11863.392: [DefNew: 3964K->0K(4032K), 0.0273610 secs] 58603K->55873K(196732K), 0.0283010 secs]
11863.443: [GC 11863.443: [DefNew: 212K->0K(4032K), 0.0125370 secs]11863.456: [CMS11863.612: [CMS-concurrent-mark: 0.233/0.361 secs]
(concurrent mode failure): 55988K->48652K(192700K), 1.0271530 secs] 56086K->48652K(196732K), 1.0406640 secs]
11864.521: [GC [1 CMS-initial-mark: 52694K(192700K)] 52698K(196732K), 0.0075070 secs]
11864.529: [CMS-concurrent-mark-start]
11864.783: [CMS-concurrent-mark: 0.253/0.253 secs]
11864.783: [CMS-concurrent-preclean-start]
11864.783: [CMS-concurrent-preclean: 0.000/0.000 secs]
11864.794: [CMS-concurrent-abortable-preclean-start]
11864.795: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs]
11865.407: [GC 11865.408: [DefNew: 3949K->0K(4032K), 0.0402310 secs] 56643K->55305K(196732K), 0.0411360 secs]
11865.755: [GC[YG occupancy: 2150 K (4032 K)]11865.755: [Rescan (non-parallel) 11865.755: [grey object rescan, 0.0046710 secs]11865.760: [root rescan, 0.0307950 secs], 0.0359280 secs]11865.791: [weak refs processing, 0.0086010 secs] [1 CMS-remark: 55305K(192700K)] 57455K(196732K), 0.0450850 secs]
11865.805: [CMS-concurrent-sweep-start]
11865.821: [CMS-concurrent-sweep: 0.016/0.016 secs]
11865.821: [CMS-concurrent-reset-start]
11865.947: [CMS-concurrent-reset: 0.126/0.126 secs]


Any ideas will be really appreciated
Thanks,
Alex