Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-4819174

SpecJBB: Spurious GCs with UseParallelGC + UseAdaptiveSizePolicy

    XMLWordPrintable

    Details

    • Subcomponent:
      gc
    • CPU:
      generic, sparc
    • OS:
      generic, solaris_8

      Description



      Name: ks84122 Date: 02/14/2003


      Please see original description from HP below. The SpecJBB application is attached to this bug report. Reproducible with the latest mantis build (16) on solaris.

      HP's report:
      ============

      I see unnecessary scavenges when running SpecJBB with the following options. The scavenges appear as consecutive pairs when one at a time would have been sufficient. This effectively doubles the overall GC pause time, slowing down the run.

      The following run is on a 2 proc/Linux/IA32/750 Mhz machine but I've been able to reproduce the problem on HP's JVM also.

      $JAVA_HOME/bin/java
      -classpath ./jbb.jar:./jbb_no_precompile.jar:./check.jar:./reporter.jar
      -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xmn150m -Xms200m -Xmx200m -XX:+UseParallelGC -XX:+UseAdaptiveSizePolicy
      spec.jbb.JBBmain -propfile SPECjbb.props


      (Note: Use a higher -Xmn if you want the scavenges to be spaced out)

      ...
      ...
      ...

      Start Terminals
        started terminals for Warehouse 1

      Benchmark SPECjbb 2.0m: warehouse 1 terminal 1

      Terminal Rampup began Thu Feb 13 17:12:19 PST 2003 for 0.5 minutes
      20.660: [GC 129060K->123900K(182016K), 0.0242160 secs] (scavenge #7)
      21.318: [GC 130556K->26476K(182016K), 0.0230780 secs] (scavenge #8)
      31.815: [GC 134508K->130228K(185408K), 0.0262060 secs]
      32.272: [GC 134772K->26708K(185408K), 0.0256040 secs]
      Timing Measurement began Thu Feb 13 17:12:49 PST 2003 for 2 minutes
      43.259: [GC 141524K->138180K(187840K), 0.0313580 secs]
      43.647: [GC 141892K->27036K(187840K), 0.0307460 secs]
      55.264: [GC 146716K->143476K(189760K), 0.0331250 secs]
      55.630: [GC 146868K->27204K(189760K), 0.0381670 secs]
      67.567: [GC 150724K->147588K(191488K), 0.0363700 secs]
      67.928: [GC 150980K->27492K(191488K), 0.0363130 secs]
      80.359: [GC 154468K->151268K(193024K), 0.0417530 secs]
      80.730: [GC 154660K->27668K(193024K), 0.0378780 secs]
      ...
      ...
      ...


      Upon examining scavenge #7 (see above) closely using -XX:+PrintHeapAtGC, I see the following:


      {Heap before GC invocations=7:
      Heap
       PSYoungGen total 128832K, used 104064K [0x44740000, 0x4dd40000, 0x4dd40000)
        eden space 104064K, 100% used [0x44740000,0x4ace0000,0x4ace0000)
        from space 24768K, 0% used [0x4c510000,0x4c510000,0x4dd40000)
        to space 24768K, 0% used [0x4ace0000,0x4ace0000,0x4c510000)
       PSOldGen total 51200K, used 25004K [0x4dd40000, 0x50f40000, 0x50f40000)
        object space 51200K, 48% used [0x4dd40000,0x4f5ab060,0x50f40000)
       PSPermGen total 4864K, used 2677K [0x50f40000, 0x51400000, 0x54f40000)
        object space 4864K, 55% used [0x50f40000,0x511dd600,0x51400000)
      20.425: [GC 129068K->124036K(182080K), 0.0258680 secs]


       Heap after GC invocations=7:
      Heap
       PSYoungGen total 130880K, used 99032K [0x44740000, 0x4dd40000, 0x4dd40000) eden space 6656K, 0% used [0x44740000,0x44740000,0x44dc0000)
        from space 124224K, 79% used [0x44dc0000,0x4ae76010,0x4c710000)
        to space 22720K, 0% used [0x4c710000,0x4c710000,0x4dd40000)
       PSOldGen total 51200K, used 25004K [0x4dd40000, 0x50f40000, 0x50f40000)
        object space 51200K, 48% used [0x4dd40000,0x4f5ab060,0x50f40000)
       PSPermGen total 4864K, used 2677K [0x50f40000, 0x51400000, 0x54f40000)
        object space 4864K, 55% used [0x50f40000,0x511dd600,0x51400000)
      }


      Notice that after scavenge #7, the eden size reduces to a tiny 6656K from 104604K. This is very strange considering that From space goes up to
      124224K. This causes the eden to get filled up soon after leading to the consecutive scavenge (#8 for above ex.). The behaviour is repeated till benchmark finishes.

      I suspect this is a bug.
      (Review ID: 181287)
      ======================================================================

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              pbk Peter Kessler
              Reporter:
              ksoshals Kirill Soshalskiy (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:
                Imported:
                Indexed: