Skip to content

Add information regarding synchronous compilations in javacore #24236

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
dev-koan wants to merge 2 commits into
base: master
Choose a base branch
from
Open

Add information regarding synchronous compilations in javacore #24236

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
c681c62
Add information regarding synchronous compilations in javacore
dev-koan Jun 24, 2026
1ca1fb1
using abosulte time stamp for endtime, storing top3 longest sync com…
dev-koan Jul 14, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions runtime/compiler/control/CompilationRuntime.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -512,6 +512,8 @@ class CompilationInfo {
}
}; // CompilationStatsPerInterval

typedef J9JITSyncCompilationStatistics SyncCompilationStatistics;

static bool createCompilationInfo(J9JITConfig *jitConfig);
static void freeCompilationInfo(J9JITConfig *jitConfig);

Expand Down Expand Up @@ -1508,6 +1510,7 @@ class CompilationInfo {

struct CompilationStatistics _stats;
struct CompilationStatsPerInterval _intervalStats;
SyncCompilationStatistics _syncCompStats;
TR_PersistentArray<TR_SignatureCountPair *> *_persistedMethods;

// Must be less than 16 at the JITClient or non-JITServer mode because
Expand Down
78 changes: 78 additions & 0 deletions runtime/compiler/control/CompilationThread.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -807,6 +807,7 @@ bool TR::CompilationInfo::createCompilationInfo(J9JITConfig *jitConfig)
memset(alloc, 0, sizeof(TR::CompilationInfo));
_compilationRuntime = new (alloc) TR::CompilationInfo(jitConfig);
jitConfig->compilationRuntime = (void *)_compilationRuntime;
jitConfig->syncCompStats = &_compilationRuntime->_syncCompStats;
#ifdef DEBUG
if (debug("traceThreadCompile"))
_compilationRuntime->_traceCompiling = true;
Expand Down Expand Up @@ -857,6 +858,18 @@ void TR::CompilationInfo::freeAllResources()
}

freeAllCompilationThreads();

PORT_ACCESS_FROM_JITCONFIG(_jitConfig);
for (int i = 0; i < J9_LONGEST_SYNC_COMP; i++) {
if (_syncCompStats.longestWaitMethods[i].method != NULL) {
j9mem_free_memory(_syncCompStats.longestWaitMethods[i].method);
_syncCompStats.longestWaitMethods[i].method = NULL;
}
if (_syncCompStats.longestWaitMethods[i].thread != NULL) {
j9mem_free_memory(_syncCompStats.longestWaitMethods[i].thread);
_syncCompStats.longestWaitMethods[i].thread = NULL;
}
}
}

void TR::CompilationInfo::freeCompilationInfo(J9JITConfig *jitConfig)
Expand Down Expand Up @@ -6162,6 +6175,12 @@ void *TR::CompilationInfo::compileOnSeparateThread(J9VMThread *vmThread, TR::IlG
//
entry->_numThreadsWaiting++;

uint64_t waitStart = 0;
Comment thread
mpirvu marked this conversation as resolved.
PORT_ACCESS_FROM_JITCONFIG(_jitConfig);
if (!async) {
waitStart = j9time_hires_clock();
}

// Release the compilation monitor
//
debugPrint(vmThread, "\tapplication thread releasing compilation monitor\n");
Expand Down Expand Up @@ -6259,6 +6278,65 @@ void *TR::CompilationInfo::compileOnSeparateThread(J9VMThread *vmThread, TR::IlG

entry->_numThreadsWaiting--;

if (!async) {
uint64_t waitEnd = j9time_hires_clock();
uint64_t duration = j9time_hires_delta(waitStart, waitEnd, J9PORT_TIME_DELTA_IN_MICROSECONDS);

_syncCompStats.totalCount++;
_syncCompStats.totalWaitTime += duration;

/* Obtain index to insert */
int idx = -1;
for (int i = 0; i < J9_LONGEST_SYNC_COMP; i++) {
if (_syncCompStats.longestWaitMethods[i].waitTime < duration) {
idx = i;
break;
}
}

if (idx >= 0) {
/* Remove the shortest wait-time */
J9JITLongestSyncComp &lastMethod = _syncCompStats.longestWaitMethods[J9_LONGEST_SYNC_COMP - 1];
if (lastMethod.method != NULL) {
j9mem_free_memory(lastMethod.method);
lastMethod.method = NULL;
}
if (lastMethod.thread != NULL) {
j9mem_free_memory(lastMethod.thread);
lastMethod.thread = NULL;
}
for (int i = J9_LONGEST_SYNC_COMP - 1; i > idx; i--) {
_syncCompStats.longestWaitMethods[i] = _syncCompStats.longestWaitMethods[i - 1];
}

_syncCompStats.longestWaitMethods[idx].waitTime = duration;
_syncCompStats.longestWaitMethods[idx].waitTimeEnd = j9time_current_time_millis();

J9UTF8 *className;
J9UTF8 *name;
J9UTF8 *signature;
getClassNameSignatureFromMethod(method, className, name, signature);

uint32_t totalLen = J9UTF8_LENGTH(className) + J9UTF8_LENGTH(name) + J9UTF8_LENGTH(signature) + 2;
char *templongestWaitMethod = (char *)j9mem_allocate_memory(totalLen, J9MEM_CATEGORY_JIT);
if (templongestWaitMethod != NULL) {
snprintf(templongestWaitMethod, totalLen, "%.*s.%.*s%.*s", J9UTF8_LENGTH(className),
J9UTF8_DATA(className), J9UTF8_LENGTH(name), J9UTF8_DATA(name), J9UTF8_LENGTH(signature),
J9UTF8_DATA(signature));
}
_syncCompStats.longestWaitMethods[idx].method = templongestWaitMethod;

char *threadName = getOMRVMThreadName(vmThread->omrVMThread);
uint32_t len = strlen(threadName) + 1;
char *tempThread = (char *)j9mem_allocate_memory(len, J9MEM_CATEGORY_JIT);
if (tempThread != NULL) {
memcpy(tempThread, threadName, len);
}
_syncCompStats.longestWaitMethods[idx].thread = tempThread;
releaseOMRVMThreadName(vmThread->omrVMThread);
}
}

TR_ASSERT_FATAL(!(entry->_freeTag & (ENTRY_DEALLOCATED | ENTRY_IN_POOL_FREE)),
"Java thread waking up with a freed entry");

Expand Down
17 changes: 17 additions & 0 deletions runtime/oti/j9nonbuilder.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -295,6 +295,9 @@
#define J9_CATCHTYPE_VALUE_FOR_SYNTHETIC_HANDLER_4BYTES 0xFFFFFFFF
#define J9_CATCHTYPE_VALUE_FOR_SYNTHETIC_HANDLER_2BYTES 0xFFFF

/* Constant for information regarding longest synchronous compilations */
#define J9_LONGEST_SYNC_COMP 3

#if JAVA_SPEC_VERSION >= 19
#define J9JVMTI_MAX_TLS_KEYS 124
typedef void(*j9_tls_finalizer_t)(void *);
Expand Down Expand Up @@ -4334,6 +4337,19 @@ typedef struct J9ClassCastParms {
struct J9Class* castClass;
} J9ClassCastParms;

typedef struct J9JITLongestSyncComp {
uint64_t waitTime; // microseconds (us)
uint64_t waitTimeEnd; // absolute Timestamp
char* method;
char* thread;
} J9JITLongestSyncComp;

typedef struct J9JITSyncCompilationStatistics {
uint32_t totalCount;
uint64_t totalWaitTime; // microseconds (us)
J9JITLongestSyncComp longestWaitMethods[J9_LONGEST_SYNC_COMP];
} J9JITSyncCompilationStatistics;

/* @ddr_namespace: map_to_type=J9JITConfig */

typedef struct J9JITConfig {
Expand Down Expand Up @@ -4607,6 +4623,7 @@ typedef struct J9JITConfig {
IDATA verboseOutputLevel;
omrthread_monitor_t compilationMonitor;
void* compilationInfo;
J9JITSyncCompilationStatistics* syncCompStats;
void* aotCompilationInfo;
void* pseudoTOC;
void* i2jTransition;
Expand Down
82 changes: 82 additions & 0 deletions runtime/rasdump/javadump.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -307,6 +307,7 @@ private :
void writeMonitorSection(void);
void writeThreadSection(void);
void writeClassSection(void);
void writeSynchronousCompilationSection(void);
#if defined(OMR_OPT_CUDA)
void writeCudaSection(void);
#endif /* defined(OMR_OPT_CUDA) */
Expand Down Expand Up @@ -556,6 +557,7 @@ JavaCoreDumpWriter::JavaCoreDumpWriter(
CALL_PROTECT(writeSharedClassSection, _Error);
#endif
CALL_PROTECT(writeClassSection, _Error);
CALL_PROTECT(writeSynchronousCompilationSection, _Error);
CALL_PROTECT(writeTrailer, _Error);

/* Record the status of the operation */
Expand Down Expand Up @@ -2915,6 +2917,86 @@ JavaCoreDumpWriter::writeHookSection(void)
_OutputStream.writeCharacters("NULL ------------------------------------------------------------------------\n");
}

void
JavaCoreDumpWriter::writeSynchronousCompilationSection(void)
{
char timeStamp[_MaximumTimeStampLength + 1];
PORT_ACCESS_FROM_PORT(_PortLibrary);
OMRPORT_ACCESS_FROM_J9PORT(PORTLIB);

J9JITConfig *jitConfig = _VirtualMachine->jitConfig;
if (NULL == jitConfig || NULL == jitConfig->syncCompStats) {
return;
}

J9JITSyncCompilationStatistics *stats = jitConfig->syncCompStats;

_OutputStream.writeCharacters("0SECTION Synchronous compilations info dump routine\n");
_OutputStream.writeCharacters("NULL ==============================\n");
_OutputStream.writeCharacters("1NOTE This data is reset after each javacore file is written\n");
_OutputStream.writeCharacters("NULL ------------------------------------------------------------------------\n");
_OutputStream.writeCharacters("1JITSYNCSTATS Synchronous Compilation Statistics\n");
_OutputStream.writeCharacters("NULL ------------------------------------------------------------------------\n");
_OutputStream.writeCharacters("2JITSYNCCOUNT Total synchronous compilations: ");
_OutputStream.writeInteger(stats->totalCount, "%u");
_OutputStream.writeCharacters("\n");
_OutputStream.writeCharacters("2JITTOTALWAIT Total application wait time: ");
_OutputStream.writeInteger(stats->totalWaitTime, "%llu");
_OutputStream.writeCharacters("us\n");
for (int i = 0; i < J9_LONGEST_SYNC_COMP; i++) {
if (stats->longestWaitMethods[i].waitTime == 0 || stats->longestWaitMethods[i].method == NULL)
break;
_OutputStream.writeCharacters("2JITLONGEST ");
if (i == 0) {
_OutputStream.writeCharacters("Longest");
}
else if (i == 1) {
_OutputStream.writeCharacters("2nd Longest");
}
else {
_OutputStream.writeCharacters("3rd Longest");
}
_OutputStream.writeCharacters(" Synchronous Compilation\n");

_OutputStream.writeCharacters("3JITWAITTIME Wait time: ");
_OutputStream.writeInteger(stats->longestWaitMethods[i].waitTime, "%llu");
_OutputStream.writeCharacters("us\n");

_OutputStream.writeCharacters("3JITENDTIME Wait time end: ");
omrstr_ftime_ex(timeStamp, _MaximumTimeStampLength, "%Y-%m-%dT%H:%M:%S",
stats->longestWaitMethods[i].waitTimeEnd, OMRSTR_FTIME_FLAG_LOCAL);
timeStamp[_MaximumTimeStampLength] = '\0';
_OutputStream.writeCharacters(timeStamp);
_OutputStream.writeInteger64(stats->longestWaitMethods[i].waitTimeEnd % 1000, ".%03llu");
_OutputStream.writeCharacters("\n");

_OutputStream.writeCharacters("3JITMETHOD Method: ");
_OutputStream.writeCharacters(stats->longestWaitMethods[i].method);
_OutputStream.writeCharacters("\n");

if (stats->longestWaitMethods[i].thread != NULL) {
_OutputStream.writeCharacters("3JITTHREAD Thread: ");
_OutputStream.writeCharacters(stats->longestWaitMethods[i].thread);
_OutputStream.writeCharacters("\n");
}
}

stats->totalCount = 0;
stats->totalWaitTime = 0;
for (int i = 0; i < J9_LONGEST_SYNC_COMP; i++) {
stats->longestWaitMethods[i].waitTime = 0;
stats->longestWaitMethods[i].waitTimeEnd = 0;
if (stats->longestWaitMethods[i].method != NULL) {
j9mem_free_memory(stats->longestWaitMethods[i].method);
stats->longestWaitMethods[i].method = NULL;
}
if (stats->longestWaitMethods[i].thread != NULL) {
j9mem_free_memory(stats->longestWaitMethods[i].thread);
stats->longestWaitMethods[i].thread = NULL;
}
}
}

#if defined(OMR_OPT_CUDA)

/**
Expand Down