Skip to main content

major gc taking much time in java 1.6

4 replies [Last post]
coolprashant_nitk
Offline
Joined: 2009-01-22
Points: 0

Hi All,

The problem is as follows:

We have a server. it receives messages from networks and puts them into a queue. From that queue application thread dequeue it process. For around one and half hour every thing works fine and there is no queue build up. But after one and half hour, queue starts building up. We investigated the issue and found out that the major GC cycle is very long and it keeps on increasing with time. We print memory plot for this application and found out that memory consumption was very stable. it was reaching to 59 before major GC and coming down to 49 after major GC. We have also checked about memory leak. There is no memory leak found in the application.

What we are suspecting is as major GC cycle increases with time, GC pause also increases. Due to this queue starts building up as application threads are in stopped state.

Is there any way by which I can reduce this GC pause or in other words reduce GC cycle. we have quite a free memory available. Increasing memory size wont be a problem with us.

followings are the details:
==============================================================
java 1.6.0_02
hardware v490 machines.

followings are my GC settings:

-server
-XX:+PrintClassHistogram
-Xdebug
-Xnoagent
-Xmx3g
-Xms3g
-XX:NewSize=256m
-XX:MaxNewSize=256m
-XX:+UseTLAB
-XX:+UseConcMarkSweepGC
-XX:CMSInitiatingOccupancyFraction=65
-verbose:gc
-XX:+PrintGCTimeStamps
-XX:+PrintGCDetails

following is the output:

952.595: [GC 952.595: [ParNew: 235968K->26176K(235968K), 0.1332150 secs] 1360700K->1164089K(3119552K), 0.1334431 secs] [Times: user=0.61 sys=0.05, real=0.13 secs]
955.707: [GC 955.707: [ParNew: 235968K->26176K(235968K), 0.1266937 secs] 1373881K->1176343K(3119552K), 0.1269041 secs] [Times: user=0.59 sys=0.04, real=0.13 secs]
958.853: [GC 958.853: [ParNew: 235968K->26176K(235968K), 0.1282773 secs] 1386135K->1189319K(3119552K), 0.1285282 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
962.038: [GC 962.039: [ParNew: 235968K->26176K(235968K), 0.1257323 secs] 1399111K->1202305K(3119552K), 0.1259797 secs] [Times: user=0.59 sys=0.04, real=0.13 secs]
965.209: [GC 965.209: [ParNew: 235968K->26176K(235968K), 0.1266497 secs] 1412097K->1215140K(3119552K), 0.1268976 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
968.337: [GC 968.337: [ParNew: 235968K->26176K(235968K), 0.1303420 secs] 1424932K->1228303K(3119552K), 0.1305618 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
971.465: [GC 971.465: [ParNew: 235968K->26176K(235968K), 0.1269842 secs] 1438095K->1240860K(3119552K), 0.1272362 secs] [Times: user=0.59 sys=0.05, real=0.13 secs]
974.604: [GC 974.605: [ParNew: 235968K->26176K(235968K), 0.1254854 secs] 1450652K->1253532K(3119552K), 0.1257359 secs] [Times: user=0.59 sys=0.05, real=0.13 secs]
977.731: [GC 977.731: [ParNew: 235968K->26176K(235968K), 0.1285040 secs] 1463324K->1266327K(3119552K), 0.1287424 secs] [Times: user=0.59 sys=0.05, real=0.13 secs]
980.869: [GC 980.869: [ParNew: 235968K->26176K(235968K), 0.1237545 secs] 1476119K->1278483K(3119552K), 0.1240085 secs] [Times: user=0.58 sys=0.04, real=0.12 secs]
984.039: [GC 984.039: [ParNew: 235968K->26176K(235968K), 0.1260557 secs] 1488275K->1291081K(3119552K), 0.1263111 secs] [Times: user=0.59 sys=0.04, real=0.13 secs]
987.179: [GC 987.180: [ParNew: 235968K->26176K(235968K), 0.1276705 secs] 1500873K->1304420K(3119552K), 0.1279319 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
990.302: [GC 990.302: [ParNew: 235968K->26176K(235968K), 0.1260388 secs] 1514212K->1317288K(3119552K), 0.1262868 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
993.462: [GC 993.462: [ParNew: 235968K->26176K(235968K), 0.1288240 secs] 1527080K->1330225K(3119552K), 0.1290740 secs] [Times: user=0.60 sys=0.05, real=0.13 secs]
996.612: [GC 996.612: [ParNew: 235968K->26176K(235968K), 0.1266921 secs] 1540017K->1342670K(3119552K), 0.1269315 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
999.743: [GC 999.743: [ParNew: 235968K->26176K(235968K), 0.1329730 secs] 1552462K->1355815K(3119552K), 0.1332207 secs] [Times: user=0.60 sys=0.05, real=0.13 secs]
1002.923: [GC 1002.923: [ParNew: 235968K->26176K(235968K), 0.1262077 secs] 1565607K->1368693K(3119552K), 0.1264656 secs] [Times: user=0.59 sys=0.04, real=0.13 secs]
1006.012: [GC 1006.013: [ParNew: 235968K->26176K(235968K), 0.1273153 secs] 1578485K->1381806K(3119552K), 0.1275394 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
1009.177: [GC 1009.178: [ParNew: 235968K->26176K(235968K), 0.1258468 secs] 1591598K->1394455K(3119552K), 0.1260550 secs] [Times: user=0.59 sys=0.04, real=0.13 secs]
1012.306: [GC 1012.307: [ParNew: 235968K->26176K(235968K), 0.1272556 secs] 1604247K->1407116K(3119552K), 0.1274939 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
1015.612: [GC 1015.612: [ParNew: 235968K->26176K(235968K), 0.1216930 secs] 1616908K->1419712K(3119552K), 0.1219091 secs] [Times: user=0.59 sys=0.04, real=0.12 secs]
1018.611: [GC 1018.611: [ParNew: 235968K->26176K(235968K), 0.1289235 secs] 1629504K->1433055K(3119552K), 0.1291653 secs] [Times: user=0.61 sys=0.04, real=0.13 secs]
1021.764: [GC 1021.764: [ParNew: 235966K->26176K(235968K), 0.1267397 secs] 1642845K->1445398K(3119552K), 0.1269638 secs] [Times: user=0.60 sys=0.05, real=0.13 secs]
1024.894: [GC 1024.894: [ParNew: 235968K->26176K(235968K), 0.1288068 secs] 1655190K->1458601K(3119552K), 0.1290619 secs] [Times: user=0.61 sys=0.05, real=0.13 secs]
1028.061: [GC 1028.061: [ParNew: 235968K->26176K(235968K), 0.1271274 secs] 1668393K->1471528K(3119552K), 0.1273572 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
1028.190: [GC [1 CMS-initial-mark: 1445352K(2883584K)] 1471553K(3119552K), 0.1281329 secs] [Times: user=0.10 sys=0.03, real=0.13 secs]
1028.319: [CMS-concurrent-mark-start]
1031.173: [GC 1031.173: [ParNew: 235968K->26176K(235968K), 0.1351893 secs] 1681320K->1485144K(3119552K), 0.1354451 secs] [Times: user=0.65 sys=0.04, real=0.14 secs]
1034.308: [GC 1034.308: [ParNew: 235968K->26176K(235968K), 0.1263800 secs] 1694936K->1497710K(3119552K), 0.1266364 secs] [Times: user=0.62 sys=0.04, real=0.13 secs]
1037.493: [GC 1037.493: [ParNew: 235968K->26176K(235968K), 0.1300500 secs] 1707502K->1509979K(3119552K), 0.1304853 secs] [Times: user=0.63 sys=0.04, real=0.13 secs]
1038.681: [CMS-concurrent-mark: 4.154/10.362 secs] [Times: user=23.87 sys=3.08, real=10.36 secs]
1038.682: [CMS-concurrent-preclean-start]
1039.196: [CMS-concurrent-preclean: 0.350/0.514 secs] [Times: user=0.95 sys=0.12, real=0.51 secs]
1039.197: [CMS-concurrent-abortable-preclean-start]
1040.632: [GC 1040.632: [ParNew: 235968K->26176K(235968K), 0.1295132 secs] 1719771K->1521988K(3119552K), 0.1297404 secs] [Times: user=0.64 sys=0.04, real=0.13 secs]
1042.193: [CMS-concurrent-abortable-preclean: 1.864/2.996 secs] [Times: user=6.29 sys=0.84, real=3.00 secs]
1042.194: [GC[YG occupancy: 132135 K (235968 K)]1042.194: [Rescan (parallel) , 0.0739065 secs]1042.268: [weak refs processing, 0.0094158 secs] [1 CMS-remark: 1495812K(2883584K)] 1627947K(3119552K), 0.0840375 secs] [Times: user=0.51 sys=0.00, real=0.08 secs]
1042.280: [CMS-concurrent-sweep-start]
1043.766: [GC 1043.766: [ParNew: 235968K->26176K(235968K), 0.1140641 secs] 1608134K->1410702K(3119552K), 0.1142853 secs] [Times: user=0.59 sys=0.01, real=0.11 secs]
1046.899: [GC 1046.899: [ParNew: 235968K->26176K(235968K), 0.1175911 secs] 1501590K->1305351K(3119552K), 0.1178341 secs] [Times: user=0.62 sys=0.01, real=0.12 secs]
1050.049: [GC 1050.049: [ParNew: 235968K->26176K(235968K), 0.1093586 secs] 1416234K->1218781K(3119552K), 0.1095879 secs] [Times: user=0.59 sys=0.01, real=0.11 secs]
1053.209: [GC 1053.209: [ParNew: 235968K->26176K(235968K), 0.1117588 secs] 1334186K->1137321K(3119552K), 0.1120020 secs] [Times: user=0.60 sys=0.01, real=0.11 secs]
1056.330: [GC 1056.331: [ParNew: 235968K->26176K(235968K), 0.1138203 secs] 1259840K->1063213K(3119552K), 0.1140839 secs] [Times: user=0.60 sys=0.02, real=0.11 secs]
1059.473: [GC 1059.473: [ParNew: 235968K->26176K(235968K), 0.1117623 secs] 1170096K->972820K(3119552K), 0.1120068 secs] [Times: user=0.59 sys=0.01, real=0.11 secs]
1062.583: [GC 1062.583: [ParNew: 235968K->26176K(235968K), 0.1180305 secs] 1104766K->907199K(3119552K), 0.1182947 secs] [Times: user=0.59 sys=0.02, real=0.12 secs]
1064.947: [CMS-concurrent-sweep: 13.940/22.667 secs] [Times: user=47.02 sys=6.12, real=22.67 secs]
1064.947: [CMS-concurrent-reset-start]
1065.064: [CMS-concurrent-reset: 0.102/0.116 secs] [Times: user=0.17 sys=0.05, real=0.12 secs]
1065.765: [GC 1065.765: [ParNew: 235968K->26176K(235968K), 0.1124282 secs] 1087749K->890867K(3119552K), 0.1126784 secs] [Times: user=0.58 sys=0.01, real=0.11 secs]
1068.886: [GC 1068.886: [ParNew: 235968K->26176K(235968K), 0.1110145 secs] 1100659K->903439K(3119552K), 0.1112537 secs] [Times: user=0.57 sys=0.02, real=0.11 secs]
1072.019: [GC 1072.020: [ParNew: 235968K->26176K(235968K), 0.1094699 secs] 1113231K->915901K(3119552K), 0.1096915 secs] [Times: user=0.57 sys=0.01, real=0.11 secs]
1075.272: [GC 1075.272: [ParNew: 235968K->26176K(235968K), 0.1092895 secs] 1125693K->928864K(3119552K), 0.1095118 secs] [Times: user=0.57 sys=0.01, real=0.11 secs]
1078.332: [GC 1078.333: [ParNew: 235968K->26176K(235968K), 0.1113217 secs] 1138656K->941564K(3119552K), 0.1115645 secs] [Times: user=0.58 sys=0.02, real=0.11 secs]
1081.523: [GC 1081.523: [ParNew: 235968K->26176K(235968K), 0.1102968 secs] 1151356K->953968K(3119552K), 0.1105326 secs] [Times: user=0.57 sys=0.02, real=0.11 secs]
1084.598: [GC 1084.599: [ParNew: 235968K->26176K(235968K), 0.1068542 secs] 1163760K->966671K(3119552K), 0.1070904 secs] [Times: user=0.57 sys=0.01, real=0.11 secs]
1087.762: [GC 1087.762: [ParNew: 235968K->26176K(235968K), 0.1142827 secs] 1176463K->979414K(3119552K), 0.1145881 secs] [Times: user=0.58 sys=0.02, real=0.11 secs]
1090.905: [GC 1090.905: [ParNew: 235968K->26176K(235968K), 0.1112105 secs] 1189206K->991533K(3119552K), 0.1114531 secs] [Times: user=0.58 sys=0.01, real=0.11 secs]
1093.985: [GC 1093.985: [ParNew: 235968K->26176K(235968K), 0.1097910 secs] 1201325K->1004267K(3119552K), 0.1100176 secs] [Times: user=0.57 sys=0.02, real=0.11 secs]
1097.145: [GC 1097.145: [ParNew: 235968K->26176K(235968K), 0.1067552 secs] 1214059K->1016804K(3119552K), 0.1069625 secs] [Times: user=0.57 sys=0.01, real=0.11 secs]
1100.280: [GC 1100.281: [ParNew: 235968K->26176K(235968K), 0.1194704 secs] 1226596K->1029257K(3119552K), 0.1197226 secs] [Times: user=0.58 sys=0.01, real=0.12 secs]
1103.424: [GC 1103.424: [ParNew: 235968K->26176K(235968K), 0.1112037 secs] 1239049K->1041670K(3119552K), 0.1114462 secs] [Times: user=0.58 sys=0.02, real=0.11 secs]
1106.612: [GC 1106.612: [ParNew: 235968K->26176K(235968K), 0.1141857 secs] 1251462K->1054230K(3119552K), 0.1144419 secs] [Times: user=0.59 sys=0.02, real=0.11 secs]
1109.765: [GC 1109.765: [ParNew: 235968K->26176K(235968K), 0.1135258 secs] 1264022K->1066954K(3119552K), 0.1137774 secs] [Times: user=0.58 sys=0.02, real=0.11 secs]
1112.874: [GC 1112.874: [ParNew: 235968K->26176K(235968K), 0.1157572 secs] 1276746K->1080129K(3119552K), 0.1160060 secs] [Times: user=0.60 sys=0.02, real=0.12 secs]
1116.078: [GC 1116.078: [ParNew: 235968K->26176K(235968K), 0.1122589 secs] 1289921K->1092934K(3119552K), 0.1126025 secs] [Times: user=0.60 sys=0.01, real=0.11 secs]
1119.151: [GC 1119.151: [ParNew: 235968K->26176K(235968K), 0.1104393 secs] 1302726K->1105507K(3119552K), 0.1106800 secs] [Times: user=0.59 sys=0.02, real=0.11 secs]
1122.267: [GC 1122.267: [ParNew: 235968K->26176K(235968K), 0.1162381 secs] 1315299K->1118208K(3119552K), 0.1164606 secs] [Times: user=0.59 sys=0.02, real=0.12 secs]
1125.400: [GC 1125.400: [ParNew: 235968K->26176K(235968K), 0.1130613 secs] 1328000K->1130329K(3119552K), 0.1132811 secs] [Times: user=0.59 sys=0.03, real=0.11 secs]
1128.542: [GC 1128.543: [ParNew: 235968K->26176K(235968K), 0.1253015 secs] 1340121K->1142820K(3119552K), 0.1255483 secs] [Times: user=0.62 sys=0.04, real=0.13 secs]
1131.710: [GC 1131.710: [ParNew: 235968K->26176K(235968K), 0.1282609 secs] 1352612K->1156314K(3119552K), 0.1285067 secs] [Times: user=0.62 sys=0.03, real=0.13 secs]
1134.835: [GC 1134.835: [ParNew: 235968K->26176K(235968K), 0.1176199 secs] 1366106K->1169175K(3119552K), 0.1178717 secs] [Times: user=0.60 sys=0.04, real=0.12 secs]
1137.997: [GC 1137.997: [ParNew: 235968K->26176K(235968K), 0.1287109 secs] 1378967K->1182560K(3119552K), 0.1289613 secs] [Times: user=0.62 sys=0.04, real=0.13 secs]
1141.140: [GC 1141.140: [ParNew: 235967K->26176K(235968K), 0.1197141 secs] 1392352K->1195223K(3119552K), 0.1199270 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1144.291: [GC 1144.291: [ParNew: 235968K->26176K(235968K), 0.1138388 secs] 1405015K->1207651K(3119552K), 0.1140695 secs] [Times: user=0.58 sys=0.03, real=0.11 secs]
1147.469: [GC 1147.469: [ParNew: 235968K->26176K(235968K), 0.1180948 secs] 1417443K->1220016K(3119552K), 0.1183390 secs] [Times: user=0.60 sys=0.03, real=0.12 secs]
1150.580: [GC 1150.580: [ParNew: 235968K->26176K(235968K), 0.1203193 secs] 1429808K->1233967K(3119552K), 0.1205660 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1153.695: [GC 1153.695: [ParNew: 235968K->26176K(235968K), 0.1122994 secs] 1443759K->1246374K(3119552K), 0.1125463 secs] [Times: user=0.58 sys=0.03, real=0.11 secs]
1156.833: [GC 1156.834: [ParNew: 235968K->26176K(235968K), 0.1162525 secs] 1456166K->1259677K(3119552K), 0.1165002 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1160.005: [GC 1160.005: [ParNew: 235968K->26176K(235968K), 0.1291183 secs] 1469469K->1271711K(3119552K), 0.1293651 secs] [Times: user=0.61 sys=0.04, real=0.13 secs]
1163.147: [GC 1163.147: [ParNew: 235968K->26176K(235968K), 0.1348566 secs] 1481503K->1284168K(3119552K), 0.1350819 secs] [Times: user=0.63 sys=0.05, real=0.14 secs]
1166.292: [GC 1166.293: [ParNew: 235968K->26176K(235968K), 0.1420900 secs] 1493960K->1297320K(3119552K), 0.1423289 secs] [Times: user=0.65 sys=0.06, real=0.14 secs]
1169.439: [GC 1169.439: [ParNew: 235968K->26176K(235968K), 0.1468694 secs] 1507112K->1310144K(3119552K), 0.1471193 secs] [Times: user=0.65 sys=0.06, real=0.15 secs]
1172.558: [GC 1172.558: [ParNew: 235968K->26176K(235968K), 0.1274584 secs] 1519936K->1322390K(3119552K), 0.1277193 secs] [Times: user=0.61 sys=0.03, real=0.13 secs]
1175.725: [GC 1175.725: [ParNew: 235968K->26176K(235968K), 0.1243575 secs] 1532182K->1335993K(3119552K), 0.1245803 secs] [Times: user=0.63 sys=0.03, real=0.12 secs]
1178.894: [GC 1178.894: [ParNew: 235968K->26176K(235968K), 0.1182924 secs] 1545785K->1349062K(3119552K), 0.1185368 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1182.018: [GC 1182.018: [ParNew: 235968K->26176K(235968K), 0.1218574 secs] 1558854K->1362512K(3119552K), 0.1221069 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1185.180: [GC 1185.180: [ParNew: 235968K->26176K(235968K), 0.1142523 secs] 1572304K->1375158K(3119552K), 0.1144940 secs] [Times: user=0.59 sys=0.03, real=0.11 secs]
1188.292: [GC 1188.293: [ParNew: 235968K->26176K(235968K), 0.1118127 secs] 1584950K->1387558K(3119552K), 0.1120637 secs] [Times: user=0.59 sys=0.03, real=0.11 secs]
1191.418: [GC 1191.418: [ParNew: 235968K->26176K(235968K), 0.1133729 secs] 1597350K->1400501K(3119552K), 0.1136304 secs] [Times: user=0.59 sys=0.02, real=0.11 secs]
1194.566: [GC 1194.566: [ParNew: 235968K->26176K(235968K), 0.1201232 secs] 1610293K->1413425K(3119552K), 0.1203702 secs] [Times: user=0.60 sys=0.03, real=0.12 secs]
1197.784: [GC 1197.785: [ParNew: 235968K->26176K(235968K), 0.1182104 secs] 1623217K->1426158K(3119552K), 0.1184631 secs] [Times: user=0.60 sys=0.03, real=0.12 secs]
1200.904: [GC 1200.904: [ParNew: 235968K->26176K(235968K), 0.1146496 secs] 1635950K->1438947K(3119552K), 0.1148960 secs] [Times: user=0.60 sys=0.03, real=0.12 secs]
1204.015: [GC 1204.015: [ParNew: 235968K->26176K(235968K), 0.1184138 secs] 1648739K->1451181K(3119552K), 0.1186749 secs] [Times: user=0.59 sys=0.02, real=0.12 secs]
1207.161: [GC 1207.161: [ParNew: 235968K->26176K(235968K), 0.1124596 secs] 1660973K->1463935K(3119552K), 0.1126979 secs] [Times: user=0.59 sys=0.03, real=0.11 secs]
1210.331: [GC 1210.331: [ParNew: 235968K->26176K(235968K), 0.1182260 secs] 1673727K->1477139K(3119552K), 0.1184739 secs] [Times: user=0.60 sys=0.02, real=0.12 secs]
1213.431: [GC 1213.431: [ParNew: 235968K->26176K(235968K), 0.1128553 secs] 1686931K->1489319K(3119552K), 0.1130859 secs] [Times: user=0.59 sys=0.02, real=0.11 secs]
1216.584: [GC 1216.585: [ParNew: 235968K->26176K(235968K), 0.1102765 secs] 1699111K->1501641K(3119552K), 0.1104849 secs] [Times: user=0.58 sys=0.03, real=0.11 secs]
1219.696: [GC 1219.697: [ParNew: 235968K->26176K(235968K), 0.1182606 secs] 1711433K->1514230K(3119552K), 0.1185097 secs] [Times: user=0.59 sys=0.03, real=0.12 secs]
1222.842: [GC 1222.842: [ParNew: 235968K->26176K(235968K), 0.1292271 secs] 1724022K->1526723K(3119552K), 0.1294659 secs] [Times: user=0.59 sys=0.04, real=0.13 secs]
1226.001: [GC 1226.001: [ParNew: 235968K->26176K(235968K), 0.1367833 secs] 1736515K->1540531K(3119552K), 0.1370208 secs] [Times: user=0.62 sys=0.05, real=0.14 secs]
1229.155: [GC 1229.156: [ParNew: 235968K->26176K(235968K), 0.1291611 secs] 1750323K->1553184K(3119552K), 0.1293990 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
1232.302: [GC 1232.302: [ParNew: 235968K->26176K(235968K), 0.1261342 secs] 1762976K->1565525K(3119552K), 0.1264084 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
1235.468: [GC 1235.468: [ParNew: 235968K->26176K(235968K), 0.1249636 secs] 1775317K->1578499K(3119552K), 0.1252280 secs] [Times: user=0.61 sys=0.04, real=0.13 secs]
1238.595: [GC 1238.595: [ParNew: 235968K->26176K(235968K), 0.1256764 secs] 1788291K->1591447K(3119552K), 0.1259248 secs] [Times: user=0.61 sys=0.05, real=0.13 secs]
1241.732: [GC 1241.732: [ParNew: 235968K->26176K(235968K), 0.1437576 secs] 1801239K->1604262K(3119552K), 0.1439925 secs] [Times: user=0.61 sys=0.04, real=0.14 secs]
1244.864: [GC 1244.865: [ParNew: 235968K->26176K(235968K), 0.1280409 secs] 1814054K->1617127K(3119552K), 0.1282718 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
[ POA RootPOA - rid: 21 oid: 00 16 01 2B 20 4C 02 20 4A 16 opname: getPerformanceStatistics - process request ]
1247.957: [GC 1247.957: [ParNew: 235968K->26176K(235968K), 0.1323874 secs] 1826919K->1629798K(3119552K), 0.1326308 secs] [Times: user=0.62 sys=0.05, real=0.13 secs]
1251.125: [GC 1251.125: [ParNew: 235968K->26176K(235968K), 0.1303039 secs] 1839590K->1642794K(3119552K), 0.1305312 secs] [Times: user=0.61 sys=0.04, real=0.13 secs]
1254.254: [GC 1254.254: [ParNew: 235968K->26176K(235968K), 0.1269808 secs] 1852586K->1655553K(3119552K), 0.1272051 secs] [Times: user=0.61 sys=0.04, real=0.13 secs]
1257.423: [GC 1257.423: [ParNew: 235968K->26176K(235968K), 0.1293535 secs] 1865345K->1668747K(3119552K), 0.1295947 secs] [Times: user=0.61 sys=0.04, real=0.13 secs]
1260.570: [GC 1260.570: [ParNew: 235968K->26176K(235968K), 0.1269249 secs] 1878539K->1681812K(3119552K), 0.1271635 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
1263.699: [GC 1263.699: [ParNew: 235968K->26176K(235968K), 0.1277488 secs] 1891604K->1694737K(3119552K), 0.1280049 secs] [Times: user=0.61 sys=0.05, real=0.13 secs]
1266.837: [GC 1266.837: [ParNew: 235968K->26176K(235968K), 0.1297062 secs] 1904529K->1707550K(3119552K), 0.1299352 secs] [Times: user=0.60 sys=0.05, real=0.13 secs]
1269.996: [GC 1269.996: [ParNew: 235968K->26176K(235968K), 0.1302212 secs] 1917342K->1720585K(3119552K), 0.1304696 secs] [Times: user=0.61 sys=0.05, real=0.13 secs]
1273.126: [GC 1273.126: [ParNew: 235968K->26176K(235968K), 0.1249282 secs] 1930377K->1733458K(3119552K), 0.1251764 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
1276.237: [GC 1276.237: [ParNew: 235968K->26176K(235968K), 0.1544852 secs] 1943250K->1747031K(3119552K), 0.1547554 secs] [Times: user=0.62 sys=0.04, real=0.15 secs]
1279.364: [GC 1279.364: [ParNew: 235968K->26176K(235968K), 0.1283479 secs] 1956823K->1759874K(3119552K), 0.1285938 secs] [Times: user=0.59 sys=0.04, real=0.13 secs]
1282.652: [GC 1282.652: [ParNew: 235968K->26176K(235968K), 0.1307106 secs] 1969666K->1772969K(3119552K), 0.1309571 secs] [Times: user=0.61 sys=0.04, real=0.13 secs]
1285.682: [GC 1285.682: [ParNew: 235968K->26176K(235968K), 0.1257509 secs] 1982761K->1785536K(3119552K), 0.1259825 secs] [Times: user=0.60 sys=0.04, real=0.13 secs]
1288.863: [GC 1288.863: [ParNew: 235968K->26176K(235968K), 0.1337245 secs] 1995328K->1798427K(3119552K), 0.1339731 secs] [Times: user=0.60 sys=0.05, real=0.13 secs]
1291.999: [GC 1291.999: [ParNew: 235968K->26176K(235968K), 0.1358105 secs] 2008219K->1810935K(3119552K), 0.1360678 secs] [Times: user=0.60 sys=0.04, real=0.14 secs]
1295.118: [GC 1295.118: [ParNew: 235968K->26176K(235968K), 0.1239505 secs] 2020727K->1823443K(3119552K), 0.1241817 secs] [Times: user=0.59 sys=0.04, real=0.12 secs]
1298.290: [GC 1298.291: [ParNew: 235968K->26176K(235968K), 0.1296132 secs] 2033235K->1836829K(3119552K), 0.1298460 secs] [Times: user=0.61 sys=0.04, real=0.13 secs]
1301.450: [GC 1301.451: [ParNew: 235968K->26176K(235968K), 0.1282136 secs] 2046621K->1849067K(3119552K), 0.1284741 secs] [Times: user=0.61 sys=0.04, real=0.13 secs]
1304.553: [GC 1304.553: [ParNew: 235968K->26176K(235968K), 0.1327430 secs] 2058859K->1861886K(3119552K), 0.1329875 secs] [Times: user=0.61 sys=0.04, real=0.13 secs]
1307.686: [GC 1307.686: [ParNew: 235968K->26176K(235968K), 0.1294349 secs] 2071678K->1874519K(3119552K), 0.1296849 secs] [Times: user=0.62 sys=0.05, real=0.13 secs]
1310.822: [GC 1310.822: [ParNew: 235968K->26176K(235968K), 0.1341838 secs] 2084311K->1888157K(3119552K), 0.1344484 secs] [Times: user=0.62 sys=0.04, real=0.13 secs]
1313.941: [GC 1313.941: [ParNew: 235968K->26176K(235968K), 0.1331439 secs] 2097949K->1900581K(3119552K), 0.1334205 secs] [Times: user=0.60 sys=0.05, real=0.13 secs]
1314.078: [GC [1 CMS-initial-mark: 1874405K(2883584K)] 1901011K(3119552K), 0.1067346 secs] [Times: user=0.11 sys=0.00, real=0.11 secs]
1314.185: [CMS-concurrent-mark-start]
1317.115: [GC 1317.116: [ParNew: 235968K->26176K(235968K), 0.1516875 secs] 2110373K->1913447K(3119552K), 0.1519333 secs] [Times: user=0.65 sys=0.05, real=0.15 secs]
1320.258: [GC 1320.259: [ParNew: 235968K->26176K(235968K), 0.1283079 secs] 2123239K->1926068K(3119552K), 0.1285496 secs] [Times: user=0.63 sys=0.04, real=0.13 secs]
1323.439: [GC 1323.439: [ParNew: 235968K->26176K(235968K), 0.1469861 secs] 2135860K->1939985K(3119552K), 0.1474587 secs] [Times: user=0.67 sys=0.04, real=0.15 secs]
1326.064: [CMS-concurrent-mark: 3.973/11.879 secs] [Times: user=26.91 sys=3.60, real=11.88 secs]
1326.064: [CMS-concurrent-preclean-start]
1326.532: [GC 1326.533: [ParNew: 235968K->26176K(235968K), 0.1320911 secs] 2149777K->1952556K(3119552K), 0.1323285 secs] [Times: user=0.63 sys=0.04, real=0.13 secs]
1327.144: [CMS-concurrent-preclean: 0.471/1.080 secs] [Times: user=2.57 sys=0.32, real=1.08 secs]
1327.144: [CMS-concurrent-abortable-preclean-start]
1328.131: [CMS-concurrent-abortable-preclean: 0.639/0.987 secs] [Times: user=1.86 sys=0.22, real=0.99 secs]
1328.133: [GC[YG occupancy: 132117 K (235968 K)]1328.134: [Rescan (parallel) , 0.0609884 secs]1328.195: [weak refs processing, 0.0096977 secs] [1 CMS-remark: 1926380K(2883584K)] 2058498K(3119552K), 0.0714247 secs] [Times: user=0.49 sys=0.00, real=0.07 secs]
1328.206: [CMS-concurrent-sweep-start]
1329.726: [GC 1329.726: [ParNew: 235968K->26176K(235968K), 0.1103713 secs] 2109057K->1911796K(3119552K), 0.1106826 secs] [Times: user=0.59 sys=0.02, real=0.11 secs]
1332.835: [GC 1332.835: [ParNew: 235968K->26176K(235968K), 0.1199359 secs] 2023895K->1826749K(3119552K), 0.1201693 secs] [Times: user=0.60 sys=0.02, real=0.12 secs]
1335.973: [GC 1335.973: [ParNew: 235968K->26176K(235968K), 0.1145999 secs] 1944866K->1747664K(3119552K), 0.1148521 secs] [Times: user=0.61 sys=0.01, real=0.12 secs]
1339.140: [GC 1339.140: [ParNew: 235968K->26176K(235968K), 0.1155663 secs] 1878237K->1681117K(3119552K), 0.1158133 secs] [Times: user=0.60 sys=0.01, real=0.12 secs]
1342.268: [GC 1342.268: [ParNew: 235968K->26176K(235968K), 0.1206783 secs] 1820011K->1623523K(3119552K), 0.1209074 secs] [Times: user=0.61 sys=0.02, real=0.12 secs]
1345.396: [GC 1345.397: [ParNew: 235968K->26176K(235968K), 0.1181520 secs] 1766947K->1569240K(3119552K), 0.1183951 secs] [Times: user=0.60 sys=0.01, real=0.12 secs]
1348.543: [GC 1348.543: [ParNew: 235968K->26176K(235968K), 0.1363045 secs] 1714755K->1517678K(3119552K), 0.1365653 secs] [Times: user=0.61 sys=0.02, real=0.14 secs]
1351.710: [GC 1351.710: [ParNew: 235968K->26176K(235968K), 0.1215021 secs] 1664674K->1467879K(3119552K), 0.1217791 secs] [Times: user=0.61 sys=0.01, real=0.12 secs]
1354.849: [GC 1354.849: [ParNew: 235968K->26176K(235968K), 0.1178464 secs] 1613593K->1416645K(3119552K), 0.1180893 secs] [Times: user=0.61 sys=0.02, real=0.12 secs]
1357.980: [GC 1357.980: [ParNew: 235968K->26176K(235968K), 0.1155614 secs] 1560124K->1363000K(3119552K), 0.1157845 secs] [Times: user=0.59 sys=0.01, real=0.12 secs]
1361.176: [GC 1361.177: [ParNew: 235968K->26176K(235968K), 0.1161968 secs] 1505674K->1308939K(3119552K), 0.1164568 secs] [Times: user=0.61 sys=0.02, real=0.12 secs]
1364.268: [GC 1364.268: [ParNew: 235968K->26176K(235968K), 0.1109603 secs] 1450332K->1252372K(3119552K), 0.1112161 secs] [Times: user=0.60 sys=0.01, real=0.11 secs]
1367.431: [GC 1367.431: [ParNew: 235963K->26176K(235968K), 0.1250225 secs] 1391600K->1194414K(3119552K), 0.1252538 secs] [Times: user=0.62 sys=0.01, real=0.13 secs]
1370.603: [GC 1370.603: [ParNew: 235968K->26176K(235968K), 0.1202760 secs] 1334457K->1137877K(3119552K), 0.1205184 secs] [Times: user=0.63 sys=0.01, real=0.12 secs]
1373.699: [GC 1373.699: [ParNew: 235924K->26176K(235968K), 0.1182778 secs] 1282414K->1085472K(3119552K), 0.1185259 secs] [Times: user=0.62 sys=0.01, real=0.12 secs]
1376.844: [GC 1376.844: [ParNew: 235968K->26176K(235968K), 0.1191815 secs] 1232636K->1036192K(3119552K), 0.1194476 secs] [Times: user=0.63 sys=0.01, real=0.12 secs]
1380.015: [GC 1380.015: [ParNew: 235968K->26176K(235968K), 0.1210715 secs] 1198412K->1001088K(3119552K), 0.1213323 secs] [Times: user=0.59 sys=0.02, real=0.12 secs]
1380.716: [CMS-concurrent-sweep: 27.977/52.510 secs] [Times: user=109.87 sys=14.53, real=52.51 secs]
1380.717: [CMS-concurrent-reset-start]
1380.800: [CMS-concurrent-reset: 0.065/0.083 secs] [Times: user=0.17 sys=0.01, real=0.08 secs]
1383.133: [GC 1383.134: [ParNew: 235968K->26176K(235968K), 0.1101977 secs] 1209618K->1012817K(3119552K), 0.1104751 secs] [Times: user=0.58 sys=0.01, real=0.11 secs]
1386.306: [GC 1386.307: [ParNew: 235968K->26176K(235968K), 0.1234258 secs] 1222609K->1025744K(3119552K), 0.1236745 secs] [Times: user=0.60 sys=0.02, real=0.12 secs]
1389.490: [GC 1389.490: [ParNew: 235968K->26176K(235968K), 0.1220901 secs] 1235536K->1038910K(3119552K), 0.1223277 secs] [Times: user=0.59 sys=0.02, real=0.12 secs]
1392.611: [GC 1392.611: [ParNew: 235968K->26176K(235968K), 0.1135522 secs] 1248702K->1051838K(3119552K), 0.1138006 secs] [Times: user=0.59 sys=0.01, real=0.11 secs]
1395.742: [GC 1395.742: [ParNew: 235968K->26176K(235968K), 0.1093493 secs] 1261630K->1064849K(3119552K), 0.1096010 secs] [Times: user=0.58 sys=0.01, real=0.11 secs]
1398.888: [GC 1398.888: [ParNew: 235968K->26176K(235968K), 0.1108448 secs] 1274641K->1077711K(3119552K), 0.1110744 secs] [Times: user=0.58 sys=0.02, real=0.11 secs]
1402.051: [GC 1402.051: [ParNew: 235968K->26176K(235968K), 0.1097508 secs] 1287503K->1089900K(3119552K), 0.1100003 secs] [Times: user=0.58 sys=0.02, real=0.11 secs]
1405.151: [GC 1405.151: [ParNew: 235968K->26176K(235968K), 0.1111797 secs] 1299692K->1102802K(3119552K), 0.1114137 secs] [Times: user=0.58 sys=0.02, real=0.11 secs]
1408.377: [GC 1408.378: [ParNew: 235968K->26176K(235968K), 0.1147780 secs] 1312594K->1115142K(3119552K), 0.1150188 secs] [Times: user=0.58 sys=0.02, real=0.12 secs]
1411.443: [GC 1411.444: [ParNew: 235968K->26176K(235968K), 0.1136920 secs] 1324934K->1127783K(3119552K), 0.1139397 secs] [Times: user=0.59 sys=0.02, real=0.11 secs]
1414.591: [GC 1414.592: [ParNew: 235968K->26176K(235968K), 0.1170490 secs] 1337575K->1140496K(3119552K), 0.1172958 secs] [Times: user=0.61 sys=0.02, real=0.12 secs]
1417.774: [GC 1417.774: [ParNew: 235968K->26176K(235968K), 0.1229694 secs] 1350288K->1153589K(3119552K), 0.1232224 secs] [Times: user=0.60 sys=0.02, real=0.12 secs]
1420.905: [GC 1420.905: [ParNew: 235968K->26176K(235968K), 0.1223881 secs] 1363381K->1166023K(3119552K), 0.1226354 secs] [Times: user=0.61 sys=0.01, real=0.12 secs]
1423.987: [GC 1423.987: [ParNew: 235968K->26176K(235968K), 0.1192085 secs] 1375815K->1178509K(3119552K), 0.1194911 secs] [Times: user=0.59 sys=0.01, real=0.12 secs]
1427.139: [GC 1427.139: [ParNew: 235968K->26176K(235968K), 0.1126876 secs] 1388301K->1191552K(3119552K), 0.1129326 secs] [Times: user=0.59 sys=0.02, real=0.11 secs]
1430.319: [GC 1430.320: [ParNew: 235968K->26176K(235968K), 0.1128170 secs] 1401344K->1204081K(3119552K), 0.1130436 secs] [Times: user=0.59 sys=0.01, real=0.11 secs]
1433.497: [GC 1433.497: [ParNew: 235968K->26176K(235968K), 0.1242837 secs] 1413873K->1217164K(3119552K), 0.1245433 secs] [Times: user=0.59 sys=0.02, real=0.12 secs]
1436.606: [GC 1436.606: [ParNew: 235968K->26176K(235968K), 0.1114143 secs] 1426956K->1229986K(3119552K), 0.1116580 secs] [Times: user=0.58 sys=0.01, real=0.11 secs]
1439.770: [GC 1439.770: [ParNew: 235968K->26176K(235968K), 0.1134755 secs] 1439778K->1242246K(3119552K), 0.1137219 secs] [Times: user=0.58 sys=0.01, real=0.11 secs]
1442.978: [GC 1442.979: [ParNew: 235968K->26176K(235968K), 0.1206118 secs] 1452038K->1255674K(3119552K), 0.1208396 secs] [Times: user=0.61 sys=0.02, real=0.12 secs]
1446.111: [GC 1446.111: [ParNew: 235968K->26176K(235968K), 0.1165038 secs] 1465466K->1268439K(3119552K), 0.1167232 secs] [Times: user=0.60 sys=0.01, real=0.12 secs]
1449.197: [GC 1449.197: [ParNew: 235968K->26176K(235968K), 0.1065993 secs] 1478231K->1280834K(3119552K), 0.1068475 secs] [Times: user=0.58 sys=0.02, real=0.11 secs]
1452.328: [GC 1452.328: [ParNew: 235968K->26176K(235968K), 0.1129941 secs] 1490626K->1293445K(3119552K), 0.1132251 secs] [Times: user=0.59 sys=0.01, real=0.11 secs]
1455.437: [GC 1455.437: [ParNew: 235968K->26176K(235968K), 0.1167176 secs] 1503237K->1306556K(3119552K), 0.1169598 secs] [Times: user=0.60 sys=0.01, real=0.12 secs]
1458.635: [GC 1458.635: [ParNew: 235968K->26176K(235968K), 0.1235066 secs] 1516348K->1320085K(3119552K), 0.1237486 secs] [Times: user=0.62 sys=0.01, real=0.12 secs]
1461.775: [GC 1461.775: [ParNew: 235968K->26176K(235968K), 0.1256788 secs] 1529877K->1333251K(3119552K), 0.1259352 secs] [Times: user=0.61 sys=0.02, real=0.13 secs]
1464.922: [GC 1464.922: [ParNew: 235966K->26176K(235968K), 0.1174605 secs] 1543041K->1346092K(3119552K), 0.1177108 secs] [Times: user=0.61 sys=0.01, real=0.12 secs]
1468.050: [GC 1468.050: [ParNew: 235968K->26176K(235968K), 0.1136931 secs] 1555884K->1358540K(3119552K), 0.1139325 secs] [Times: user=0.60 sys=0.02, real=0.11 secs]
1471.226: [GC 1471.226: [ParNew: 235968K->26176K(235968K), 0.1254544 secs] 1568332K->1371101K(3119552K), 0.1256807 secs] [Times: user=0.63 sys=0.02, real=0.13 secs]
1474.381: [GC 1474.381: [ParNew: 235968K->26176K(235968K), 0.1288636 secs] 1580893K->1384625K(3119552K), 0.1291117 secs] [Times: user=0.64 sys=0.03, real=0.13 secs]
1477.540: [GC 1477.540: [ParNew: 235968K->26176K(235968K), 0.1273859 secs] 1594417K->1397636K(3119552K), 0.1276360 secs] [Times: user=0.63 sys=0.02, real=0.13 secs]
1480.635: [GC 1480.635: [ParNew: 235968K->26176K(235968K), 0.1175335 secs] 1607428K->1410107K(3119552K), 0.1178254 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1483.748: [GC 1483.748: [ParNew: 235968K->26176K(235968K), 0.1226011 secs] 1619899K->1422612K(3119552K), 0.1228572 secs] [Times: user=0.63 sys=0.03, real=0.12 secs]
1486.899: [GC 1486.899: [ParNew: 235968K->26176K(235968K), 0.1190227 secs] 1632404K->1435424K(3119552K), 0.1192641 secs] [Times: user=0.62 sys=0.03, real=0.12 secs]
1490.092: [GC 1490.092: [ParNew: 235968K->26176K(235968K), 0.1253609 secs] 1645216K->1448702K(3119552K), 0.1255884 secs] [Times: user=0.63 sys=0.03, real=0.13 secs]
1493.254: [GC 1493.254: [ParNew: 235968K->26176K(235968K), 0.1215734 secs] 1658494K->1461690K(3119552K), 0.1218251 secs] [Times: user=0.62 sys=0.03, real=0.12 secs]
1496.324: [GC 1496.325: [ParNew: 235968K->26176K(235968K), 0.1291558 secs] 1671482K->1474421K(3119552K), 0.1294154 secs] [Times: user=0.62 sys=0.04, real=0.13 secs]
1499.528: [GC 1499.529: [ParNew: 235968K->26176K(235968K), 0.1294864 secs] 1684213K->1486724K(3119552K), 0.1297983 secs] [Times: user=0.62 sys=0.03, real=0.13 secs]
1502.666: [GC 1502.666: [ParNew: 235968K->26176K(235968K), 0.1243760 secs] 1696516K->1499704K(3119552K), 0.1246253 secs] [Times: user=0.62 sys=0.02, real=0.12 secs]
1505.828: [GC 1505.828: [ParNew: 235968K->26176K(235968K), 0.1173773 secs] 1709496K->1512155K(3119552K), 0.1176192 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1508.966: [GC 1508.967: [ParNew: 235968K->26176K(235968K), 0.1149758 secs] 1721947K->1524445K(3119552K), 0.1151938 secs] [Times: user=0.60 sys=0.03, real=0.12 secs]
1512.088: [GC 1512.088: [ParNew: 235968K->26176K(235968K), 0.1176993 secs] 1734237K->1536807K(3119552K), 0.1179527 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1515.194: [GC 1515.194: [ParNew: 235968K->26176K(235968K), 0.1221361 secs] 1746599K->1549842K(3119552K), 0.1223906 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1518.360: [GC 1518.360: [ParNew: 235968K->26176K(235968K), 0.1189255 secs] 1759634K->1562559K(3119552K), 0.1191759 secs] [Times: user=0.62 sys=0.03, real=0.12 secs]
1521.450: [GC 1521.450: [ParNew: 235968K->26176K(235968K), 0.1239180 secs] 1772351K->1574890K(3119552K), 0.1241787 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1524.617: [GC 1524.617: [ParNew: 235968K->26176K(235968K), 0.1224415 secs] 1784682K->1587999K(3119552K), 0.1226897 secs] [Times: user=0.62 sys=0.03, real=0.12 secs]
1527.772: [GC 1527.772: [ParNew: 235967K->26176K(235968K), 0.1244054 secs] 1797791K->1600942K(3119552K), 0.1246517 secs] [Times: user=0.63 sys=0.03, real=0.12 secs]
1530.917: [GC 1530.917: [ParNew: 235968K->26176K(235968K), 0.1217420 secs] 1810734K->1613769K(3119552K), 0.1220071 secs] [Times: user=0.62 sys=0.03, real=0.12 secs]
1534.038: [GC 1534.038: [ParNew: 235968K->26176K(235968K), 0.1249350 secs] 1823561K->1625692K(3119552K), 0.1252021 secs] [Times: user=0.61 sys=0.02, real=0.13 secs]
1537.219: [GC 1537.219: [ParNew: 235968K->26176K(235968K), 0.1498083 secs] 1835484K->1638900K(3119552K), 0.1500711 secs] [Times: user=0.65 sys=0.03, real=0.15 secs]
1540.347: [GC 1540.347: [ParNew: 235968K->26176K(235968K), 0.1230693 secs] 1848692K->1651724K(3119552K), 0.1233299 secs] [Times: user=0.62 sys=0.03, real=0.12 secs]
1543.467: [GC 1543.467: [ParNew: 235968K->26176K(235968K), 0.1175380 secs] 1861516K->1664421K(3119552K), 0.1177906 secs] [Times: user=0.60 sys=0.03, real=0.12 secs]
1546.617: [GC 1546.617: [ParNew: 235968K->26176K(235968K), 0.1203270 secs] 1874213K->1677291K(3119552K), 0.1205744 secs] [Times: user=0.62 sys=0.02, real=0.12 secs]
1549.754: [GC 1549.754: [ParNew: 235968K->26176K(235968K), 0.1189926 secs] 1887083K->1690705K(3119552K), 0.1192382 secs] [Times: user=0.62 sys=0.03, real=0.12 secs]
1552.881: [GC 1552.881: [ParNew: 235968K->26176K(235968K), 0.1181706 secs] 1900497K->1703503K(3119552K), 0.1184005 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1556.118: [GC 1556.118: [ParNew: 235968K->26176K(235968K), 0.1270550 secs] 1913295K->1715900K(3119552K), 0.1272866 secs] [Times: user=0.62 sys=0.03, real=0.13 secs]
1559.279: [GC 1559.279: [ParNew: 235968K->26176K(235968K), 0.1216717 secs] 1925692K->1728201K(3119552K), 0.1219191 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1562.340: [GC 1562.340: [ParNew: 235968K->26176K(235968K), 0.1208208 secs] 1937993K->1741209K(3119552K), 0.1210710 secs] [Times: user=0.62 sys=0.03, real=0.12 secs]
1565.490: [GC 1565.490: [ParNew: 235968K->26176K(235968K), 0.1261020 secs] 1951001K->1754513K(3119552K), 0.1263533 secs] [Times: user=0.62 sys=0.03, real=0.13 secs]
1568.664: [GC 1568.664: [ParNew: 235968K->26176K(235968K), 0.1154821 secs] 1964305K->1766765K(3119552K), 0.1157349 secs] [Times: user=0.60 sys=0.03, real=0.12 secs]
1571.826: [GC 1571.827: [ParNew: 235968K->26176K(235968K), 0.1280581 secs] 1976557K->1779852K(3119552K), 0.1283280 secs] [Times: user=0.64 sys=0.03, real=0.13 secs]
1574.958: [GC 1574.958: [ParNew: 235968K->26176K(235968K), 0.1256562 secs] 1989644K->1793535K(3119552K), 0.1258779 secs] [Times: user=0.62 sys=0.03, real=0.13 secs]
1578.058: [GC 1578.058: [ParNew: 235968K->26176K(235968K), 0.1135160 secs] 2003327K->1805729K(3119552K), 0.1137320 secs] [Times: user=0.60 sys=0.02, real=0.11 secs]
1581.213: [GC 1581.213: [ParNew: 235968K->26176K(235968K), 0.1198479 secs] 2015521K->1818597K(3119552K), 0.1200759 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1584.360: [GC 1584.360: [ParNew: 235968K->26176K(235968K), 0.1186191 secs] 2028389K->1831572K(3119552K), 0.1188703 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1587.519: [GC 1587.520: [ParNew: 235968K->26176K(235968K), 0.1199977 secs] 2041364K->1844030K(3119552K), 0.1202458 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1590.664: [GC 1590.664: [ParNew: 235968K->26176K(235968K), 0.1248110 secs] 2053822K->1857393K(3119552K), 0.1250493 secs] [Times: user=0.63 sys=0.04, real=0.13 secs]
1593.816: [GC 1593.816: [ParNew: 235968K->26176K(235968K), 0.1157989 secs] 2067185K->1870250K(3119552K), 0.1160291 secs] [Times: user=0.61 sys=0.03, real=0.12 secs]
1596.916: [GC 1596.917: [ParNew: 235968K->26176K(235968K), 0.1199275 secs] 2080042K->1883185K(3119552K), 0.1201970 secs] [Times: user=0.61 sys=0.02, real=0.12 secs]
1600.060: [GC 1600.060: [ParNew: 235968K->26176K(235968K), 0.1191815 secs] 2092977K->1895609K(3119552K), 0.1194657 secs] [Times: user=0.62 sys=0.03, real=0.12 secs]
1603.186: [GC 1603.186: [ParNew: 235968K->26176K(235968K), 0.1161773 secs] 2105401K->1908113K(3119552K), 0.1164045 secs] [Times: user=0.62 sys=0.03, real=0.12 secs]
1603.305: [GC [1 CMS-initial-mark: 1881937K(2883584K)] 1908745K(3119552K), 0.1053681 secs] [Times: user=0.11 sys=0.00, real=0.11 secs]
1603.411: [CMS-concurrent-mark-start]
1606.331: [GC 1606.331: [ParNew: 235968K->26176K(235968K), 0.1214042 secs] 2117905K->1920797K(3119552K), 0.1216542 secs] [Times: user=0.65 sys=0.02, real=0.12 secs]
1609.497: [GC 1609.497: [ParNew: 235968K->26176K(235968K), 0.1350758 secs] 2130589K->1933703K(3119552K), 0.1353314 secs] [Times: user=0.67 sys=0.03, real=0.14 secs]
1612.678: [GC 1612.678: [ParNew: 235968K->26176K(235968K), 0.1368928 secs] 2143495K->1946337K(3119552K), 0.1373882 secs] [Times: user=0.66 sys=0.03, real=0.14 secs]
1615.838: [GC 1615.838: [ParNew: 235968K->26176K(235968K), 0.1353874 secs] 2156129K->1959931K(3119552K), 0.1356362 secs] [Times: user=0.67 sys=0.04, real=0.14 secs]
1616.625: [CMS-concurrent-mark: 3.867/13.214 secs] [Times: user=29.95 sys=3.99, real=13.21 secs]
1616.625: [CMS-concurrent-preclean-start]
1617.522: [CMS-concurrent-preclean: 0.454/0.897 secs] [Times: user=1.67 sys=0.24, real=0.90 secs]
1617.523: [CMS-concurrent-abortable-preclean-start]
1618.975: [GC 1618.975: [ParNew: 235968K->26176K(235968K), 0.1347560 secs] 2169723K->1972224K(3119552K), 0.1350129 secs] [Times: user=0.66 sys=0.04, real=0.14 secs]
1620.553: [CMS-concurrent-abortable-preclean: 1.474/3.030 secs] [Times: user=6.46 sys=0.87, real=3.03 secs]
1620.554: [GC[YG occupancy: 134336 K (235968 K)]1620.554: [Rescan (parallel) , 0.0652708 secs]1620.620: [weak refs processing, 0.0089602 secs] [1 CMS-remark: 1946048K(2883584K)] 2080384K(3119552K), 0.0749045 secs] [Times: user=0.51 sys=0.00, real=0.08 secs]
1620.630: [CMS-concurrent-sweep-start]
1622.112: [GC 1622.112: [ParNew: 235968K->26176K(235968K), 0.1158510 secs] 2106660K->1910342K(3119552K), 0.1160978 secs] [Times: user=0.62 sys=0.01, real=0.12 secs]
1625.279: [GC 1625.279: [ParNew: 235968K->26176K(235968K), 0.1179837 secs] 2017329K->1820608K(3119552K), 0.1182430 secs] [Times: user=0.61 sys=0.01, real=0.12 secs]
1628.395: [GC 1628.395: [ParNew: 235968K->26176K(235968K), 0.1105697 secs] 1945318K->1747464K(3119552K), 0.1108322 secs] [Times: user=0.60 sys=0.01, real=0.11 secs]
1631.574: [GC 1631.575: [ParNew: 235968K->26176K(235968K), 0.1176483 secs] 1878224K->1681725K(3119552K), 0.1179239 secs] [Times: user=0.61 sys=0.01, real=0.12 secs]
1634.664: [GC 1634.664: [ParNew: 235968K->26176K(235968K), 0.1149223 secs] 1822094K->1625014K(3119552K), 0.1151535 secs] [Times: user=0.61 sys=0.01, real=0.12 secs]
1637.799: [GC 1637.800: [ParNew: 235968K->26176K(235968K), 0.1126565 secs] 1760744K->1563627K(3119552K), 0.1129003 secs] [Times: user=0.60 sys=0.02, real=0.11 secs]
1641.101: [GC 1641.101: [ParNew: 235968K->26176K(235968K), 0.1248007 secs] 1691039K->1494706K(3119552K), 0.1250517 secs] [Times: user=0.63 sys=0.01, real=0.13 secs]
1644.091: [GC 1644.091: [ParNew: 235968K->26176K(235968K), 0.1119253 secs] 1627439K->1430271K(3119552K), 0.1121912 secs] [Times: user=0.60 sys=0.02, real=0.11 secs]
1647.246: [GC 1647.246: [ParNew: 235968K->26176K(235968K), 0.1171195 secs] 1544528K->1347668K(3119552K), 0.1173679 secs] [Times: user=0.62 sys=0.02, real=0.12 secs]
1650.384: [GC 1650.384: [ParNew: 235968K->26176K(235968K), 0.1142251 secs] 1497684K->1300594K(3119552K), 0.1144635 secs] [Times: user=0.61 sys=0.02, real=0.11 secs]
1653.502: [GC 1653.502: [ParNew: 235968K->26176K(235968K), 0.1331177 secs] 1442424K->1246288K(3119552K), 0.1333961 secs] [Times: user=0.63 sys=0.02, real=0.13 secs]
1656.674: [GC 1656.675: [ParNew: 235968K->26176K(235968K), 0.1219078 secs] 1393195K->1196042K(3119552K), 0.1221802 secs] [Times: user=0.61 sys=0.02, real=0.12 secs]
1659.828: [GC 1659.828: [ParNew: 235968K->26176K(235968K), 0.1199344 secs] 1342639K->1145580K(3119552K), 0.1202100 secs] [Times: user=0.61 sys=0.01, real=0.12 secs]
1663.016: [GC 1663.016: [ParNew: 235968K->26176K(235968K), 0.1176156 secs] 1287615K->1090626K(3119552K), 0.1178598 secs] [Times: user=0.62 sys=0.01, real=0.12 secs]
1666.132: [GC 1666.132: [ParNew: 235968K->26176K(235968K), 0.1223003 secs] 1234462K->1037465K(3119552K), 0.1225536 secs] [Times: user=0.62 sys=0.02, real=0.12 secs]
1669.216: [GC 1669.216: [ParNew: 235968K->26176K(235968K), 0.1178559 secs] 1186223K->989109K(3119552K), 0.1181120 secs] [Times: user=0.62 sys=0.01, real=0.12 secs]
1669.934: [CMS-concurrent-sweep: 24.772/49.299 secs] [Times: user=103.63 sys=13.62, real=49.30 secs]
1669.935: [CMS-concurrent-reset-start]
1670.039: [CMS-concurrent-reset: 0.065/0.103 secs] [Times: user=0.22 sys=0.02, real=0.10 secs]
1672.347: [GC 1672.347: [ParNew: 235968K->26176K(235968K), 0.1121000 secs] 1189855K->993168K(3119552K), 0.1123805 secs] [Times: user=0.58 sys=0.01, real=0.11 secs]
1675.527: [GC 1675.527: [ParNew: 235968K->26176K(235968K), 0.1177750 secs] 1202960K->1005952K(3119552K), 0.1180262 secs] [Times: user=0.59 sys=0.02, real=0.12 secs]

Reply viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.
peter__lawrey
Offline
Joined: 2005-11-01
Points: 0

> java 1.6.0_02
I suggest you try the current version 1.6.0_13 There have been a lot of bug fixes/improvements since update 2

linuxhippy
Offline
Joined: 2004-01-07
Points: 0

> What we are suspecting is as major GC cycle increases with time, GC pause also increases.
> Due to this queue starts building up as application threads are in stopped state.

You are using CMS, so threads should be usually in stopped state very shortly (the GC is running most of the time side-by-side app threads).
What could be a problem is the GC eating CPU cycles away from application threads, so that the server can't keep up anymore with processing.

I would probably add a limit on the queue, and threads should wait until the queue has less entries than XY.

- Clemens

coolprashant_nitk
Offline
Joined: 2009-01-22
Points: 0

Thanks for the reply,

The CPU was never more than 40 %. So I don't think CPU is a problem. Moreover I don't understand why major GC cycle is continuously increasing with time.

coolprashant_nitk
Offline
Joined: 2009-01-22
Points: 0

For you info, I tried using -XX:+CMSParallelRemarkEnabled and it enhanced the performance quite a bit. is there any thing else I can use with in GC option?