8160064: StackWalker implementation added logging option without using UL
authorrprotacio
Thu, 29 Sep 2016 13:32:17 -0400
changeset 41664 07e88a4b405f
parent 41307 a89905798992
child 41665 14f1cb3d2d3a
8160064: StackWalker implementation added logging option without using UL Summary: Moved StackWalk logging to Unified Logging framework Reviewed-by: coleenp, mockner, dholmes, mchung
hotspot/src/share/vm/logging/logTag.hpp
hotspot/src/share/vm/prims/stackwalk.cpp
hotspot/src/share/vm/runtime/globals.hpp
hotspot/test/runtime/logging/StackWalkTest.java
--- a/hotspot/src/share/vm/logging/logTag.hpp	Thu Sep 22 10:24:25 2016 -0700
+++ b/hotspot/src/share/vm/logging/logTag.hpp	Thu Sep 29 13:32:17 2016 -0400
@@ -105,6 +105,7 @@
   LOG_TAG(scavenge) \
   LOG_TAG(scrub) \
   LOG_TAG(stacktrace) \
+  LOG_TAG(stackwalk) \
   LOG_TAG(start) \
   LOG_TAG(startuptime) \
   LOG_TAG(state) \
--- a/hotspot/src/share/vm/prims/stackwalk.cpp	Thu Sep 22 10:24:25 2016 -0700
+++ b/hotspot/src/share/vm/prims/stackwalk.cpp	Thu Sep 29 13:32:17 2016 -0400
@@ -26,6 +26,7 @@
 #include "classfile/javaClasses.hpp"
 #include "classfile/javaClasses.inline.hpp"
 #include "classfile/vmSymbols.hpp"
+#include "logging/log.hpp"
 #include "memory/oopFactory.hpp"
 #include "oops/oop.inline.hpp"
 #include "oops/objArrayOop.inline.hpp"
@@ -105,10 +106,8 @@
                               int max_nframes, int start_index,
                               objArrayHandle  frames_array,
                               int& end_index, TRAPS) {
-  if (TraceStackWalk) {
-    tty->print_cr("fill_in_frames limit=%d start=%d frames length=%d",
-                  max_nframes, start_index, frames_array->length());
-  }
+  log_debug(stackwalk)("fill_in_frames limit=%d start=%d frames length=%d",
+                       max_nframes, start_index, frames_array->length());
   assert(max_nframes > 0, "invalid max_nframes");
   assert(start_index + max_nframes <= frames_array->length(), "oob");
 
@@ -122,18 +121,24 @@
     // not set) and when StackWalker::getCallerClass is called
     if (!ShowHiddenFrames && (skip_hidden_frames(mode) || get_caller_class(mode))) {
       if (method->is_hidden()) {
-        if (TraceStackWalk) {
-          tty->print("  hidden method: "); method->print_short_name();
-          tty->print("\n");
+        if (log_is_enabled(Debug, stackwalk)) {
+          ResourceMark rm(THREAD);
+          outputStream* st = Log(stackwalk)::debug_stream();
+          st->print("  hidden method: ");
+          method->print_short_name(st);
+          st->cr();
         }
         continue;
       }
     }
 
     int index = end_index++;
-    if (TraceStackWalk) {
-      tty->print("  %d: frame method: ", index); method->print_short_name();
-      tty->print_cr(" bci=%d", stream.bci());
+    if (log_is_enabled(Debug, stackwalk)) {
+      ResourceMark rm(THREAD);
+      outputStream* st = Log(stackwalk)::debug_stream();
+      st->print("  %d: frame method: ", index);
+      method->print_short_name(st);
+      st->print_cr(" bci=%d", stream.bci());
     }
 
     if (!need_method_info(mode) && get_caller_class(mode) &&
@@ -317,10 +322,8 @@
                     TRAPS) {
   ResourceMark rm(THREAD);
   JavaThread* jt = (JavaThread*)THREAD;
-  if (TraceStackWalk) {
-    tty->print_cr("Start walking: mode " JLONG_FORMAT " skip %d frames batch size %d",
-                  mode, skip_frames, frame_count);
-  }
+  log_debug(stackwalk)("Start walking: mode " JLONG_FORMAT " skip %d frames batch size %d",
+                       mode, skip_frames, frame_count);
 
   if (frames_array.is_null()) {
     THROW_MSG_(vmSymbols::java_lang_NullPointerException(), "frames_array is NULL", NULL);
@@ -355,8 +358,12 @@
         break;
       }
 
-      if (TraceStackWalk) {
-        tty->print("  skip "); stream.method()->print_short_name(); tty->print("\n");
+      if (log_is_enabled(Debug, stackwalk)) {
+        ResourceMark rm(THREAD);
+        outputStream* st = Log(stackwalk)::debug_stream();
+        st->print("  skip ");
+        stream.method()->print_short_name(st);
+        st->cr();
       }
       stream.next();
     }
@@ -364,8 +371,12 @@
     // stack frame has been traversed individually and resume stack walk
     // from the stack frame at depth == skip_frames.
     for (int n=0; n < skip_frames && !stream.at_end(); stream.next(), n++) {
-      if (TraceStackWalk) {
-        tty->print("  skip "); stream.method()->print_short_name(); tty->cr();
+      if (log_is_enabled(Debug, stackwalk)) {
+        ResourceMark rm(THREAD);
+        outputStream* st = Log(stackwalk)::debug_stream();
+        st->print("  skip ");
+        stream.method()->print_short_name(st);
+        st->cr();
       }
     }
   }
@@ -438,10 +449,9 @@
     THROW_MSG_(vmSymbols::java_lang_NullPointerException(), "frames_array is NULL", 0L);
   }
 
-  if (TraceStackWalk) {
-    tty->print_cr("StackWalk::fetchNextBatch frame_count %d existing_stream " PTR_FORMAT " start %d frames %d",
-                  frame_count, p2i(existing_stream), start_index, frames_array->length());
-  }
+  log_debug(stackwalk)("StackWalk::fetchNextBatch frame_count %d existing_stream "
+                       PTR_FORMAT " start %d frames %d",
+                       frame_count, p2i(existing_stream), start_index, frames_array->length());
   int end_index = start_index;
   if (frame_count <= 0) {
     return end_index;        // No operation.
--- a/hotspot/src/share/vm/runtime/globals.hpp	Thu Sep 22 10:24:25 2016 -0700
+++ b/hotspot/src/share/vm/runtime/globals.hpp	Thu Sep 29 13:32:17 2016 -0400
@@ -2884,9 +2884,6 @@
           "exceptions (0 means all)")                                       \
           range(0, max_jint/2)                                              \
                                                                             \
-  develop(bool, TraceStackWalk, false,                                      \
-          "Trace stack walking")                                            \
-                                                                            \
   /* notice: the max range value here is max_jint, not max_intx  */         \
   /* because of overflow issue                                   */         \
   diagnostic(intx, GuaranteedSafepointInterval, 1000,                       \
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/hotspot/test/runtime/logging/StackWalkTest.java	Thu Sep 29 13:32:17 2016 -0400
@@ -0,0 +1,67 @@
+/*
+ * Copyright (c) 2016, 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 StackWalkTest
+ * @bug 8160064
+ * @summary -Xlog:stackwalk should produce logging from the source code
+ * @library /test/lib
+ * @run driver StackWalkTest
+ */
+
+import jdk.test.lib.process.ProcessTools;
+import jdk.test.lib.process.OutputAnalyzer;
+
+public class StackWalkTest {
+    static void analyzeOutputOn(ProcessBuilder pb) throws Exception {
+        OutputAnalyzer output = new OutputAnalyzer(pb.start());
+        output.shouldContain("Start walking");
+        output.shouldContain("fill_in_frames");
+        output.shouldHaveExitValue(0);
+    }
+
+    static void analyzeOutputOff(ProcessBuilder pb) throws Exception {
+        OutputAnalyzer output = new OutputAnalyzer(pb.start());
+        output.shouldNotContain("[stackwalk]");
+        output.shouldHaveExitValue(0);
+    }
+
+    public static void main(String... args) throws Exception {
+        ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-Xlog:stackwalk=debug",
+                                                                  InnerClass.class.getName());
+        analyzeOutputOn(pb);
+
+        pb = ProcessTools.createJavaProcessBuilder("-Xlog:stackwalk=off",
+                                                   InnerClass.class.getName());
+        analyzeOutputOff(pb);
+    }
+
+    public static class InnerClass {
+        public static void main(String[] args) throws Exception {
+            System.out.println("Testing stackwalk.");
+            StackWalker sw = StackWalker.getInstance();
+            sw.forEach(System.out::println);
+        }
+    }
+}