7903188: Log time spent waiting to acquire exclusive access lock

Reviewed-by: cstein, jjg

src/share/classes/com/sun/javatest/regtest/config/RegressionTestSuite.java

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2000, 2022, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2000, 2024, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -215,7 +215,11 @@ public boolean useOtherVM(TestDescription td) throws TestSuite.Fault {
         return properties.useOtherVM(td.getFile());
     }
 
-    public boolean needsExclusiveAccess(TestDescription td) throws TestSuite.Fault {
+    /**
+     * {@return true if the test is configured to run exclusively, false otherwise}
+     * @param td the test description
+     */
+    public boolean needsExclusiveAccess(TestDescription td) {
         return properties.needsExclusiveAccess(td.getFile());
     }
 

src/share/classes/com/sun/javatest/regtest/config/TestProperties.java

@@ -130,7 +130,7 @@ File getJUnitRoot(File file) throws TestSuite.Fault {
         return getEntry(file).junitRoot;
     }
 
-    boolean needsExclusiveAccess(File file) throws TestSuite.Fault {
+    boolean needsExclusiveAccess(File file) {
         return getEntry(file).needsExclusiveAccess;
     }
 

src/share/classes/com/sun/javatest/regtest/exec/Action.java

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 1998, 2023, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 1998, 2024, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -33,6 +33,7 @@
 import java.io.PrintWriter;
 import java.nio.file.Files;
 import java.nio.file.Path;
+import java.time.Duration;
 import java.util.ArrayList;
 import java.util.Collections;
 import java.util.Date;
@@ -376,6 +377,21 @@ protected String parseSecure(String value) throws ParseException {
      * @param initConfig whether or not to initialize a configuration section
      */
     protected void startAction(boolean initConfig) {
+        long exclusiveAccessWaitMillis = 0;
+        // if the RegressionScript isn't meant to only check the test description,
+        // then before starting the action, we check if the RegressionScript
+        // requires a exclusiveAccess lock and if it does, we acquire it.
+        if (supportsExclusiveAccess() && !script.isCheck()) {
+            exclusiveAccessLock = script.getLockIfRequired();
+            if (exclusiveAccessLock != null) {
+                long startNanos = System.nanoTime();
+                exclusiveAccessLock.lock();
+                exclusiveAccessWaitMillis = Duration.ofNanos(
+                        System.nanoTime() - startNanos).toMillis();
+            }
+        }
+        Date startDate = new Date();
+        startTime = startDate.getTime();
         String name = getName();
         section = script.getTestResult().createSection(name);
 
@@ -387,27 +403,42 @@ protected void startAction(boolean initConfig) {
         if (initConfig) {
             configWriter = section.createOutput("configuration");
         }
-
-        Date startDate = new Date();
-        startTime = startDate.getTime();
+        if (exclusiveAccessLock != null) {
+            // log the time spent (in seconds) waiting for exclusiveAccess
+            pw.println(LOG_EXCLUSIVE_ACCESS_TIME + ((double) exclusiveAccessWaitMillis / 1000.0));
+        }
         pw.println(LOG_STARTED + startDate);
-    } // startAction()
+    }
 
     /**
      * Set the status for the passed action. After this call, the recording area
-     * for the action become immutable.
+     * for the action becomes immutable.
      *
      * @param status The final status of the action.
      */
     protected void endAction(Status status) {
-        Date endDate = new Date();
-        long elapsedTime = endDate.getTime() - startTime;
-        PrintWriter pw = section.getMessageWriter();
-        pw.println(LOG_FINISHED + endDate);
-        pw.println(LOG_ELAPSED_TIME + ((double) elapsedTime/1000.0));
-        recorder.close();
-        section.setStatus(status);
-    } // endAction()
+        try {
+            Date endDate = new Date();
+            long elapsedTime = endDate.getTime() - startTime;
+            PrintWriter pw = section.getMessageWriter();
+            pw.println(LOG_FINISHED + endDate);
+            pw.println(LOG_ELAPSED_TIME + ((double) elapsedTime / 1000.0));
+            recorder.close();
+            section.setStatus(status);
+        } finally {
+            if (exclusiveAccessLock != null) {
+                exclusiveAccessLock.unlock();
+            }
+        }
+    }
+
+    /**
+     * {@return true if the action can run a {@code RegressionScript}
+     *          that has been configured to run exclusively, false otherwise}
+     */
+    protected boolean supportsExclusiveAccess() {
+        return false;
+    }
 
     //----------workarounds-------------------------------------------------------
 
@@ -711,6 +742,7 @@ protected boolean includesOption(String option, String arg, List<String> options
         LOG_JT_COMMAND        = "JavaTest command: ",
         LOG_REASON            = "reason: ",
         LOG_ELAPSED_TIME      = "elapsed time (seconds): ",
+        LOG_EXCLUSIVE_ACCESS_TIME = "exclusiveAccess wait time (seconds): ",
         LOG_STARTED = "started: ",
         LOG_FINISHED = "finished: ",
         //LOG_JDK               = "JDK under test: ",
@@ -844,6 +876,9 @@ protected boolean includesOption(String option, String arg, List<String> options
     protected /*final*/ ActionRecorder recorder;
     protected /*final*/ PrintWriter configWriter;
     private long startTime;
+    // used when the action's RegressionScript is configured to
+    // run in exclusiveAccess.dir
+    private Lock exclusiveAccessLock;
 
     protected static final boolean showCmd = Flags.get("showCmd");
     protected static final boolean showMode = Flags.get("showMode");

src/share/classes/com/sun/javatest/regtest/exec/MainAction.java

@@ -337,12 +337,7 @@ public Status run() throws TestRunException {
             status = passed(CHECK_PASS);
             endAction(status);
         } else {
-            Lock lock = script.getLockIfRequired();
-            if (lock != null) lock.lock();
-
-            // Start action after the lock is taken to ensure correct "elapsed time".
             startAction(true);
-
             try {
                 switch (!othervmOverrideReasons.isEmpty() ? ExecMode.OTHERVM : script.getExecMode()) {
                     case AGENTVM:
@@ -357,9 +352,7 @@ public Status run() throws TestRunException {
                         throw new AssertionError();
                 }
             } finally {
-                // End action before releasing the lock.
                 endAction(status);
-                if (lock != null) lock.unlock();
             }
         }
 
@@ -378,6 +371,11 @@ protected Status build() throws TestRunException {
         return ba.build(buildOpts, buildArgs, SREASON_ASSUMED_BUILD, script);
     }
 
+    @Override
+    protected boolean supportsExclusiveAccess() {
+        return true;
+    }
+
     private Status runOtherJVM() throws TestRunException {
         // Arguments to wrapper:
         String runModuleName;

src/share/classes/com/sun/javatest/regtest/exec/RegressionScript.java

@@ -1058,15 +1058,8 @@ SummaryReporter getJUnitSummaryReporter() {
         return SummaryReporter.forJUnit(workDir);
     }
 
-    Lock getLockIfRequired() throws TestRunException {
-        try {
-            if (!testSuite.needsExclusiveAccess(td))
-                return null;
-        } catch (TestSuite.Fault e) {
-            throw new TestRunException("Can't determine if lock required", e);
-        }
-
-        return Lock.get(params);
+    Lock getLockIfRequired() {
+        return testSuite.needsExclusiveAccess(td) ? Lock.get(params) : null;
     }
 
     int getNextSerial() {

src/share/classes/com/sun/javatest/regtest/exec/ShellAction.java

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 1998, 2022, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 1998, 2024, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -161,6 +161,11 @@ public Set<File> getSourceFiles() {
         return Set.of(script.absTestSrcDir().resolve(shellFN).toFile());
     }
 
+    @Override
+    protected boolean supportsExclusiveAccess() {
+        return true;
+    }
+
     /**
      * The method that does the work of the action.  The necessary work for the
      * given action is defined by the tag specification.
@@ -281,8 +286,6 @@ public Status run() throws TestRunException {
             // PASS TO PROCESSCOMMAND
             PrintWriter sysOut = section.createOutput("System.out");
             PrintWriter sysErr = section.createOutput("System.err");
-            Lock lock = script.getLockIfRequired();
-            if (lock != null) lock.lock();
             try {
                 if (showCmd)
                     showCmd("shell", command, section);
@@ -303,7 +306,6 @@ public Status run() throws TestRunException {
                 status = normalize(cmd.exec());
 
             } finally {
-                if (lock != null) lock.unlock();
                 if (sysOut != null) sysOut.close();
                 if (sysErr != null) sysErr.close();
             }

test/exclusive/ExclusiveAccessTest.gmk

@@ -1,5 +1,5 @@
 #
-# Copyright (c) 2011, 2017, Oracle and/or its affiliates. All rights reserved.
+# Copyright (c) 2011, 2024, Oracle and/or its affiliates. All rights reserved.
 # DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
 #
 # This code is free software; you can redistribute it and/or modify it
@@ -34,11 +34,12 @@ $(BUILDTESTDIR)/ExclusiveAccessTest.single.ok: \
 	$(JTREG_IMAGEDIR)/bin/jtreg $(JTREG_OPTS) \
 		-w:$(@:%.ok=%)/work -r:$(@:%.ok=%)/report \
 		-jdk:$(JDKHOME) \
-		-conc:4 \
+		-conc:5 \
 		$(TESTDIR)/exclusive \
 			> $(@:%.ok=%/jt.log) 2>&1 || \
 	    true "non-zero exit code from JavaTest intentionally ignored"
-	$(GREP) -s 'Test results: passed: 4' $(@:%.ok=%/jt.log)  > /dev/null
+	$(GREP) -s 'Test results: passed: 5' $(@:%.ok=%/jt.log)  > /dev/null
+	$(GREP) -s 'exclusiveAccess wait time' -R $(@:%.ok=%/work/)  > /dev/null
 	$(DIFF) $(BUILDTESTDIR)/ExclusiveAccessTest.ref $(@:%.ok=%)/Test.log
 	echo "test passed at `date`" > $@
 

test/exclusive/dir/Test.java

@@ -0,0 +1,35 @@
+/*
+ * Copyright (c) 2024, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+
+import java.util.Date;
+
+/*
+ * @test
+ * @run main Test
+ */
+public class Test {
+
+    public static void main(final String[] args) throws Exception {
+        System.out.println("test run at " + new Date());
+    }
+}