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 

    24 package 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 

    45 import sun.hotspot.WhiteBox;

    46 

    47 import java.util.ArrayList;

    48 import java.util.Collections;

    49 import java.util.List;

    50 

    51 import java.util.regex.Matcher;

    52 import java.util.regex.Pattern;

    53 

    54 import jdk.test.lib.Platform;

    55 import jdk.test.lib.process.OutputAnalyzer;

    56 import jdk.test.lib.process.ProcessTools;

    57 

    58 public 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 }