8382430: Extend output format of -XX:+PrintCompilation2 diagnostic flag

Reviewed-by: vlivanov, aseoane
This commit is contained in:
Vladimir Kozlov 2026-04-20 15:51:49 +00:00
parent b854ba1d1d
commit ae5b765e38
9 changed files with 300 additions and 54 deletions

View File

@ -345,6 +345,8 @@ void CompileQueue::add(CompileTask* task) {
// Mark the method as being in the compile queue.
task->method()->set_queued_for_compilation();
task->mark_queued(os::elapsed_counter());
if (CIPrintCompileQueue) {
print_tty();
}
@ -2402,7 +2404,7 @@ void CompileBroker::invoke_compiler_on_method(CompileTask* task) {
}
}
DirectivesStack::release(directive);
task->mark_finished(os::elapsed_counter());
methodHandle method(thread, task->method());
@ -2410,15 +2412,11 @@ void CompileBroker::invoke_compiler_on_method(CompileTask* task) {
collect_statistics(thread, time, task);
if (PrintCompilation && PrintCompilation2) {
tty->print("%7d ", (int) tty->time_stamp().milliseconds()); // print timestamp
tty->print("%4d ", compile_id); // print compilation number
tty->print("%s ", (is_osr ? "%" : " "));
if (task->is_success()) {
tty->print("size: %d(%d) ", task->nm_total_size(), task->nm_insts_size());
}
tty->print_cr("time: %d inlined: %d bytes", (int)time.milliseconds(), task->num_inlined_bytecodes());
if (PrintCompilation2 || directive->PrintCompilation2Option) {
ResourceMark rm;
task->print_post(tty);
}
DirectivesStack::release(directive);
Log(compilation, codecache) log;
if (log.is_debug()) {
@ -2614,7 +2612,7 @@ void CompileBroker::collect_statistics(CompilerThread* thread, elapsedTimer time
}
// Collect statistic per compiler
AbstractCompiler* comp = compiler(comp_level);
AbstractCompiler* comp = task->compiler();
if (comp) {
CompilerStatistics* stats = comp->stats();
if (is_osr) {

View File

@ -51,8 +51,6 @@ CompileTask::CompileTask(int compile_id,
_method_holder = JNIHandles::make_weak_global(Handle(thread, method->method_holder()->klass_holder()));
_osr_bci = osr_bci;
_is_blocking = is_blocking;
JVMCI_ONLY(_has_waiter = CompileBroker::compiler(comp_level)->is_jvmci();)
JVMCI_ONLY(_blocking_jvmci_compile_state = nullptr;)
_comp_level = comp_level;
_num_inlined_bytecodes = 0;
@ -60,17 +58,24 @@ CompileTask::CompileTask(int compile_id,
_is_success = false;
_hot_count = hot_count;
_time_queued = os::elapsed_counter();
_time_created = os::elapsed_counter();
_time_queued = 0;
_time_started = 0;
_time_finished = 0;
_compile_reason = compile_reason;
_nm_content_size = 0;
AbstractCompiler* comp = compiler();
_directive = DirectivesStack::getMatchingDirective(method, comp);
_nm_insts_size = 0;
_nm_total_size = 0;
_failure_reason = nullptr;
_failure_reason_on_C_heap = false;
_training_data = nullptr;
AbstractCompiler* comp = CompileBroker::compiler(comp_level);
_compiler = comp;
_directive = DirectivesStack::getMatchingDirective(method, comp);
JVMCI_ONLY(_has_waiter = comp->is_jvmci();)
JVMCI_ONLY(_blocking_jvmci_compile_state = nullptr;)
_arena_bytes = 0;
_next = nullptr;
@ -108,7 +113,8 @@ void CompileTask::wait_for_no_active_tasks() {
* Returns the compiler for this task.
*/
AbstractCompiler* CompileTask::compiler() const {
return CompileBroker::compiler(_comp_level);
assert(_compiler != nullptr, "should be set");
return _compiler;
}
// Replace weak handles by strong handles to avoid unloading during compilation.
@ -157,7 +163,7 @@ void CompileTask::metadata_do(MetadataClosure* f) {
//
void CompileTask::print_line_on_error(outputStream* st, char* buf, int buflen) {
// print compiler name
st->print("%s:", CompileBroker::compiler_name(comp_level()));
st->print("%s:", compiler()->name());
print(st);
}
@ -168,29 +174,71 @@ void CompileTask::print_tty() {
print(tty);
}
void CompileTask::print_post(outputStream* st) {
bool is_osr_method = osr_bci() != InvocationEntryBci;
print_impl(st, is_unloaded() ? nullptr : method(), compile_id(), comp_level(),
is_osr_method, osr_bci(), is_blocking(),
compiler()->name(), nullptr, false /* short_form */, true /* cr */,
true /* after_compile_details */,
_num_inlined_bytecodes, _nm_total_size, _nm_insts_size,
_time_created, _time_queued, _time_started, _time_finished);
}
// ------------------------------------------------------------------
// CompileTask::print_impl
void CompileTask::print_impl(outputStream* st, Method* method, int compile_id, int comp_level,
bool is_osr_method, int osr_bci, bool is_blocking,
const char* msg, bool short_form, bool cr,
jlong time_queued, jlong time_started) {
if (!short_form) {
const char* compiler_name,
const char* msg, bool short_form, bool cr, bool after_compile_details,
int inlined_bytecodes, int nm_total_size, int nm_insts_size,
jlong time_created, jlong time_queued, jlong time_started, jlong time_finished) {
// Use stringStream to avoid breaking the line
stringStream sst;
if (after_compile_details) {
{ // Print current time
stringStream ss;
ss.print(UINT64_FORMAT, (uint64_t) tty->time_stamp().milliseconds());
sst.print("%7s ", ss.freeze());
}
{ // Time waiting to be put on queue
stringStream ss;
if (time_created != 0 && time_queued != 0) {
ss.print("W%.1f", TimeHelper::counter_to_millis(time_queued - time_created));
}
sst.print("%7s ", ss.freeze());
}
{ // Time in queue
stringStream ss;
if (time_queued != 0 && time_started != 0) {
ss.print("Q%.1f", TimeHelper::counter_to_millis(time_started - time_queued));
}
sst.print("%7s ", ss.freeze());
}
{ // Time in compilation
stringStream ss;
if (time_started != 0 && time_finished != 0) {
ss.print("C%.1f", TimeHelper::counter_to_millis(time_finished - time_started));
}
sst.print("%7s ", ss.freeze());
}
} else if (!short_form) {
// Print current time
st->print(UINT64_FORMAT " ", (uint64_t) tty->time_stamp().milliseconds());
sst.print(UINT64_FORMAT " ", (uint64_t) tty->time_stamp().milliseconds());
if (Verbose && time_queued != 0) {
// Print time in queue and time being processed by compiler thread
jlong now = os::elapsed_counter();
st->print("%.0f ", TimeHelper::counter_to_millis(now-time_queued));
sst.print("%.0f ", TimeHelper::counter_to_millis(now-time_queued));
if (time_started != 0) {
st->print("%.0f ", TimeHelper::counter_to_millis(now-time_started));
sst.print("%.0f ", TimeHelper::counter_to_millis(now-time_started));
}
}
}
// print compiler name if requested
if (CIPrintCompilerName) {
st->print("%s:", CompileBroker::compiler_name(comp_level));
sst.print("%s:", compiler_name);
}
st->print("%4d ", compile_id); // print compilation number
sst.print("%4d ", compile_id); // print compilation number
bool is_synchronized = false;
bool has_exception_handler = false;
@ -208,40 +256,52 @@ void CompileTask::print_impl(outputStream* st, Method* method, int compile_id, i
const char native_char = is_native ? 'n' : ' ';
// print method attributes
st->print("%c%c%c%c%c ", compile_type, sync_char, exception_char, blocking_char, native_char);
sst.print("%c%c%c%c%c ", compile_type, sync_char, exception_char, blocking_char, native_char);
if (TieredCompilation) {
if (comp_level != -1) st->print("%d ", comp_level);
else st->print("- ");
if (comp_level != -1) sst.print("%d ", comp_level);
else sst.print("- ");
}
st->print(" "); // more indent
sst.print(" "); // more indent
if (method == nullptr) {
st->print("(method)");
sst.print("(method)");
} else {
method->print_short_name(st);
if (is_osr_method) {
st->print(" @ %d", osr_bci);
if (after_compile_details) {
sst.print("%s", method->name_and_sig_as_C_string(true /* use_double_colon */));
} else {
method->print_short_name(&sst);
}
if (method->is_native())
st->print(" (native)");
else
st->print(" (%d bytes)", method->code_size());
if (is_osr_method) {
sst.print(" @ %d", osr_bci);
}
if (method->is_native()) {
sst.print(" (native)");
} else {
sst.print(" (%d bytes)", method->code_size());
}
}
if (after_compile_details) {
sst.print(" (inlined %d)", inlined_bytecodes);
sst.print(" (size %d/%d)", nm_total_size, nm_insts_size);
}
if (msg != nullptr) {
st->print(" %s", msg);
sst.print(" %s", msg);
}
if (cr) {
st->cr();
sst.cr();
}
st->print("%s",sst.freeze());
}
// ------------------------------------------------------------------
// CompileTask::print_compilation
void CompileTask::print(outputStream* st, const char* msg, bool short_form, bool cr) {
bool is_osr_method = osr_bci() != InvocationEntryBci;
print_impl(st, is_unloaded() ? nullptr : method(), compile_id(), comp_level(), is_osr_method, osr_bci(), is_blocking(), msg, short_form, cr, _time_queued, _time_started);
print_impl(st, is_unloaded() ? nullptr : method(), compile_id(), comp_level(),
is_osr_method, osr_bci(), is_blocking(),
compiler()->name(), msg, short_form, cr);
}
// ------------------------------------------------------------------
@ -435,6 +495,7 @@ void CompileTask::print_ul(const nmethod* nm, const char* msg) {
nm->comp_level(), nm->is_osr_method(),
nm->is_osr_method() ? nm->osr_entry_bci() : -1,
/*is_blocking*/ false,
nm->compiler_name(),
msg, /* short form */ true, /* cr */ true);
}
}

View File

@ -93,7 +93,8 @@ class CompileTask : public CHeapObj<mtCompiler> {
CodeSection::csize_t _nm_content_size;
CodeSection::csize_t _nm_total_size;
CodeSection::csize_t _nm_insts_size;
DirectiveSet* _directive;
DirectiveSet* _directive;
AbstractCompiler* _compiler;
#if INCLUDE_JVMCI
bool _has_waiter;
// Compilation state for a blocking JVMCI compilation
@ -104,8 +105,10 @@ class CompileTask : public CHeapObj<mtCompiler> {
CompileTask* _next;
CompileTask* _prev;
// Fields used for logging why the compilation was initiated:
jlong _time_created; // time when task was created
jlong _time_queued; // time when task was enqueued
jlong _time_started; // time when compilation started
jlong _time_finished; // time when compilation finished
int _hot_count; // information about its invocation counter
CompileReason _compile_reason; // more info about the task
const char* _failure_reason;
@ -118,6 +121,7 @@ class CompileTask : public CHeapObj<mtCompiler> {
CompileTask(int compile_id, const methodHandle& method, int osr_bci, int comp_level,
int hot_count, CompileReason compile_reason, bool is_blocking);
~CompileTask();
static void wait_for_no_active_tasks();
int compile_id() const { return _compile_id; }
@ -127,6 +131,7 @@ class CompileTask : public CHeapObj<mtCompiler> {
bool is_blocking() const { return _is_blocking; }
bool is_success() const { return _is_success; }
DirectiveSet* directive() const { return _directive; }
CompileReason compile_reason() const { return _compile_reason; }
CodeSection::csize_t nm_content_size() { return _nm_content_size; }
void set_nm_content_size(CodeSection::csize_t size) { _nm_content_size = size; }
CodeSection::csize_t nm_insts_size() { return _nm_insts_size; }
@ -166,8 +171,9 @@ class CompileTask : public CHeapObj<mtCompiler> {
void mark_complete() { _is_complete = true; }
void mark_success() { _is_success = true; }
void mark_queued(jlong time) { _time_queued = time; }
void mark_started(jlong time) { _time_started = time; }
void mark_finished(jlong time) { _time_finished = time; }
int comp_level() { return _comp_level;}
void set_comp_level(int comp_level) { _comp_level = comp_level;}
@ -198,16 +204,20 @@ class CompileTask : public CHeapObj<mtCompiler> {
private:
static void print_impl(outputStream* st, Method* method, int compile_id, int comp_level,
bool is_osr_method = false, int osr_bci = -1, bool is_blocking = false,
const char* compiler_name = nullptr,
const char* msg = nullptr, bool short_form = false, bool cr = true,
jlong time_queued = 0, jlong time_started = 0);
bool after_compile_details = false,
int inlined_bytecodes = 0, int nm_total_size = 0, int nm_insts_size = 0,
jlong time_created = 0, jlong time_queued = 0,
jlong time_started = 0, jlong time_finished = 0);
public:
void print(outputStream* st = tty, const char* msg = nullptr, bool short_form = false, bool cr = true);
void print_ul(const char* msg = nullptr);
static void print(outputStream* st, const nmethod* nm, const char* msg = nullptr, bool short_form = false, bool cr = true) {
print_impl(st, nm->method(), nm->compile_id(), nm->comp_level(),
nm->is_osr_method(), nm->is_osr_method() ? nm->osr_entry_bci() : -1, /*is_blocking*/ false,
msg, short_form, cr);
nm->is_osr_method(), nm->is_osr_method() ? nm->osr_entry_bci() : -1, /*is_blocking*/ false,
nm->compiler_name(), msg, short_form, cr);
}
static void print_ul(const nmethod* nm, const char* msg = nullptr);
@ -217,6 +227,7 @@ public:
static void print_inline_indent(int inline_level, outputStream* st = tty);
void print_tty();
void print_post(outputStream* st);
void print_line_on_error(outputStream* st, char* buf, int buflen);
void log_task(xmlStream* log);

View File

@ -44,6 +44,7 @@
cflags(MemStat, uintx, 0, MemStat) \
cflags(PrintAssembly, bool, PrintAssembly, PrintAssembly) \
cflags(PrintCompilation, bool, PrintCompilation, PrintCompilation) \
cflags(PrintCompilation2, bool, PrintCompilation2, PrintCompilation2) \
cflags(PrintInlining, bool, PrintInlining, PrintInlining) \
cflags(PrintNMethods, bool, PrintNMethods, PrintNMethods) \
cflags(BackgroundCompilation, bool, BackgroundCompilation, BackgroundCompilation) \

View File

@ -63,6 +63,7 @@ class methodHandle;
option(MemStat, "MemStat", Uintx) \
option(PrintAssembly, "PrintAssembly", Bool) \
option(PrintCompilation, "PrintCompilation", Bool) \
option(PrintCompilation2, "PrintCompilation2", Bool) \
option(PrintInlining, "PrintInlining", Bool) \
option(PrintIntrinsics, "PrintIntrinsics", Bool) \
option(PrintNMethods, "PrintNMethods", Bool) \

View File

@ -184,24 +184,30 @@ address Method::get_c2i_no_clinit_check_entry() {
return adapter()->get_c2i_no_clinit_check_entry();
}
char* Method::name_and_sig_as_C_string() const {
return name_and_sig_as_C_string(constants()->pool_holder(), name(), signature());
char* Method::name_and_sig_as_C_string(bool use_double_colon) const {
return name_and_sig_as_C_string(constants()->pool_holder(), name(), signature(), use_double_colon);
}
char* Method::name_and_sig_as_C_string(char* buf, int size) const {
return name_and_sig_as_C_string(constants()->pool_holder(), name(), signature(), buf, size);
}
char* Method::name_and_sig_as_C_string(Klass* klass, Symbol* method_name, Symbol* signature) {
char* Method::name_and_sig_as_C_string(Klass* klass, Symbol* method_name, Symbol* signature, bool use_double_colon) {
const char* klass_name = klass->external_name();
int klass_name_len = (int)strlen(klass_name);
int method_name_len = method_name->utf8_length();
int len = klass_name_len + 1 + method_name_len + signature->utf8_length();
int separator_len = use_double_colon ? 2 : 1;
int len = klass_name_len + separator_len + method_name_len + signature->utf8_length();
char* dest = NEW_RESOURCE_ARRAY(char, len + 1);
strcpy(dest, klass_name);
dest[klass_name_len] = '.';
strcpy(&dest[klass_name_len + 1], method_name->as_C_string());
strcpy(&dest[klass_name_len + 1 + method_name_len], signature->as_C_string());
if (use_double_colon) {
dest[klass_name_len + 0] = ':';
dest[klass_name_len + 1] = ':';
} else {
dest[klass_name_len] = '.';
}
strcpy(&dest[klass_name_len + separator_len], method_name->as_C_string());
strcpy(&dest[klass_name_len + separator_len + method_name_len], signature->as_C_string());
dest[len] = 0;
return dest;
}

View File

@ -171,11 +171,11 @@ class Method : public Metadata {
// C string, for the purpose of providing more useful
// fatal error handling. The string is allocated in resource
// area if a buffer is not provided by the caller.
char* name_and_sig_as_C_string() const;
char* name_and_sig_as_C_string(bool use_double_colon = false) const;
char* name_and_sig_as_C_string(char* buf, int size) const;
// Static routine in the situations we don't have a Method*
static char* name_and_sig_as_C_string(Klass* klass, Symbol* method_name, Symbol* signature);
static char* name_and_sig_as_C_string(Klass* klass, Symbol* method_name, Symbol* signature, bool use_double_colon = false);
static char* name_and_sig_as_C_string(Klass* klass, Symbol* method_name, Symbol* signature, char* buf, int size);
// Get return type + klass name + "." + method name + ( parameters types )

View File

@ -0,0 +1,86 @@
/*
* Copyright (c) 2026, 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 8255746
* @summary Checks that -XX:+UnlockDiagnosticVMOptions -XX:CompileCommand=PrintCompilation2,... works
* @library /test/lib
* @run driver compiler.print.CompileCommandPrintCompilation2
*/
package compiler.print;
import java.util.ArrayList;
import java.util.List;
import jdk.test.lib.Asserts;
import jdk.test.lib.process.OutputAnalyzer;
import jdk.test.lib.process.ProcessTools;
public class CompileCommandPrintCompilation2 {
final static String METHOD1 = "method1";
final static String METHOD2 = "method2";
public static void main(String[] args) throws Exception {
test(METHOD1, METHOD2);
test(METHOD2, METHOD1);
}
private static void test(String include, String exclude) throws Exception {
List<String> options = new ArrayList<String>();
options.add("-Xcomp");
options.add("-XX:-Inline");
options.add("-XX:CompileCommand=compileonly," + getTestClass() + "::*");
options.add("-XX:+UnlockDiagnosticVMOptions");
options.add("-XX:CompileCommand=PrintCompilation2," + getTestMethod(include));
options.add(getTestClass());
OutputAnalyzer oa = ProcessTools.executeTestJava(options);
oa.shouldHaveExitValue(0)
.shouldContain(getTestMethod(include))
.shouldNotContain(getTestMethod(exclude));
}
// Test class that is invoked by the sub process
public static String getTestClass() {
return TestMain.class.getName();
}
public static String getTestMethod(String method) {
return getTestClass() + "::" + method;
}
public static class TestMain {
public static void main(String[] args) {
method1();
method2();
}
static void method1() {}
static void method2() {}
}
}

View File

@ -0,0 +1,82 @@
/*
* Copyright (c) 2026, 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
* @summary Checks that -XX:PrintCompilation2 works
* @library /test/lib
* @run driver compiler.print.PrintCompilation2
*/
package compiler.print;
import java.util.ArrayList;
import java.util.List;
import jdk.test.lib.Asserts;
import jdk.test.lib.process.OutputAnalyzer;
import jdk.test.lib.process.ProcessTools;
public class PrintCompilation2 {
public static void main(String[] args) throws Exception {
List<String> options = new ArrayList<String>();
options.add("-XX:+UnlockDiagnosticVMOptions");
options.add("-XX:+PrintCompilation2");
options.add("-Xcomp");
options.add("-XX:-Inline");
options.add("-XX:CompileCommand=compileonly," + getTestClass() + "::*");
options.add(getTestClass());
OutputAnalyzer oa = ProcessTools.executeTestJava(options);
oa.shouldHaveExitValue(0)
.shouldContain(getTestMethod("method1"))
.shouldContain(getTestMethod("method2"))
.shouldContain(getTestMethod("method3"))
.shouldNotContain(getTestMethod("notcalled"));
}
// Test class that is invoked by the sub process
public static String getTestClass() {
return TestMain.class.getName();
}
public static String getTestMethod(String method) {
return getTestClass() + "::" + method;
}
public static class TestMain {
public static void main(String[] args) {
method1();
method2();
method3();
}
static void method1() { System.out.println("method1()"); }
static void method2() {}
static void method3() {}
static void notcalled() {}
}
}