Databases
StackOverflow2013
Postsdbo
POTomcat full GC every 2 minutes for first 5 hours of application run time
 

Note that there are some explanatory texts on larger screens.

plurals
  1. POTomcat full GC every 2 minutes for first 5 hours of application run time
    primarykey
    data
    text
    <p>We have a cluster of tomcat servers being used on a very high volume website. We've noticed that for the first 5-6 hours after an application re-load that Full GC will run every 2 minutes pausing the application for anywhere between 5 and 20 seconds. After 5-6 hours the full GC will no longer run until tomcat is restarted. Traffic level isn't a factor we'll go through our peak hours with no problem.</p> <p>The servers are all dual quad core with 32GB of RAM running Centos 5. Our java opts are being played with on a daily basis however here are the settings that correspond to the sample GC log below:</p> <pre><code>-server -Xmx27g -Xms27g -XX:+DisableExplicitGC -XX:+UseConcMarkSweepGC -XX:+PrintTenuringDistribution -Dsun.rmi.dgc.client.gcInterval=900000 -Dsun.rmi.dgc.server.gcInterval=900000 -XX:NewSize=8g -XX:SurvivorRatio=16 -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails </code></pre> <p><strong>Log samples from shortly after application reload</strong></p> <pre><code>191.955: [Full GC 191.958: [CMS: 1815877K-&gt;1158107K(19922944K), 3.0376720 secs] 3118102K-&gt;1158107K(27845568K), [CMS Perm : 83787K-&gt;46767K(83960K)], 3.0415080 secs] [Times: user=2.95 sys=0.10, real=3.04 secs] 215.501: [GC 215.504: [ParNew Desired survivor size 238583808 bytes, new threshold 15 (max 15) - age 1: 50457968 bytes, 50457968 total : 7456799K-&gt;111048K(7922624K), 0.0617110 secs] 8614906K-&gt;1269155K(27845568K), 0.0661400 secs] [Times: user=0.68 sys=0.00, real=0.07 secs] 215.577: [GC 215.579: [ParNew Desired survivor size 238583808 bytes, new threshold 15 (max 15) - age 1: 66288 bytes, 66288 total - age 2: 50219144 bytes, 50285432 total : 114868K-&gt;66525K(7922624K), 0.0381810 secs] 1272975K-&gt;1224632K(27845568K), 0.0413630 secs] [Times: user=0.46 sys=0.00, real=0.04 secs] 236.177: [GC 236.180: [ParNew Desired survivor size 238583808 bytes, new threshold 15 (max 15) - age 1: 45071064 bytes, 45071064 total - age 2: 26112 bytes, 45097176 total - age 3: 34785960 bytes, 79883136 total : 7523165K-&gt;110355K(7922624K), 0.0921350 secs] 8681272K-&gt;1268462K(27845568K), 0.0969290 secs] [Times: user=0.95 sys=0.01, real=0.10 secs] ... 316.456: [GC 316.459: [ParNew Desired survivor size 238583808 bytes, new threshold 15 (max 15) - age 1: 41430416 bytes, 41430416 total - age 3: 22728376 bytes, 64158792 total - age 5: 19599960 bytes, 83758752 total - age 6: 21847616 bytes, 105606368 total - age 7: 27667592 bytes, 133273960 total - age 8: 10904 bytes, 133284864 total - age 9: 31824256 bytes, 165109120 total : 7650333K-&gt;215213K(7922624K), 0.1332630 secs] 8808440K-&gt;1373320K(27845568K), 0.1380590 secs] [Times: user=1.45 sys=0.01, real=0.14 secs] 338.851: [GC 338.854: [ParNew Desired survivor size 238583808 bytes, new threshold 15 (max 15) - age 1: 40678840 bytes, 40678840 total - age 2: 27075936 bytes, 67754776 total - age 4: 20399720 bytes, 88154496 total - age 6: 19271008 bytes, 107425504 total - age 7: 21655032 bytes, 129080536 total - age 8: 27118800 bytes, 156199336 total - age 9: 10904 bytes, 156210240 total - age 10: 31747808 bytes, 187958048 total : 7671853K-&gt;285541K(7922624K), 0.1456470 secs] 8829960K-&gt;1443648K(27845568K), 0.1503540 secs] [Times: user=1.62 sys=0.01, real=0.15 secs] 343.376: [Full GC 343.378: [CMS: 1158107K-&gt;1312570K(19922944K), 3.4129290 secs] 2884580K-&gt;1312570K(27845568K), [CMS Perm : 83964K-&gt;47203K(83968K)], 3.4168600 secs] [Times: user=3.87 sys=0.02, real=3.41 secs] **Last Full GC** 20517.892: [GC 20517.898: [ParNew Desired survivor size 238583808 bytes, new threshold 15 (max 15) - age 1: 33948208 bytes, 33948208 total - age 2: 88280 bytes, 34036488 total - age 3: 19872472 bytes, 53908960 total - age 4: 16072608 bytes, 69981568 total - age 5: 15718712 bytes, 85700280 total - age 6: 15771016 bytes, 101471296 total - age 7: 16895976 bytes, 118367272 total - age 8: 24233728 bytes, 142601000 total : 7618727K-&gt;200950K(7922624K), 0.1728420 secs] 16794482K-&gt;9376705K(27845568K), 0.1822350 secs] [Times: user=2.21 sys=0.01, real=0.18 secs] 20526.469: [Full GC 20526.475: [CMS: 9175755K-&gt;9210800K(19922944K), 33.1161300 secs] 13632232K-&gt;9210800K(27845568K), [CMS Perm : 83967K-&gt;53332K(83968K)], 33.1254170 secs] [Times: user=33.12 sys=0.02, real=33.12 secs] **Log samples after Full GC no longer runs** 74412.335: [GC 74412.340: [ParNew Desired survivor size 238583808 bytes, new threshold 11 (max 15) - age 1: 43614032 bytes, 43614032 total - age 2: 41194144 bytes, 84808176 total - age 3: 27392888 bytes, 112201064 total - age 5: 22753896 bytes, 134954960 total - age 7: 24439608 bytes, 159394568 total - age 8: 24015704 bytes, 183410272 total - age 9: 24080848 bytes, 207491120 total - age 10: 24715800 bytes, 232206920 total - age 11: 21844024 bytes, 254050944 total : 7813778K-&gt;312911K(7922624K), 0.3329150 secs] 24426351K-&gt;16967791K(27845568K), 0.3416730 secs] [Times: user=3.69 sys=0.02, real=0.35 secs] 74445.007: [GC 74445.012: [ParNew Desired survivor size 238583808 bytes, new threshold 11 (max 15) - age 1: 42690688 bytes, 42690688 total - age 2: 37055848 bytes, 79746536 total - age 3: 37107464 bytes, 116854000 total - age 4: 26223088 bytes, 143077088 total - age 6: 22478672 bytes, 165555760 total - age 8: 24259744 bytes, 189815504 total - age 9: 23862672 bytes, 213678176 total - age 10: 23911864 bytes, 237590040 total - age 11: 24496888 bytes, 262086928 total : 7769547K-&gt;344030K(7922624K), 0.3088470 secs] 24424428K-&gt;17021685K(27845568K), 0.3175830 secs] [Times: user=3.57 sys=0.01, real=0.32 secs] 74475.169: [GC 74475.175: [ParNew Desired survivor size 238583808 bytes, new threshold 10 (max 15) - age 1: 42011656 bytes, 42011656 total - age 2: 33147608 bytes, 75159264 total - age 3: 32391640 bytes, 107550904 total - age 4: 36516584 bytes, 144067488 total - age 5: 25940856 bytes, 170008344 total - age 7: 22037464 bytes, 192045808 total - age 9: 24130040 bytes, 216175848 total - age 10: 23724672 bytes, 239900520 total - age 11: 23329640 bytes, 263230160 total : 7803184K-&gt;331046K(7922624K), 0.3091600 secs] 24480839K-&gt;17033619K(27845568K), 0.3179630 secs] [Times: user=3.56 sys=0.01, real=0.32 secs] </code></pre> <p>If we don't restart this server for the next week it'll run fine.</p> <p>Any help would be greatly appreciated. </p> <p><strong>EDIT: The problem will only show up if the WAR file is re-deployed. Restarting tomcat on it's own does not cause this problem.</strong></p>
    singulars
    1. This table or related slice is empty.
    1. This table or related slice is empty.
    1. PTQuestion
    1. USKevin Krieg
    1. USKevin Krieg
    plurals
    1. This table or related slice is empty.
    1. This table or related slice is empty.
    1. This table or related slice is empty.
    1. PO
      singulars
      1. PTAnswer
    2. PO
      singulars
      1. PTAnswer
    1. VO
      singulars
      1. POTomcat full GC every 2 minutes for first 5 hours of application run time
      1. This table or related slice is empty.
      1. VTDownMod
    2. VO
      singulars
      1. POTomcat full GC every 2 minutes for first 5 hours of application run time
      1. This table or related slice is empty.
      1. VTUpMod
    3. VO
      singulars
      1. POTomcat full GC every 2 minutes for first 5 hours of application run time
      1. USArnost Valicek
      1. VTFavorite
    1. COAll the servers run the same WAR. We're analyzing the code but the big question is why does the Full GC run right after the reload but then go away for good and run very stable for days after 5-6 hours of runtime. Is there a way to skip these initial hours and jump to the stable state.
      singulars
      1. POTomcat full GC every 2 minutes for first 5 hours of application run time
      1. USKevin Krieg
    2. COIt may help to have more infos on what kind of site is this/what kind of operations are run on it.
      singulars
      1. POTomcat full GC every 2 minutes for first 5 hours of application run time
      1. USViruzzo
    3. COI can see this behavior for minutes but not 6 hours. If the objects are allocated un-necessarily then I would expect the problem not to go away and the Full GC would run at all times.
      singulars
      1. POTomcat full GC every 2 minutes for first 5 hours of application run time
      1. USKevin Krieg
 

Querying!

 
Guidance
A row detail

Detail views are divided into sections. All the information in the data section comes from columns in the selected row. The other sections display data from other, related rows.

Related data can be related in a to-one or a to-many fashion. Captions of data related in a to-many fashion link to a list view showing a filtered view of the table.

Try moving around until you find a non-empty to-many entry and click on the label to get to one. You can move back to the root by clicking on the database name in the header.

SQuiL has stopped working due to an internal error.

If you are curious you may find further information in the browser console, which is accessible through the devtools (F12).

Reload