diff --git a/runtime/oti/VMHelpers.hpp b/runtime/oti/VMHelpers.hpp index c3cab71cd0f..201d98338fb 100644 --- a/runtime/oti/VMHelpers.hpp +++ b/runtime/oti/VMHelpers.hpp @@ -2275,6 +2275,37 @@ class VM_VMHelpers targetThread->privateFlags2 |= J9_PRIVATE_FLAGS2_REENTER_INTERPRETER; indicateAsyncMessagePending(targetThread); } + + static VMINLINE J9Class* + getThreadParkClassObject(J9VMThread *targetThread) + { + J9JavaVM *vm = targetThread->javaVM; + J9StackWalkState walkState = {0}; + J9Class *result = NULL; + jint depth = 2; + walkState.frameWalkFunction = getThreadParkClassIterator; + walkState.walkThread = targetThread; + walkState.skipCount = 0; + walkState.flags = J9_STACKWALK_VISIBLE_ONLY | J9_STACKWALK_INCLUDE_NATIVES | J9_STACKWALK_ITERATE_FRAMES; + walkState.userData1 = (void *) (IDATA) depth; + walkState.userData2 = NULL; + vm->walkStackFrames(targetThread, &walkState); + result = (J9Class*) walkState.userData2; + return result; + } + + static VMINLINE UDATA + getThreadParkClassIterator(J9VMThread *targetThread, J9StackWalkState *walkState) + { + J9Class *currentClass = J9_CLASS_FROM_CP(walkState->constantPool); + if ((UDATA)walkState->userData1 == 0) { + walkState->userData2 = currentClass; + return J9_STACKWALK_STOP_ITERATING; + } else { + walkState->userData1 = (void *) (((UDATA) walkState->userData1) - 1); + return J9_STACKWALK_KEEP_ITERATING; + } + } }; #endif /* VMHELPERS_HPP_ */ diff --git a/runtime/oti/j9consts.h b/runtime/oti/j9consts.h index 4af0f674686..e84a92a01b2 100644 --- a/runtime/oti/j9consts.h +++ b/runtime/oti/j9consts.h @@ -952,6 +952,7 @@ extern "C" { #define J9JFR_EVENT_TYPE_THREAD_CPU_LOAD 6 #define J9JFR_EVENT_TYPE_CLASS_LOADING_STATISTICS 7 #define J9JFR_EVENT_TYPE_THREAD_CONTEXT_SWITCH_RATE 8 +#define J9JFR_EVENT_TYPE_THREAD_PARK 9 /* JFR thread states */ diff --git a/runtime/oti/j9nonbuilder.h b/runtime/oti/j9nonbuilder.h index dafc7c6fcd6..c93b722760b 100644 --- a/runtime/oti/j9nonbuilder.h +++ b/runtime/oti/j9nonbuilder.h @@ -421,6 +421,19 @@ typedef struct J9JFRMonitorWaited { #define J9JFRMonitorWaitedED_STACKTRACE(jfrEvent) ((UDATA*)(((J9JFRMonitorWaited*)(jfrEvent)) + 1)) +typedef struct J9JFRThreadParked { + J9JFR_EVENT_WITH_STACKTRACE_FIELDS + I_64 time; + I_64 duration; + struct J9VMThread *thread; + struct J9Class *parkedClass; + I_64 timeOut; + I_64 untilTime; + UDATA parkedAddress; +} J9JFRThreadParked; + +#define J9JFRTHREADPARKED_STACKTRACE(jfrEvent) ((UDATA*)(((J9JFRThreadParked*)(jfrEvent)) + 1)) + typedef struct J9JFRCPULoad { J9JFR_EVENT_COMMON_FIELDS float jvmUser; diff --git a/runtime/oti/j9vm.hdf b/runtime/oti/j9vm.hdf index 4aaf4affac7..bd496eb5420 100644 --- a/runtime/oti/j9vm.hdf +++ b/runtime/oti/j9vm.hdf @@ -604,6 +604,11 @@ typedef UDATA (* lookupNativeAddressCallback)(struct J9VMThread *currentThread, J9VMUnparkedEvent + + + + + diff --git a/runtime/vm/JFRChunkWriter.hpp b/runtime/vm/JFRChunkWriter.hpp index 521352644b6..5a1145e47a6 100644 --- a/runtime/vm/JFRChunkWriter.hpp +++ b/runtime/vm/JFRChunkWriter.hpp @@ -65,6 +65,7 @@ enum MetadataTypeID { ThreadStartID = 2, ThreadEndID = 3, ThreadSleepID = 4, + ThreadParkID = 5, MonitorWaitID = 7, JVMInformationID = 87, OSInformationID = 88, @@ -339,6 +340,8 @@ class VM_JFRChunkWriter { pool_do(_constantPoolTypes.getMonitorWaitTable(), &writeMonitorWaitEvent, _bufferWriter); + pool_do(_constantPoolTypes.getThreadParkTable(), &writeThreadParkEvent, _bufferWriter); + pool_do(_constantPoolTypes.getCPULoadTable(), &writeCPULoadEvent, _bufferWriter); pool_do(_constantPoolTypes.getThreadCPULoadTable(), &writeThreadCPULoadEvent, _bufferWriter); @@ -552,6 +555,49 @@ class VM_JFRChunkWriter { _bufferWriter->writeLEB128PaddedU32(dataStart, _bufferWriter->getCursor() - dataStart); } + static void + writeThreadParkEvent(void *anElement, void *userData) + { + ThreadParkEntry *entry = (ThreadParkEntry *)anElement; + VM_BufferWriter *_bufferWriter = (VM_BufferWriter *) userData; + + /* reserve size field */ + U_8 *dataStart = _bufferWriter->getAndIncCursor(sizeof(U_32)); + + /* write event type */ + _bufferWriter->writeLEB128(ThreadParkID); + + /* write start time - this is when the sleep started not when it ended so we + * need to subtract the duration since the event is emitted when the sleep ends. + */ + _bufferWriter->writeLEB128(entry->ticks - entry->duration); + + /* write duration time which is always in ticks, in our case nanos */ + _bufferWriter->writeLEB128(entry->duration); + + /* write event thread index */ + _bufferWriter->writeLEB128(entry->eventThreadIndex); + + /* stacktrace index */ + _bufferWriter->writeLEB128(entry->stackTraceIndex); + + /* class index */ + _bufferWriter->writeLEB128(entry->parkedClass); + + /* timeout value which is always in millis */ + _bufferWriter->writeLEB128(entry->timeOut/1000000); + + /* until value which is always in millis */ + _bufferWriter->writeLEB128(entry->untilTime/1000000); + + /* address of monitor */ + _bufferWriter->writeLEB128(entry->parkedAddress); + + /* write size */ + _bufferWriter->writeLEB128PaddedU32(dataStart, _bufferWriter->getCursor() - dataStart); + } + + static void writeCPULoadEvent(void *anElement, void *userData) { diff --git a/runtime/vm/JFRConstantPoolTypes.cpp b/runtime/vm/JFRConstantPoolTypes.cpp index 67663e19bf6..2f81296ae7d 100644 --- a/runtime/vm/JFRConstantPoolTypes.cpp +++ b/runtime/vm/JFRConstantPoolTypes.cpp @@ -1051,8 +1051,8 @@ VM_JFRConstantPoolTypes::addThreadSleepEntry(J9JFRThreadSlept *threadSleepData) entry->stackTraceIndex = consumeStackTrace(threadSleepData->vmThread, J9JFRTHREADSLEPT_STACKTRACE(threadSleepData), threadSleepData->stackTraceSize); if (isResultNotOKay()) goto done; - index = _threadEndCount; - _threadEndCount += 1; + index = _threadSleepCount; + _threadSleepCount += 1; done: return index; @@ -1089,13 +1089,47 @@ VM_JFRConstantPoolTypes::addMonitorWaitEntry(J9JFRMonitorWaited* threadWaitData) entry->notifierThread = 0; //Need a way to find the notifiying thread - index = _threadEndCount; - _threadEndCount += 1; + index = _monitorWaitCount; + _monitorWaitCount += 1; done: return index; } +void +VM_JFRConstantPoolTypes::addThreadParkEntry(J9JFRThreadParked* threadParkData) +{ + ThreadParkEntry *entry = (ThreadParkEntry*)pool_newElement(_threadParkTable); + + if (NULL == entry) { + _buildResult = OutOfMemory; + goto done; + } + + entry->ticks = threadParkData->startTicks; + entry->duration = threadParkData->duration; + + entry->parkedAddress = (I_64)(U_64)threadParkData->parkedAddress; + + entry->threadIndex = addThreadEntry(threadParkData->vmThread); + if (isResultNotOKay()) goto done; + + entry->eventThreadIndex = addThreadEntry(threadParkData->vmThread); + if (isResultNotOKay()) goto done; + + entry->stackTraceIndex = consumeStackTrace(threadParkData->vmThread, J9JFRTHREADPARKED_STACKTRACE(threadParkData), threadParkData->stackTraceSize); + if (isResultNotOKay()) goto done; + + entry->parkedClass = getClassEntry(threadParkData->parkedClass); + if (isResultNotOKay()) goto done; + + entry->timeOut = threadParkData->timeOut; + entry->untilTime = threadParkData->untilTime; + + done: + return; +} + U_32 VM_JFRConstantPoolTypes::addCPULoadEntry(J9JFRCPULoad *cpuLoadData) { diff --git a/runtime/vm/JFRConstantPoolTypes.hpp b/runtime/vm/JFRConstantPoolTypes.hpp index 0c44720079d..f2b5caf2551 100644 --- a/runtime/vm/JFRConstantPoolTypes.hpp +++ b/runtime/vm/JFRConstantPoolTypes.hpp @@ -204,6 +204,18 @@ struct MonitorWaitEntry { BOOLEAN timedOut; }; +struct ThreadParkEntry { + I_64 ticks; + I_64 duration; + U_32 threadIndex; + U_32 eventThreadIndex; + U_32 stackTraceIndex; + U_32 parkedClass; + I_64 timeOut; + I_64 untilTime; + I_64 parkedAddress; +}; + struct StackTraceEntry { J9VMThread *vmThread; I_64 ticks; @@ -316,6 +328,8 @@ class VM_JFRConstantPoolTypes { UDATA _threadSleepCount; J9Pool *_monitorWaitTable; UDATA _monitorWaitCount; + J9Pool *_threadParkTable; + UDATA _threadParkCount; J9Pool *_cpuLoadTable; UDATA _cpuLoadCount; J9Pool *_threadCPULoadTable; @@ -587,6 +601,8 @@ class VM_JFRConstantPoolTypes { U_32 addMonitorWaitEntry(J9JFRMonitorWaited* threadWaitData); + void addThreadParkEntry(J9JFRThreadParked* threadParkData); + U_32 addCPULoadEntry(J9JFRCPULoad *cpuLoadData); U_32 addThreadCPULoadEntry(J9JFRThreadCPULoad *threadCPULoadData); @@ -620,6 +636,11 @@ class VM_JFRConstantPoolTypes { return _monitorWaitTable; } + J9Pool *getThreadParkTable() + { + return _threadParkTable; + } + J9Pool *getCPULoadTable() { return _cpuLoadTable; @@ -665,6 +686,11 @@ class VM_JFRConstantPoolTypes { return _monitorWaitCount; } + UDATA getThreadParkCount() + { + return _threadParkCount; + } + UDATA getCPULoadCount() { return _cpuLoadCount; @@ -828,6 +854,9 @@ class VM_JFRConstantPoolTypes { case J9JFR_EVENT_TYPE_OBJECT_WAIT: addMonitorWaitEntry((J9JFRMonitorWaited*) event); break; + case J9JFR_EVENT_TYPE_THREAD_PARK: + addThreadParkEntry((J9JFRThreadParked*) event); + break; case J9JFR_EVENT_TYPE_CPU_LOAD: addCPULoadEntry((J9JFRCPULoad *)event); break; @@ -1162,6 +1191,8 @@ class VM_JFRConstantPoolTypes { , _threadSleepCount(0) , _monitorWaitTable(NULL) , _monitorWaitCount(0) + , _threadParkTable(NULL) + , _threadParkCount(0) , _cpuLoadTable(NULL) , _cpuLoadCount(0) , _threadCPULoadTable(NULL) @@ -1272,6 +1303,12 @@ class VM_JFRConstantPoolTypes { goto done; } + _threadParkTable = pool_new(sizeof(ThreadParkEntry), 0, sizeof(U_64), 0, J9_GET_CALLSITE(), OMRMEM_CATEGORY_VM, POOL_FOR_PORT(privatePortLibrary)); + if (NULL == _threadParkTable) { + _buildResult = OutOfMemory; + goto done; + } + _cpuLoadTable = pool_new(sizeof(CPULoadEntry), 0, sizeof(U_64), 0, J9_GET_CALLSITE(), OMRMEM_CATEGORY_VM, POOL_FOR_PORT(privatePortLibrary)); if (NULL == _cpuLoadTable) { _buildResult = OutOfMemory; @@ -1382,6 +1419,7 @@ class VM_JFRConstantPoolTypes { pool_kill(_threadEndTable); pool_kill(_threadSleepTable); pool_kill(_monitorWaitTable); + pool_kill(_threadParkTable); pool_kill(_cpuLoadTable); pool_kill(_threadCPULoadTable); pool_kill(_classLoadingStatisticsTable); diff --git a/runtime/vm/jfr.cpp b/runtime/vm/jfr.cpp index 6fdd0b5a68b..da896a3c7bd 100644 --- a/runtime/vm/jfr.cpp +++ b/runtime/vm/jfr.cpp @@ -53,6 +53,7 @@ static void jfrThreadStarting(J9HookInterface **hook, UDATA eventNum, void *even static void jfrThreadEnd(J9HookInterface **hook, UDATA eventNum, void *eventData, void *userData); static void jfrVMInitialized(J9HookInterface **hook, UDATA eventNum, void *eventData, void *userData); static void jfrVMMonitorWaited(J9HookInterface **hook, UDATA eventNum, void *eventData, void *userData); +static void jfrVMThreadParked(J9HookInterface **hook, UDATA eventNum, void *eventData, void *userData); static void jfrStartSamplingThread(J9JavaVM *vm); static void initializeEventFields(J9VMThread *currentThread, J9JFREvent *jfrEvent, UDATA eventType); static int J9THREAD_PROC jfrSamplingThreadProc(void *entryArg); @@ -87,6 +88,9 @@ jfrEventSize(J9JFREvent *jfrEvent) case J9JFR_EVENT_TYPE_OBJECT_WAIT: size = sizeof(J9JFRMonitorWaited) + (((J9JFRMonitorWaited*)jfrEvent)->stackTraceSize * sizeof(UDATA)); break; + case J9JFR_EVENT_TYPE_THREAD_PARK: + size = sizeof(J9JFRThreadParked) + (((J9JFRThreadParked*)jfrEvent)->stackTraceSize * sizeof(UDATA)); + break; case J9JFR_EVENT_TYPE_CPU_LOAD: size = sizeof(J9JFRCPULoad); break; @@ -638,6 +642,36 @@ jfrVMMonitorWaited(J9HookInterface **hook, UDATA eventNum, void *eventData, void } } +/** + * Hook for VM thread parked. Called without VM access. + * + * @param hook[in] the VM hook interface + * @param eventNum[in] the event number + * @param eventData[in] the event data + * @param userData[in] the registered user data + */ +static void +jfrVMThreadParked(J9HookInterface **hook, UDATA eventNum, void *eventData, void* userData) +{ + J9VMUnparkedEvent *event = (J9VMUnparkedEvent *)eventData; + J9VMThread *currentThread = event->currentThread; + PORT_ACCESS_FROM_VMC(currentThread); + +#if defined(DEBUG) + j9tty_printf(PORTLIB, "\n!!! thread park %p\n", currentThread); +#endif /* defined(DEBUG) */ + + J9JFRThreadParked *jfrEvent = (J9JFRThreadParked*)reserveBufferWithStackTrace(currentThread, currentThread, J9JFR_EVENT_TYPE_THREAD_PARK, sizeof(*jfrEvent)); + if (NULL != jfrEvent) { + // TODO: worry about overflow? + jfrEvent->time = (event->millis * 1000000) + event->nanos; + jfrEvent->duration = j9time_nano_time() - event->startTicks; + jfrEvent->parkedAddress = event->parkedAddress; + jfrEvent->parkedClass = event->parkedClass; + } +} + + jint initializeJFR(J9JavaVM *vm, BOOLEAN lateInit) { @@ -690,6 +724,10 @@ initializeJFR(J9JavaVM *vm, BOOLEAN lateInit) goto fail; } + if ((*vmHooks)->J9HookRegisterWithCallSite(vmHooks, J9HOOK_VM_UNPARKED, jfrVMThreadParked, OMR_GET_CALLSITE(), NULL)) { + goto fail; + } + /* Allocate constantEvents. */ vm->jfrState.constantEvents = j9mem_allocate_memory(sizeof(JFRConstantEvents), J9MEM_CATEGORY_VM); if (NULL == vm->jfrState.constantEvents) { @@ -813,6 +851,7 @@ tearDownJFR(J9JavaVM *vm) /* Unregister it anyway even it wasn't registered for initializeJFR(vm, TRUE). */ (*vmHooks)->J9HookUnregister(vmHooks, J9HOOK_VM_INITIALIZED, jfrVMInitialized, NULL); (*vmHooks)->J9HookUnregister(vmHooks, J9HOOK_VM_MONITOR_WAITED, jfrVMMonitorWaited, NULL); + (*vmHooks)->J9HookUnregister(vmHooks, J9HOOK_VM_UNPARKED, jfrVMThreadParked, NULL); /* Free global data */ VM_JFRConstantPoolTypes::freeJFRConstantEvents(vm); diff --git a/runtime/vm/threadpark.cpp b/runtime/vm/threadpark.cpp index 14c5dcce63b..a6ef741e760 100644 --- a/runtime/vm/threadpark.cpp +++ b/runtime/vm/threadpark.cpp @@ -92,6 +92,9 @@ threadParkImpl(J9VMThread *vmThread, BOOLEAN timeoutIsEpochRelative, I_64 timeou if (J9THREAD_TIMED_OUT != rc) { PORT_ACCESS_FROM_VMC(vmThread); + J9Class *parkedClass = VM_VMHelpers::getThreadParkClassObject(vmThread); + UDATA parkedAddress = (UDATA) vmThread->threadObject; + I_64 startTicks = (U_64) j9time_nano_time(); /* vmThread->threadObject != NULL because vmThread must be the current thread */ J9VMTHREAD_SET_BLOCKINGENTEROBJECT(vmThread, vmThread, J9VMJAVALANGTHREAD_PARKBLOCKER(vmThread, vmThread->threadObject)); TRIGGER_J9HOOK_VM_PARK(vm->hookInterface, vmThread, millis, nanos); @@ -113,7 +116,7 @@ threadParkImpl(J9VMThread *vmThread, BOOLEAN timeoutIsEpochRelative, I_64 timeou } internalAcquireVMAccessClearStatus(vmThread, thrstate); - TRIGGER_J9HOOK_VM_UNPARKED(vm->hookInterface, vmThread); + TRIGGER_J9HOOK_VM_UNPARKED(vm->hookInterface, vmThread, millis, nanos, startTicks, (UDATA) parkedAddress, VM_VMHelpers::currentClass(parkedClass)); J9VMTHREAD_SET_BLOCKINGENTEROBJECT(vmThread, vmThread, NULL); } /* Trc_JCL_park_Exit(vmThread, rc); */