Skip to content

OpenJ9 support for new OMR compiler tracing and logging infrastructure #22751

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 10 commits into
base: master
Choose a base branch
from
+7,484 −9,146
Open

OpenJ9 support for new OMR compiler tracing and logging infrastructure #22751

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
18376cb
Initial OMR::Logger support
0xdaryl Dec 19, 2022
dc25555
Add JitDump Logger support and improve code readability
0xdaryl Apr 11, 2025
3bb9779
Replace traceMsg() with direct log updates
0xdaryl Nov 30, 2024
27bad1e
Use conditional logger macros to make code more readable
0xdaryl Jan 10, 2025
bb6dfc5
Initial cleanup of diagnostic() macros
0xdaryl Jan 22, 2025
3683038
Replace Debug::trace() with OMR::Logger
0xdaryl Feb 24, 2025
a00fa1d
Replace some uses of getLoggingEnabled()
0xdaryl Feb 6, 2025
7b21a5f
Support caching of log file and logger in Compilation object
0xdaryl May 9, 2025
468545a
Ensure Logger is initialized in SVM_ASSERT_IMPL
0xdaryl Sep 26, 2025
e6602fd
Use TRIOStreamLogger as default OpenJ9 logger
0xdaryl Nov 5, 2025
File filter

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
88 changes: 37 additions & 51 deletions runtime/compiler/aarch64/codegen/ARM64PrivateLinkage.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -49,6 +49,7 @@
#include "il/SymbolReference.hpp"
#include "infra/Assert.hpp"
#include "infra/List.hpp"
#include "ras/Logger.hpp"
#include "runtime/Runtime.hpp"

#define MIN_PROFILED_CALL_FREQUENCY (.075f)
Expand Down Expand Up @@ -260,24 +261,21 @@ J9::ARM64::PrivateLinkage::entryPointFromInterpretedMethod()
void J9::ARM64::PrivateLinkage::alignLocalReferences(uint32_t &stackIndex)
{
TR::Compilation *comp = self()->comp();
OMR::Logger *log = comp->log();
bool trace = comp->getOption(TR_TraceCG);
TR::GCStackAtlas *atlas = self()->cg()->getStackAtlas();
const int32_t localObjectAlignment = TR::Compiler->om.getObjectAlignmentInBytes();
const uint8_t pointerSize = TR::Compiler->om.sizeofReferenceAddress();

if (comp->useCompressedPointers())
{
if (comp->getOption(TR_TraceCG))
{
traceMsg(comp,"\nLOCAL OBJECT ALIGNMENT: stack offset before alignment: %d,", stackIndex);
}
logprintf(trace, log, "\nLOCAL OBJECT ALIGNMENT: stack offset before alignment: %d,", stackIndex);

// stackIndex in mapCompactedStack is calculated using only local reference sizes and does not include the padding
stackIndex -= pointerSize * atlas->getNumberOfPaddingSlots();

if (comp->getOption(TR_TraceCG))
{
traceMsg(comp," with padding: %d,", stackIndex);
}
logprintf(trace, log, " with padding: %d,", stackIndex);

// If there are any local objects we have to make sure they are aligned properly
// when compressed pointers are used. Otherwise, pointer compression may clobber
// part of the pointer.
Expand Down Expand Up @@ -891,7 +889,7 @@ void J9::ARM64::PrivateLinkage::createPrologue(TR::Instruction *cursor)
TR::RealRegister *zeroReg = machine->getRealRegister(TR::RealRegister::RegNum::xzr);
TR::RealRegister *baseReg = machine->getRealRegister(TR::RealRegister::RegNum::x10);

cursor = initializeLocals(cursor, numLocalsToBeInitialized, initializedLocalsOffsetFromAdjustedJavaSP,
cursor = initializeLocals(cursor, numLocalsToBeInitialized, initializedLocalsOffsetFromAdjustedJavaSP,
zeroReg, baseReg, javaSP, cg());

if (atlas->getInternalPointerMap())
Expand All @@ -902,7 +900,7 @@ void J9::ARM64::PrivateLinkage::createPrologue(TR::Instruction *cursor)
int32_t numSlotsToBeInitialized = atlas->getNumberOfDistinctPinningArrays() + atlas->getInternalPointerMap()->getNumInternalPointers();
int32_t offsetToFirstInternalPointerFromAdjustedJavaSP = alignedFrameSizeIncludingReturnAddress + atlas->getOffsetOfFirstInternalPointer() + firstLocalOffset;

cursor = initializeLocals(cursor, numSlotsToBeInitialized, offsetToFirstInternalPointerFromAdjustedJavaSP,
cursor = initializeLocals(cursor, numSlotsToBeInitialized, offsetToFirstInternalPointerFromAdjustedJavaSP,
zeroReg, baseReg, javaSP, cg());
}
}
Expand Down Expand Up @@ -1039,6 +1037,7 @@ int32_t J9::ARM64::PrivateLinkage::buildPrivateLinkageArgs(TR::Node *callNode,
TR_ASSERT(linkage == TR_Private || linkage == TR_Helper || linkage == TR_CHelper, "Unexpected linkage convention");

const TR::ARM64LinkageProperties& properties = getProperties();
TR::Compilation *comp = this->comp();
TR::ARM64MemoryArgument *pushToMemory = NULL;
TR::Register *tempReg;
int32_t argIndex = 0;
Expand Down Expand Up @@ -1101,12 +1100,10 @@ int32_t J9::ARM64::PrivateLinkage::buildPrivateLinkageArgs(TR::Node *callNode,
}
if (specialArgReg != TR::RealRegister::NoReg)
{
if (comp()->getOption(TR_TraceCG))
{
traceMsg(comp(), "Special arg %s in %s\n",
comp()->getDebug()->getName(callNode->getChild(from)),
comp()->getDebug()->getName(cg()->machine()->getRealRegister(specialArgReg)));
}
logprintf(comp->getOption(TR_TraceCG), comp->log(), "Special arg %s in %s\n",
comp->getDebug()->getName(callNode->getChild(from)),
comp->getDebug()->getName(cg()->machine()->getRealRegister(specialArgReg)));

// Skip the special arg in the first loop
from += step;
}
Expand Down Expand Up @@ -1510,6 +1507,9 @@ static bool getProfiledCallSiteInfo(TR::CodeGenerator *cg, TR::Node *callNode, u
if (comp->compileRelocatableCode())
return false;

OMR::Logger *log = comp->log();
bool trace = comp->getOption(TR_TraceCG);

TR::SymbolReference *methodSymRef = callNode->getSymbolReference();
TR::MethodSymbol *methodSymbol = methodSymRef->getSymbol()->castToMethodSymbol();

Expand All @@ -1519,26 +1519,20 @@ static bool getProfiledCallSiteInfo(TR::CodeGenerator *cg, TR::Node *callNode, u
TR_AddressInfo *info = static_cast<TR_AddressInfo*>(TR_ValueProfileInfoManager::getProfiledValueInfo(callNode, comp, AddressInfo));
if (!info)
{
if (comp->getOption(TR_TraceCG))
{
traceMsg(comp, "Profiled target not found for node %p\n", callNode);
}
logprintf(trace, log, "Profiled target not found for node %p\n", callNode);
return false;
}
static const bool tracePIC = (feGetEnv("TR_TracePIC") != NULL);
if (tracePIC && comp->getOption(TR_TraceCG))
if (tracePIC && trace)
{
traceMsg(comp, "Value profile info for callNode %p in %s\n", callNode, comp->signature());
info->getProfiler()->dumpInfo(comp->getOutFile());
traceMsg(comp, "\n");
log->printf("Value profile info for callNode %p in %s\n", callNode, comp->signature());
info->getProfiler()->dumpInfo(log);
log->println();
}
uint32_t totalFreq = info->getTotalFrequency();
if (totalFreq == 0 || info->getTopProbability() < MIN_PROFILED_CALL_FREQUENCY)
{
if (comp->getOption(TR_TraceCG))
{
traceMsg(comp, "Profiled target with enough frequency not found for node %p\n", callNode);
}
logprintf(trace, log, "Profiled target with enough frequency not found for node %p\n", callNode);
return false;
}

Expand Down Expand Up @@ -1626,7 +1620,7 @@ static TR::Instruction* buildStaticPICCall(TR::CodeGenerator *cg, TR::Node *call

if (isUnloadAssumptionRequired)
{
loadAddressConstantInSnippet(cg, callNode, reinterpret_cast<intptr_t>(profiledClass), tempReg, TR_NoRelocation, true);
loadAddressConstantInSnippet(cg, callNode, reinterpret_cast<intptr_t>(profiledClass), tempReg, TR_NoRelocation, true);
}
else
{
Expand Down Expand Up @@ -2063,6 +2057,8 @@ void J9::ARM64::PrivateLinkage::buildVirtualDispatch(TR::Node *callNode,
TR::Instruction *gcPoint;

TR_J9VMBase *fej9 = (TR_J9VMBase *)(comp()->fe());
OMR::Logger *log = comp()->log();
bool trace = comp()->getOption(TR_TraceCG);

// Computed calls
//
Expand Down Expand Up @@ -2169,10 +2165,8 @@ void J9::ARM64::PrivateLinkage::buildVirtualDispatch(TR::Node *callNode,
if (!resolvedMethod->virtualMethodIsOverridden() &&
!resolvedMethod->isAbstract())
{
if (comp()->getOption(TR_TraceCG))
{
traceMsg(comp(), "Creating TR_NonoverriddenGuard for node %p\n", callNode);
}
logprintf(trace, log, "Creating TR_NonoverriddenGuard for node %p\n", callNode);

virtualGuard = TR_VirtualGuard::createGuardedDevirtualizationGuard(TR_NonoverriddenGuard, comp(), callNode);
}
else
Expand All @@ -2191,10 +2185,8 @@ void J9::ARM64::PrivateLinkage::buildVirtualDispatch(TR::Node *callNode,
!calleeMethod->isInterpreted() ||
calleeMethod->isJITInternalNative()))
{
if (comp()->getOption(TR_TraceCG))
{
traceMsg(comp(), "Creating TR_AbstractGuard for node %p\n", callNode);
}
logprintf(trace, log, "Creating TR_AbstractGuard for node %p\n", callNode);

resolvedMethod = calleeMethod;
virtualGuard = TR_VirtualGuard::createGuardedDevirtualizationGuard(TR_AbstractGuard, comp(), callNode);
}
Expand All @@ -2209,10 +2201,8 @@ void J9::ARM64::PrivateLinkage::buildVirtualDispatch(TR::Node *callNode,
!calleeMethod->isInterpreted() ||
calleeMethod->isJITInternalNative()))
{
if (comp()->getOption(TR_TraceCG))
{
traceMsg(comp(), "Creating TR_HierarchyGuard for node %p\n", callNode);
}
logprintf(trace, log, "Creating TR_HierarchyGuard for node %p\n", callNode);

resolvedMethod = calleeMethod;
virtualGuard = TR_VirtualGuard::createGuardedDevirtualizationGuard(TR_HierarchyGuard, comp(), callNode);
}
Expand Down Expand Up @@ -2325,18 +2315,16 @@ void J9::ARM64::PrivateLinkage::buildVirtualDispatch(TR::Node *callNode,
if (numImplementers <= numPICSlots)
{
useLastITableCache = false;
if (comp()->getOption(TR_TraceCG))
traceMsg(comp(),"Found %d implementers for call to %s, can be fit into %d pic slots, disabling lastITable cache\n", numImplementers, methodSymbol->getMethod()->signature(comp()->trMemory()), numPICSlots);
logprintf(trace, log, "Found %d implementers for call to %s, can be fit into %d pic slots, disabling lastITable cache\n",
numImplementers, methodSymbol->getMethod()->signature(comp()->trMemory()), numPICSlots);
}
}
}
// If this value is dominant, optimize exclusively for it
if (pic->_frequency > MAX_PROFILED_CALL_FREQUENCY)
{
if (comp()->getOption(TR_TraceCG))
{
traceMsg(comp(), "Found dominant profiled target, frequency = %f\n", pic->_frequency);
}
logprintf(trace, log, "Found dominant profiled target, frequency = %f\n", pic->_frequency);

TR::LabelSymbol *slowCallLabel = generateLabelSymbol(cg());

TR::Instruction *gcPoint = buildStaticPICCall(cg(), callNode, pic->_clazz, pic->_method,
Expand Down Expand Up @@ -2386,10 +2374,8 @@ void J9::ARM64::PrivateLinkage::buildVirtualDispatch(TR::Node *callNode,
}
else
{
if (comp()->getOption(TR_TraceCG))
{
traceMsg(comp(), "Generating %d static PIC calls\n", values.getSize());
}
logprintf(trace, log, "Generating %d static PIC calls\n", values.getSize());

// Build multiple static PIC calls
int32_t slotCount = 1;
while (pic)
Expand Down
16 changes: 8 additions & 8 deletions runtime/compiler/aarch64/codegen/ARM64RecompilationSnippet.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -53,25 +53,25 @@ uint32_t TR::ARM64RecompilationSnippet::getLength(int32_t estimatedSnippetStart)
}

void
TR_Debug::print(TR::FILE *pOutFile, TR::ARM64RecompilationSnippet *snippet)
TR_Debug::print(OMR::Logger *log, TR::ARM64RecompilationSnippet *snippet)
{
uint8_t *cursor = snippet->getSnippetLabel()->getCodeLocation();

printSnippetLabel(pOutFile, snippet->getSnippetLabel(), cursor, getName(snippet));
printSnippetLabel(log, snippet->getSnippetLabel(), cursor, getName(snippet));

int32_t distance;
distance = *((int32_t *)cursor) & 0x03ffffff; // imm26
distance = (distance << 6) >> 4; // sign extend and add two 0 bits

printPrefix(pOutFile, NULL, cursor, ARM64_INSTRUCTION_LENGTH);
trfprintf(pOutFile, "bl \t" POINTER_PRINTF_FORMAT "\t\t; %s",
printPrefix(log, NULL, cursor, ARM64_INSTRUCTION_LENGTH);
log->printf("bl \t" POINTER_PRINTF_FORMAT "\t\t; %s",
(intptr_t)cursor + distance, getRuntimeHelperName(TR_ARM64countingRecompileMethod));
cursor += ARM64_INSTRUCTION_LENGTH;

printPrefix(pOutFile, NULL, cursor, sizeof(intptr_t));
trfprintf(pOutFile, ".dword \t" POINTER_PRINTF_FORMAT "\t\t; BodyInfo", *(intptr_t *)cursor);
printPrefix(log, NULL, cursor, sizeof(intptr_t));
log->printf(".dword \t" POINTER_PRINTF_FORMAT "\t\t; BodyInfo", *(intptr_t *)cursor);
cursor += sizeof(intptr_t);

printPrefix(pOutFile, NULL, cursor, sizeof(intptr_t));
trfprintf(pOutFile, ".dword \t" POINTER_PRINTF_FORMAT "\t\t; startPC", *(intptr_t *)cursor);
printPrefix(log, NULL, cursor, sizeof(intptr_t));
log->printf(".dword \t" POINTER_PRINTF_FORMAT "\t\t; startPC", *(intptr_t *)cursor);
}
Loading