8141211: Convert TraceExceptions to Unified Logging

The -XX:+TraceExceptions flag has been updated to the unified logging framework, i.e. -Xlog:exceptions. The old flag, because it is product-level, has been aliased to the UL option.

Reviewed-by: dholmes, coleenp, mockner
This commit is contained in:
Rachel Protacio 2015-12-22 16:29:48 -05:00
parent 348d3ab0f4
commit 7973ef05b3
12 changed files with 195 additions and 86 deletions

View File

@ -43,6 +43,7 @@
#include "gc/shared/collectedHeap.hpp"
#include "interpreter/bytecode.hpp"
#include "interpreter/interpreter.hpp"
#include "logging/log.hpp"
#include "memory/allocation.inline.hpp"
#include "memory/oopFactory.hpp"
#include "memory/resourceArea.hpp"
@ -548,11 +549,14 @@ JRT_ENTRY_NO_ASYNC(static address, exception_handler_for_pc_helper(JavaThread* t
// debugging support
// tracing
if (TraceExceptions) {
ttyLocker ttyl;
if (log_is_enabled(Info, exceptions)) {
ResourceMark rm;
tty->print_cr("Exception <%s> (" INTPTR_FORMAT ") thrown in compiled method <%s> at PC " INTPTR_FORMAT " for thread " INTPTR_FORMAT "",
exception->print_value_string(), p2i((address)exception()), nm->method()->print_value_string(), p2i(pc), p2i(thread));
log_info(exceptions)("Exception <%s> (" INTPTR_FORMAT
") thrown in compiled method <%s> at PC " INTPTR_FORMAT
" for thread " INTPTR_FORMAT,
exception->print_value_string(),
p2i((address)exception()),
nm->method()->print_value_string(), p2i(pc), p2i(thread));
}
// for AbortVMOnException flag
Exceptions::debug_check_abort(exception);
@ -583,11 +587,11 @@ JRT_ENTRY_NO_ASYNC(static address, exception_handler_for_pc_helper(JavaThread* t
// Set flag if return address is a method handle call site.
thread->set_is_method_handle_return(nm->is_method_handle_return(pc));
if (TraceExceptions) {
ttyLocker ttyl;
if (log_is_enabled(Info, exceptions)) {
ResourceMark rm;
tty->print_cr("Thread " PTR_FORMAT " continuing at PC " PTR_FORMAT " for exception thrown at PC " PTR_FORMAT,
p2i(thread), p2i(continuation), p2i(pc));
log_info(exceptions)("Thread " PTR_FORMAT " continuing at PC " PTR_FORMAT
" for exception thrown at PC " PTR_FORMAT,
p2i(thread), p2i(continuation), p2i(pc));
}
return continuation;

View File

@ -31,6 +31,7 @@
#include "interpreter/bytecodeInterpreterProfiling.hpp"
#include "interpreter/interpreter.hpp"
#include "interpreter/interpreterRuntime.hpp"
#include "logging/log.hpp"
#include "memory/resourceArea.hpp"
#include "oops/methodCounters.hpp"
#include "oops/objArrayKlass.hpp"
@ -2778,14 +2779,15 @@ run:
SET_STACK_OBJECT(except_oop(), 0);
MORE_STACK(1);
pc = METHOD->code_base() + continuation_bci;
if (TraceExceptions) {
ttyLocker ttyl;
if (log_is_enabled(Info, exceptions)) {
ResourceMark rm;
tty->print_cr("Exception <%s> (" INTPTR_FORMAT ")", except_oop->print_value_string(), p2i(except_oop()));
tty->print_cr(" thrown in interpreter method <%s>", METHOD->print_value_string());
tty->print_cr(" at bci %d, continuing at %d for thread " INTPTR_FORMAT,
(int)(istate->bcp() - METHOD->code_base()),
(int)continuation_bci, p2i(THREAD));
log_info(exceptions)("Exception <%s> (" INTPTR_FORMAT ")\n"
" thrown in interpreter method <%s>\n"
" at bci %d, continuing at %d for thread " INTPTR_FORMAT,
except_oop->print_value_string(), p2i(except_oop()),
METHOD->print_value_string(),
(int)(istate->bcp() - METHOD->code_base()),
(int)continuation_bci, p2i(THREAD));
}
// for AbortVMOnException flag
Exceptions::debug_check_abort(except_oop);
@ -2794,14 +2796,15 @@ run:
BI_PROFILE_ALIGN_TO_CURRENT_BCI();
goto run;
}
if (TraceExceptions) {
ttyLocker ttyl;
if (log_is_enabled(Info, exceptions)) {
ResourceMark rm;
tty->print_cr("Exception <%s> (" INTPTR_FORMAT ")", except_oop->print_value_string(), p2i(except_oop()));
tty->print_cr(" thrown in interpreter method <%s>", METHOD->print_value_string());
tty->print_cr(" at bci %d, unwinding for thread " INTPTR_FORMAT,
(int)(istate->bcp() - METHOD->code_base()),
p2i(THREAD));
log_info(exceptions)("Exception <%s> (" INTPTR_FORMAT ")\n"
" thrown in interpreter method <%s>\n"
" at bci %d, unwinding for thread " INTPTR_FORMAT,
except_oop->print_value_string(), p2i(except_oop()),
METHOD->print_value_string(),
(int)(istate->bcp() - METHOD->code_base()),
p2i(THREAD));
}
// for AbortVMOnException flag
Exceptions::debug_check_abort(except_oop);

View File

@ -35,6 +35,7 @@
#include "interpreter/interpreterRuntime.hpp"
#include "interpreter/linkResolver.hpp"
#include "interpreter/templateTable.hpp"
#include "logging/log.hpp"
#include "memory/oopFactory.hpp"
#include "memory/universe.inline.hpp"
#include "oops/constantPool.hpp"
@ -456,21 +457,23 @@ IRT_ENTRY(address, InterpreterRuntime::exception_handler_for_exception(JavaThrea
#endif
// tracing
if (TraceExceptions) {
if (log_is_enabled(Info, exceptions)) {
ResourceMark rm(thread);
Symbol* message = java_lang_Throwable::detail_message(h_exception());
ttyLocker ttyl; // Lock after getting the detail message
stringStream tempst;
if (message != NULL) {
tty->print_cr("Exception <%s: %s> (" INTPTR_FORMAT ")",
h_exception->print_value_string(), message->as_C_string(),
p2i(h_exception()));
tempst.print("Exception <%s: %s> (" INTPTR_FORMAT ")\n",
h_exception->print_value_string(), message->as_C_string(),
p2i(h_exception()));
} else {
tty->print_cr("Exception <%s> (" INTPTR_FORMAT ")",
h_exception->print_value_string(),
p2i(h_exception()));
tempst.print("Exception <%s> (" INTPTR_FORMAT ")\n",
h_exception->print_value_string(),
p2i(h_exception()));
}
tty->print_cr(" thrown in interpreter method <%s>", h_method->print_value_string());
tty->print_cr(" at bci %d for thread " INTPTR_FORMAT, current_bci, p2i(thread));
tempst.print(" thrown in interpreter method <%s>\n"
" at bci %d for thread " INTPTR_FORMAT,
h_method->print_value_string(), current_bci, p2i(thread));
LogHandle(exceptions)::info_stream()->print_raw_cr(tempst.as_string());
}
// Don't go paging in something which won't be used.
// else if (extable->length() == 0) {

View File

@ -31,6 +31,7 @@
#include "jvmci/jvmciCompiler.hpp"
#include "jvmci/jvmciJavaClasses.hpp"
#include "jvmci/jvmciEnv.hpp"
#include "logging/log.hpp"
#include "memory/oopFactory.hpp"
#include "oops/oop.inline.hpp"
#include "oops/objArrayOop.inline.hpp"
@ -294,11 +295,15 @@ JRT_ENTRY_NO_ASYNC(static address, exception_handler_for_pc_helper(JavaThread* t
// debugging support
// tracing
if (TraceExceptions) {
ttyLocker ttyl;
if (log_is_enabled(Info, exceptions)) {
ResourceMark rm;
tty->print_cr("Exception <%s> (" INTPTR_FORMAT ") thrown in compiled method <%s> at PC " INTPTR_FORMAT " for thread " INTPTR_FORMAT "",
exception->print_value_string(), p2i((address)exception()), nm->method()->print_value_string(), p2i(pc), p2i(thread));
log_info(exceptions)("Exception <%s> (" INTPTR_FORMAT ") thrown in"
" compiled method <%s> at PC " INTPTR_FORMAT
" for thread " INTPTR_FORMAT,
exception->print_value_string(),
p2i((address)exception()),
nm->method()->print_value_string(), p2i(pc),
p2i(thread));
}
// for AbortVMOnException flag
NOT_PRODUCT(Exceptions::debug_check_abort(exception));
@ -323,11 +328,11 @@ JRT_ENTRY_NO_ASYNC(static address, exception_handler_for_pc_helper(JavaThread* t
// Set flag if return address is a method handle call site.
thread->set_is_method_handle_return(nm->is_method_handle_return(pc));
if (TraceExceptions) {
ttyLocker ttyl;
if (log_is_enabled(Info, exceptions)) {
ResourceMark rm;
tty->print_cr("Thread " PTR_FORMAT " continuing at PC " PTR_FORMAT " for exception thrown at PC " PTR_FORMAT,
p2i(thread), p2i(continuation), p2i(pc));
log_info(exceptions)("Thread " PTR_FORMAT " continuing at PC " PTR_FORMAT
" for exception thrown at PC " PTR_FORMAT,
p2i(thread), p2i(continuation), p2i(pc));
}
return continuation;

View File

@ -44,6 +44,7 @@
LOG_TAG(cset) \
LOG_TAG(defaultmethods) \
LOG_TAG(ergo) \
LOG_TAG(exceptions) \
LOG_TAG(exit) \
LOG_TAG(freelist) \
LOG_TAG(gc) \

View File

@ -42,6 +42,7 @@
#include "interpreter/bytecode.hpp"
#include "interpreter/interpreter.hpp"
#include "interpreter/linkResolver.hpp"
#include "logging/log.hpp"
#include "memory/oopFactory.hpp"
#include "oops/objArrayKlass.hpp"
#include "oops/oop.inline.hpp"
@ -1211,7 +1212,7 @@ bool OptoRuntime::is_callee_saved_register(MachRegisterNumbers reg) {
// Exceptions
//
static void trace_exception(oop exception_oop, address exception_pc, const char* msg) PRODUCT_RETURN;
static void trace_exception(outputStream* st, oop exception_oop, address exception_pc, const char* msg);
// The method is an entry that is always called by a C++ method not
// directly from compiled code. Compiled code will call the C++ method following.
@ -1234,8 +1235,9 @@ JRT_ENTRY_NO_ASYNC(address, OptoRuntime::handle_exception_C_helper(JavaThread* t
// normal bytecode execution.
thread->clear_exception_oop_and_pc();
if (TraceExceptions) {
trace_exception(exception(), pc, "");
if (log_is_enabled(Info, exceptions)) {
ResourceMark rm;
trace_exception(LogHandle(exceptions)::info_stream(), exception(), pc, "");
}
// for AbortVMOnException flag
@ -1600,29 +1602,25 @@ NamedCounter* OptoRuntime::new_named_counter(JVMState* youngest_jvms, NamedCount
return c;
}
//-----------------------------------------------------------------------------
// Non-product code
#ifndef PRODUCT
int trace_exception_counter = 0;
static void trace_exception(oop exception_oop, address exception_pc, const char* msg) {
ttyLocker ttyl;
static void trace_exception(outputStream* st, oop exception_oop, address exception_pc, const char* msg) {
trace_exception_counter++;
tty->print("%d [Exception (%s): ", trace_exception_counter, msg);
exception_oop->print_value();
tty->print(" in ");
stringStream tempst;
tempst.print("%d [Exception (%s): ", trace_exception_counter, msg);
exception_oop->print_value_on(&tempst);
tempst.print(" in ");
CodeBlob* blob = CodeCache::find_blob(exception_pc);
if (blob->is_nmethod()) {
nmethod* nm = blob->as_nmethod_or_null();
nm->method()->print_value();
nm->method()->print_value_on(&tempst);
} else if (blob->is_runtime_stub()) {
tty->print("<runtime-stub>");
tempst.print("<runtime-stub>");
} else {
tty->print("<unknown>");
tempst.print("<unknown>");
}
tty->print(" at " INTPTR_FORMAT, p2i(exception_pc));
tty->print_cr("]");
tempst.print(" at " INTPTR_FORMAT, p2i(exception_pc));
tempst.print("]");
st->print_raw_cr(tempst.as_string());
}
#endif // PRODUCT

View File

@ -400,6 +400,8 @@ static AliasedFlag const aliased_jvm_flags[] = {
};
static AliasedFlag const aliased_jvm_logging_flags[] = {
{ "-XX:+TraceExceptions", "-Xlog:exceptions=info" },
{ "-XX:-TraceExceptions", "-Xlog:exceptions=off" },
{ "-XX:+TraceMonitorInflation", "-Xlog:monitorinflation=debug" },
{ "-XX:-TraceMonitorInflation", "-Xlog:monitorinflation=off" },
{ NULL, NULL }

View File

@ -1448,9 +1448,6 @@ public:
develop(bool, TraceBytecodes, false, \
"Trace bytecode execution") \
\
product(bool, TraceExceptions, false, \
"Trace exceptions") \
\
develop(bool, TraceICs, false, \
"Trace inline cache changes") \
\

View File

@ -38,6 +38,7 @@
#include "interpreter/linkResolver.hpp"
#include "interpreter/oopMapCache.hpp"
#include "jvmtifiles/jvmtiEnv.hpp"
#include "logging/log.hpp"
#include "logging/logConfiguration.hpp"
#include "memory/metaspaceShared.hpp"
#include "memory/oopFactory.hpp"
@ -2062,10 +2063,7 @@ void JavaThread::check_and_handle_async_exceptions(bool check_unsafe_error) {
frame caller_fr = last_frame().sender(&map);
assert(caller_fr.is_compiled_frame(), "what?");
if (caller_fr.is_deoptimized_frame()) {
if (TraceExceptions) {
ResourceMark rm;
tty->print_cr("deferred async exception at compiled safepoint");
}
log_info(exceptions)("deferred async exception at compiled safepoint");
return;
}
}
@ -2091,14 +2089,15 @@ void JavaThread::check_and_handle_async_exceptions(bool check_unsafe_error) {
// We cannot call Exceptions::_throw(...) here because we cannot block
set_pending_exception(_pending_async_exception, __FILE__, __LINE__);
if (TraceExceptions) {
if (log_is_enabled(Info, exceptions)) {
ResourceMark rm;
tty->print("Async. exception installed at runtime exit (" INTPTR_FORMAT ")", p2i(this));
if (has_last_Java_frame()) {
frame f = last_frame();
tty->print(" (pc: " INTPTR_FORMAT " sp: " INTPTR_FORMAT " )", p2i(f.pc()), p2i(f.sp()));
}
tty->print_cr(" of type: %s", _pending_async_exception->klass()->external_name());
outputStream* logstream = LogHandle(exceptions)::info_stream();
logstream->print("Async. exception installed at runtime exit (" INTPTR_FORMAT ")", p2i(this));
if (has_last_Java_frame()) {
frame f = last_frame();
logstream->print(" (pc: " INTPTR_FORMAT " sp: " INTPTR_FORMAT " )", p2i(f.pc()), p2i(f.sp()));
}
logstream->print_cr(" of type: %s", _pending_async_exception->klass()->external_name());
}
_pending_async_exception = NULL;
clear_has_async_exception();
@ -2214,9 +2213,10 @@ void JavaThread::send_thread_stop(oop java_throwable) {
// Set async. pending exception in thread.
set_pending_async_exception(java_throwable);
if (TraceExceptions) {
ResourceMark rm;
tty->print_cr("Pending Async. exception installed of type: %s", _pending_async_exception->klass()->external_name());
if (log_is_enabled(Info, exceptions)) {
ResourceMark rm;
log_info(exceptions)("Pending Async. exception installed of type: %s",
InstanceKlass::cast(_pending_async_exception->klass())->external_name());
}
// for AbortVMOnException flag
Exceptions::debug_check_abort(_pending_async_exception->klass()->external_name());

View File

@ -26,6 +26,7 @@
#include "classfile/systemDictionary.hpp"
#include "classfile/vmSymbols.hpp"
#include "compiler/compileBroker.hpp"
#include "logging/log.hpp"
#include "oops/oop.inline.hpp"
#include "runtime/init.hpp"
#include "runtime/java.hpp"
@ -136,14 +137,11 @@ void Exceptions::_throw(Thread* thread, const char* file, int line, Handle h_exc
assert(h_exception() != NULL, "exception should not be NULL");
// tracing (do this up front - so it works during boot strapping)
if (TraceExceptions) {
ttyLocker ttyl;
tty->print_cr("Exception <%s%s%s> (" INTPTR_FORMAT ") \n"
"thrown [%s, line %d]\nfor thread " INTPTR_FORMAT,
h_exception->print_value_string(),
message ? ": " : "", message ? message : "",
p2i(h_exception()), file, line, p2i(thread));
}
log_info(exceptions)("Exception <%s%s%s> (" INTPTR_FORMAT ") \n"
"thrown [%s, line %d]\nfor thread " INTPTR_FORMAT,
h_exception->print_value_string(),
message ? ": " : "", message ? message : "",
p2i(h_exception()), file, line, p2i(thread));
// for AbortVMOnException flag
Exceptions::debug_check_abort(h_exception, message);

View File

@ -36,7 +36,7 @@ public class TraceExceptionsTest {
public static void main(String[] args) throws Exception {
ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(
"-XX:+TraceExceptions", "NoClassFound");
"-Xlog:exceptions=info", "NoClassFound");
OutputAnalyzer output = new OutputAnalyzer(pb.start());
output.shouldContain("<a 'java/lang/ClassNotFoundException': NoClassFound>");
output.shouldNotContain("<a 'java/lang/ClassNotFoundException'>");

View File

@ -0,0 +1,98 @@
/*
* 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 8141211
* @summary exceptions=info output should have an exception message for both interpreter and compiled methods
* @library /testlibrary
* @modules java.base/sun.misc
* java.management
* @build jdk.test.lib.OutputAnalyzer jdk.test.lib.ProcessTools
* @run driver ExceptionsTest
*/
import jdk.test.lib.OutputAnalyzer;
import jdk.test.lib.ProcessTools;
public class ExceptionsTest {
static void analyzeOutputOn(ProcessBuilder pb) throws Exception {
OutputAnalyzer output = new OutputAnalyzer(pb.start());
output.shouldContain("<a 'java/lang/RuntimeException': Test exception 1 for logging>");
output.shouldContain(" thrown in interpreter method ");
output.shouldContain(") thrown in compiled method ");
output.shouldContain("Exception 2 caught.");
output.shouldHaveExitValue(0);
}
static void analyzeOutputOff(ProcessBuilder pb) throws Exception {
OutputAnalyzer output = new OutputAnalyzer(pb.start());
output.shouldNotContain("[exceptions]");
output.shouldHaveExitValue(0);
}
public static void main(String[] args) throws Exception {
ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(
"-Xlog:exceptions=info", "-Xcomp",
"-XX:CompileCommand=compileonly,ExceptionsTest$InternalClass::compileMe",
InternalClass.class.getName());
analyzeOutputOn(pb);
pb = ProcessTools.createJavaProcessBuilder(
"-XX:+TraceExceptions", "-Xcomp",
"-XX:CompileCommand=compileonly,ExceptionsTest$InternalClass::compileMe",
InternalClass.class.getName());
analyzeOutputOn(pb);
pb = ProcessTools.createJavaProcessBuilder(
"-Xlog:exceptions=off", "-Xcomp",
"-XX:CompileCommand=compileonly,ExceptionsTest$InternalClass::compileMe",
InternalClass.class.getName());
analyzeOutputOff(pb);
pb = ProcessTools.createJavaProcessBuilder(
"-XX:-TraceExceptions", "-Xcomp",
"-XX:CompileCommand=compileonly,ExceptionsTest$InternalClass::compileMe",
InternalClass.class.getName());
analyzeOutputOff(pb);
}
public static class InternalClass {
public static void compileMe() throws Exception {
try {
throw new RuntimeException("Test exception 2 for logging");
} catch (Exception e) {
System.out.println("Exception 2 caught.");
}
}
public static void main(String[] args) throws Exception {
try {
throw new RuntimeException("Test exception 1 for logging");
} catch (Exception e) {
System.out.println("Exception 1 caught.");
}
compileMe();
}
}
}