void
MM_ParallelMarkTask::cleanup(MM_EnvironmentBase *env)
{
_markingScheme->workerCleanupAfterGC(env);
if (env->isMasterThread()) {
Assert_MM_true(_cycleState == env->_cycleState);
} else {
env->_cycleState = NULL;
}
/* record the thread-specific parallelism stats in the trace buffer. This partially duplicates info in -Xtgc:parallel */
OMRPORT_ACCESS_FROM_OMRPORT(env->getPortLibrary());
Trc_MM_ParallelMarkTask_parallelStats(
env->getLanguageVMThread(),
(uint32_t)env->getSlaveID(),
(uint32_t)omrtime_hires_delta(0, env->_workPacketStats._workStallTime, OMRPORT_TIME_DELTA_IN_MILLISECONDS),
(uint32_t)omrtime_hires_delta(0, env->_workPacketStats._completeStallTime, OMRPORT_TIME_DELTA_IN_MILLISECONDS),
(uint32_t)omrtime_hires_delta(0, env->_markStats._syncStallTime, OMRPORT_TIME_DELTA_IN_MILLISECONDS),
(uint32_t)env->_workPacketStats._workStallCount,
(uint32_t)env->_workPacketStats._completeStallCount,
(uint32_t)env->_markStats._syncStallCount,
env->_workPacketStats.workPacketsAcquired,
env->_workPacketStats.workPacketsReleased,
env->_workPacketStats.workPacketsExchanged,
0/* TODO CRG figure out to get the array split size*/);
}
/**
* Gather sweep statistics into the global statistics counter at the end of the sweep task.
*/
void
MM_ParallelSweepTask::cleanup(MM_EnvironmentBase *env)
{
OMRPORT_ACCESS_FROM_OMRPORT(env->getPortLibrary());
MM_GlobalGCStats *finalGCStats = &env->getExtensions()->globalGCStats;
finalGCStats->sweepStats.merge(&env->_sweepStats);
Trc_MM_ParallelSweepTask_parallelStats(
env->getLanguageVMThread(),
(uint32_t)env->getSlaveId(),
(uint32_t)omrtime_hires_delta(0, env->_sweepStats.idleTime, OMRPORT_TIME_DELTA_IN_MILLISECONDS),
env->_sweepStats.sweepChunksProcessed,
(uint32_t)omrtime_hires_delta(0, env->_sweepStats.mergeTime, OMRPORT_TIME_DELTA_IN_MILLISECONDS));
}
void
MM_VerboseHandlerOutputStandard::handleScavengeEnd(J9HookInterface** hook, uintptr_t eventNum, void* eventData)
{
MM_ScavengeEndEvent* event = (MM_ScavengeEndEvent*)eventData;
MM_EnvironmentBase* env = MM_EnvironmentBase::getEnvironment(event->currentThread);
MM_GCExtensionsBase *extensions = MM_GCExtensionsBase::getExtensions(env->getOmrVM());
MM_VerboseManager* manager = getManager();
MM_VerboseWriterChain* writer = manager->getWriterChain();
MM_ScavengerStats *scavengerStats = &extensions->scavengerStats;
OMRPORT_ACCESS_FROM_OMRPORT(env->getPortLibrary());
uint64_t duration = 0;
bool deltaTimeSuccess = getTimeDeltaInMicroSeconds(&duration, scavengerStats->_startTime, scavengerStats->_endTime);
enterAtomicReportingBlock();
handleGCOPOuterStanzaStart(env, "scavenge", env->_cycleState->_verboseContextID, duration, deltaTimeSuccess);
writer->formatAndOutput(env, 1, "<scavenger-info tenureage=\"%zu\" tenuremask=\"%4zx\" tiltratio=\"%zu\" />", scavengerStats->_tenureAge, scavengerStats->getFlipHistory(0)->_tenureMask, scavengerStats->_tiltRatio);
if (0 != scavengerStats->_flipCount) {
writer->formatAndOutput(env, 1, "<memory-copied type=\"nursery\" objects=\"%zu\" bytes=\"%zu\" bytesdiscarded=\"%zu\" />",
scavengerStats->_flipCount, scavengerStats->_flipBytes, scavengerStats->_flipDiscardBytes);
}
if (0 != scavengerStats->_tenureAggregateCount) {
writer->formatAndOutput(env, 1, "<memory-copied type=\"tenure\" objects=\"%zu\" bytes=\"%zu\" bytesdiscarded=\"%zu\" />",
scavengerStats->_tenureAggregateCount, scavengerStats->_tenureAggregateBytes, scavengerStats->_tenureDiscardBytes);
}
if (0 != scavengerStats->_failedFlipCount) {
writer->formatAndOutput(env, 1, "<copy-failed type=\"nursery\" objects=\"%zu\" bytes=\"%zu\" />",
scavengerStats->_failedFlipCount, scavengerStats->_failedFlipBytes);
}
if (0 != scavengerStats->_failedTenureCount) {
writer->formatAndOutput(env, 1, "<copy-failed type=\"tenure\" objects=\"%zu\" bytes=\"%zu\" />",
scavengerStats->_failedTenureCount, scavengerStats->_failedTenureBytes);
}
handleScavengeEndInternal(env, eventData);
if(0 != scavengerStats->_tenureExpandedCount) {
uint64_t expansionMicros = omrtime_hires_delta(0, scavengerStats->_tenureExpandedTime, OMRPORT_TIME_DELTA_IN_MICROSECONDS);
outputCollectorHeapResizeInfo(env, 1, HEAP_EXPAND, scavengerStats->_tenureExpandedBytes, scavengerStats->_tenureExpandedCount, MEMORY_TYPE_OLD, SATISFY_COLLECTOR, expansionMicros);
}
if(scavengerStats->_rememberedSetOverflow) {
writer->formatAndOutput(env, 1, "<warning details=\"remembered set overflow detected\" />");
if(scavengerStats->_causedRememberedSetOverflow) {
writer->formatAndOutput(env, 1, "<warning details=\"remembered set overflow triggered\" />");
}
}
if(scavengerStats->_scanCacheOverflow) {
writer->formatAndOutput(env, 1, "<warning details=\"scan cache overflow (storage acquired from heap)\" />");
}
if(scavengerStats->_backout) {
writer->formatAndOutput(env, 1, "<warning details=\"aborted collection due to insufficient free space\" />");
}
handleGCOPOuterStanzaEnd(env);
writer->flush(env);
exitAtomicReportingBlock();
}
void
MM_VerboseHandlerOutputStandard::handleConcurrentCollectionStart(J9HookInterface** hook, uintptr_t eventNum, void* eventData)
{
MM_ConcurrentCollectionStartEvent* event = (MM_ConcurrentCollectionStartEvent*)eventData;
MM_VerboseManager* manager = getManager();
MM_VerboseWriterChain* writer = manager->getWriterChain();
MM_EnvironmentBase* env = MM_EnvironmentBase::getEnvironment(event->currentThread);
OMRPORT_ACCESS_FROM_ENVIRONMENT(env);
uint64_t currentTime = event->timestamp;
uint64_t previousTime = manager->getLastConcurrentGCTime();
manager->setLastConcurrentGCTime(currentTime);
if (0 == previousTime) {
previousTime = manager->getInitializedTime();
}
uint64_t deltaTime = omrtime_hires_delta(previousTime, currentTime, OMRPORT_TIME_DELTA_IN_MICROSECONDS);
const char* cardCleaningReasonString = "unknown";
switch (event->cardCleaningReason) {
case TRACING_COMPLETED:
cardCleaningReasonString = "tracing completed";
break;
case CARD_CLEANING_THRESHOLD_REACHED:
cardCleaningReasonString = "card cleaning threshold reached";
break;
}
char tagTemplate[200];
enterAtomicReportingBlock();
getTagTemplate(tagTemplate, sizeof(tagTemplate), manager->getIdAndIncrement(), omrtime_current_time_millis());
writer->formatAndOutput(env, 0, "<concurrent-collection-start %s intervalms=\"%llu.%03llu\" >",
tagTemplate, deltaTime / 1000, deltaTime % 1000);
writer->formatAndOutput(env, 1, "<concurrent-trace-info reason=\"%s\" tracedByMutators=\"%zu\" tracedByHelpers=\"%zu\" cardsCleaned=\"%zu\" workStackOverflowCount=\"%zu\" />",
cardCleaningReasonString, event->tracedByMutators, event->tracedByHelpers, event->cardsCleaned, event->workStackOverflowCount);
writer->formatAndOutput(env, 0, "</concurrent-collection-start>");
writer->flush(env);
handleConcurrentCollectionStartInternal(env, eventData);
exitAtomicReportingBlock();
}
void
MM_VerboseHandlerOutputStandard::handleConcurrentTracingEnd(J9HookInterface** hook, uintptr_t eventNum, void* eventData)
{
MM_ConcurrentCompleteTracingEndEvent* event = (MM_ConcurrentCompleteTracingEndEvent*)eventData;
MM_VerboseManager* manager = getManager();
MM_VerboseWriterChain* writer = manager->getWriterChain();
MM_EnvironmentBase* env = MM_EnvironmentBase::getEnvironment(event->currentThread);
OMRPORT_ACCESS_FROM_ENVIRONMENT(env);
uint64_t durationUs = omrtime_hires_delta(0, event->duration, OMRPORT_TIME_DELTA_IN_MICROSECONDS);
enterAtomicReportingBlock();
handleGCOPOuterStanzaStart(env, "tracing", env->_cycleState->_verboseContextID, durationUs, true);
writer->formatAndOutput(env, 1, "<trace bytesTraced=\"%zu\" workStackOverflowCount=\"%zu\" />", event->bytesTraced, event->workStackOverflowCount);
handleConcurrentTracingEndInternal(env, eventData);
handleGCOPOuterStanzaEnd(env);
writer->flush(env);
exitAtomicReportingBlock();
}
