Re: How frequently should full gc we expect

2015-08-27 Thread Akhil Das 
Used to hit GC: Overhead limit exceeded and sometime GC: Heap error too.

Thanks
Best Regards

On Sat, Aug 22, 2015 at 2:44 AM, java8964 java8...@hotmail.com wrote:

 In the test job I am running in Spark 1.3.1 in our stage cluster, I can
 see following information on the application stage information:

 MetricMin25th percentileMedian75th percentileMaxDuration0 ms1.1 min1.5 min1.7
 min3.4 minGC Time11 s16 s21 s25 s54 s

 From the GC output log, I can see it is about full GC in the executor
 every minutes, like below.

 My question is that the committed heap is more than 14G, and
 -XX:MaxPermSize=128m, in this case, the heap usage max is about 10G, why
 full GC happened every minute?

 The job runs fine, just want to know what exception you guys normally have
 for full GC in the spark jobs?

 Thanks

 Yong

 2015-08-21T16:53:59.561-0400: [Full GC [PSYoungGen: 328038K-0K(3728384K)] 
 [ParOldGen: 10359817K-5856671K(11185152K)] 10687855K-5856671K(14913536K) 
 [PSPermGen: 57214K-57214K(57856K)], 8.6951450 secs] [Times: user=140.72 
 sys=0.18, real=8.69 secs]
 2015-08-21T16:54:09.605-0400: [GC [PSYoungGen: 1864192K-251539K(3728384K)] 
 7720863K-6108211K(14913536K), 0.1217750 secs] [Times: user=2.12 sys=0.01, 
 real=0.12 secs]
 2015-08-21T16:54:11.131-0400: [GC [PSYoungGen: 2115731K-163448K(3728384K)] 
 7972404K-6197142K(14913536K), 0.1802910 secs] [Times: user=3.19 sys=0.01, 
 real=0.18 secs]
 2015-08-21T16:54:12.832-0400: [GC [PSYoungGen: 2027640K-144369K(3728384K)] 
 8061339K-6314232K(14913536K), 0.1816010 secs] [Times: user=3.03 sys=0.00, 
 real=0.19 secs]
 2015-08-21T16:54:14.547-0400: [GC [PSYoungGen: 2008561K-121478K(3728384K)] 
 8178424K-6435609K(14913536K), 0.1411160 secs] [Times: user=2.50 sys=0.00, 
 real=0.14 secs]
 2015-08-21T16:54:15.931-0400: [GC [PSYoungGen: 1985670K-114489K(3728384K)] 
 8299801K-6550508K(14913536K), 0.1285300 secs] [Times: user=2.13 sys=0.00, 
 real=0.13 secs]
 2015-08-21T16:54:17.323-0400: [GC [PSYoungGen: 1978681K-219811K(3792896K)] 
 8414700K-6769504K(14978048K), 0.1649230 secs] [Times: user=2.89 sys=0.01, 
 real=0.17 secs]
 2015-08-21T16:54:18.878-0400: [GC [PSYoungGen: 2148515K-425173K(3728384K)] 
 8698218K-6974876K(14913536K), 0.3130360 secs] [Times: user=5.56 sys=0.00, 
 real=0.31 secs]
 2015-08-21T16:54:20.596-0400: [GC [PSYoungGen: 2353877K-313071K(3985408K)] 
 8903582K-7071556K(15170560K), 0.2423240 secs] [Times: user=4.30 sys=0.00, 
 real=0.24 secs]
 2015-08-21T16:54:22.695-0400: [GC [PSYoungGen: 2608367K-371370K(3902464K)] 
 9366852K-7338548K(15087616K), 0.2647510 secs] [Times: user=4.48 sys=0.00, 
 real=0.26 secs]
 2015-08-21T16:54:24.747-0400: [GC [PSYoungGen: 266K-459392K(4174336K)] 
 9633844K-7528652K(15359488K), 0.3564370 secs] [Times: user=6.36 sys=0.00, 
 real=0.35 secs]
 2015-08-21T16:54:26.951-0400: [GC [PSYoungGen: 3116160K-445880K(4075008K)] 
 10185420K-7746897K(15260160K), 0.2853880 secs] [Times: user=5.07 sys=0.00, 
 real=0.29 secs]
 2015-08-21T16:54:29.340-0400: [GC [PSYoungGen: 3102648K-286176K(4314112K)] 
 10403665K-7809242K(15499264K), 0.2534940 secs] [Times: user=4.48 sys=0.01, 
 real=0.25 secs]
 2015-08-21T16:54:31.979-0400: [GC [PSYoungGen: 3269600K-122064K(4261888K)] 
 10792666K-7863493K(15447040K), 0.2035800 secs] [Times: user=3.41 sys=0.00, 
 real=0.20 secs]
 2015-08-21T16:54:34.737-0400: [GC [PSYoungGen: 3105488K-555850K(4373504K)] 
 10846917K-8297279K(15558656K), 0.2401510 secs] [Times: user=4.14 sys=0.00, 
 real=0.24 secs]
 2015-08-21T16:54:38.015-0400: [GC [PSYoungGen: 3675978K-1146062K(4266496K)] 
 11417409K-8887493K(15451648K), 0.4298600 secs] [Times: user=7.65 sys=0.00, 
 real=0.43 secs]
 2015-08-21T16:54:41.492-0400: [GC [PSYoungGen: 4266190K-1326063K(3565056K)] 
 12007627K-9231644K(14750208K), 0.5542100 secs] [Times: user=9.90 sys=0.01, 
 real=0.55 secs]
 2015-08-21T16:54:43.797-0400: [GC [PSYoungGen: 3565039K-1587981K(3827200K)] 
 11470620K-9612725K(15012352K), 0.5359080 secs] [Times: user=9.57 sys=0.00, 
 real=0.54 secs]
 2015-08-21T16:54:45.856-0400: [GC [PSYoungGen: 3826957K-1047737K(3629568K)] 
 11851701K-9914434K(14814720K), 0.7787060 secs] [Times: user=13.91 sys=0.00, 
 real=0.78 secs]
 2015-08-21T16:54:48.174-0400: [GC [PSYoungGen: 2911929K-459808K(3728384K)] 
 11778626K-10058483K(14913536K), 0.5953360 secs] [Times: user=10.62 sys=0.03, 
 real=0.60 secs]
 2015-08-21T16:54:50.217-0400: [GC [PSYoungGen: 2324000K-102928K(3740160K)] 
 11922675K-10159967K(14925312K), 0.3191560 secs] [Times: user=5.68 sys=0.01, 
 real=0.32 secs]
 2015-08-21T16:54:51.951-0400: [GC [PSYoungGen: 1978896K-296227K(3728384K)] 
 12035935K-10456136K(14913536K), 0.1809970 secs] [Times: user=3.02 sys=0.00, 
 real=0.18 secs]
 2015-08-21T16:54:53.550-0400: [GC [PSYoungGen: 2172195K-316636K(3866624K)] 
 12332104K-10720591K(15051776K), 0.2545970 secs] [Times: user=4.43 sys=0.00, 
 real=0.25 secs]
 2015-08-21T16:54:55.340-0400: [GC [PSYoungGen: 2390748K-336907K(3800064K)] 
 12794703K-11043658K(14985216K), 0.3550330 secs] [Times: user=6.28 sys=0.00, 
 real=0.35

How frequently should full gc we expect

2015-08-21 Thread java8964 
In the test job I am running in Spark 1.3.1 in our stage cluster, I can see 
following information on the application stage information:
MetricMin25th percentileMedian75th percentileMaxDuration0 ms1.1 min1.5 min1.7 
min3.4 minGC Time11 s16 s21 s25 s54 s
From the GC output log, I can see it is about full GC in the executor every 
minutes, like below.
My question is that the committed heap is more than 14G, and 
-XX:MaxPermSize=128m, in this case, the heap usage max is about 10G, why full 
GC happened every minute?
The job runs fine, just want to know what exception you guys normally have for 
full GC in the spark jobs?
Thanks
Yong
2015-08-21T16:53:59.561-0400: [Full GC [PSYoungGen: 328038K-0K(3728384K)] 
[ParOldGen: 10359817K-5856671K(11185152K)] 10687855K-5856671K(14913536K) 
[PSPermGen: 57214K-57214K(57856K)], 8.6951450 secs] [Times: user=140.72 
sys=0.18, real=8.69 secs] 
2015-08-21T16:54:09.605-0400: [GC [PSYoungGen: 1864192K-251539K(3728384K)] 
7720863K-6108211K(14913536K), 0.1217750 secs] [Times: user=2.12 sys=0.01, 
real=0.12 secs] 
2015-08-21T16:54:11.131-0400: [GC [PSYoungGen: 2115731K-163448K(3728384K)] 
7972404K-6197142K(14913536K), 0.1802910 secs] [Times: user=3.19 sys=0.01, 
real=0.18 secs] 
2015-08-21T16:54:12.832-0400: [GC [PSYoungGen: 2027640K-144369K(3728384K)] 
8061339K-6314232K(14913536K), 0.1816010 secs] [Times: user=3.03 sys=0.00, 
real=0.19 secs] 
2015-08-21T16:54:14.547-0400: [GC [PSYoungGen: 2008561K-121478K(3728384K)] 
8178424K-6435609K(14913536K), 0.1411160 secs] [Times: user=2.50 sys=0.00, 
real=0.14 secs] 
2015-08-21T16:54:15.931-0400: [GC [PSYoungGen: 1985670K-114489K(3728384K)] 
8299801K-6550508K(14913536K), 0.1285300 secs] [Times: user=2.13 sys=0.00, 
real=0.13 secs] 
2015-08-21T16:54:17.323-0400: [GC [PSYoungGen: 1978681K-219811K(3792896K)] 
8414700K-6769504K(14978048K), 0.1649230 secs] [Times: user=2.89 sys=0.01, 
real=0.17 secs] 
2015-08-21T16:54:18.878-0400: [GC [PSYoungGen: 2148515K-425173K(3728384K)] 
8698218K-6974876K(14913536K), 0.3130360 secs] [Times: user=5.56 sys=0.00, 
real=0.31 secs] 
2015-08-21T16:54:20.596-0400: [GC [PSYoungGen: 2353877K-313071K(3985408K)] 
8903582K-7071556K(15170560K), 0.2423240 secs] [Times: user=4.30 sys=0.00, 
real=0.24 secs] 
2015-08-21T16:54:22.695-0400: [GC [PSYoungGen: 2608367K-371370K(3902464K)] 
9366852K-7338548K(15087616K), 0.2647510 secs] [Times: user=4.48 sys=0.00, 
real=0.26 secs] 
2015-08-21T16:54:24.747-0400: [GC [PSYoungGen: 266K-459392K(4174336K)] 
9633844K-7528652K(15359488K), 0.3564370 secs] [Times: user=6.36 sys=0.00, 
real=0.35 secs] 
2015-08-21T16:54:26.951-0400: [GC [PSYoungGen: 3116160K-445880K(4075008K)] 
10185420K-7746897K(15260160K), 0.2853880 secs] [Times: user=5.07 sys=0.00, 
real=0.29 secs] 
2015-08-21T16:54:29.340-0400: [GC [PSYoungGen: 3102648K-286176K(4314112K)] 
10403665K-7809242K(15499264K), 0.2534940 secs] [Times: user=4.48 sys=0.01, 
real=0.25 secs] 
2015-08-21T16:54:31.979-0400: [GC [PSYoungGen: 3269600K-122064K(4261888K)] 
10792666K-7863493K(15447040K), 0.2035800 secs] [Times: user=3.41 sys=0.00, 
real=0.20 secs] 
2015-08-21T16:54:34.737-0400: [GC [PSYoungGen: 3105488K-555850K(4373504K)] 
10846917K-8297279K(15558656K), 0.2401510 secs] [Times: user=4.14 sys=0.00, 
real=0.24 secs] 
2015-08-21T16:54:38.015-0400: [GC [PSYoungGen: 3675978K-1146062K(4266496K)] 
11417409K-8887493K(15451648K), 0.4298600 secs] [Times: user=7.65 sys=0.00, 
real=0.43 secs] 
2015-08-21T16:54:41.492-0400: [GC [PSYoungGen: 4266190K-1326063K(3565056K)] 
12007627K-9231644K(14750208K), 0.5542100 secs] [Times: user=9.90 sys=0.01, 
real=0.55 secs] 
2015-08-21T16:54:43.797-0400: [GC [PSYoungGen: 3565039K-1587981K(3827200K)] 
11470620K-9612725K(15012352K), 0.5359080 secs] [Times: user=9.57 sys=0.00, 
real=0.54 secs] 
2015-08-21T16:54:45.856-0400: [GC [PSYoungGen: 3826957K-1047737K(3629568K)] 
11851701K-9914434K(14814720K), 0.7787060 secs] [Times: user=13.91 sys=0.00, 
real=0.78 secs] 
2015-08-21T16:54:48.174-0400: [GC [PSYoungGen: 2911929K-459808K(3728384K)] 
11778626K-10058483K(14913536K), 0.5953360 secs] [Times: user=10.62 sys=0.03, 
real=0.60 secs] 
2015-08-21T16:54:50.217-0400: [GC [PSYoungGen: 2324000K-102928K(3740160K)] 
11922675K-10159967K(14925312K), 0.3191560 secs] [Times: user=5.68 sys=0.01, 
real=0.32 secs] 
2015-08-21T16:54:51.951-0400: [GC [PSYoungGen: 1978896K-296227K(3728384K)] 
12035935K-10456136K(14913536K), 0.1809970 secs] [Times: user=3.02 sys=0.00, 
real=0.18 secs] 
2015-08-21T16:54:53.550-0400: [GC [PSYoungGen: 2172195K-316636K(3866624K)] 
12332104K-10720591K(15051776K), 0.2545970 secs] [Times: user=4.43 sys=0.00, 
real=0.25 secs] 
2015-08-21T16:54:55.340-0400: [GC [PSYoungGen: 2390748K-336907K(3800064K)] 
12794703K-11043658K(14985216K), 0.3550330 secs] [Times: user=6.28 sys=0.00, 
real=0.35 secs] 
2015-08-21T16:54:55.695-0400: [Full GC [PSYoungGen: 336907K-0K(3800064K)] 
[ParOldGen: 10706750K-5725402K(11185152K)] 11043658K-5725402K(14985216K) 
[PSPermGen: 57214K-57214K(57856K)], 9.5623960 secs] [Times: user=150.15