8140348: Convert TraceSafepoint to Unified Logging

The former -XX:+TraceSafepoint flag is updated to the unified logging framework and is now replaced with -Xlog:safepoint in product mode.

Reviewed-by: coleenp, hseigel

hotspot/src/share/vm/logging/logTag.hpp

@@ -32,7 +32,8 @@
 // not be used in log calls, and should not be listed below.)
 #define LOG_TAG_LIST \
   LOG_TAG(defaultmethods) \
-  LOG_TAG(logging)
+  LOG_TAG(logging) \
+  LOG_TAG(safepoint)
 
 #define PREFIX_LOG_TAG(T) (LogTag::T)
 

hotspot/src/share/vm/runtime/globals.hpp

@@ -1498,9 +1498,6 @@ public:
   develop(bool, TraceOopMapRewrites, false,                                 \
           "Trace rewriting of method oops during oop map generation")       \
                                                                             \
-  develop(bool, TraceSafepoint, false,                                      \
-          "Trace safepoint operations")                                     \
-                                                                            \
   develop(bool, TraceICBuffer, false,                                       \
           "Trace usage of IC buffer")                                       \
                                                                             \

hotspot/src/share/vm/runtime/os.cpp

@@ -32,6 +32,7 @@
 #include "code/vtableStubs.hpp"
 #include "gc/shared/vmGCOperations.hpp"
 #include "interpreter/interpreter.hpp"
+#include "logging/log.hpp"
 #include "memory/allocation.inline.hpp"
 #ifdef ASSERT
 #include "memory/guardedMemory.hpp"
@@ -1363,9 +1364,8 @@ static volatile intptr_t SerializePageLock = 0;
 // thread tries to store to the "read-only" memory serialize page during state
 // transition.
 void os::block_on_serialize_page_trap() {
-  if (TraceSafepoint) {
+  log_debug(safepoint)("Block until the serialize page permission restored");
-    tty->print_cr("Block until the serialize page permission restored");
+
-  }
   // When VMThread is holding the SerializePageLock during modifying the
   // access permission of the memory serialize page, the following call
   // will block until the permission of that page is restored to rw.

hotspot/src/share/vm/runtime/safepoint.cpp

@@ -33,6 +33,7 @@
 #include "gc/shared/collectedHeap.hpp"
 #include "gc/shared/gcLocker.inline.hpp"
 #include "interpreter/interpreter.hpp"
+#include "logging/log.hpp"
 #include "memory/resourceArea.hpp"
 #include "memory/universe.inline.hpp"
 #include "oops/oop.inline.hpp"
@@ -104,9 +105,7 @@ void SafepointSynchronize::begin() {
 
   int nof_threads = Threads::number_of_threads();
 
-  if (TraceSafepoint) {
+  log_debug(safepoint)("Safepoint synchronization initiated. (%d)", nof_threads);
-    tty->print_cr("Safepoint synchronization initiated. (%d)", nof_threads);
-  }
 
   RuntimeService::record_safepoint_begin();
 
@@ -219,7 +218,10 @@ void SafepointSynchronize::begin() {
            //   steps = MIN(steps, 2000-100)
            //   if (iterations != 0) steps -= NNN
         }
-        if (TraceSafepoint && Verbose) cur_state->print();
+        if (log_is_enabled(Trace, safepoint)) {
+          ResourceMark rm;
+          cur_state->print_on(LogHandle(safepoint)::debug_stream());
+        }
       }
     }
 
@@ -316,7 +318,7 @@ void SafepointSynchronize::begin() {
 
   // wait until all threads are stopped
   while (_waiting_to_block > 0) {
-    if (TraceSafepoint) tty->print_cr("Waiting for %d thread(s) to block", _waiting_to_block);
+    log_debug(safepoint)("Waiting for %d thread(s) to block", _waiting_to_block);
     if (!SafepointTimeout || timeout_error_printed) {
       Safepoint_lock->wait(true);  // true, means with no safepoint checks
     } else {
@@ -362,9 +364,10 @@ void SafepointSynchronize::begin() {
   // Update the count of active JNI critical regions
   GC_locker::set_jni_lock_count(_current_jni_active_count);
 
-  if (TraceSafepoint) {
+  if (log_is_enabled(Debug, safepoint)) {
     VM_Operation *op = VMThread::vm_operation();
-    tty->print_cr("Entering safepoint region: %s", (op != NULL) ? op->name() : "no vm operation");
+    log_debug(safepoint)("Entering safepoint region: %s",
+                         (op != NULL) ? op->name() : "no vm operation");
   }
 
   RuntimeService::record_safepoint_synchronized();
@@ -428,9 +431,7 @@ void SafepointSynchronize::end() {
     _state = _not_synchronized;
     OrderAccess::fence();
 
-    if (TraceSafepoint) {
+    log_debug(safepoint)("Leaving safepoint region");
-       tty->print_cr("Leaving safepoint region");
-    }
 
     // Start suspended threads
     for(JavaThread *current = Threads::first(); current; current = current->next()) {
@@ -919,7 +920,6 @@ void ThreadSafepointState::print_on(outputStream *st) const {
   _thread->print_thread_state_on(st);
 }
 
-
 // ---------------------------------------------------------------------------------------------------------------------
 
 // Block the thread at the safepoint poll or poll return.

hotspot/src/share/vm/runtime/sharedRuntime.cpp

@@ -37,6 +37,7 @@
 #include "gc/shared/gcLocker.inline.hpp"
 #include "interpreter/interpreter.hpp"
 #include "interpreter/interpreterRuntime.hpp"
+#include "logging/log.hpp"
 #include "memory/universe.inline.hpp"
 #include "oops/oop.inline.hpp"
 #include "prims/forte.hpp"
@@ -556,17 +557,10 @@ address SharedRuntime::get_poll_stub(address pc) {
            "polling page safepoint stub not created yet");
     stub = SharedRuntime::polling_page_safepoint_handler_blob()->entry_point();
   }
-#ifndef PRODUCT
+  log_debug(safepoint)("... found polling page %s exception at pc = "
-  if (TraceSafepoint) {
+                       INTPTR_FORMAT ", stub =" INTPTR_FORMAT,
-    char buf[256];
+                       at_poll_return ? "return" : "loop",
-    jio_snprintf(buf, sizeof(buf),
+                       (intptr_t)pc, (intptr_t)stub);
-                 "... found polling page %s exception at pc = "
-                 INTPTR_FORMAT ", stub =" INTPTR_FORMAT,
-                 at_poll_return ? "return" : "loop",
-                 (intptr_t)pc, (intptr_t)stub);
-    tty->print_raw_cr(buf);
-  }
-#endif // PRODUCT
   return stub;
 }
 

hotspot/test/runtime/logging/SafepointTest.java

@@ -0,0 +1,51 @@
+/*
+ * Copyright (c) 2015, 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.
+ */
+
+/*
+ * @test
+ * @bug 8140348
+ * @summary safepoint=trace should have output from each log statement in the code
+ * @library /testlibrary
+ * @compile SafepointTestMain.java
+ * @modules java.base/sun.misc
+ *          java.management
+ * @build SafepointTest
+ * @run main SafepointTest
+ */
+
+import jdk.test.lib.*;
+
+public class SafepointTest {
+    public static void main(String[] args) throws Exception {
+        ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(
+            "-Xlog:safepoint=trace", "SafepointTestMain");
+        OutputAnalyzer output = new OutputAnalyzer(pb.start());
+        output.shouldContain("Safepoint synchronization initiated. (");
+        output.shouldContain(" thread(s) to block");
+        output.shouldContain("Entering safepoint region: ");
+        output.shouldContain("Leaving safepoint region");
+        output.shouldContain("_at_poll_safepoint");
+        output.shouldContain("... found polling page ");
+        output.shouldHaveExitValue(0);
+    }
+}

hotspot/test/runtime/logging/SafepointTestMain.java

@@ -0,0 +1,70 @@
+/*
+ * Copyright (c) 2015, 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.lang.ref.WeakReference;
+
+public class SafepointTestMain {
+    public static class B {
+        static int count = 0;
+        public static volatile boolean stop = false;
+        static void localSleep(int time) {
+          try{
+            Thread.currentThread().sleep(time);
+          } catch(InterruptedException ie) {
+          }
+        }
+
+        public static void infinite() {
+            while (!stop) { count++; }
+        }
+    }
+
+    public static byte[] garbage;
+    public static volatile WeakReference<Object> weakref;
+
+    public static void createweakref() {
+        Object o = new Object();
+        weakref = new WeakReference<>(o);
+    }
+
+    public static void main(String[] args) throws Exception {
+        // Run function in separate thread to force compilation and pint safepoint
+        // message for compiled method
+        new Thread() {
+            public void run() {
+                B.infinite();
+            }
+        }.start();
+        B.localSleep(1000);
+        // Cause several safepoints to run GC while the compiled method is running,
+        // to see safepoint messages
+        for (int i = 0; i < 2; i++) {
+            createweakref();
+            while(weakref.get() != null) {
+                garbage = new byte[8192];
+                System.gc();
+            }
+        }
+        B.stop = true;
+    }
+}