diff --git a/src/hotspot/share/interpreter/interpreterRuntime.cpp b/src/hotspot/share/interpreter/interpreterRuntime.cpp index fcc0b96efa4..8e7e5772ba6 100644 --- a/src/hotspot/share/interpreter/interpreterRuntime.cpp +++ b/src/hotspot/share/interpreter/interpreterRuntime.cpp @@ -500,6 +500,10 @@ JRT_ENTRY(address, InterpreterRuntime::exception_handler_for_exception(JavaThrea h_method->print_value_string(), current_bci, p2i(current), current->name()); Exceptions::log_exception(h_exception, tempst.as_string()); } + if (log_is_enabled(Info, exceptions, stacktrace)) { + Exceptions::log_exception_stacktrace(h_exception, h_method, current_bci); + } + // Don't go paging in something which won't be used. // else if (extable->length() == 0) { // // disabled for now - interpreter is not using shortcut yet diff --git a/src/hotspot/share/utilities/exceptions.cpp b/src/hotspot/share/utilities/exceptions.cpp index c48b33b1e1f..fd1a2930034 100644 --- a/src/hotspot/share/utilities/exceptions.cpp +++ b/src/hotspot/share/utilities/exceptions.cpp @@ -114,15 +114,17 @@ bool Exceptions::special_exception(JavaThread* thread, const char* file, int lin #endif // ASSERT if (h_exception.is_null() && !thread->can_call_java()) { - ResourceMark rm(thread); - const char* exc_value = h_name != nullptr ? h_name->as_C_string() : "null"; - log_info(exceptions)("Thread cannot call Java so instead of throwing exception <%.*s%s%.*s> (" PTR_FORMAT ") \n" - "at [%s, line %d]\nfor thread " PTR_FORMAT ",\n" - "throwing pre-allocated exception: %s", - MAX_LEN, exc_value, message ? ": " : "", - MAX_LEN, message ? message : "", - p2i(h_exception()), file, line, p2i(thread), - Universe::vm_exception()->print_value_string()); + if (log_is_enabled(Info, exceptions)) { + ResourceMark rm(thread); + const char* exc_value = h_name != nullptr ? h_name->as_C_string() : "null"; + log_info(exceptions)("Thread cannot call Java so instead of throwing exception <%.*s%s%.*s> (" PTR_FORMAT ") \n" + "at [%s, line %d]\nfor thread " PTR_FORMAT ",\n" + "throwing pre-allocated exception: %s", + MAX_LEN, exc_value, message ? ": " : "", + MAX_LEN, message ? message : "", + p2i(h_exception()), file, line, p2i(thread), + Universe::vm_exception()->print_value_string()); + } // We do not care what kind of exception we get for a thread which // is compiling. We just install a dummy exception object thread->set_pending_exception(Universe::vm_exception(), file, line); @@ -152,6 +154,9 @@ void Exceptions::_throw(JavaThread* thread, const char* file, int line, Handle h message ? ": " : "", MAX_LEN, message ? message : "", p2i(h_exception()), file, line, p2i(thread)); + if (log_is_enabled(Info, exceptions, stacktrace)) { + log_exception_stacktrace(h_exception); + } // for AbortVMOnException flag Exceptions::debug_check_abort(h_exception, message); @@ -609,3 +614,42 @@ void Exceptions::log_exception(Handle exception, const char* message) { MAX_LEN, message); } } + +// This is called from InterpreterRuntime::exception_handler_for_exception(), which is the only +// easy way to be notified in the VM that an _athrow bytecode has been executed. (The alternative +// would be to add hooks into the interpreter and compiler, for all platforms ...). +// +// Unfortunately, InterpreterRuntime::exception_handler_for_exception() is called for every level +// of the Java stack when looking for an exception handler. To avoid excessive output, +// we print the stack only when the bci points to an _athrow bytecode. +// +// NOTE: exceptions that are NOT thrown by _athrow are handled by Exceptions::special_exception() +// and Exceptions::_throw()). +void Exceptions::log_exception_stacktrace(Handle exception, methodHandle method, int bci) { + if (!method->is_native() && (Bytecodes::Code) *method->bcp_from(bci) == Bytecodes::_athrow) { + // TODO: try to find a way to avoid repeated stacktraces when an exception gets re-thrown + // by a finally block + log_exception_stacktrace(exception); + } +} + +// This should be called only from a live Java thread. +void Exceptions::log_exception_stacktrace(Handle exception) { + LogStreamHandle(Info, exceptions, stacktrace) st; + ResourceMark rm; + const char* detail_message = java_lang_Throwable::message_as_utf8(exception()); + if (detail_message != nullptr) { + st.print_cr("Exception <%.*s: %.*s>", + MAX_LEN, exception->print_value_string(), + MAX_LEN, detail_message); + } else { + st.print_cr("Exception <%.*s>", + MAX_LEN, exception->print_value_string()); + } + JavaThread* t = JavaThread::current(); + if (t->has_last_Java_frame()) { + t->print_active_stack_on(&st); + } else { + st.print_cr("(Cannot print stracktrace)"); + } +} diff --git a/src/hotspot/share/utilities/exceptions.hpp b/src/hotspot/share/utilities/exceptions.hpp index 0dca7971ef9..94f4a04546d 100644 --- a/src/hotspot/share/utilities/exceptions.hpp +++ b/src/hotspot/share/utilities/exceptions.hpp @@ -1,5 +1,5 @@ /* - * Copyright (c) 1998, 2024, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 1998, 2025, 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 @@ -190,6 +190,8 @@ class Exceptions { // for logging exceptions static void log_exception(Handle exception, const char* message); + static void log_exception_stacktrace(Handle exception); + static void log_exception_stacktrace(Handle exception, methodHandle method, int bci); }; diff --git a/test/hotspot/jtreg/runtime/logging/ExceptionsTest.java b/test/hotspot/jtreg/runtime/logging/ExceptionsTest.java index 327b1cc0f24..c2c966cb047 100644 --- a/test/hotspot/jtreg/runtime/logging/ExceptionsTest.java +++ b/test/hotspot/jtreg/runtime/logging/ExceptionsTest.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2015, 2023, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2015, 2025, 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 @@ -23,7 +23,7 @@ /* * @test - * @bug 8141211 8147477 + * @bug 8141211 8147477 8358080 * @summary exceptions=info output should have an exception message for interpreter methods * @requires vm.flagless * @library /test/lib @@ -34,6 +34,8 @@ import java.io.File; import java.util.Map; +import java.util.regex.Matcher; +import java.util.regex.Pattern; import jdk.test.lib.process.OutputAnalyzer; import jdk.test.lib.process.ProcessTools; @@ -44,10 +46,24 @@ public class ExceptionsTest { } static void analyzeOutputOn(ProcessBuilder pb) throws Exception { - OutputAnalyzer output = new OutputAnalyzer(pb.start()); + OutputAnalyzer output = ProcessTools.executeProcess(pb); output.shouldContain(""); output.shouldContain(" thrown in interpreter method "); - output.shouldHaveExitValue(0); + output.shouldMatch("info..exceptions,stacktrace.*at ExceptionsTest[$]InternalClass.bar[(]ExceptionsTest.java:[0-9]+" + + ".*\n.*" + + "info..exceptions,stacktrace.*at ExceptionsTest[$]InternalClass.foo[(]ExceptionsTest.java:[0-9]+" + + ".*\n.*" + + "info..exceptions,stacktrace.*at ExceptionsTest[$]InternalClass.main[(]ExceptionsTest.java:[0-9]+"); + + // Note: "(?s)" means that the "." in the regexp can match the newline character. + // To avoid verbosity, stack trace for bar2()->baz2() should be printed only once: + // - It should be printed when the exception is thrown inside bzz2() + // - It should not be printed when the interpreter is looking for an exception handler inside bar2() + output.shouldMatch("(?s)baz2.*bar2"); + output.shouldNotMatch("(?s)baz2.*bar2,*baz2.*bar2"); + + // Two stack traces should include main()->foo2(), as an exception is thrown at two different BCIs in bar2(). + output.shouldMatch("(?s)foo2.*main.*foo2.*main"); } static void analyzeOutputOff(ProcessBuilder pb) throws Exception { @@ -57,7 +73,7 @@ public class ExceptionsTest { } public static void main(String[] args) throws Exception { - ProcessBuilder pb = ProcessTools.createLimitedTestJavaProcessBuilder("-Xlog:exceptions=info", + ProcessBuilder pb = ProcessTools.createLimitedTestJavaProcessBuilder("-Xlog:exceptions,exceptions+stacktrace", InternalClass.class.getName()); analyzeOutputOn(pb); @@ -66,7 +82,7 @@ public class ExceptionsTest { analyzeOutputOff(pb); pb = ProcessTools.createLimitedTestJavaProcessBuilder(InternalClass.class.getName()); - updateEnvironment(pb, "_JAVA_OPTIONS", "-Xlog:exceptions=info"); + updateEnvironment(pb, "_JAVA_OPTIONS", "-Xlog:exceptions,exceptions+stacktrace"); analyzeOutputOn(pb); pb = ProcessTools.createLimitedTestJavaProcessBuilder(InternalClass.class.getName()); @@ -80,12 +96,45 @@ public class ExceptionsTest { } public static class InternalClass { - public static void main(String[] args) throws Exception { + public static void main(String[] args) { + foo(); + foo2(); + } + + static void foo() { + bar(); + } + + static void bar() { try { throw new RuntimeException("Test exception 1 for logging"); } catch (Exception e) { System.out.println("Exception 1 caught."); } } + + static void foo2() { + try { + bar2(); + } catch (Exception e) { + System.out.println("Exception 2 caught."); + } + } + + static void bar2() { + try { + baz2(); + } catch (RuntimeException e) { + throw e; // Rethrow -- should print a new callstack. + } + } + + static void baz2() { + bzz2(); + } + + static void bzz2() { + throw new RuntimeException("Test exception 2 for logging"); + } } } diff --git a/test/hotspot/jtreg/runtime/logging/ExceptionsTest_options_file b/test/hotspot/jtreg/runtime/logging/ExceptionsTest_options_file index d3e8be7f857..1b566aaa456 100644 --- a/test/hotspot/jtreg/runtime/logging/ExceptionsTest_options_file +++ b/test/hotspot/jtreg/runtime/logging/ExceptionsTest_options_file @@ -1 +1 @@ --Xlog:exceptions=info +-Xlog:exceptions,exceptions+stacktrace