Skip to content

Commit fbec998

Browse files
dev-koandev-koan
committed
d2
1 parent 70be98b commit fbec998

3 files changed

Lines changed: 97 additions & 15 deletions

File tree

‎runtime/compiler/control/CompilationThread.cpp‎

Lines changed: 33 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,8 @@
2121
* Assisted-by: IBM Bob
2222
*******************************************************************************/
2323

24+
#include <_string.h>
25+
#include <cstddef>
2426
#include <cstdint>
2527
#include <sys/wait.h>
2628
#define J9_EXTERNAL_TO_VM
@@ -810,6 +812,12 @@ bool TR::CompilationInfo::createCompilationInfo(J9JITConfig *jitConfig)
810812
_compilationRuntime = new (alloc) TR::CompilationInfo(jitConfig);
811813
jitConfig->compilationRuntime = (void *)_compilationRuntime;
812814
jitConfig->syncCompStats = &_compilationRuntime->_syncCompStats;
815+
_compilationRuntime->_syncCompStats.longestWaitTime = 0;
816+
_compilationRuntime->_syncCompStats.longestWaitTimeStart = 0;
817+
_compilationRuntime->_syncCompStats.longestWaitTimeEnd = 0;
818+
_compilationRuntime->_syncCompStats.longestWaitMethodName = NULL;
819+
_compilationRuntime->_syncCompStats.longestWaitMethodClass = NULL;
820+
_compilationRuntime->_syncCompStats.longestWaitMethodSignature = NULL;
813821
#ifdef DEBUG
814822
if (debug("traceThreadCompile"))
815823
_compilationRuntime->_traceCompiling = true;
@@ -5643,9 +5651,10 @@ void *TR::CompilationInfo::compileMethod(J9VMThread *vmThread, TR::IlGeneratorMe
56435651

56445652
if (needCompile) {
56455653
// AOT goes to application thread?
5646-
if (!fe->isAOT_DEPRECATED_DO_NOT_USE())
5654+
if (!fe->isAOT_DEPRECATED_DO_NOT_USE()) {
56475655
startPC = compileOnSeparateThread(vmThread, details, oldStartPC, requireAsyncCompile, compErrCode, queued,
56485656
optimizationPlan);
5657+
}
56495658
} else {
56505659
if (compErrCode)
56515660
*compErrCode = compilationNotNeeded;
@@ -6164,9 +6173,11 @@ void *TR::CompilationInfo::compileOnSeparateThread(J9VMThread *vmThread, TR::IlG
61646173
// Before releasing the compilation monitor, mark that we have one more thead waiting for this entry
61656174
//
61666175
uint64_t waitStart = 0;
6176+
uint64_t waitStartMs = 0;
61676177
if (!async && entry->_numThreadsWaiting == 0) {
61686178
PORT_ACCESS_FROM_JITCONFIG(jitConfig);
61696179
waitStart = j9time_hires_clock();
6180+
waitStartMs = j9time_current_time_millis();
61706181
}
61716182

61726183
entry->_numThreadsWaiting++;
@@ -6278,6 +6289,27 @@ void *TR::CompilationInfo::compileOnSeparateThread(J9VMThread *vmThread, TR::IlG
62786289

62796290
if (duration > _syncCompStats.longestWaitTime) {
62806291
_syncCompStats.longestWaitTime = duration;
6292+
_syncCompStats.longestWaitTimeStart = waitStartMs;
6293+
_syncCompStats.longestWaitTimeEnd = waitStartMs + (duration / 1000);
6294+
6295+
J9UTF8 *className;
6296+
J9UTF8 *name;
6297+
J9UTF8 *signature;
6298+
getClassNameSignatureFromMethod(method, className, name, signature);
6299+
6300+
if (_syncCompStats.longestWaitMethodName != NULL) {
6301+
free(_syncCompStats.longestWaitMethodName);
6302+
}
6303+
if (_syncCompStats.longestWaitMethodClass != NULL) {
6304+
free(_syncCompStats.longestWaitMethodClass);
6305+
}
6306+
if (_syncCompStats.longestWaitMethodSignature != NULL) {
6307+
free(_syncCompStats.longestWaitMethodSignature);
6308+
}
6309+
6310+
_syncCompStats.longestWaitMethodName = strdup((char *)J9UTF8_DATA(name));
6311+
_syncCompStats.longestWaitMethodClass = strdup((char *)J9UTF8_DATA(className));
6312+
_syncCompStats.longestWaitMethodSignature = strdup((char *)J9UTF8_DATA(signature));
62816313
}
62826314
}
62836315

‎runtime/oti/j9nonbuilder.h‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4325,6 +4325,11 @@ typedef struct J9JITSyncCompilationStatistics {
43254325
uint32_t invalidationCount;
43264326
uint64_t totalWaitTime;
43274327
uint64_t longestWaitTime;
4328+
uint64_t longestWaitTimeStart;
4329+
uint64_t longestWaitTimeEnd;
4330+
char* longestWaitMethodName;
4331+
char* longestWaitMethodClass;
4332+
char* longestWaitMethodSignature;
43284333
} J9JITSyncCompilationStatistics;
43294334

43304335
/* @ddr_namespace: map_to_type=J9JITConfig */

‎runtime/rasdump/javadump.cpp‎

Lines changed: 59 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -557,8 +557,8 @@ JavaCoreDumpWriter::JavaCoreDumpWriter(
557557
CALL_PROTECT(writeSharedClassSection, _Error);
558558
#endif
559559
CALL_PROTECT(writeClassSection, _Error);
560-
CALL_PROTECT(writeTrailer, _Error);
561560
CALL_PROTECT(writeSynchronousCompilationSection, _Error);
561+
CALL_PROTECT(writeTrailer, _Error);
562562

563563
/* Record the status of the operation */
564564
_FileMode = _FileMode || _OutputStream.isOpen();
@@ -2920,37 +2920,82 @@ JavaCoreDumpWriter::writeHookSection(void)
29202920
void
29212921
JavaCoreDumpWriter::writeSynchronousCompilationSection(void)
29222922
{
2923+
char timeStampStart[_MaximumTimeStampLength + 1];
2924+
char timeStampEnd[_MaximumTimeStampLength + 1];
2925+
PORT_ACCESS_FROM_PORT(_PortLibrary);
2926+
OMRPORT_ACCESS_FROM_J9PORT(PORTLIB);
2927+
29232928
J9JITConfig *jitConfig = _VirtualMachine->jitConfig;
29242929
if (NULL == jitConfig || NULL == jitConfig->syncCompStats) {
29252930
return;
29262931
}
29272932

29282933
J9JITSyncCompilationStatistics *stats = jitConfig->syncCompStats;
29292934

2930-
_OutputStream.writeCharacters("0SECTION Synchronous compliations info dump routine\n");
2931-
_OutputStream.writeCharacters("NULL ==============================\n");
2932-
_OutputStream.writeCharacters("1NOTE This data is reset after each javacore file is written\n");
2933-
_OutputStream.writeCharacters("NULL ------------------------------------------------------------------------\n");
2934-
_OutputStream.writeCharacters("1JITSYNCSTATS Synchronous Compilation Statistics\n");
2935-
_OutputStream.writeCharacters("NULL ------------------------------------------------------------------------\n");
2936-
_OutputStream.writeCharacters("2JITSYNCCOUNT Total synchronous compilations: ");
2935+
_OutputStream.writeCharacters("0SECTION Synchronous compliations info dump routine\n");
2936+
_OutputStream.writeCharacters("NULL =============================\n");
2937+
_OutputStream.writeCharacters("1NOTE This data is reset after each javacore file is written\n");
2938+
_OutputStream.writeCharacters("NULL ------------------------------------------------------------------------\n");
2939+
_OutputStream.writeCharacters("1JITSYNCSTATS Synchronous Compilation Statistics\n");
2940+
_OutputStream.writeCharacters("NULL ------------------------------------------------------------------------\n");
2941+
_OutputStream.writeCharacters("2JITSYNCCOUNT Total synchronous compilations: ");
29372942
_OutputStream.writeInteger(stats->totalCount, "%u");
29382943
_OutputStream.writeCharacters("\n");
2939-
_OutputStream.writeCharacters("2JITINVALCOUNT Due to invalidations: ");
2944+
_OutputStream.writeCharacters("2JITINVALCOUNT Due to invalidations: ");
29402945
_OutputStream.writeInteger(stats->invalidationCount, "%u");
29412946
_OutputStream.writeCharacters("\n");
2942-
_OutputStream.writeCharacters("2JITTOTALWAIT Total application wait time: ");
2947+
_OutputStream.writeCharacters("2JITTOTALWAIT Total application wait time: ");
29432948
_OutputStream.writeInteger(stats->totalWaitTime, "%llu");
29442949
_OutputStream.writeCharacters("us\n");
2945-
_OutputStream.writeCharacters("2JITLONGEST Longest Synchronous Compilation\n");
2946-
_OutputStream.writeCharacters("3JITWAITTIME Wait time: ");
2947-
_OutputStream.writeInteger(stats->longestWaitTime, "%llu");
2948-
_OutputStream.writeCharacters("us\n");
2950+
if (stats->longestWaitTime != 0) {
2951+
_OutputStream.writeCharacters("2JITLONGEST Longest Synchronous Compilation\n");
2952+
_OutputStream.writeCharacters("3JITWAITTIME Wait time: ");
2953+
_OutputStream.writeInteger(stats->longestWaitTime, "%llu");
2954+
_OutputStream.writeCharacters("us\n");
2955+
2956+
_OutputStream.writeCharacters("3JITSTARTTIME Wait time start: ");
2957+
omrstr_ftime_ex(timeStampStart, _MaximumTimeStampLength, "%Y-%m-%dT%H:%M:%S", stats->longestWaitTimeStart, OMRSTR_FTIME_FLAG_LOCAL);
2958+
timeStampStart[_MaximumTimeStampLength] = '\0';
2959+
_OutputStream.writeCharacters(timeStampStart);
2960+
_OutputStream.writeInteger64(stats->longestWaitTimeStart % 1000, ".%03llu");
2961+
_OutputStream.writeCharacters("\n");
2962+
2963+
_OutputStream.writeCharacters("3JITENDTIME Wait time end: ");
2964+
omrstr_ftime_ex(timeStampEnd, _MaximumTimeStampLength, "%Y-%m-%dT%H:%M:%S", stats->longestWaitTimeEnd, OMRSTR_FTIME_FLAG_LOCAL);
2965+
timeStampEnd[_MaximumTimeStampLength] = '\0';
2966+
_OutputStream.writeCharacters(timeStampEnd);
2967+
_OutputStream.writeInteger64(stats->longestWaitTimeEnd % 1000, ".%03llu");
2968+
_OutputStream.writeCharacters("\n");
2969+
2970+
_OutputStream.writeCharacters("3JITMETHODNAME Method Name: ");
2971+
_OutputStream.writeCharacters(stats->longestWaitMethodName);
2972+
_OutputStream.writeCharacters("\n");
2973+
_OutputStream.writeCharacters("3JITMETHODCLASS Method Class: ");
2974+
_OutputStream.writeCharacters(stats->longestWaitMethodClass);
2975+
_OutputStream.writeCharacters("\n");
2976+
_OutputStream.writeCharacters("3JITMETHODSIGNATURE Method Signature: ");
2977+
_OutputStream.writeCharacters(stats->longestWaitMethodSignature);
2978+
_OutputStream.writeCharacters("\n");
2979+
}
2980+
2981+
29492982

29502983
stats->totalCount = 0;
29512984
stats->invalidationCount = 0;
29522985
stats->totalWaitTime = 0;
29532986
stats->longestWaitTime = 0;
2987+
if (stats->longestWaitMethodName != NULL) {
2988+
free(stats->longestWaitMethodName);
2989+
stats->longestWaitMethodName = NULL;
2990+
}
2991+
if (stats->longestWaitMethodClass != NULL) {
2992+
free(stats->longestWaitMethodClass);
2993+
stats->longestWaitMethodClass = NULL;
2994+
}
2995+
if (stats->longestWaitMethodSignature != NULL) {
2996+
free(stats->longestWaitMethodSignature);
2997+
stats->longestWaitMethodSignature = NULL;
2998+
}
29542999
}
29553000

29563001
#if defined(OMR_OPT_CUDA)

0 commit comments

Comments
 (0)