Skip to content
This repository has been archived by the owner. It is now read-only.
Permalink
Browse files
8248321: [JVMCI] improve libgraal logging and fatal error handling
Reviewed-by: kvn, never
  • Loading branch information
Doug Simon committed Jul 2, 2020
1 parent 1356a0f commit 4e962f967548820dc0dd0dff0456a89c5244a056
Show file tree
Hide file tree
Showing 14 changed files with 188 additions and 86 deletions.
@@ -21,7 +21,8 @@
* questions.
*/

#include "jvmci/jvmciCodeInstaller.hpp"
#include "jvmci/jvmci.hpp"
#include "jvmci/jvmciCodeInstaller.hpp"
#include "jvmci/jvmciRuntime.hpp"
#include "jvmci/jvmciCompilerToVM.hpp"
#include "jvmci/jvmciJavaClasses.hpp"
@@ -72,12 +73,12 @@ void CodeInstaller::pd_patch_MetaspaceConstant(int pc_offset, JVMCIObject consta
if (jvmci_env()->get_HotSpotMetaspaceConstantImpl_compressed(constant)) {
narrowKlass narrowOop = record_narrow_metadata_reference(_instructions, pc, constant, JVMCI_CHECK);
MacroAssembler::patch_narrow_klass(pc, narrowOop);
TRACE_jvmci_3("relocating (narrow metaspace constant) at " PTR_FORMAT "/0x%x", p2i(pc), narrowOop);
JVMCI_event_3("relocating (narrow metaspace constant) at " PTR_FORMAT "/0x%x", p2i(pc), narrowOop);
} else {
NativeMovConstReg* move = nativeMovConstReg_at(pc);
void* reference = record_metadata_reference(_instructions, pc, constant, JVMCI_CHECK);
move->set_data((intptr_t) reference);
TRACE_jvmci_3("relocating (metaspace constant) at " PTR_FORMAT "/" PTR_FORMAT, p2i(pc), p2i(reference));
JVMCI_event_3("relocating (metaspace constant) at " PTR_FORMAT "/" PTR_FORMAT, p2i(pc), p2i(reference));
}
}

@@ -88,7 +89,7 @@ void CodeInstaller::pd_patch_DataSectionReference(int pc_offset, int data_offset
|| (NativeInstruction::maybe_cpool_ref(pc))) {
address dest = _constants->start() + data_offset;
_instructions->relocate(pc, section_word_Relocation::spec((address) dest, CodeBuffer::SECT_CONSTS));
TRACE_jvmci_3("relocating at " PTR_FORMAT " (+%d) with destination at %d", p2i(pc), pc_offset, data_offset);
JVMCI_event_3("relocating at " PTR_FORMAT " (+%d) with destination at %d", p2i(pc), pc_offset, data_offset);
} else {
JVMCI_ERROR("unknown load or move instruction at " PTR_FORMAT, p2i(pc));
}
@@ -115,7 +116,7 @@ void CodeInstaller::pd_relocate_ForeignCall(NativeInstruction* inst, jlong forei
} else {
JVMCI_ERROR("unknown call or jump instruction at " PTR_FORMAT, p2i(pc));
}
TRACE_jvmci_3("relocating (foreign call) at " PTR_FORMAT, p2i(inst));
JVMCI_event_3("relocating (foreign call) at " PTR_FORMAT, p2i(inst));
}

void CodeInstaller::pd_relocate_JavaMethod(CodeBuffer &cbuf, JVMCIObject hotspot_method, jint pc_offset, JVMCI_TRAPS) {
@@ -27,6 +27,7 @@
#include "runtime/handles.inline.hpp"
#include "runtime/javaCalls.hpp"
#include "runtime/sharedRuntime.hpp"
#include "jvmci/jvmci.hpp"
#include "jvmci/jvmciEnv.hpp"
#include "jvmci/jvmciCodeInstaller.hpp"
#include "jvmci/jvmciJavaClasses.hpp"
@@ -74,15 +75,15 @@ void CodeInstaller::pd_patch_OopConstant(int pc_offset, JVMCIObject constant, JV
address operand = Assembler::locate_operand(pc, Assembler::narrow_oop_operand);
int oop_index = _oop_recorder->find_index(value);
_instructions->relocate(pc, oop_Relocation::spec(oop_index), Assembler::narrow_oop_operand);
TRACE_jvmci_3("relocating (narrow oop constant) at " PTR_FORMAT "/" PTR_FORMAT, p2i(pc), p2i(operand));
JVMCI_event_3("relocating (narrow oop constant) at " PTR_FORMAT "/" PTR_FORMAT, p2i(pc), p2i(operand));
#else
JVMCI_ERROR("compressed oop on 32bit");
#endif
} else {
address operand = Assembler::locate_operand(pc, Assembler::imm_operand);
*((jobject*) operand) = value;
_instructions->relocate(pc, oop_Relocation::spec_for_immediate(), Assembler::imm_operand);
TRACE_jvmci_3("relocating (oop constant) at " PTR_FORMAT "/" PTR_FORMAT, p2i(pc), p2i(operand));
JVMCI_event_3("relocating (oop constant) at " PTR_FORMAT "/" PTR_FORMAT, p2i(pc), p2i(operand));
}
}

@@ -92,14 +93,14 @@ void CodeInstaller::pd_patch_MetaspaceConstant(int pc_offset, JVMCIObject consta
#ifdef _LP64
address operand = Assembler::locate_operand(pc, Assembler::narrow_oop_operand);
*((narrowKlass*) operand) = record_narrow_metadata_reference(_instructions, operand, constant, JVMCI_CHECK);
TRACE_jvmci_3("relocating (narrow metaspace constant) at " PTR_FORMAT "/" PTR_FORMAT, p2i(pc), p2i(operand));
JVMCI_event_3("relocating (narrow metaspace constant) at " PTR_FORMAT "/" PTR_FORMAT, p2i(pc), p2i(operand));
#else
JVMCI_ERROR("compressed Klass* on 32bit");
#endif
} else {
address operand = Assembler::locate_operand(pc, Assembler::imm_operand);
*((void**) operand) = record_metadata_reference(_instructions, operand, constant, JVMCI_CHECK);
TRACE_jvmci_3("relocating (metaspace constant) at " PTR_FORMAT "/" PTR_FORMAT, p2i(pc), p2i(operand));
JVMCI_event_3("relocating (metaspace constant) at " PTR_FORMAT "/" PTR_FORMAT, p2i(pc), p2i(operand));
}
}

@@ -115,7 +116,7 @@ void CodeInstaller::pd_patch_DataSectionReference(int pc_offset, int data_offset
*((jint*) operand) = (jint) disp;

_instructions->relocate(pc, section_word_Relocation::spec((address) dest, CodeBuffer::SECT_CONSTS), Assembler::disp32_operand);
TRACE_jvmci_3("relocating at " PTR_FORMAT "/" PTR_FORMAT " with destination at " PTR_FORMAT " (%d)", p2i(pc), p2i(operand), p2i(dest), data_offset);
JVMCI_event_3("relocating at " PTR_FORMAT "/" PTR_FORMAT " with destination at " PTR_FORMAT " (%d)", p2i(pc), p2i(operand), p2i(dest), data_offset);
}

void CodeInstaller::pd_relocate_ForeignCall(NativeInstruction* inst, jlong foreign_call_destination, JVMCI_TRAPS) {
@@ -143,7 +144,7 @@ void CodeInstaller::pd_relocate_ForeignCall(NativeInstruction* inst, jlong forei
JVMCI_ERROR("unsupported relocation for foreign call");
}

TRACE_jvmci_3("relocating (foreign call) at " PTR_FORMAT, p2i(inst));
JVMCI_event_3("relocating (foreign call) at " PTR_FORMAT, p2i(inst));
}

void CodeInstaller::pd_relocate_JavaMethod(CodeBuffer &, JVMCIObject hotspot_method, jint pc_offset, JVMCI_TRAPS) {
@@ -37,6 +37,8 @@ volatile bool JVMCI::_is_initialized = false;
void* JVMCI::_shared_library_handle = NULL;
char* JVMCI::_shared_library_path = NULL;
volatile bool JVMCI::_in_shutdown = false;
StringEventLog* JVMCI::_events = NULL;
StringEventLog* JVMCI::_verbose_events = NULL;

void jvmci_vmStructs_init() NOT_DEBUG_RETURN;

@@ -80,7 +82,7 @@ void* JVMCI::get_shared_library(char*& path, bool load) {
_shared_library_handle = handle;
_shared_library_path = strdup(path);

TRACE_jvmci_1("loaded JVMCI shared library from %s", path);
JVMCI_event_1("loaded JVMCI shared library from %s", path);
}
path = _shared_library_path;
return _shared_library_handle;
@@ -97,6 +99,19 @@ void JVMCI::initialize_compiler(TRAPS) {

void JVMCI::initialize_globals() {
jvmci_vmStructs_init();
if (LogEvents) {
if (JVMCIEventLogLevel > 0) {
_events = new StringEventLog("JVMCI Events", "jvmci");
if (JVMCIEventLogLevel > 1) {
int count = LogEventsBufferEntries;
for (int i = 1; i < JVMCIEventLogLevel && i < max_EventLog_level; i++) {
// Expand event buffer by 10x for each level above 1
count = count * 10;
}
_verbose_events = new StringEventLog("Verbose JVMCI Events", "verbose-jvmci", count);
}
}
}
if (UseJVMCINativeLibrary) {
// There are two runtimes.
_compiler_runtime = new JVMCIRuntime(0);
@@ -137,7 +152,7 @@ void JVMCI::shutdown() {
{
MutexLocker locker(JVMCI_lock);
_in_shutdown = true;
TRACE_jvmci_1("shutting down JVMCI");
JVMCI_event_1("shutting down JVMCI");
}
JVMCIRuntime* java_runtime = _java_runtime;
if (java_runtime != compiler_runtime()) {
@@ -151,3 +166,38 @@ void JVMCI::shutdown() {
bool JVMCI::in_shutdown() {
return _in_shutdown;
}

void JVMCI::vlog(int level, const char* format, va_list ap) {
if (LogEvents && JVMCIEventLogLevel >= level) {
StringEventLog* events = level == 1 ? _events : _verbose_events;
guarantee(events != NULL, "JVMCI event log not yet initialized");
Thread* thread = Thread::current_or_null_safe();
events->logv(thread, format, ap);
}
}

void JVMCI::vtrace(int level, const char* format, va_list ap) {
if (JVMCITraceLevel >= level) {
Thread* thread = Thread::current_or_null_safe();
if (thread != NULL) {
ResourceMark rm;
tty->print("JVMCITrace-%d[%s]:%*c", level, thread->name(), level, ' ');
} else {
tty->print("JVMCITrace-%d[?]:%*c", level, level, ' ');
}
tty->vprint_cr(format, ap);
}
}

#define LOG_TRACE(level) { va_list ap; \
va_start(ap, format); vlog(level, format, ap); va_end(ap); \
va_start(ap, format); vtrace(level, format, ap); va_end(ap); \
}

void JVMCI::event(int level, const char* format, ...) LOG_TRACE(level)
void JVMCI::event1(const char* format, ...) LOG_TRACE(1)
void JVMCI::event2(const char* format, ...) LOG_TRACE(2)
void JVMCI::event3(const char* format, ...) LOG_TRACE(3)
void JVMCI::event4(const char* format, ...) LOG_TRACE(4)

#undef LOG_TRACE
@@ -25,6 +25,7 @@
#define SHARE_JVMCI_JVMCI_HPP

#include "compiler/compilerDefinitions.hpp"
#include "utilities/events.hpp"
#include "utilities/exceptions.hpp"

class BoolObjectClosure;
@@ -65,6 +66,16 @@ class JVMCI : public AllStatic {
// Access to the HotSpot heap based JVMCIRuntime
static JVMCIRuntime* _java_runtime;

// JVMCI event log (shows up in hs_err crash logs).
static StringEventLog* _events;
static StringEventLog* _verbose_events;
enum {
max_EventLog_level = 4
};

// Gets the Thread* value for the current thread or NULL if it's not available.
static Thread* current_thread_or_null();

public:
enum CodeInstallResult {
ok,
@@ -103,6 +114,26 @@ class JVMCI : public AllStatic {
// Gets the single runtime for JVMCI on the Java heap. This is the only
// JVMCI runtime available when !UseJVMCINativeLibrary.
static JVMCIRuntime* java_runtime() { return _java_runtime; }

// Appends an event to the JVMCI event log if JVMCIEventLogLevel >= `level`
static void vlog(int level, const char* format, va_list ap) ATTRIBUTE_PRINTF(2, 0);

// Traces an event to tty if JVMCITraceLevel >= `level`
static void vtrace(int level, const char* format, va_list ap) ATTRIBUTE_PRINTF(2, 0);

public:
// Log/trace a JVMCI event
static void event(int level, const char* format, ...) ATTRIBUTE_PRINTF(2, 3);
static void event1(const char* format, ...) ATTRIBUTE_PRINTF(1, 2);
static void event2(const char* format, ...) ATTRIBUTE_PRINTF(1, 2);
static void event3(const char* format, ...) ATTRIBUTE_PRINTF(1, 2);
static void event4(const char* format, ...) ATTRIBUTE_PRINTF(1, 2);
};

// JVMCI event macros.
#define JVMCI_event_1 if (JVMCITraceLevel < 1 && JVMCIEventLogLevel < 1) ; else ::JVMCI::event1
#define JVMCI_event_2 if (JVMCITraceLevel < 2 && JVMCIEventLogLevel < 2) ; else ::JVMCI::event2
#define JVMCI_event_3 if (JVMCITraceLevel < 3 && JVMCIEventLogLevel < 3) ; else ::JVMCI::event3
#define JVMCI_event_4 if (JVMCITraceLevel < 4 && JVMCIEventLogLevel < 4) ; else ::JVMCI::event4

#endif // SHARE_JVMCI_JVMCI_HPP
@@ -245,14 +245,14 @@ void* CodeInstaller::record_metadata_reference(CodeSection* section, address des
assert(!jvmci_env()->get_HotSpotMetaspaceConstantImpl_compressed(constant), "unexpected compressed klass pointer %s @ " INTPTR_FORMAT, klass->name()->as_C_string(), p2i(klass));
int index = _oop_recorder->find_index(klass);
section->relocate(dest, metadata_Relocation::spec(index));
TRACE_jvmci_3("metadata[%d of %d] = %s", index, _oop_recorder->metadata_count(), klass->name()->as_C_string());
JVMCI_event_3("metadata[%d of %d] = %s", index, _oop_recorder->metadata_count(), klass->name()->as_C_string());
return klass;
} else if (jvmci_env()->isa_HotSpotResolvedJavaMethodImpl(obj)) {
Method* method = jvmci_env()->asMethod(obj);
assert(!jvmci_env()->get_HotSpotMetaspaceConstantImpl_compressed(constant), "unexpected compressed method pointer %s @ " INTPTR_FORMAT, method->name()->as_C_string(), p2i(method));
int index = _oop_recorder->find_index(method);
section->relocate(dest, metadata_Relocation::spec(index));
TRACE_jvmci_3("metadata[%d of %d] = %s", index, _oop_recorder->metadata_count(), method->name()->as_C_string());
JVMCI_event_3("metadata[%d of %d] = %s", index, _oop_recorder->metadata_count(), method->name()->as_C_string());
return method;
} else {
JVMCI_ERROR_NULL("unexpected metadata reference for constant of type %s", jvmci_env()->klass_name(obj));
@@ -271,7 +271,7 @@ narrowKlass CodeInstaller::record_narrow_metadata_reference(CodeSection* section
Klass* klass = JVMCIENV->asKlass(obj);
int index = _oop_recorder->find_index(klass);
section->relocate(dest, metadata_Relocation::spec(index));
TRACE_jvmci_3("narrowKlass[%d of %d] = %s", index, _oop_recorder->metadata_count(), klass->name()->as_C_string());
JVMCI_event_3("narrowKlass[%d of %d] = %s", index, _oop_recorder->metadata_count(), klass->name()->as_C_string());
return CompressedKlassPointers::encode(klass);
}
#endif
@@ -690,7 +690,7 @@ void CodeInstaller::initialize_fields(JVMCIObject target, JVMCIObject compiled_c
Thread* thread = Thread::current();
methodHandle method(thread, jvmci_env()->asMethod(hotspotJavaMethod));
_parameter_count = method->size_of_parameters();
TRACE_jvmci_2("installing code for %s", method->name_and_sig_as_C_string());
JVMCI_event_2("installing code for %s", method->name_and_sig_as_C_string());
} else {
// Must be a HotSpotCompiledRuntimeStub.
// Only used in OopMap constructor for non-product builds
@@ -883,35 +883,35 @@ JVMCI::CodeInstallResult CodeInstaller::initialize_buffer(CodeBuffer& buffer, bo
jint pc_offset = jvmci_env()->get_site_Site_pcOffset(site);

if (jvmci_env()->isa_site_Call(site)) {
TRACE_jvmci_4("call at %i", pc_offset);
JVMCI_event_4("call at %i", pc_offset);
site_Call(buffer, pc_offset, site, JVMCI_CHECK_OK);
} else if (jvmci_env()->isa_site_Infopoint(site)) {
// three reasons for infopoints denote actual safepoints
JVMCIObject reason = jvmci_env()->get_site_Infopoint_reason(site);
if (JVMCIENV->equals(reason, jvmci_env()->get_site_InfopointReason_SAFEPOINT()) ||
JVMCIENV->equals(reason, jvmci_env()->get_site_InfopointReason_CALL()) ||
JVMCIENV->equals(reason, jvmci_env()->get_site_InfopointReason_IMPLICIT_EXCEPTION())) {
TRACE_jvmci_4("safepoint at %i", pc_offset);
JVMCI_event_4("safepoint at %i", pc_offset);
site_Safepoint(buffer, pc_offset, site, JVMCI_CHECK_OK);
if (_orig_pc_offset < 0) {
JVMCI_ERROR_OK("method contains safepoint, but has no deopt rescue slot");
}
if (JVMCIENV->equals(reason, jvmci_env()->get_site_InfopointReason_IMPLICIT_EXCEPTION())) {
TRACE_jvmci_4("implicit exception at %i", pc_offset);
JVMCI_event_4("implicit exception at %i", pc_offset);
_implicit_exception_table.add_deoptimize(pc_offset);
}
} else {
TRACE_jvmci_4("infopoint at %i", pc_offset);
JVMCI_event_4("infopoint at %i", pc_offset);
site_Infopoint(buffer, pc_offset, site, JVMCI_CHECK_OK);
}
} else if (jvmci_env()->isa_site_DataPatch(site)) {
TRACE_jvmci_4("datapatch at %i", pc_offset);
JVMCI_event_4("datapatch at %i", pc_offset);
site_DataPatch(buffer, pc_offset, site, JVMCI_CHECK_OK);
} else if (jvmci_env()->isa_site_Mark(site)) {
TRACE_jvmci_4("mark at %i", pc_offset);
JVMCI_event_4("mark at %i", pc_offset);
site_Mark(buffer, pc_offset, site, JVMCI_CHECK_OK);
} else if (jvmci_env()->isa_site_ExceptionHandler(site)) {
TRACE_jvmci_4("exceptionhandler at %i", pc_offset);
JVMCI_event_4("exceptionhandler at %i", pc_offset);
site_ExceptionHandler(pc_offset, site);
} else {
JVMCI_ERROR_OK("unexpected site subclass: %s", jvmci_env()->klass_name(site));
@@ -1100,7 +1100,7 @@ void CodeInstaller::record_scope(jint pc_offset, JVMCIObject position, ScopeMode
bci = SynchronizationEntryBCI;
}

TRACE_jvmci_2("Recording scope pc_offset=%d bci=%d method=%s", pc_offset, bci, method->name_and_sig_as_C_string());
JVMCI_event_2("Recording scope pc_offset=%d bci=%d method=%s", pc_offset, bci, method->name_and_sig_as_C_string());

bool reexecute = false;
if (frame.is_non_null()) {
@@ -1141,8 +1141,8 @@ void CodeInstaller::record_scope(jint pc_offset, JVMCIObject position, ScopeMode
GrowableArray<ScopeValue*>* expressions = expression_count > 0 ? new GrowableArray<ScopeValue*> (expression_count) : NULL;
GrowableArray<MonitorValue*>* monitors = monitor_count > 0 ? new GrowableArray<MonitorValue*> (monitor_count) : NULL;

TRACE_jvmci_2("Scope at bci %d with %d values", bci, JVMCIENV->get_length(values));
TRACE_jvmci_2("%d locals %d expressions, %d monitors", local_count, expression_count, monitor_count);
JVMCI_event_2("Scope at bci %d with %d values", bci, JVMCIENV->get_length(values));
JVMCI_event_2("%d locals %d expressions, %d monitors", local_count, expression_count, monitor_count);

for (jint i = 0; i < JVMCIENV->get_length(values); i++) {
// HandleMark hm(THREAD);
@@ -1253,7 +1253,7 @@ void CodeInstaller::site_Call(CodeBuffer& buffer, jint pc_offset, JVMCIObject si
JVMCI_ERROR("debug info expected at call at %i", pc_offset);
}

TRACE_jvmci_3("method call");
JVMCI_event_3("method call");
CodeInstaller::pd_relocate_JavaMethod(buffer, hotspot_method, pc_offset, JVMCI_CHECK);
if (_next_call_type == INVOKESTATIC || _next_call_type == INVOKESPECIAL) {
// Need a static call stub for transitions from compiled to interpreted.
@@ -146,6 +146,6 @@ void JVMCICompiler::print_timers() {

// Print compilation timers and statistics
void JVMCICompiler::print_compilation_timers() {
TRACE_jvmci_1("JVMCICompiler::print_timers");
JVMCI_event_1("JVMCICompiler::print_timers");
tty->print_cr(" JVMCI code install time: %6.3f s", _codeInstallTimer.seconds());
}
@@ -103,10 +103,10 @@ class JVMCITraceMark : public StackObj {
public:
JVMCITraceMark(const char* msg) {
_msg = msg;
TRACE_jvmci_2("Enter %s", _msg);
JVMCI_event_2("Enter %s", _msg);
}
~JVMCITraceMark() {
TRACE_jvmci_2(" Exit %s", _msg);
JVMCI_event_2(" Exit %s", _msg);
}
};

@@ -1611,7 +1611,7 @@ C2V_VMENTRY_PREFIX(jint, writeDebugOutput, (JNIEnv* env, jobject, jbyteArray byt
if (thread == NULL) {
if (!ad._attached) {
// Can only use tty if the current thread is attached
TRACE_jvmci_1("Cannot write to tty on unattached thread");
JVMCI_event_1("Cannot write to tty on unattached thread");
return 0;
}
thread = get_current_thread();
@@ -2382,7 +2382,7 @@ C2V_VMENTRY_PREFIX(jboolean, attachCurrentThread, (JNIEnv* env, jobject c2vm, jb

if (res == JNI_OK) {
guarantee(peerJNIEnv != NULL, "must be");
TRACE_jvmci_1("attached to JavaVM for JVMCI runtime %d", runtime->id());
JVMCI_event_1("attached to JavaVM for JVMCI runtime %d", runtime->id());
return true;
}
JVMCI_THROW_MSG_0(InternalError, err_msg("Error %d while attaching %s", res, attach_args.name));

0 comments on commit 4e962f9

Please sign in to comment.