8379015: Convert TraceNewOopMapGeneration to unified logging

Reviewed-by: dholmes, matsaave
This commit is contained in:
Coleen Phillimore 2026-03-18 16:07:41 +00:00
parent 766959f884
commit 446fb203b2
7 changed files with 139 additions and 85 deletions

View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2022, 2025, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2022, 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
@ -224,6 +224,7 @@ void ClassPrinter::print_flags_help(outputStream* os) {
os->print_cr(" 0x%02x - print info for invokehandle", PRINT_METHOD_HANDLE);
os->print_cr(" 0x%02x - print details of the C++ and Java objects that represent classes", PRINT_CLASS_DETAILS);
os->print_cr(" 0x%02x - print details of the C++ objects that represent methods", PRINT_METHOD_DETAILS);
os->print_cr(" 0x%02x - print MethodData", PRINT_METHOD_DATA);
os->cr();
}

View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2022, 2025, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2022, 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
@ -54,6 +54,7 @@ public:
PRINT_METHOD_HANDLE = 1 << 4, // extra information for invokehandle
PRINT_CLASS_DETAILS = 1 << 5, // print details of the C++ and Java objects that represent classes
PRINT_METHOD_DETAILS = 1 << 6, // print details of the C++ objects that represent methods
PRINT_METHOD_DATA = 1 << 7, // print MethodData - requires MDO lock
};
static bool has_mode(int flags, Mode mode) {
return (flags & static_cast<int>(mode)) != 0;

View File

@ -78,7 +78,7 @@ class BytecodePrinter {
void print_field_or_method(int cp_index, outputStream* st);
void print_dynamic(int cp_index, outputStream* st);
void print_attributes(int bci, outputStream* st);
void bytecode_epilog(int bci, outputStream* st);
void print_method_data_at(int bci, outputStream* st);
public:
BytecodePrinter(int flags = 0) : _is_wide(false), _code(Bytecodes::_illegal), _flags(flags) {}
@ -171,7 +171,9 @@ class BytecodePrinter {
}
_next_pc = is_wide() ? bcp+2 : bcp+1;
print_attributes(bci, st);
bytecode_epilog(bci, st);
if (ClassPrinter::has_mode(_flags, ClassPrinter::PRINT_METHOD_DATA)) {
print_method_data_at(bci, st);
}
}
};
@ -598,7 +600,7 @@ void BytecodePrinter::print_attributes(int bci, outputStream* st) {
}
void BytecodePrinter::bytecode_epilog(int bci, outputStream* st) {
void BytecodePrinter::print_method_data_at(int bci, outputStream* st) {
MethodData* mdo = method()->method_data();
if (mdo != nullptr) {

View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2015, 2025, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2015, 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
@ -90,6 +90,7 @@ class outputStream;
LOG_TAG(freelist) \
LOG_TAG(gc) \
NOT_PRODUCT(LOG_TAG(generate)) \
LOG_TAG(generateoopmap) \
LOG_TAG(handshake) \
LOG_TAG(hashtables) \
LOG_TAG(heap) \

View File

@ -400,9 +400,7 @@ void GenerateOopMap::bb_mark_fct(GenerateOopMap *c, int bci, int *data) {
if (c->is_bb_header(bci))
return;
if (TraceNewOopMapGeneration) {
tty->print_cr("Basicblock#%d begins at: %d", c->_bb_count, bci);
}
log_debug(generateoopmap)( "Basicblock#%d begins at: %d", c->_bb_count, bci);
c->set_bbmark_bit(bci);
c->_bb_count++;
}
@ -913,13 +911,12 @@ void GenerateOopMap::do_interpretation()
// iterated more than once.
int i = 0;
do {
#ifndef PRODUCT
if (TraceNewOopMapGeneration) {
tty->print("\n\nIteration #%d of do_interpretation loop, method:\n", i);
method()->print_name(tty);
tty->print("\n\n");
if (log_is_enabled(Trace, generateoopmap)) {
LogStream st(Log(generateoopmap)::trace());
st.print("Iteration #%d of do_interpretation loop, method:", i);
method()->print_name(&st);
st.print("\n\n");
}
#endif
_conflict = false;
_monitor_safe = true;
// init_state is now called from init_basic_blocks. The length of a
@ -1084,8 +1081,7 @@ void GenerateOopMap::initialize_vars() {
void GenerateOopMap::add_to_ref_init_set(int localNo) {
if (TraceNewOopMapGeneration)
tty->print_cr("Added init vars: %d", localNo);
log_debug(generateoopmap)("Added init vars: %d", localNo);
// Is it already in the set?
if (_init_vars->contains(localNo) )
@ -1284,13 +1280,13 @@ void GenerateOopMap::report_monitor_mismatch(const char *msg) {
void GenerateOopMap::print_states(outputStream *os,
CellTypeState* vec, int num) {
for (int i = 0; i < num; i++) {
vec[i].print(tty);
vec[i].print(os);
}
}
// Print the state values at the current bytecode.
void GenerateOopMap::print_current_state(outputStream *os,
BytecodeStream *currentBC,
void GenerateOopMap::print_current_state(outputStream* os,
BytecodeStream* currentBC,
bool detailed) {
if (detailed) {
os->print(" %4d vars = ", currentBC->bci());
@ -1312,6 +1308,7 @@ void GenerateOopMap::print_current_state(outputStream *os,
case Bytecodes::_invokestatic:
case Bytecodes::_invokedynamic:
case Bytecodes::_invokeinterface: {
ResourceMark rm;
int idx = currentBC->has_index_u4() ? currentBC->get_index_u4() : currentBC->get_index_u2();
ConstantPool* cp = method()->constants();
int nameAndTypeIdx = cp->name_and_type_ref_index_at(idx, currentBC->code());
@ -1342,8 +1339,9 @@ void GenerateOopMap::print_current_state(outputStream *os,
// Sets the current state to be the state after executing the
// current instruction, starting in the current state.
void GenerateOopMap::interp1(BytecodeStream *itr) {
if (TraceNewOopMapGeneration) {
print_current_state(tty, itr, TraceNewOopMapGenerationDetailed);
if (log_is_enabled(Trace, generateoopmap)) {
LogStream st(Log(generateoopmap)::trace());
print_current_state(&st, itr, Verbose);
}
// Should we report the results? Result is reported *before* the instruction at the current bci is executed.
@ -2026,9 +2024,7 @@ void GenerateOopMap::ret_jump_targets_do(BytecodeStream *bcs, jmpFct_t jmpFct, i
DEBUG_ONLY(BasicBlock* target_bb = &jsr_bb[1];)
assert(target_bb == get_basic_block_at(target_bci), "wrong calc. of successor basicblock");
bool alive = jsr_bb->is_alive();
if (TraceNewOopMapGeneration) {
tty->print("pc = %d, ret -> %d alive: %s\n", bci, target_bci, alive ? "true" : "false");
}
log_debug(generateoopmap)("pc = %d, ret -> %d alive: %s", bci, target_bci, alive ? "true" : "false");
if (alive) jmpFct(this, target_bci, data);
}
}
@ -2046,6 +2042,7 @@ char* GenerateOopMap::state_vec_to_string(CellTypeState* vec, int len) {
return _state_vec_buf;
}
#ifndef PRODUCT
void GenerateOopMap::print_time() {
tty->print_cr ("Accumulated oopmap times:");
tty->print_cr ("---------------------------");
@ -2053,6 +2050,7 @@ void GenerateOopMap::print_time() {
tty->print_cr (" (%3.0f bytecodes per sec) ",
(double)GenerateOopMap::_total_byte_count / GenerateOopMap::_total_oopmap_time.seconds());
}
#endif
//
// ============ Main Entry Point ===========
@ -2062,27 +2060,16 @@ GenerateOopMap::GenerateOopMap(const methodHandle& method) {
_method = method;
_max_locals=0;
_init_vars = nullptr;
#ifndef PRODUCT
// If we are doing a detailed trace, include the regular trace information.
if (TraceNewOopMapGenerationDetailed) {
TraceNewOopMapGeneration = true;
}
#endif
}
bool GenerateOopMap::compute_map(Thread* current) {
#ifndef PRODUCT
if (TimeOopMap2) {
method()->print_short_name(tty);
tty->print(" ");
}
if (TimeOopMap) {
_total_byte_count += method()->code_size();
TraceTime t_all(nullptr, &_total_oopmap_time, TimeOopMap);
}
#endif
TraceTime t_single("oopmap time", TimeOopMap2);
TraceTime t_all(nullptr, &_total_oopmap_time, TimeOopMap);
TraceTime t_single("oopmap time", TRACETIME_LOG(Debug, generateoopmap));
// Initialize values
_got_error = false;
@ -2099,16 +2086,16 @@ bool GenerateOopMap::compute_map(Thread* current) {
_did_rewriting = false;
_did_relocation = false;
if (TraceNewOopMapGeneration) {
tty->print("Method name: %s\n", method()->name()->as_C_string());
if (Verbose) {
_method->print_codes();
tty->print_cr("Exception table:");
ExceptionTable excps(method());
for(int i = 0; i < excps.length(); i ++) {
tty->print_cr("[%d - %d] -> %d",
excps.start_pc(i), excps.end_pc(i), excps.handler_pc(i));
}
if (log_is_enabled(Debug, generateoopmap)) {
ResourceMark rm;
LogStream st(Log(generateoopmap)::debug());
st.print_cr("Method name: %s\n", method()->name()->as_C_string());
_method->print_codes_on(&st);
st.print_cr("Exception table:");
ExceptionTable excps(method());
for (int i = 0; i < excps.length(); i ++) {
st.print_cr("[%d - %d] -> %d",
excps.start_pc(i), excps.end_pc(i), excps.handler_pc(i));
}
}
@ -2175,7 +2162,7 @@ void GenerateOopMap::verify_error(const char *format, ...) {
//
void GenerateOopMap::report_result() {
if (TraceNewOopMapGeneration) tty->print_cr("Report result pass");
log_debug(generateoopmap)("Report result pass");
// We now want to report the result of the parse
_report_result = true;
@ -2192,7 +2179,7 @@ void GenerateOopMap::report_result() {
}
void GenerateOopMap::result_for_basicblock(int bci) {
if (TraceNewOopMapGeneration) tty->print_cr("Report result pass for basicblock");
log_debug(generateoopmap)("Report result pass for basicblock");
// We now want to report the result of the parse
_report_result = true;
@ -2200,7 +2187,7 @@ void GenerateOopMap::result_for_basicblock(int bci) {
// Find basicblock and report results
BasicBlock* bb = get_basic_block_containing(bci);
guarantee(bb != nullptr, "no basic block for bci");
assert(bb->is_reachable(), "getting result from unreachable basicblock");
assert(bb->is_reachable(), "getting result from unreachable basicblock %d", bci);
bb->set_changed(true);
interp_bb(bb);
}
@ -2212,9 +2199,7 @@ void GenerateOopMap::result_for_basicblock(int bci) {
void GenerateOopMap::record_refval_conflict(int varNo) {
assert(varNo>=0 && varNo< _max_locals, "index out of range");
if (TraceOopMapRewrites) {
tty->print("### Conflict detected (local no: %d)\n", varNo);
}
log_trace(generateoopmap)("### Conflict detected (local no: %d)", varNo);
if (!_new_var_map) {
_new_var_map = NEW_RESOURCE_ARRAY(int, _max_locals);
@ -2253,10 +2238,12 @@ void GenerateOopMap::rewrite_refval_conflicts()
// Tracing flag
_did_rewriting = true;
if (TraceOopMapRewrites) {
tty->print_cr("ref/value conflict for method %s - bytecodes are getting rewritten", method()->name()->as_C_string());
method()->print();
method()->print_codes();
if (log_is_enabled(Trace, generateoopmap)) {
ResourceMark rm;
LogStream st(Log(generateoopmap)::trace());
st.print_cr("ref/value conflict for method %s - bytecodes are getting rewritten", method()->name()->as_C_string());
method()->print_on(&st);
method()->print_codes_on(&st);
}
assert(_new_var_map!=nullptr, "nothing to rewrite");
@ -2266,9 +2253,7 @@ void GenerateOopMap::rewrite_refval_conflicts()
if (!_got_error) {
for (int k = 0; k < _max_locals && !_got_error; k++) {
if (_new_var_map[k] != k) {
if (TraceOopMapRewrites) {
tty->print_cr("Rewriting: %d -> %d", k, _new_var_map[k]);
}
log_trace(generateoopmap)("Rewriting: %d -> %d", k, _new_var_map[k]);
rewrite_refval_conflict(k, _new_var_map[k]);
if (_got_error) return;
nof_conflicts++;
@ -2319,22 +2304,16 @@ bool GenerateOopMap::rewrite_refval_conflict_inst(BytecodeStream *itr, int from,
int bci = itr->bci();
if (is_aload(itr, &index) && index == from) {
if (TraceOopMapRewrites) {
tty->print_cr("Rewriting aload at bci: %d", bci);
}
log_trace(generateoopmap)("Rewriting aload at bci: %d", bci);
return rewrite_load_or_store(itr, Bytecodes::_aload, Bytecodes::_aload_0, to);
}
if (is_astore(itr, &index) && index == from) {
if (!stack_top_holds_ret_addr(bci)) {
if (TraceOopMapRewrites) {
tty->print_cr("Rewriting astore at bci: %d", bci);
}
log_trace(generateoopmap)("Rewriting astore at bci: %d", bci);
return rewrite_load_or_store(itr, Bytecodes::_astore, Bytecodes::_astore_0, to);
} else {
if (TraceOopMapRewrites) {
tty->print_cr("Suppress rewriting of astore at bci: %d", bci);
}
log_trace(generateoopmap)("Suppress rewriting of astore at bci: %d", bci);
}
}
@ -2502,9 +2481,7 @@ void GenerateOopMap::compute_ret_adr_at_TOS() {
// TDT: should this be is_good_address() ?
if (_stack_top > 0 && stack()[_stack_top-1].is_address()) {
_ret_adr_tos->append(bcs.bci());
if (TraceNewOopMapGeneration) {
tty->print_cr("Ret_adr TOS at bci: %d", bcs.bci());
}
log_debug(generateoopmap)("Ret_adr TOS at bci: %d", bcs.bci());
}
interp1(&bcs);
}

View File

@ -871,21 +871,9 @@ const int ObjectAlignmentInBytes = 8;
develop(bool, VerifyDependencies, trueInDebug, \
"Exercise and verify the compilation dependency mechanism") \
\
develop(bool, TraceNewOopMapGeneration, false, \
"Trace OopMapGeneration") \
\
develop(bool, TraceNewOopMapGenerationDetailed, false, \
"Trace OopMapGeneration: print detailed cell states") \
\
develop(bool, TimeOopMap, false, \
"Time calls to GenerateOopMap::compute_map() in sum") \
\
develop(bool, TimeOopMap2, false, \
"Time calls to GenerateOopMap::compute_map() individually") \
\
develop(bool, TraceOopMapRewrites, false, \
"Trace rewriting of methods during oop map generation") \
\
develop(bool, TraceFinalizerRegistration, false, \
"Trace registration of final references") \
\

View File

@ -0,0 +1,84 @@
/*
* 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 GenerateOopMap
* @bug 8379015
* @requires vm.flagless
* @modules java.base/jdk.internal.misc
* @library /test/lib
* @run driver GenerateOopMapTest
*/
import java.nio.file.Files;
import java.nio.file.Path;
import java.util.regex.Matcher;
import java.util.regex.Pattern;
import jdk.test.lib.process.OutputAnalyzer;
import jdk.test.lib.process.ProcessTools;
import jdk.test.lib.Platform;
public class GenerateOopMapTest {
static String infoPattern = "[generateoopmap]";
static String debugPattern = "[generateoopmap] Basicblock#0 begins at:";
static String tracePattern = "[trace][generateoopmap] 5 vars = 'r' stack = 'v' monitors = '' \tifne";
static String traceDetailPattern = "[generateoopmap] 0 vars = ( r |slot0) invokestatic()V";
static void test() throws Exception {
// Don't print much with info level.
ProcessBuilder pb = ProcessTools.createLimitedTestJavaProcessBuilder("-Xlog:generateoopmap=info",
"GenerateOopMapTest", "test");
OutputAnalyzer o = new OutputAnalyzer(pb.start());
o.shouldNotContain(infoPattern).shouldHaveExitValue(0);
// Prints bytecodes and BasicBlock information in debug.
pb = ProcessTools.createLimitedTestJavaProcessBuilder("-Xlog:generateoopmap=debug",
"GenerateOopMapTest", "test");
o = new OutputAnalyzer(pb.start());
o.shouldContain(debugPattern).shouldHaveExitValue(0);
// Prints ref/val for each bytecode in trace.
pb = ProcessTools.createLimitedTestJavaProcessBuilder("-Xlog:generateoopmap=trace",
"GenerateOopMapTest", "test");
o = new OutputAnalyzer(pb.start());
o.shouldContain(tracePattern).shouldHaveExitValue(0);
// Prints extra stuff with detailed. Not sure how useful this is but keep it for now.
if (Platform.isDebugBuild()) {
pb = ProcessTools.createLimitedTestJavaProcessBuilder("-Xlog:generateoopmap=trace",
"-XX:+Verbose",
"GenerateOopMapTest", "test");
o = new OutputAnalyzer(pb.start());
o.shouldContain(traceDetailPattern).shouldHaveExitValue(0);
}
};
public static void main(String... args) throws Exception {
System.gc();
if (args.length == 0) {
test();
}
}
}