8262454: Handshake timeout improvements, single target, kill unfinish…

…ed thread

Reviewed-by: pchilanomate, dholmes, dcubed

src/hotspot/share/runtime/handshake.cpp

@@ -30,6 +30,7 @@
 #include "runtime/atomic.hpp"
 #include "runtime/handshake.hpp"
 #include "runtime/interfaceSupport.inline.hpp"
+#include "runtime/os.hpp"
 #include "runtime/osThread.hpp"
 #include "runtime/stackWatermarkSet.hpp"
 #include "runtime/task.hpp"
@@ -73,6 +74,7 @@ class HandshakeOperation : public CHeapObj<mtThread> {
     return val == 0;
   }
   void add_target_count(int count) { Atomic::add(&_pending_threads, count); }
+  int32_t pending_threads()        { return Atomic::load(&_pending_threads); }
   const char* name()               { return _handshake_cl->name(); }
   bool is_async()                  { return _handshake_cl->is_async(); }
 };
@@ -174,39 +176,43 @@ class HandshakeSpinYield : public StackObj {
   }
 };
 
-class VM_Handshake: public VM_Operation {
-  const jlong _handshake_timeout;
- public:
-  bool evaluate_at_safepoint() const { return false; }
-
- protected:
-  HandshakeOperation* const _op;
+static void handle_timeout(HandshakeOperation* op, JavaThread* target) {
+  JavaThreadIteratorWithHandle jtiwh;
 
-  VM_Handshake(HandshakeOperation* op) :
-      _handshake_timeout(millis_to_nanos(HandshakeTimeout)), _op(op) {}
+  log_error(handshake)("Handshake timeout: %s(" INTPTR_FORMAT "), pending threads: " INT32_FORMAT,
+                       op->name(), p2i(op), op->pending_threads());
 
-  bool handshake_has_timed_out(jlong start_time);
-  static void handle_timeout();
-};
+  if (target == NULL) {
+    for ( ; JavaThread* thr = jtiwh.next(); ) {
+      if (thr->handshake_state()->operation_pending(op)) {
+        log_error(handshake)("JavaThread " INTPTR_FORMAT " has not cleared handshake op: " INTPTR_FORMAT, p2i(thr), p2i(op));
+        // Remember the last one found for more diagnostics below.
+        target = thr;
+      }
+    }
+  } else {
+    log_error(handshake)("JavaThread " INTPTR_FORMAT " has not cleared handshake op: " INTPTR_FORMAT, p2i(target), p2i(op));
+  }
 
-bool VM_Handshake::handshake_has_timed_out(jlong start_time) {
-  // Check if handshake operation has timed out
-  if (_handshake_timeout > 0) {
-    return os::javaTimeNanos() >= (start_time + _handshake_timeout);
+  if (target != NULL) {
+    if (os::signal_thread(target, SIGILL, "cannot be handshaked")) {
+      // Give target a chance to report the error and terminate the VM.
+      os::naked_sleep(3000);
+    }
+  } else {
+    log_error(handshake)("No thread with an unfinished handshake op(" INTPTR_FORMAT ") found.", p2i(op));
   }
-  return false;
+  fatal("Handshake timeout");
 }
 
-void VM_Handshake::handle_timeout() {
-  LogStreamHandle(Warning, handshake) log_stream;
-  for (JavaThreadIteratorWithHandle jtiwh; JavaThread* thr = jtiwh.next(); ) {
-    if (thr->handshake_state()->has_operation()) {
-      log_stream.print("Thread " PTR_FORMAT " has not cleared its handshake op", p2i(thr));
-      thr->print_thread_state_on(&log_stream);
+static void check_handshake_timeout(jlong start_time, HandshakeOperation* op, JavaThread* target = NULL) {
+  // Check if handshake operation has timed out
+  jlong timeout_ns = millis_to_nanos(HandshakeTimeout);
+  if (timeout_ns > 0) {
+    if (os::javaTimeNanos() >= (start_time + timeout_ns)) {
+      handle_timeout(op, target);
     }
   }
-  log_stream.flush();
-  fatal("Handshake operation timed out");
 }
 
 static void log_handshake_info(jlong start_time_ns, const char* name, int targets, int emitted_handshakes_executed, const char* extra = NULL) {
@@ -221,9 +227,12 @@ static void log_handshake_info(jlong start_time_ns, const char* name, int target
   }
 }
 
-class VM_HandshakeAllThreads: public VM_Handshake {
+class VM_HandshakeAllThreads: public VM_Operation {
+  HandshakeOperation* const _op;
  public:
-  VM_HandshakeAllThreads(HandshakeOperation* op) : VM_Handshake(op) {}
+  VM_HandshakeAllThreads(HandshakeOperation* op) : _op(op) {}
+
+  bool evaluate_at_safepoint() const { return false; }
 
   void doit() {
     jlong start_time_ns = os::javaTimeNanos();
@@ -249,9 +258,7 @@ class VM_HandshakeAllThreads: public VM_Handshake {
     int emitted_handshakes_executed = 0;
     do {
       // Check if handshake operation has timed out
-      if (handshake_has_timed_out(start_time_ns)) {
-        handle_timeout();
-      }
+      check_handshake_timeout(start_time_ns, _op);
 
       // Have VM thread perform the handshake operation for blocked threads.
       // Observing a blocked state may of course be transient but the processing is guarded
@@ -359,6 +366,10 @@ void Handshake::execute(HandshakeClosure* hs_cl, JavaThread* target) {
     if (op.is_completed()) {
       break;
     }
+
+    // Check if handshake operation has timed out
+    check_handshake_timeout(start_time_ns, &op, target);
+
     hsy.add_result(pr);
     // Check for pending handshakes to avoid possible deadlocks where our
     // target is trying to handshake us.
@@ -406,6 +417,20 @@ void HandshakeState::add_operation(HandshakeOperation* op) {
   SafepointMechanism::arm_local_poll_release(_handshakee);
 }
 
+bool HandshakeState::operation_pending(HandshakeOperation* op) {
+  MutexLocker ml(&_lock, Mutex::_no_safepoint_check_flag);
+  class MatchOp {
+    HandshakeOperation* _op;
+   public:
+    MatchOp(HandshakeOperation* op) : _op(op) {}
+    bool operator()(HandshakeOperation* op) {
+      return op == _op;
+    }
+  };
+  MatchOp mo(op);
+  return _queue.contains(mo);
+}
+
 HandshakeOperation* HandshakeState::pop_for_self() {
   assert(_handshakee == Thread::current(), "Must be called by self");
   assert(_lock.owned_by_self(), "Lock must be held");

src/hotspot/share/runtime/handshake.hpp

@@ -97,6 +97,8 @@ class HandshakeState {
     return !_queue.is_empty();
   }
 
+  bool operation_pending(HandshakeOperation* op);
+
   // Both _queue and _lock must be checked. If a thread has seen this _handshakee
   // as safe it will execute all possible handshake operations in a loop while
   // holding _lock. We use lock free addition to the queue, which means it is

test/hotspot/jtreg/runtime/handshake/HandshakeTimeoutTest.java

@@ -0,0 +1,91 @@
+/*
+ * Copyright (c) 2021, 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 jdk.test.lib.process.OutputAnalyzer;
+import jdk.test.lib.process.ProcessTools;
+import jdk.test.lib.Utils;
+
+import sun.hotspot.WhiteBox;
+
+/*
+ * @test HandshakeTimeoutTest
+ * @summary Test handshake timeout.
+ * @requires vm.debug
+ * @library /testlibrary /test/lib
+ * @build HandshakeTimeoutTest
+ * @run driver ClassFileInstaller sun.hotspot.WhiteBox
+ * @run main/othervm -Xbootclasspath/a:. -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI HandshakeTimeoutTest
+ */
+
+public class HandshakeTimeoutTest {
+    public static void main(String[] args) throws Exception {
+        WhiteBox wb = WhiteBox.getWhiteBox();
+        Boolean useJVMCICompiler = wb.getBooleanVMFlag("UseJVMCICompiler");
+        String useJVMCICompilerStr;
+        if (useJVMCICompiler != null) {
+            useJVMCICompilerStr = useJVMCICompiler ?  "-XX:+UseJVMCICompiler" : "-XX:-UseJVMCICompiler";
+        } else {
+            // pass something innocuous
+            useJVMCICompilerStr = "-XX:+UnlockExperimentalVMOptions";
+        }
+        ProcessBuilder pb =
+            ProcessTools.createTestJvm(
+                    "-Xbootclasspath/a:.",
+                    "-XX:+UnlockDiagnosticVMOptions",
+                    "-XX:+WhiteBoxAPI",
+                    "-XX:+HandshakeALot",
+                    "-XX:GuaranteedSafepointInterval=10",
+                    "-XX:ParallelGCThreads=1",
+                    "-XX:ConcGCThreads=1",
+                    "-XX:CICompilerCount=2",
+                    "-XX:+UnlockExperimentalVMOptions",
+                    "-XX:HandshakeTimeout=50",
+                    useJVMCICompilerStr,
+                    "HandshakeTimeoutTest$Test");
+
+        OutputAnalyzer output = ProcessTools.executeProcess(pb);
+        output.reportDiagnosticSummary();
+        // In rare cases the target wakes up and performs the handshake at the same time as we timeout.
+        // Therefore it's not certain the timeout will find any thread.
+        output.shouldMatch("has not cleared handshake op|No thread with an unfinished handshake op");
+    }
+
+    static class Test implements Runnable {
+        public static void main(String[] args) throws Exception {
+            Test test = new Test();
+            Thread thread = new Thread(test);
+            thread.start();
+            thread.join();
+        }
+
+        @Override
+        public void run() {
+            while (true) {
+                // If there is a safepoint this thread might still be able to perform
+                // it's handshake in time. Therefore we loop util failure.
+                WhiteBox.getWhiteBox().waitUnsafe(100);
+            }
+        }
+    }
+}