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
37package gc.g1.mixedgc;
38
39import jdk.test.lib.process.OutputAnalyzer;
40import jdk.test.lib.process.ProcessTools;
41import jdk.test.lib.Asserts;
42import sun.hotspot.WhiteBox;
43
44import java.util.ArrayList;
45import java.util.List;
46import 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 */
52public 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 */
114class 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}
176