8150083: Convert VerboseVerification to Unified Logging
authorrprotacio
Tue, 08 Mar 2016 15:19:53 -0500
changeset 37044 f1965d5d1055
parent 37043 5aa55674a362
child 37045 41e3f98fa3dc
8150083: Convert VerboseVerification to Unified Logging Summary: Converted -XX:+VerboseVerfication to -Xlog:verboseverification=info Reviewed-by: hseigel, dholmes
hotspot/src/share/vm/classfile/verifier.cpp
hotspot/src/share/vm/logging/logTag.hpp
hotspot/src/share/vm/runtime/globals.hpp
hotspot/test/runtime/logging/ClassInitializationTest.java
hotspot/test/runtime/logging/VerboseVerificationTest.java
--- a/hotspot/src/share/vm/classfile/verifier.cpp	Tue Mar 08 12:57:44 2016 -0500
+++ b/hotspot/src/share/vm/classfile/verifier.cpp	Tue Mar 08 15:19:53 2016 -0500
@@ -33,6 +33,7 @@
 #include "classfile/vmSymbols.hpp"
 #include "interpreter/bytecodes.hpp"
 #include "interpreter/bytecodeStream.hpp"
+#include "logging/log.hpp"
 #include "memory/oopFactory.hpp"
 #include "memory/resourceArea.hpp"
 #include "oops/instanceKlass.hpp"
@@ -176,9 +177,7 @@
     if (can_failover && !HAS_PENDING_EXCEPTION &&
         (exception_name == vmSymbols::java_lang_VerifyError() ||
          exception_name == vmSymbols::java_lang_ClassFormatError())) {
-      if (VerboseVerification) {
-        tty->print_cr("Fail over class verification to old verifier for: %s", klassName);
-      }
+      log_info(verboseverification)("Fail over class verification to old verifier for: %s", klassName);
       log_info(classinit)("Fail over class verification to old verifier for: %s", klassName);
       exception_name = inference_verify(
         klass, message_buffer, message_buffer_len, THREAD);
@@ -194,8 +193,8 @@
   if (log_is_enabled(Info, classinit)){
     log_end_verification(LogHandle(classinit)::info_stream(), klassName, exception_name, THREAD);
   }
-  if (VerboseVerification){
-    log_end_verification(tty, klassName, exception_name, THREAD);
+  if (log_is_enabled(Info, verboseverification)){
+    log_end_verification(LogHandle(verboseverification)::info_stream(), klassName, exception_name, THREAD);
   }
 
   if (HAS_PENDING_EXCEPTION) {
@@ -269,9 +268,7 @@
   }
 
   ResourceMark rm(THREAD);
-  if (VerboseVerification) {
-    tty->print_cr("Verifying class %s with old format", klass->external_name());
-  }
+  log_info(verboseverification)("Verifying class %s with old format", klass->external_name());
 
   jclass cls = (jclass) JNIHandles::make_local(env, klass->java_mirror());
   jint result;
@@ -583,10 +580,7 @@
 }
 
 void ClassVerifier::verify_class(TRAPS) {
-  if (VerboseVerification) {
-    tty->print_cr("Verifying class %s with new format",
-      _klass->external_name());
-  }
+  log_info(verboseverification)("Verifying class %s with new format", _klass->external_name());
 
   Array<Method*>* methods = _klass->methods();
   int num_methods = methods->length();
@@ -606,10 +600,7 @@
   }
 
   if (was_recursively_verified()){
-    if (VerboseVerification){
-      tty->print_cr("Recursive verification detected for: %s",
-                    _klass->external_name());
-    }
+    log_info(verboseverification)("Recursive verification detected for: %s", _klass->external_name());
     log_info(classinit)("Recursive verification detected for: %s",
                         _klass->external_name());
   }
@@ -618,9 +609,7 @@
 void ClassVerifier::verify_method(const methodHandle& m, TRAPS) {
   HandleMark hm(THREAD);
   _method = m;   // initialize _method
-  if (VerboseVerification) {
-    tty->print_cr("Verifying method %s", m->name_and_sig_as_C_string());
-  }
+  log_info(verboseverification)("Verifying method %s", m->name_and_sig_as_C_string());
 
 // For clang, the only good constant format string is a literal constant format string.
 #define bad_type_msg "Bad type on operand stack in %s"
@@ -667,8 +656,9 @@
   StackMapTable stackmap_table(&reader, &current_frame, max_locals, max_stack,
                                code_data, code_length, CHECK_VERIFY(this));
 
-  if (VerboseVerification) {
-    stackmap_table.print_on(tty);
+  if (log_is_enabled(Info, verboseverification)) {
+    ResourceMark rm(THREAD);
+    stackmap_table.print_on(LogHandle(verboseverification)::info_stream());
   }
 
   RawBytecodeStream bcs(m);
@@ -708,12 +698,11 @@
       VerificationType type, type2;
       VerificationType atype;
 
-#ifndef PRODUCT
-      if (VerboseVerification) {
-        current_frame.print_on(tty);
-        tty->print_cr("offset = %d,  opcode = %s", bci, Bytecodes::name(opcode));
+      if (log_is_enabled(Info, verboseverification)) {
+        ResourceMark rm(THREAD);
+        current_frame.print_on(LogHandle(verboseverification)::info_stream());
+        log_info(verboseverification)("offset = %d,  opcode = %s", bci, Bytecodes::name(opcode));
       }
-#endif
 
       // Make sure wide instruction is in correct format
       if (bcs.is_wide()) {
@@ -2533,11 +2522,10 @@
             verify_error(ErrorContext::bad_code(bci),
               "Bad <init> method call from after the start of a try block");
             return;
-          } else if (VerboseVerification) {
-            ResourceMark rm;
-            tty->print_cr(
-              "Survived call to ends_in_athrow(): %s",
-              current_class()->name()->as_C_string());
+          } else if (log_is_enabled(Info, verboseverification)) {
+            ResourceMark rm(THREAD);
+            log_info(verboseverification)("Survived call to ends_in_athrow(): %s",
+                                          current_class()->name()->as_C_string());
           }
         }
       }
--- a/hotspot/src/share/vm/logging/logTag.hpp	Tue Mar 08 12:57:44 2016 -0500
+++ b/hotspot/src/share/vm/logging/logTag.hpp	Tue Mar 08 15:19:53 2016 -0500
@@ -87,6 +87,7 @@
   LOG_TAG(thread) \
   LOG_TAG(tlab) \
   LOG_TAG(time) \
+  LOG_TAG(verboseverification) \
   LOG_TAG(verify) \
   LOG_TAG(vmoperation) \
   LOG_TAG(vtables)
--- a/hotspot/src/share/vm/runtime/globals.hpp	Tue Mar 08 12:57:44 2016 -0500
+++ b/hotspot/src/share/vm/runtime/globals.hpp	Tue Mar 08 15:19:53 2016 -0500
@@ -990,9 +990,6 @@
   develop(bool, PrintVMMessages, true,                                      \
           "Print VM messages on console")                                   \
                                                                             \
-  diagnostic(bool, VerboseVerification, false,                              \
-          "Display detailed verification details")                          \
-                                                                            \
   notproduct(uintx, ErrorHandlerTest, 0,                                    \
           "If > 0, provokes an error after VM initialization; the value "   \
           "determines which error to provoke. See test_error_handler() "    \
--- a/hotspot/test/runtime/logging/ClassInitializationTest.java	Tue Mar 08 12:57:44 2016 -0500
+++ b/hotspot/test/runtime/logging/ClassInitializationTest.java	Tue Mar 08 15:19:53 2016 -0500
@@ -62,16 +62,6 @@
             out.shouldContain("[Initialized").shouldContain("without side effects]");
             out.shouldHaveExitValue(0);
         }
-        // (3) Ensure that VerboseVerification still triggers appropriate messages.
-        pb = ProcessTools.createJavaProcessBuilder("-XX:+UnlockDiagnosticVMOptions",
-                                                   "-XX:+VerboseVerification",
-                                                   "-Xverify:all",
-                                                   "-Xmx64m",
-                                                   "BadMap50");
-        out = new OutputAnalyzer(pb.start());
-        out.shouldContain("End class verification for:");
-        out.shouldContain("Verification for BadMap50 failed");
-        out.shouldContain("Fail over class verification to old verifier for: BadMap50");
     }
     public static class InnerClass {
         public static void main(String[] args) throws Exception {
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/hotspot/test/runtime/logging/VerboseVerificationTest.java	Tue Mar 08 15:19:53 2016 -0500
@@ -0,0 +1,69 @@
+/*
+ * 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
+ * @bug 8150083
+ * @summary verboseverification=info output should have output from the code
+ * @library /testlibrary
+ * @modules java.base/sun.misc
+ *          java.management
+ * @build jdk.test.lib.OutputAnalyzer jdk.test.lib.ProcessTools
+ * @run driver VerboseVerificationTest
+ */
+
+import jdk.test.lib.OutputAnalyzer;
+import jdk.test.lib.ProcessTools;
+
+public class VerboseVerificationTest {
+    static void analyzeOutputOn(ProcessBuilder pb) throws Exception {
+        OutputAnalyzer output = new OutputAnalyzer(pb.start());
+        output.shouldContain("[verboseverification]");
+        output.shouldContain("Verifying class VerboseVerificationTest$InternalClass with new format");
+        output.shouldContain("Verifying method VerboseVerificationTest$InternalClass.<init>()V");
+        output.shouldContain("End class verification for: VerboseVerificationTest$InternalClass");
+        output.shouldHaveExitValue(0);
+    }
+
+    static void analyzeOutputOff(ProcessBuilder pb) throws Exception {
+        OutputAnalyzer output = new OutputAnalyzer(pb.start());
+        output.shouldNotContain("[verboseverification]");
+        output.shouldHaveExitValue(0);
+    }
+
+    public static void main(String[] args) throws Exception {
+        ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-Xlog:verboseverification=info",
+                                                                  InternalClass.class.getName());
+        analyzeOutputOn(pb);
+
+        pb = ProcessTools.createJavaProcessBuilder("-Xlog:verboseverification=off",
+                                                   InternalClass.class.getName());
+        analyzeOutputOff(pb);
+    }
+
+    public static class InternalClass {
+        public static void main(String[] args) throws Exception {
+            System.out.println("VerboseVerificationTest");
+        }
+    }
+}