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 4 commits into
base: master
Choose a base branch
from
+174 −0
Open

Add information regarding synchronous compilations in javacore #24236

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
88e217d
Add information regarding synchronous compilations in javacore
dev-koan Jun 24, 2026
5052e90
recent review updates
dev-koan Jul 23, 2026
a89e375
review update
dev-koan Jul 24, 2026
a3b6534
review updates
dev-koan Jul 24, 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;

@keithc-ca keithc-ca Jul 29, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This doesn't appear to be used anywhere: Please remove it.


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;
Comment thread
mpirvu marked this conversation as resolved.
Outdated
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) {
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
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 @@ -6182,6 +6195,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);

@keithc-ca keithc-ca Jul 29, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

With this, line 6375 provides a duplicate local; that line should be removed.

if (!async) {
waitStart = j9time_hires_clock();
}

// Release the compilation monitor
//
debugPrint(vmThread, "\tapplication thread releasing compilation monitor\n");
Expand Down Expand Up @@ -6279,6 +6298,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;

@keithc-ca keithc-ca Jul 24, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This should use the same type as i.

@dev-koan dev-koan Jul 24, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Updated.

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;
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
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),
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
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);
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
uint32_t len = strlen(threadName) + 1;
char *tempThread = (char *)j9mem_allocate_memory(len, J9MEM_CATEGORY_JIT);
if (tempThread != NULL) {
memcpy(tempThread, threadName, len);
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
}
_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
21 changes: 21 additions & 0 deletions runtime/oti/j9nonbuilder.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -297,6 +297,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 */
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
#define J9_LONGEST_SYNC_COMP 3
Comment thread
keithc-ca marked this conversation as resolved.
Outdated

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

typedef struct J9JITLongestSyncComp {
/* microseconds (us) */
uint64_t waitTime;
/* absolute timestamp */
uint64_t waitTimeEnd;
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
char* method;
char* thread;
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
} J9JITLongestSyncComp;

typedef struct J9JITSyncCompilationStatistics {
uint32_t totalCount;
/* microseconds (us) */
uint64_t totalWaitTime;
Comment thread
mpirvu marked this conversation as resolved.
Outdated
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
/* sorted in increasing order */
J9JITLongestSyncComp longestWaitMethods[J9_LONGEST_SYNC_COMP];
Comment thread
mpirvu marked this conversation as resolved.
Outdated
} J9JITSyncCompilationStatistics;

/* @ddr_namespace: map_to_type=J9JITConfig */

typedef struct J9JITConfig {
Expand Down Expand Up @@ -4649,6 +4669,7 @@ typedef struct J9JITConfig {
IDATA verboseOutputLevel;
omrthread_monitor_t compilationMonitor;
void* compilationInfo;
J9JITSyncCompilationStatistics *syncCompStats;
Comment thread
mpirvu marked this conversation as resolved.
Outdated
void* aotCompilationInfo;
void* pseudoTOC;
void* i2jTransition;
Expand Down
74 changes: 74 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,78 @@ 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) {
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
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++) {
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
if (stats->longestWaitMethods[i].waitTime == 0 || stats->longestWaitMethods[i].method == NULL)
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
break;
_OutputStream.writeCharacters("2JITLONGEST ");
_OutputStream.writeInteger64(i + 1, "%zu");
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
_OutputStream.writeCharacters(". Longest 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) {
Comment thread
keithc-ca marked this conversation as resolved.
Outdated
_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;

@keithc-ca keithc-ca Jul 21, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This seems racy: other threads may be active.

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