Skip to content

Commit

Permalink
Merge pull request #20000 from dsouzai/criuFootprintImprovements
Browse files Browse the repository at this point in the history 
Footprint Improvements under `-XX:+DebugOnRestore`
  • Loading branch information
@mpirvu
mpirvu authored Aug 23, 2024
2 parents 193c5a4 + 606b74f commit 9249e24
Show file tree
Hide file tree
Showing 7 changed files with 164 additions and 66 deletions.
164 changes: 103 additions & 61 deletions runtime/compiler/control/HookedByTheJit.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4268,61 +4268,6 @@ static void jitHookAboutToRunMain(J9HookInterface * * hook, UDATA eventNum, void
}


#if defined(J9VM_INTERP_PROFILING_BYTECODES)
// Below, options and jitConfig are guaranteed to be not null
void printIprofilerStats(TR::Options *options, J9JITConfig * jitConfig, TR_IProfiler *iProfiler)
{
if (!options->getOption(TR_DisableInterpreterProfiling))
{
PORT_ACCESS_FROM_JITCONFIG(jitConfig);
if (TR::Options::getCmdLineOptions()->getOption(TR_VerboseInterpreterProfiling))
{
j9tty_printf(PORTLIB, "VM shutdown event received.\n");
j9tty_printf(PORTLIB, "Total events: %d\n", TEST_events);
j9tty_printf(PORTLIB, "Total records: %d\n", TEST_records);
j9tty_printf(PORTLIB, "Total method persistence opportunities: %d\n", TR_IProfiler::_STATS_methodPersistenceAttempts);
j9tty_printf(PORTLIB, "Total jitprofile entries: %d\n", TR_IProfiler::_STATS_methodPersisted);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted due to locked entry: %d\n", TR_IProfiler::_STATS_abortedPersistence);
j9tty_printf(PORTLIB, "Total IProfiler persistence failed: %d\n", TR_IProfiler::_STATS_persistError);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted because SCC full: %d\n", TR_IProfiler::_STATS_methodNotPersisted_SCCfull);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted because ROM class in not in SCC: %d\n", TR_IProfiler::_STATS_methodNotPersisted_classNotInSCC);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted due to other reasons: %d\n", TR_IProfiler::_STATS_methodNotPersisted_other);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted because already stored: %d\n", TR_IProfiler::_STATS_methodNotPersisted_alreadyStored);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted because nothing needs to be stored: %d\n", TR_IProfiler::_STATS_methodNotPersisted_noEntries);
j9tty_printf(PORTLIB, "Total IProfiler persisted delayed: %d\n", TR_IProfiler::_STATS_methodNotPersisted_delayed);
j9tty_printf(PORTLIB, "Total records persisted: %d\n", TR_IProfiler::_STATS_entriesPersisted);
j9tty_printf(PORTLIB, "Total records not persisted_NotInSCC: %d\n", TR_IProfiler::_STATS_entriesNotPersisted_NotInSCC);
j9tty_printf(PORTLIB, "Total records not persisted_unloaded: %d\n", TR_IProfiler::_STATS_entriesNotPersisted_Unloaded);
j9tty_printf(PORTLIB, "Total records not persisted_noInfo in bc table: %d\n", TR_IProfiler::_STATS_entriesNotPersisted_NoInfo);
j9tty_printf(PORTLIB, "Total records not persisted_Other: %d\n", TR_IProfiler::_STATS_entriesNotPersisted_Other);
j9tty_printf(PORTLIB, "IP Total Persistent Read Failed Attempts: %d\n", TR_IProfiler::_STATS_persistedIPReadFail);

j9tty_printf(PORTLIB, "IP Total Persistent Reads with Bad Data: %d\n", TR_IProfiler::_STATS_persistedIPReadHadBadData);
j9tty_printf(PORTLIB, "IP Total Persistent Read Success: %d\n", TR_IProfiler::_STATS_persistedIPReadSuccess);
j9tty_printf(PORTLIB, "IP Total Persistent vs Current Data Differ: %d\n", TR_IProfiler::_STATS_persistedAndCurrentIPDataDiffer);
j9tty_printf(PORTLIB, "IP Total Persistent vs Current Data Match: %d\n", TR_IProfiler::_STATS_persistedAndCurrentIPDataMatch);
j9tty_printf(PORTLIB, "IP Total Current Read Fail: %d\n", TR_IProfiler::_STATS_currentIPReadFail);
j9tty_printf(PORTLIB, "IP Total Current Read Success: %d\n", TR_IProfiler::_STATS_currentIPReadSuccess);
j9tty_printf(PORTLIB, "IP Total Current Read Bad Data: %d\n", TR_IProfiler::_STATS_currentIPReadHadBadData);
j9tty_printf(PORTLIB, "Total records read: %d\n", TR_IProfiler::_STATS_IPEntryRead);
j9tty_printf(PORTLIB, "Total records choose persistent: %d\n", TR_IProfiler::_STATS_IPEntryChoosePersistent);
}
if (TR_IProfiler::_STATS_abortedPersistence > 0)
{
TR_ASSERT(TR_IProfiler::_STATS_methodPersisted / TR_IProfiler::_STATS_abortedPersistence > 20 ||
TR_IProfiler::_STATS_methodPersisted < 200,
"too many aborted persistence attempts due to locked entries (%d aborted, %d total methods persisted)",
TR_IProfiler::_STATS_abortedPersistence, TR_IProfiler::_STATS_methodPersisted);
}
if (TR::Options::getCmdLineOptions()->getOption(TR_EnableNewAllocationProfiling))
iProfiler->printAllocationReport();
if (TEST_verbose || TR::Options::getCmdLineOptions()->getOption(TR_VerboseInterpreterProfiling))
iProfiler->outputStats();
}
}
#endif


/// JIT cleanup code
void JitShutdown(J9JITConfig * jitConfig)
{
Expand Down Expand Up @@ -4365,7 +4310,7 @@ void JitShutdown(J9JITConfig * jitConfig)
// so the fact that this option is true doesn't mean that IProfiler structures were not allocated
if (options /* && !options->getOption(TR_DisableInterpreterProfiling) */ && iProfiler)
{
printIprofilerStats(options, jitConfig, iProfiler);
printIprofilerStats(options, jitConfig, iProfiler, "Shutdown");
// Prevent the interpreter to accumulate more info
// stopInterpreterProfiling is stronger than turnOff... because it prevents the reactivation
// by setting TR_DisableInterpreterProfiling option to false
Expand Down Expand Up @@ -5168,7 +5113,12 @@ static void jitStateLogic(J9JITConfig * jitConfig, TR::CompilationInfo * compInf
if (IProfilerOffSinceStartup &&
!TR::Options::getCmdLineOptions()->getOption(TR_DisableInterpreterProfiling) &&
TR::Options::getCmdLineOptions()->getOption(TR_NoIProfilerDuringStartupPhase) &&
interpreterProfilingState == IPROFILING_STATE_OFF)
interpreterProfilingState == IPROFILING_STATE_OFF
#if defined(J9VM_OPT_CRIU_SUPPORT)
&& (!jitConfig->javaVM->internalVMFunctions->isDebugOnRestoreEnabled(compInfo->getSamplerThread())
|| compInfo->getCRRuntime()->allowStateChange())
#endif
)
{
// Should we turn it ON?
TR_IProfiler *iProfiler = TR_J9VMBase::get(jitConfig, 0)->getIProfiler();
Expand Down Expand Up @@ -5231,7 +5181,12 @@ static void jitStateLogic(J9JITConfig * jitConfig, TR::CompilationInfo * compInf
if (compInfo->isInZOSSupervisorState())
waitTime = waitTime * 2;
#endif
if (crtElapsedTime - lastTimeInStartupMode > waitTime)
if (crtElapsedTime - lastTimeInStartupMode > waitTime
#if defined(J9VM_OPT_CRIU_SUPPORT)
&& (!jitConfig->javaVM->internalVMFunctions->isDebugOnRestoreEnabled(compInfo->getSamplerThread())
|| compInfo->getCRRuntime()->allowStateChange())
#endif
)
{
javaVM->internalVMFunctions->jvmPhaseChange(javaVM, J9VM_PHASE_NOT_STARTUP);
}
Expand All @@ -5246,8 +5201,15 @@ static void jitStateLogic(J9JITConfig * jitConfig, TR::CompilationInfo * compInf
// Exit startup when the 'endOfStartup' arrives
// The case where the 'endOfStartup' hint arrived, but don't want to follow strictly
// is implemented above in the IF block
if (persistentInfo->getExternalStartupEndedSignal())
if (persistentInfo->getExternalStartupEndedSignal()
#if defined(J9VM_OPT_CRIU_SUPPORT)
&& (!jitConfig->javaVM->internalVMFunctions->isDebugOnRestoreEnabled(compInfo->getSamplerThread())
|| compInfo->getCRRuntime()->allowStateChange())
#endif
)
{
javaVM->internalVMFunctions->jvmPhaseChange(javaVM, J9VM_PHASE_NOT_STARTUP);
}
}
}
else // javaVM->phase == J9VM_PHASE_EARLY_STARTUP
Expand All @@ -5261,14 +5223,42 @@ static void jitStateLogic(J9JITConfig * jitConfig, TR::CompilationInfo * compInf
{
// Normal gracePeriod rules apply
if (crtElapsedTime >= (uint64_t)persistentInfo->getClassLoadingPhaseGracePeriod()) // grace period has ended
javaVM->internalVMFunctions->jvmPhaseChange(javaVM, (newState == STARTUP_STATE) ? J9VM_PHASE_STARTUP : J9VM_PHASE_NOT_STARTUP);
{
if (newState == STARTUP_STATE)
{
javaVM->internalVMFunctions->jvmPhaseChange(javaVM, J9VM_PHASE_STARTUP);
}
else
{
#if defined(J9VM_OPT_CRIU_SUPPORT)
if (!jitConfig->javaVM->internalVMFunctions->isDebugOnRestoreEnabled(compInfo->getSamplerThread())
|| compInfo->getCRRuntime()->allowStateChange())
#endif
{
javaVM->internalVMFunctions->jvmPhaseChange(javaVM, J9VM_PHASE_NOT_STARTUP);
}
}
}
}
else
{
// 'beginningOfStartup' hint was seen
// If 'endOfStartup' was not seen, move to STARTUP, otherwise, following hints strictly,
// we have to exit STARTUP
javaVM->internalVMFunctions->jvmPhaseChange(javaVM, !persistentInfo->getExternalStartupEndedSignal() ? J9VM_PHASE_STARTUP : J9VM_PHASE_NOT_STARTUP);
if (!persistentInfo->getExternalStartupEndedSignal())
{
javaVM->internalVMFunctions->jvmPhaseChange(javaVM, J9VM_PHASE_STARTUP);
}
else
{
#if defined(J9VM_OPT_CRIU_SUPPORT)
if (!jitConfig->javaVM->internalVMFunctions->isDebugOnRestoreEnabled(compInfo->getSamplerThread())
|| compInfo->getCRRuntime()->allowStateChange())
#endif
{
javaVM->internalVMFunctions->jvmPhaseChange(javaVM, J9VM_PHASE_NOT_STARTUP);
}
}
}
}
if (javaVM->phase == J9VM_PHASE_NOT_STARTUP)
Expand Down Expand Up @@ -7760,6 +7750,58 @@ int32_t waitJITServerTermination(J9JITConfig *jitConfig)
} /* extern "C" */

#if defined(J9VM_INTERP_PROFILING_BYTECODES)
// Below, options and jitConfig are guaranteed to be not null
void printIprofilerStats(TR::Options *options, J9JITConfig * jitConfig, TR_IProfiler *iProfiler, const char *event)
{
if (!options->getOption(TR_DisableInterpreterProfiling))
{
PORT_ACCESS_FROM_JITCONFIG(jitConfig);
if (options->getOption(TR_VerboseInterpreterProfiling))
{
j9tty_printf(PORTLIB, "VM %s event received.\n", event);
j9tty_printf(PORTLIB, "Total events: %d\n", TEST_events);
j9tty_printf(PORTLIB, "Total records: %d\n", TEST_records);
j9tty_printf(PORTLIB, "Total method persistence opportunities: %d\n", TR_IProfiler::_STATS_methodPersistenceAttempts);
j9tty_printf(PORTLIB, "Total jitprofile entries: %d\n", TR_IProfiler::_STATS_methodPersisted);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted due to locked entry: %d\n", TR_IProfiler::_STATS_abortedPersistence);
j9tty_printf(PORTLIB, "Total IProfiler persistence failed: %d\n", TR_IProfiler::_STATS_persistError);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted because SCC full: %d\n", TR_IProfiler::_STATS_methodNotPersisted_SCCfull);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted because ROM class in not in SCC: %d\n", TR_IProfiler::_STATS_methodNotPersisted_classNotInSCC);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted due to other reasons: %d\n", TR_IProfiler::_STATS_methodNotPersisted_other);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted because already stored: %d\n", TR_IProfiler::_STATS_methodNotPersisted_alreadyStored);
j9tty_printf(PORTLIB, "Total IProfiler persistence aborted because nothing needs to be stored: %d\n", TR_IProfiler::_STATS_methodNotPersisted_noEntries);
j9tty_printf(PORTLIB, "Total IProfiler persisted delayed: %d\n", TR_IProfiler::_STATS_methodNotPersisted_delayed);
j9tty_printf(PORTLIB, "Total records persisted: %d\n", TR_IProfiler::_STATS_entriesPersisted);
j9tty_printf(PORTLIB, "Total records not persisted_NotInSCC: %d\n", TR_IProfiler::_STATS_entriesNotPersisted_NotInSCC);
j9tty_printf(PORTLIB, "Total records not persisted_unloaded: %d\n", TR_IProfiler::_STATS_entriesNotPersisted_Unloaded);
j9tty_printf(PORTLIB, "Total records not persisted_noInfo in bc table: %d\n", TR_IProfiler::_STATS_entriesNotPersisted_NoInfo);
j9tty_printf(PORTLIB, "Total records not persisted_Other: %d\n", TR_IProfiler::_STATS_entriesNotPersisted_Other);
j9tty_printf(PORTLIB, "IP Total Persistent Read Failed Attempts: %d\n", TR_IProfiler::_STATS_persistedIPReadFail);

j9tty_printf(PORTLIB, "IP Total Persistent Reads with Bad Data: %d\n", TR_IProfiler::_STATS_persistedIPReadHadBadData);
j9tty_printf(PORTLIB, "IP Total Persistent Read Success: %d\n", TR_IProfiler::_STATS_persistedIPReadSuccess);
j9tty_printf(PORTLIB, "IP Total Persistent vs Current Data Differ: %d\n", TR_IProfiler::_STATS_persistedAndCurrentIPDataDiffer);
j9tty_printf(PORTLIB, "IP Total Persistent vs Current Data Match: %d\n", TR_IProfiler::_STATS_persistedAndCurrentIPDataMatch);
j9tty_printf(PORTLIB, "IP Total Current Read Fail: %d\n", TR_IProfiler::_STATS_currentIPReadFail);
j9tty_printf(PORTLIB, "IP Total Current Read Success: %d\n", TR_IProfiler::_STATS_currentIPReadSuccess);
j9tty_printf(PORTLIB, "IP Total Current Read Bad Data: %d\n", TR_IProfiler::_STATS_currentIPReadHadBadData);
j9tty_printf(PORTLIB, "Total records read: %d\n", TR_IProfiler::_STATS_IPEntryRead);
j9tty_printf(PORTLIB, "Total records choose persistent: %d\n", TR_IProfiler::_STATS_IPEntryChoosePersistent);
}
if (TR_IProfiler::_STATS_abortedPersistence > 0)
{
TR_ASSERT(TR_IProfiler::_STATS_methodPersisted / TR_IProfiler::_STATS_abortedPersistence > 20 ||
TR_IProfiler::_STATS_methodPersisted < 200,
"too many aborted persistence attempts due to locked entries (%d aborted, %d total methods persisted)",
TR_IProfiler::_STATS_abortedPersistence, TR_IProfiler::_STATS_methodPersisted);
}
if (options->getOption(TR_EnableNewAllocationProfiling))
iProfiler->printAllocationReport();
if (TEST_verbose || options->getOption(TR_VerboseInterpreterProfiling))
iProfiler->outputStats();
}
}

void turnOffInterpreterProfiling(J9JITConfig *jitConfig)
{
// Turn off interpreter profiling
Expand Down
6 changes: 6 additions & 0 deletions runtime/compiler/control/J9Options.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -183,6 +183,7 @@ int32_t J9::Options::_iProfilerMethodHashTableSize = 32707; // 32707 could be an
int32_t J9::Options::_IprofilerOffSubtractionFactor = 500;
int32_t J9::Options::_IprofilerOffDivisionFactor = 16;

int32_t J9::Options::_IprofilerPreCheckpointDropRate = 0;


int32_t J9::Options::_maxIprofilingCount = TR_DEFAULT_INITIAL_COUNT; // 3000
Expand Down Expand Up @@ -223,6 +224,7 @@ int32_t J9::Options::_waitTimeToExitStartupMode = DEFAULT_WAIT_TIME_TO_EXIT_STAR
int32_t J9::Options::_waitTimeToGCR = 10000; // ms
int32_t J9::Options::_waitTimeToStartIProfiler = 1000; // ms
int32_t J9::Options::_compilationDelayTime = 0; // sec; 0 means disabled
int32_t J9::Options::_delayBeforeStateChange = 500; // ms

int32_t J9::Options::_invocationThresholdToTriggerLowPriComp = 250;

Expand Down Expand Up @@ -937,6 +939,8 @@ TR::OptionTable OMR::Options::_feOptions[] = {
TR::Options::setStaticNumeric, (intptr_t)&TR::Options::_dataCacheQuantumSize, 0, "F%d", NOT_IN_SUBSET},
{"datatotal=", "C<nnn>\ttotal data memory limit, in KB",
TR::Options::setJitConfigNumericValue, offsetof(J9JITConfig, dataCacheTotalKB), 0, "F%d (KB)"},
{"delayBeforeStateChange=", "M<nnn>\tTime (ms) after restore before allowing the JIT to change states.",
TR::Options::setStaticNumeric, (intptr_t)&TR::Options::_delayBeforeStateChange, 0, "F%d", NOT_IN_SUBSET},
{"disableIProfilerClassUnloadThreshold=", "R<nnn>\tNumber of classes that can be unloaded before we disable the IProfiler",
TR::Options::setStaticNumeric, (intptr_t)&TR::Options::_disableIProfilerClassUnloadThreshold, 0, "F%d", NOT_IN_SUBSET},
{"dltPostponeThreshold=", "M<nnn>\tNumber of dlt attempts inv. count for a method is seen not advancing",
Expand Down Expand Up @@ -1055,6 +1059,8 @@ TR::OptionTable OMR::Options::_feOptions[] = {
TR::Options::setStaticNumeric, (intptr_t)&TR::Options::_IprofilerOffDivisionFactor, 0, "F%d", NOT_IN_SUBSET},
{"iprofilerOffSubtractionFactor=", "O<nnn>\tCounts Subtraction factor when IProfiler is Off",
TR::Options::setStaticNumeric, (intptr_t)&TR::Options::_IprofilerOffSubtractionFactor, 0, "F%d", NOT_IN_SUBSET},
{"iprofilerPreCheckpointDropRate=", "O<nnn>\tPercent*10 of buffers to drop precheckpoint",
TR::Options::setStaticNumeric, (intptr_t)&TR::Options::_IprofilerPreCheckpointDropRate, 0, "F%d", NOT_IN_SUBSET},
{"iprofilerSamplesBeforeTurningOff=", "O<nnn>\tnumber of interpreter profiling samples "
"needs to be taken after the profiling starts going off to completely turn it off. "
"Specify a very large value to disable this optimization",
Expand Down
3 changes: 3 additions & 0 deletions runtime/compiler/control/J9Options.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -296,6 +296,8 @@ class OMR_EXTENSIBLE Options : public OMR::OptionsConnector
static int32_t _IprofilerOffSubtractionFactor;
static int32_t _IprofilerOffDivisionFactor;

static int32_t _IprofilerPreCheckpointDropRate;

static int32_t _LoopyMethodSubtractionFactor;
static int32_t _LoopyMethodDivisionFactor;

Expand Down Expand Up @@ -398,6 +400,7 @@ class OMR_EXTENSIBLE Options : public OMR::OptionsConnector
static int32_t _waitTimeToGCR;
static int32_t _waitTimeToStartIProfiler;
static int32_t _compilationDelayTime;
static int32_t _delayBeforeStateChange;

static int32_t _invocationThresholdToTriggerLowPriComp; // we trigger an LPQ comp req only if the method
// was invoked at least this many times
Expand Down
Loading

0 comments on commit 9249e24

Please sign in to comment.