1/*
2 * Copyright (c) 2017, 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
24package gc.concurrent_phase_control;
25
26/*
27 * Utility class that uses the WhiteBox concurrent GC phase control to
28 * step through a provided sequence of phases, and verify that the
29 * phases were actually reached as expected.
30 *
31 * To use:
32 *
33 * (1) The main test class has a main function which calls this helper
34 * class's check() function with appropriate arguments for the
35 * collector being tested.
36 *
37 * (2) The test program must provide access to WhiteBox, as it is used
38 * by this support class.
39 *
40 * (4) The main test class should be invoked as a driver.  This
41 * helper class's check() function will run its Executor class in a
42 * subprocess, in order to capture its output for analysis.
43 */
44
45import sun.hotspot.WhiteBox;
46
47import java.util.ArrayList;
48import java.util.Collections;
49import java.util.List;
50
51import java.util.regex.Matcher;
52import java.util.regex.Pattern;
53
54import jdk.test.lib.Platform;
55import jdk.test.lib.process.OutputAnalyzer;
56import jdk.test.lib.process.ProcessTools;
57
58public final class CheckControl {
59    // gcName: The name of the GC, logged as "Using <name>" near the
60    // beginning of the log output.
61    //
62    // gcOptions: Command line options for invoking the desired
63    // collector and logging options to produce output that can be
64    // matched against the regex patterns in the gcPhaseInfo pairs.
65    //
66    // gcPhaseInfo: An array of pairs of strings.  Each pair is a
67    // phase name and a regex pattern for recognizing the associated
68    // log message.  The regex pattern can be null if no log message
69    // is associated with the named phase.  The test will iterate
70    // through the array, requesting each phase in turn.
71    public static void check(String gcName,
72                             String[] gcOptions,
73                             String[][] gcPhaseInfo) throws Exception {
74        String[] stepPhases = new String[gcPhaseInfo.length];
75        for (int i = 0; i < gcPhaseInfo.length; ++i) {
76            stepPhases[i] = gcPhaseInfo[i][0];
77        }
78        String messages = executeTest(gcName, gcOptions, stepPhases);
79        checkPhaseControl(messages, gcPhaseInfo);
80    }
81
82    private static void fail(String message) throws Exception {
83        throw new RuntimeException(message);
84    }
85
86    private static final String requestPrefix = "Requesting concurrent phase: ";
87    private static final String reachedPrefix = "Reached concurrent phase: ";
88
89    private static String executeTest(String gcName,
90                                      String[] gcOptions,
91                                      String[] gcStepPhases) throws Exception {
92        System.out.println("\n---------- Testing ---------");
93
94        final String[] wb_arguments = {
95            "-Xbootclasspath/a:.",
96            "-XX:+UnlockDiagnosticVMOptions",
97            "-XX:+WhiteBoxAPI"
98        };
99
100        List<String> arglist = new ArrayList<String>();
101        Collections.addAll(arglist, wb_arguments);
102        Collections.addAll(arglist, gcOptions);
103        arglist.add(Executor.class.getName());
104        Collections.addAll(arglist, gcStepPhases);
105        String[] arguments = arglist.toArray(new String[arglist.size()]);
106
107        ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(arguments);
108        OutputAnalyzer output = new OutputAnalyzer(pb.start());
109
110        String messages = output.getStdout();
111        System.out.println(messages);
112
113        output.shouldHaveExitValue(0);
114        output.shouldContain("Using " + gcName);
115
116        return messages;
117    }
118
119    private static void checkPhaseControl(String messages,
120                                          String[][] gcPhaseInfo)
121        throws Exception
122    {
123        // Iterate through the phase sequence for the test, verifying
124        // output contains appropriate sequences of request message,
125        // log message for phase, and request reached message.  Note
126        // that a log message for a phase may occur later than the
127        // associated request reached message, or even the following
128        // request message.
129
130        Pattern nextReqP = Pattern.compile(requestPrefix);
131        Matcher nextReqM = nextReqP.matcher(messages);
132
133        Pattern nextReachP = Pattern.compile(reachedPrefix);
134        Matcher nextReachM = nextReachP.matcher(messages);
135
136        String pendingPhaseMessage = null;
137        int pendingPhaseMessagePosition = -1;
138
139        int position = 0;
140        for (String[] phase: gcPhaseInfo) {
141            String phaseName = phase[0];
142            String phaseMsg = phase[1];
143
144            System.out.println("Checking phase " + phaseName);
145
146            // Update the "next" matchers to refer to the next
147            // corresponding pair of request and reached messages.
148            if (!nextReqM.find()) {
149                fail("Didn't find next phase request");
150            } else if ((position != 0) && (nextReqM.start() < nextReachM.end())) {
151                fail("Next request before previous reached");
152            } else if (!nextReachM.find()) {
153                fail("Didn't find next phase reached");
154            } else if (nextReachM.start() <= nextReqM.end()) {
155                fail("Next request/reached misordered");
156            }
157
158            // Find the expected request message, and ensure it is the next.
159            Pattern reqP = Pattern.compile(requestPrefix + phaseName);
160            Matcher reqM = reqP.matcher(messages);
161            if (!reqM.find(position)) {
162                fail("Didn't find request for " + phaseName);
163            } else if (reqM.start() != nextReqM.start()) {
164                fail("Request mis-positioned for " + phaseName);
165            }
166
167            // Find the expected reached message, and ensure it is the next.
168            Pattern reachP = Pattern.compile(reachedPrefix + phaseName);
169            Matcher reachM = reachP.matcher(messages);
170            if (!reachM.find(position)) {
171                fail("Didn't find reached for " + phaseName);
172            } else if (reachM.start() != nextReachM.start()) {
173                fail("Reached mis-positioned for " + phaseName);
174            }
175
176            // If there is a pending log message (see below), ensure
177            // it was before the current reached message.
178            if (pendingPhaseMessage != null) {
179                if (pendingPhaseMessagePosition >= reachM.start()) {
180                    fail("Log message after next reached message: " +
181                         pendingPhaseMessage);
182                }
183            }
184
185            // If the phase has an associated logging message, verify
186            // such a logging message is present following the
187            // request, and otherwise positioned appropriately.  The
188            // complication here is that the logging message
189            // associated with a request might follow the reached
190            // message, and even the next request message, if there is
191            // a later request.  But it must preceed the next
192            // logging message and the next reached message.
193            boolean clearPendingPhaseMessage = true;
194            if (phaseMsg != null) {
195                Pattern logP = Pattern.compile("GC\\(\\d+\\)\\s+" + phaseMsg);
196                Matcher logM = logP.matcher(messages);
197                if (!logM.find(reqM.end())) {
198                    fail("Didn't find message " + phaseMsg);
199                }
200
201                if (pendingPhaseMessage != null) {
202                    if (pendingPhaseMessagePosition >= logM.start()) {
203                        fail("Log messages out of order: " +
204                             pendingPhaseMessage + " should preceed " +
205                             phaseMsg);
206                    }
207                }
208
209                if (reachM.end() <= logM.start()) {
210                    clearPendingPhaseMessage = false;
211                    pendingPhaseMessage = phaseMsg;
212                    pendingPhaseMessagePosition = logM.end();
213                }
214            }
215            if (clearPendingPhaseMessage) {
216                pendingPhaseMessage = null;
217                pendingPhaseMessagePosition = -1;
218            }
219
220            // Update position for start of next phase search.
221            position = reachM.end();
222        }
223        // It's okay for there to be a leftover pending phase message.
224        // We know it was found before the end of the log.
225    }
226
227    private static final class Executor {
228        private static final WhiteBox WB = WhiteBox.getWhiteBox();
229
230        private static void step(String phase) {
231            System.out.println(requestPrefix + phase);
232            WB.requestConcurrentGCPhase(phase);
233            System.out.println(reachedPrefix + phase);
234        }
235
236        public static void main(String[] phases) throws Exception {
237            // Iterate through set sequence of phases, reporting each.
238            for (String phase: phases) {
239                step(phase);
240            }
241            // Wait a little to allow a delayed logging message for
242            // the final request/reached to be printed before exiting
243            // the program.
244            Thread.sleep(250);
245        }
246    }
247}
248