1 /*
   2  * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
   3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   4  *
   5  * This code is free software; you can redistribute it and/or modify it
   6  * under the terms of the GNU General Public License version 2 only, as
   7  * published by the Free Software Foundation.
   8  *
   9  * This code is distributed in the hope that it will be useful, but WITHOUT
  10  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  11  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  12  * version 2 for more details (a copy is included in the LICENSE file that
  13  * accompanied this code).
  14  *
  15  * You should have received a copy of the GNU General Public License version
  16  * 2 along with this work; if not, write to the Free Software Foundation,
  17  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
  18  *
  19  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
  20  * or visit www.oracle.com if you need additional information or have any
  21  * questions.
  22  */
  23 
  24 /*
  25  * @test TestLogging
  26  * @summary Check that a mixed GC is reflected in the gc logs
  27  * @requires vm.gc.G1
  28  * @requires vm.opt.MaxGCPauseMillis == "null"
  29  * @library /test/lib
  30  * @modules java.base/jdk.internal.misc
  31  * @modules java.management
  32  * @build sun.hotspot.WhiteBox
  33  * @run main ClassFileInstaller sun.hotspot.WhiteBox
  34  * @run driver gc.g1.mixedgc.TestLogging
  35  */
  36 
  37 package gc.g1.mixedgc;
  38 
  39 import jdk.test.lib.process.OutputAnalyzer;
  40 import jdk.test.lib.process.ProcessTools;
  41 import jdk.test.lib.Asserts;
  42 import sun.hotspot.WhiteBox;
  43 
  44 import java.util.ArrayList;
  45 import java.util.List;
  46 import java.util.Collections;
  47 
  48 /**
  49  * Test spawns MixedGCProvoker in a separate VM and expects to find a message
  50  * telling that a mixed gc has happened
  51  */
  52 public class TestLogging {
  53     private static final String[] COMMON_OPTIONS = new String[]{
  54             "-Xbootclasspath/a:.", "-XX:+UseG1GC",
  55             "-XX:+UnlockExperimentalVMOptions",
  56             "-XX:+UnlockDiagnosticVMOptions",
  57             "-XX:+WhiteBoxAPI",
  58             "-XX:SurvivorRatio=1", // Survivor-to-eden ratio is 1:1
  59             "-Xms10M", "-Xmx10M",
  60             "-XX:MaxTenuringThreshold=1", // promote objects after first gc
  61             "-XX:InitiatingHeapOccupancyPercent=100", // set initial CMC threshold and disable adaptive IHOP
  62             "-XX:-G1UseAdaptiveIHOP",                 // to avoid additional concurrent cycles caused by ergonomics
  63             "-XX:G1MixedGCCountTarget=4",
  64             "-XX:MaxGCPauseMillis=30000", // to have enough time
  65             "-XX:G1HeapRegionSize=1m", "-XX:G1HeapWastePercent=0",
  66             "-XX:G1MixedGCLiveThresholdPercent=100"};
  67 
  68     public static final int ALLOCATION_SIZE = 20000;
  69     public static final int ALLOCATION_COUNT = 15;
  70 
  71     public static void main(String args[]) throws Exception {
  72         // Test turns logging on by giving -Xlog:gc flag
  73         test("-Xlog:gc");
  74         // Test turns logging on by giving -Xlog:gc=debug flag
  75         test("-Xlog:gc=debug");
  76     }
  77 
  78     private static void test(String vmFlag) throws Exception {
  79         System.out.println(String.format("%s: running with %s flag", TestLogging.class.getSimpleName(), vmFlag));
  80         OutputAnalyzer output = spawnMixedGCProvoker(vmFlag);
  81         System.out.println(output.getStdout());
  82         output.shouldHaveExitValue(0);
  83         output.shouldContain("Pause Mixed (G1 Evacuation Pause)");
  84     }
  85 
  86     /**
  87      * Method spawns MixedGCProvoker with addition flags set
  88      *
  89      * @parameter extraFlags -flags to be added to the common options set
  90      */
  91     private static OutputAnalyzer spawnMixedGCProvoker(String... extraFlags)
  92             throws Exception {
  93         List<String> testOpts = new ArrayList<>();
  94         Collections.addAll(testOpts, COMMON_OPTIONS);
  95         Collections.addAll(testOpts, extraFlags);
  96         testOpts.add(MixedGCProvoker.class.getName());
  97         System.out.println(testOpts);
  98         ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(false,
  99                 testOpts.toArray(new String[testOpts.size()]));
 100         return new OutputAnalyzer(pb.start());
 101     }
 102 }
 103 
 104 /**
 105  * Utility class to guarantee a mixed GC. The class allocates several arrays and
 106  * promotes them to the oldgen. After that it tries to provoke mixed GC by
 107  * allocating new objects.
 108  *
 109  * The necessary condition for guaranteed mixed GC is running MixedGCProvoker is
 110  * running in VM with the following flags: -XX:MaxTenuringThreshold=1, -Xms10M,
 111  * -Xmx10M, -XX:G1MixedGCLiveThresholdPercent=100, -XX:G1HeapWastePercent=0,
 112  * -XX:G1HeapRegionSize=1m
 113  */
 114 class MixedGCProvoker {
 115     private static final WhiteBox WB = WhiteBox.getWhiteBox();
 116     private static final List<byte[]> liveOldObjects = new ArrayList<>();
 117     private static final List<byte[]> newObjects = new ArrayList<>();
 118 
 119     private static void allocateOldObjects() throws Exception {
 120         List<byte[]> deadOldObjects = new ArrayList<>();
 121         // Allocates buffer and promotes it to the old gen. Mix live and dead old
 122         // objects
 123         for (int i = 0; i < TestLogging.ALLOCATION_COUNT; ++i) {
 124             liveOldObjects.add(new byte[TestLogging.ALLOCATION_SIZE * 5]);
 125             deadOldObjects.add(new byte[TestLogging.ALLOCATION_SIZE * 5]);
 126         }
 127 
 128         // need only 2 promotions to promote objects to the old gen
 129         WB.youngGC();
 130         WB.youngGC();
 131         // check it is promoted & keep alive
 132         Asserts.assertTrue(WB.isObjectInOldGen(liveOldObjects),
 133                 "List of the objects is suppose to be in OldGen");
 134         Asserts.assertTrue(WB.isObjectInOldGen(deadOldObjects),
 135                 "List of the objects is suppose to be in OldGen");
 136     }
 137 
 138 
 139     /**
 140      * Waits until Concurent Mark Cycle finishes
 141      * @param wb  Whitebox instance
 142      * @param sleepTime sleep time
 143      */
 144     public static void waitTillCMCFinished(WhiteBox wb, int sleepTime) {
 145         while (wb.g1InConcurrentMark()) {
 146             if (sleepTime > -1) {
 147                 try {
 148                     Thread.sleep(sleepTime);
 149                 } catch (InterruptedException e) {
 150                     System.out.println("Got InterruptedException while waiting for ConcMarkCycle to finish");
 151                 }
 152             }
 153         }
 154     }
 155 
 156 
 157 
 158     public static void main(String args[]) throws Exception {
 159         // allocate old objects
 160         allocateOldObjects();
 161         waitTillCMCFinished(WB, 0);
 162         WB.g1StartConcMarkCycle();
 163         waitTillCMCFinished(WB, 0);
 164 
 165         WB.youngGC();
 166         System.out.println("Allocating new objects to provoke mixed GC");
 167         // allocate more objects to provoke GC
 168         for (int i = 0; i < (TestLogging.ALLOCATION_COUNT * 20); i++) {
 169             newObjects.add(new byte[TestLogging.ALLOCATION_SIZE]);
 170         }
 171         // check that liveOldObjects still alive
 172         Asserts.assertTrue(WB.isObjectInOldGen(liveOldObjects),
 173                 "List of the objects is suppose to be in OldGen");
 174     }
 175 }