January 2015 - hotspot-gc-dev

[JDK 6u21]: does CMS report concurrent mode failure on perm gen expansion ?
by Charlie Hunt 05 Dec '18

05 Dec '18

I'm looking at a GC log and surprised by the "concurrent mode failure" messages. I'm seeing the following GC log entries as the first 8 GCs: 3.398: [Full GC 3.398: [CMS (concurrent mode failure)[YG occupancy: 594957 K (1887488 K)]3.489: [weak refs processing, 0.0000140 secs]: 0K->0K(6291456K), 0.1308660 secs] 594957K->594957K(8178944K), [CMS Perm : 21247K->21247K(21248K)], 0.1310260 secs] [Times: user=0.13 sys=0.03, real=0.14 secs] 3.529: [Full GC 3.529: [CMS (concurrent mode failure)[YG occupancy: 594957 K (1887488 K)]3.617: [weak refs processing, 0.0000110 secs]: 0K->0K(6291456K), 0.1010290 secs] 594957K->594957K(8178944K), [CMS Perm : 21248K->21248K(42496K)], 0.1011530 secs] [Times: user=0.12 sys=0.00, real=0.10 secs] 3.638: [Full GC 3.638: [CMS (concurrent mode failure)[YG occupancy: 662071 K (1887488 K)]3.730: [weak refs processing, 0.0000140 secs]: 0K->0K(6291456K), 0.1068710 secs] 662071K->662071K(8178944K), [CMS Perm : 21319K->21319K(42688K)], 0.1069610 secs] [Times: user=0.15 sys=0.00, real=0.11 secs] 3.772: [Full GC 3.772: [CMS (concurrent mode failure)[YG occupancy: 729184 K (1887488 K)]3.915: [weak refs processing, 0.0000140 secs]: 0K->0K(6291456K), 0.1582170 secs] 729184K->729184K(8178944K), [CMS Perm : 21499K->21499K(42880K)], 0.1583500 secs] [Times: user=0.20 sys=0.00, real=0.16 secs] 3.962: [Full GC 3.962: [CMS (concurrent mode failure)[YG occupancy: 804686 K (1887488 K)]4.107: [weak refs processing, 0.0000130 secs]: 0K->0K(6291456K), 0.1598050 secs] 804686K->804686K(8178944K), [CMS Perm : 21702K->21702K(43072K)], 0.1599420 secs] [Times: user=0.21 sys=0.00, real=0.16 secs] 4.497: [Full GC 4.497: [CMS (concurrent mode failure)[YG occupancy: 939150 K (1887488 K)]4.672: [weak refs processing, 0.0000130 secs]: 0K->0K(6291456K), 0.1895350 secs] 939150K->939150K(8178944K), [CMS Perm : 22202K->22202K(43408K)], 0.1896680 secs] [Times: user=0.23 sys=0.00, real=0.19 secs] 5.054: [Full GC 5.054: [CMS (concurrent mode failure)[YG occupancy: 992483 K (1887488 K)]5.274: [weak refs processing, 0.0000130 secs]: 0K->0K(6291456K), 0.2347170 secs] 992483K->992483K(8178944K), [CMS Perm : 24058K->24058K(44408K)], 0.2348700 secs] [Times: user=0.28 sys=0.00, real=0.23 secs] 6.662: [Full GC 6.662: [CMS (concurrent mode failure)[YG occupancy: 1292895 K (1887488 K)]6.953: [weak refs processing, 0.0000140 secs]: 0K->0K(6291456K), 0.3063690 secs] 1292895K->1292895K(8178944K), [CMS Perm : 30692K->30692K(48120K)], 0.3065860 secs] [Times: user=0.66 sys=0.01, real=0.30 secs] After these 8 GCs, the GC log is much inline with what I'd expect, i.e. ParNew GCs, initial-marks, remarks, etc. In each of the above GCs: - young gen is increasing in occupancy - old gen remains empty - perm gen space size is expanding I can understand the Full GC being reported since perm gen is expanding, but I don't understand the reporting of "concurrent mode failure". Am I missing something? Is it possible HotSpot is reporting concurrent mode failure when perm gen is expanding? Here's the set of command line options in use: -Xmx8G -Xms8G -Xmn1500m -XX:+UseCompressedOops -XX:-UseGCOverheadLimit -XX:+UseConcMarkSweepGC -XX:MaxDirectMemorySize=5000m thanks, charlie ... PS: I didn't go look at / investigate OpenJDK HotSpot source code since this is JDK 6u21 and thought it might be possible something may have changed between 6u21 and what's in OpenJDK.

4 4

[RFR] 8016752: Test case for 8005857/8016740 (assert in GC_locker from PSOldGen::expand with -XX:+PrintGCDetails and Verbose)
by Andrey Zakharov 26 Nov '15

26 Nov '15

Hi, team. Here is simple test for JVM don't crash when its with PSOldGen, low memory and with -XX:+PrintGCDetails and -XX:+Verbose flags (https://bugs.openjdk.java.net/browse/JDK-8016740) based on Crasher attached to original incident bug webrev: http://cr.openjdk.java.net/~azakharov/8016752/webrev/ test bug: https://bugs.openjdk.java.net/browse/JDK-8016752 bug: https://bugs.openjdk.java.net/browse/JDK-8016740 https://bugs.openjdk.java.net/browse/JDK-8005857 Thanks.

4 14

RFR: 8066821(S) Enhance command line processing to manage deprecating and obsoleting -XX command line arguments
by Derek White 23 Jul '15

23 Jul '15

http://cr.openjdk.java.net/~drwhite/8066821/webrev.00/ https://bugs.openjdk.java.net/browse/JDK-8066821 This webrev adds support for handling "/deprecated/" -XX options (options that still *do* something but are planned for removal) and "/alias/" options (alternate names for other -XX options) by simply adding entries to the deprecated_jvm_flags and/or aliased_jvm_flags tables. This follows the example of the existing obsolete_jvm_flags table. This replaces a lot of ad-hoc and occasionally wrong code in arguments.cpp (including Arguments::check_deprecated_gc_flags) as well as supporting automatically disabling options after a certain version. Removed Code: - Removed global DefaultMaxRAMFraction, which was an "improper" alias for "MaxRAMFraction" (two variables that were roughly kept in sync vs. two names for the same variable). - Arguments::check_deprecated_gc_flags(). - Alias handling code in Arguments::parse_each_vm_init_arg(). It also avoids future ad-hoc and occasionally wrong code as new options get aliased and deprecated. Tests: Deprecated and alias options can be tested by adding entries to tables in new tests: VMAliasOptions.java VMDeprecatedOptions.java The new tests subsume these existing tests: test/gc/startup_warnings/TestDefaultMaxRAMFraction.java test/gc/startup_warnings/TestNoParNew.java Tests run: jprt jtreg Thanks, - Derek

9 27

RFR 7097567: G1: abstract and encapsulate collector phases and transitions between them
by Derek White 02 Jun '15

02 Jun '15

Review request! This is a change Ramki did before he left that didn't get checked in. The basic idea is to move a bunch fields that encapsulate collector state from G1CollectorPolicy into a separate class " G1CollectorState". Thanks in advance! - Derek /Bug/: https://bugs.openjdk.java.net/browse/JDK-7097567 /Webrev/: http://cr.openjdk.java.net/~drwhite/7097567/webrev.00/ /Ran/: * jtreg * jprt * refworkload (looks good, but improvement is unexplained). ./compare -r Logs/ref.1/ Logs/cms.1/ ============================================================================== Logs/ref.1/: Benchmark Samples Mean Stdev Geomean Weight specjbb2000 15 660639.27 8546.73 First_Warehouse 15 91712.47 2908.19 Last_Warehouse 15 660639.27 8546.73 rw.runtime 15 604.00 0.00 specjbb2005 15 372212.33 8495.85 first 15 44054.38 2190.33 interval_average 15 7596.13 173.44 last 15 372212.33 8495.85 last_warehouse 15 8.00 0.00 overall_average 15 342311.21 27049.43 peak 15 418062.71 21056.23 peak_warehouse 15 2.87 1.25 rw.runtime 15 458.40 0.99 specjvm98 15 950.96 10.07 compress 15 695.97 7.54 db 15 361.98 6.56 jack 15 1461.28 51.26 javac 15 522.44 13.72 jess 15 1145.71 15.97 mpegaudio 15 1197.56 14.91 mtrt 15 2670.94 137.46 rw.runtime 15 36.07 0.59 ============================================================================== Logs/cms.1/: Benchmark Samples Mean Stdev %Diff P Significant specjbb2000 15 646579.89 5829.25 -2.13 0.000 Yes First_Warehouse 15 86084.97 1381.09 -6.14 0.000 Yes Last_Warehouse 15 646579.89 5829.25 -2.13 0.000 Yes rw.runtime 15 604.33 0.49 -0.06 0.019 * specjbb2005 15 372333.48 8449.27 0.03 0.969 * first 15 44028.81 591.86 -0.06 0.966 * interval_average 15 7598.67 172.40 0.03 0.968 * last 15 372333.48 8449.27 0.03 0.969 * last_warehouse 15 8.00 0.00 0.00 1.000 * overall_average 15 347967.16 8974.17 1.65 0.453 * peak 15 427459.90 13498.58 2.25 0.159 * peak_warehouse 15 2.27 0.46 20.93 0.097 * rw.runtime 15 458.47 0.52 -0.01 0.819 * specjvm98 15 891.61 9.95 -6.24 0.000 Yes compress 15 696.34 6.57 0.05 0.888 * db 15 363.90 5.55 0.53 0.395 * jack 15 1402.76 48.98 -4.01 0.003 Yes javac 15 453.21 8.57 -13.25 0.000 Yes jess 15 1024.87 7.81 -10.55 0.000 Yes mpegaudio 15 1146.54 37.59 -4.26 0.000 Yes mtrt 15 2369.88 70.39 -11.27 0.000 Yes rw.runtime 15 38.00 0.38 -5.36 0.000 Yes ============================================================================== * - Not Significant: A non-zero %Diff for the mean could be noise. If the %Diff is 0, an actual difference may still exist. In either case, more samples would be needed to detect an actual difference in sample means. Alpha for this run: 0.010

4 11

RFR (L): 8024319: Add regression tests on documented GC-related -XX:+Print* options
by denis kononenko 21 May '15

21 May '15

Hi All, Could you please review new tests on GC-related -XX:Print options. Webrev link: http://cr.openjdk.java.net/~eistepan/dkononen/8024319/webrev.00/ Bug id: https://bugs.openjdk.java.net/browse/JDK-8024319 Testing: automated Description: There is a group of new tests to test the following GC options: -XX:+-PrintAdaptiveSizePolicy -XX:+-PrintGCApplicationConcurrentTime -XX:+-PrintGCApplicationStoppedTime -XX:+-PrintGCDateStamps -XX:+-PrintGCDetails -XX:+-PrintGC -XX:+-PrintGCTimeStamps -XX:+-PrintTenuringDistribution Each of the tested options has a pair of corresponding tests, one is for testing an enabled option and another for disabled. The tests are simple parsers of GC's logger output and looking for a specific marker corresponding to the tested option. The output is provided by another process which is implemented in GCTask.java. It's necessary because we have to guarantee that GC's log has been completely written and committed to the filesystem before we start analyzing it. The most obvious solution is to politely finish the writing process. Thus the every test spawns an auxiliary process which produces GC's log file, waits for its finish, loads the output and then performs actual testing. These steps are implemented with jtreg's annotations and a helper class which can be found AbstractPrintGCTest.java. This class encapsulates reading GC's log output from the log file and provides that output to the tests. To get GC's logger working GCTask forces the garbage collecting process. It attempts to consume all memory available to the young generation by creating a lot of unreferenced objects. Sooner or later the garbage collector shall be invoked. In favor of performance the task is implemented to be ran with a small memory size less or equal to 128 megabytes. This is excplicitly specified with -Xmx JVM's option in jtreg's annotations. Please note that some options work for specific GCs only. To prevent them from being executed against wrong GC jtreg's annotations and groups are used. Thank you, Denis.

4 10

RFR: 8057037: Verification in ClassLoaderData::is_alive is too slow
by Stefan Karlsson 08 Apr '15

08 Apr '15

Hi all, Please review this patch to remove some verification code that was added during the G1 Class Unloading project. The code was added to make sure we catch any class unloading bugs as early as possible. This verification code is run too often and is causing large GC times in our fastdebug test runs. In one of the tests I investigated, the Full GCs take 8 seconds with this verification and 0.2 seconds without it. Most of the verified pointers are already verified before and after GCs in ClassLoaderDataGraph::verify(). http://cr.openjdk.java.net/~stefank/8057037/webrev.00/ thanks, StefanK

5 6

RFR (L): 8058354: SPECjvm2008-Derby -2.7% performance regression on Solaris-X64 starting with 9-b29
by Thomas Schatzl 07 Apr '15

07 Apr '15

Hi all, can I have reviews for the following change that fixes the use of large pages for auxiliary data on G1? In JDK-8038423 there has been a large change in how G1 handles virtual memory, and overlooked that auxiliary data may use large pages. This caused some performance regressions after introducing that build. This change fixes this problem: G1 is now more flexible in using large pages: particularly auxiliary data that often is not sized to multiples of (large) page size suffers from that. By allowing the virtual space implementation to use small pages on the tail (upper) end of the virtual space, everything else can use large pages. There is one limitation to that: the start address of the used virtual spaces must be aligned to large page size to use large pages in auxiliary data. This is to simplify commit and uncommit within the regions, since very small areas in the auxiliary data can map to large areas in the heap (e.g. for the BOT, at 4k page size, one page maps to 2M of memory, 2M pages map to 1G of memory). The problem is, if the start address of such auxiliary data were not aligned to requested page size, we would potentially need to split neighbouring large pages if we tried to uncommit one. I.e. some ascii art showing the problem. AAAAAA AAAAAA AAAAAA // heap area, each AAAAAA is a single region | | | // area covered by auxilary pages 1 2 // auxiliary data pages So if auxiliary data pages were unaligned, so that they correspond to uneven multiples of the heap, when uncommitting e.g. the second region (second set of AAAAAA), we would have to split the auxiliary data pages 1 and 2 into smaller ones. That does not seem to be a good tradeoff in complexity, given that the waste is at most one large page in reserved space (and unfortunately, due to the Linux large page implementation also in actually used space). Changes in detail containing some additional fixes: - page selection corresponds to other collectors, i.e. if some auxiliary data covers at least one large page, try to use large pages if available. - fix CMBitMap::compute_size() to align to alignment granularity (this has not been a real problem because the actual size is always a multiple of that) - allow (very restricted) mixed use of small and large pages in the G1 heap. - pass on alignment hints to os::commit() - some refactoring extracting out the code to reserve auxiliary memory structures With these changes, performance when using large pages is at least as good as before 9b29. Webrev: http://cr.openjdk.java.net/~tschatzl/8058354/webrev/ CR: https://bugs.openjdk.java.net/browse/JDK-8058354 Testing: jprt, specjbb*, specjvm*, vm.quick.testlist, some large benchmarks, test case Thanks, Thomas

3 22

RFR: 8026047: [TESTBUG] add regression test for DisableExplicitGC flag
by Michail Chernov 11 Mar '15

11 Mar '15

Hi all, Please review the fix with new test for DisableExplicitGC VM flag. Webrev: http://cr.openjdk.java.net/~eistepan/~mchernov/8026047/webrev.00/ Enhancement: https://bugs.openjdk.java.net/browse/JDK-8026047 There is one scenario with 6 parameters combinations. 1,2,3 scenarios test default value for DisableExplicitGC, DisableExplicitGC=true and DisableExplicitGC=false 4,5,6 scenarios check how VM works when VM changes DisableExplicitGC flag using WhiteBox. Test tries to call System.gc() and check that VM puts message to stdout. After (in case of 4,5,6 scenarios) test tries to change DisableExplicitGC value and calls System.gc() twice. Test was executed locally on linux-i586 with all available GC and several GC-related flags. Also it was executed using Aurora on other platforms. Thanks, Michail

4 18

RFR: 8030646: Track collection set membership in one place
by Erik Helin 09 Mar '15

09 Mar '15

Hi all, this (rather) small patch removes the field HeapRegion::_in_collection_set and instead only uses the G1BiasedMappedArray G1CollectedHeap::_in_cset_fast_test to track collection set membership. Given that _in_cset_fast_test already track collection set membership, the _in_collection_set field in HeapRegion is redundant, it is only messy to keep track of this information in two places. Patch: http://cr.openjdk.java.net/~ehelin/8030646/webrev.00/ Issue: https://bugs.openjdk.java.net/browse/JDK-8030646 Testing: - JPRT - GCBasher (locally, Linux x86-64) - Ad-hoc: - BigApps: - DaCapo - runThese - Kitchensink - Weblogic - Regression: - nashorn - hotspot - vm: - stress - compiler - gc - runtime - quick - oom - parallel class loading - regression Thanks, Erik

4 8

Request for sponsor - JDK-8031538
by Staffan Friberg 03 Mar '15

03 Mar '15

Hi, I have created the a patch for JDK-8031538 - G1 eden usage is sometimes higher than target eden (printed Eden size) [1]. Since I'm not author I can't upload public WebRevs or request reviews, so I would like to ask if someone could sponsor this change and push it through the process. I have attached the small patch to this email. The patch make sure that the nursery target size calculation takes into account any regions that might currently be used for eden and not only the size of the survivor space. [1] - https://bugs.openjdk.java.net/browse/JDK-8031538 Cheers, Staffan Friberg

2 5