Merge pull request eclipse-openj9#20885 from adpopescu/jfr-threadpark

Adding in jfr thread park event.

Author: tajila

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 */
 

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;

runtime/oti/j9vm.hdf

@@ -604,6 +604,11 @@ typedef UDATA (* lookupNativeAddressCallback)(struct J9VMThread *currentThread,
 		</description>
 		<struct>J9VMUnparkedEvent</struct>
 		<data type="struct J9VMThread *" name="currentThread" description="current thread" />
+		<data type="I_64" name="millis" description="milliseconds to park for" />
+		<data type="IDATA" name="nanos" description="nanoseconds to park for" />
+		<data type="I_64" name="startTicks" description="current ticks when wait began" />
+		<data type="UDATA" name="parkedAddress" description="object parked address" />
+		<data type="struct J9Class*" name="parkedClass" description="the class which park was called from?" />
 	</event>
 
 	<event>

runtime/oti/vm_api.h

@@ -4935,6 +4935,10 @@ void
 threadParkImpl(J9VMThread *vmThread, BOOLEAN timeoutIsEpochRelative, I_64 timeout);
 void
 threadUnparkImpl (J9VMThread* vmThread, j9object_t threadObject);
+J9Class*
+getThreadParkClassObject(J9VMThread *vmThread);
+UDATA
+getThreadParkClassIterator(J9VMThread *vmThread, J9StackWalkState *walkState);
 
 /* -------------------- threadhelp.cpp ------------ */
 

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)
 	{

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 = (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)
 {

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;
+	U_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);

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)
 {
@@ -691,6 +725,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) {
@@ -821,6 +859,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);