diff --git a/runtime/oti/j9nonbuilder.h b/runtime/oti/j9nonbuilder.h index 8ae6c498441..d21ce28bced 100644 --- a/runtime/oti/j9nonbuilder.h +++ b/runtime/oti/j9nonbuilder.h @@ -393,12 +393,13 @@ typedef struct J9JFRThreadStart { #define J9JFRTHREADSTART_STACKTRACE(jfrEvent) ((UDATA*)(((J9JFRThreadStart*)(jfrEvent)) + 1)) /* Variable-size structure - stackTraceSize worth of UDATA follow the fixed portion */ -typedef struct J9JFRThreadSleep { +typedef struct J9JFRThreadSlept { J9JFR_EVENT_WITH_STACKTRACE_FIELDS I_64 time; -} J9JFRThreadSleep; + I_64 duration; +} J9JFRThreadSlept; -#define J9JFRTHREADSLEEP_STACKTRACE(jfrEvent) ((UDATA*)(((J9JFRThreadSleep*)(jfrEvent)) + 1)) +#define J9JFRTHREADSLEPT_STACKTRACE(jfrEvent) ((UDATA*)(((J9JFRThreadSlept*)(jfrEvent)) + 1)) #endif /* defined(J9VM_OPT_JFR) */ diff --git a/runtime/oti/j9vm.hdf b/runtime/oti/j9vm.hdf index fd67b034ee6..4af5de549b9 100644 --- a/runtime/oti/j9vm.hdf +++ b/runtime/oti/j9vm.hdf @@ -278,7 +278,7 @@ typedef UDATA (* lookupNativeAddressCallback)(struct J9VMThread *currentThread, J9VMAcquireVMAccessEvent - + J9HOOK_VM_RELEASEVMACCESS @@ -287,13 +287,13 @@ typedef UDATA (* lookupNativeAddressCallback)(struct J9VMThread *currentThread, J9VMReleaseVMAccessEvent - + J9HOOK_VM_ACQUIRING_EXCLUSIVE_IN_NATIVE Triggered during acquire exclusive thread loop, when encountered a thread in native (which we did not count for exclusive). This hook serves similar purpose as J9HOOK_VM_RELEASEVMACCESS, to ensure that required work for thread in native - is performed before exclusive access is obtained. + is performed before exclusive access is obtained. J9VMAcquringExclusiveInNativeEvent @@ -608,7 +608,7 @@ typedef UDATA (* lookupNativeAddressCallback)(struct J9VMThread *currentThread, Triggered just before an instance field is read by the bytecode interpreter or JNI. If the listener allows a GC to occur, the object field in the hook - data must be kept up-to-date. + data must be kept up-to-date. J9VMGetFieldEvent @@ -1216,6 +1216,9 @@ typedef UDATA (* lookupNativeAddressCallback)(struct J9VMThread *currentThread, J9VMSleptEvent + + + diff --git a/runtime/vm/BufferWriter.hpp b/runtime/vm/BufferWriter.hpp index fc149d4f475..990774985c5 100644 --- a/runtime/vm/BufferWriter.hpp +++ b/runtime/vm/BufferWriter.hpp @@ -218,6 +218,33 @@ class VM_BufferWriter { } while (newVal > 0); } + void + writeLEB128PaddedU72(U_8 *cursor, U_64 val) + { + U_8 *old = _cursor; + _cursor = cursor; + writeLEB128PaddedU72(val); + _cursor = old; + } + + void + writeLEB128PaddedU72(U_64 val) + { + U_64 newVal = val; + if (!_isLE) { + newVal = byteSwap(val); + } + writeU8((newVal & 0x7F) | 0x80); + writeU8(((newVal >> 7) & 0x7F) | 0x80); + writeU8(((newVal >> 14) & 0x7F) | 0x80); + writeU8(((newVal >> 21) & 0x7F) | 0x80); + writeU8(((newVal >> 28) & 0x7F) | 0x80); + writeU8(((newVal >> 35) & 0x7F) | 0x80); + writeU8(((newVal >> 42) & 0x7F) | 0x80); + writeU8(((newVal >> 49) & 0x7F) | 0x80); + writeU8(((newVal >> 56) & 0x7F)); + } + void writeLEB128PaddedU64(U_8 *cursor, U_64 val) { @@ -328,7 +355,12 @@ class VM_BufferWriter { if (J9_ARE_ALL_BITS_SET(*start, 0x80)) { start++; - val |= (U_64)(*start & 0X7F) << 59; + val |= (U_64)(*start & 0X7F) << 49; + } + + if (J9_ARE_ALL_BITS_SET(*start, 0x80)) { + start++; + val |= (U_64)(*start & 0X7F) << 56; } if (!_isLE) { val = byteSwap(val); diff --git a/runtime/vm/JFRChunkWriter.cpp b/runtime/vm/JFRChunkWriter.cpp index 083fd7853db..8b4f7f68675 100644 --- a/runtime/vm/JFRChunkWriter.cpp +++ b/runtime/vm/JFRChunkWriter.cpp @@ -55,8 +55,8 @@ VM_JFRChunkWriter::writeJFRHeader() /* start ticks */ _bufferWriter->writeU64(0); // 48 - /* ticks per second */ - _bufferWriter->writeU64(1); // 56 // TODO ??? + /* ticks per second - 1000_000_000 ticks per second means that we are reporting nanosecond timestamps */ + _bufferWriter->writeU64(1000000000); // 56 /* file state or generation */ _bufferWriter->writeU8(0); // 64 // TODO ??? diff --git a/runtime/vm/JFRChunkWriter.hpp b/runtime/vm/JFRChunkWriter.hpp index 5d8b7339ea0..7e4f3eeae41 100644 --- a/runtime/vm/JFRChunkWriter.hpp +++ b/runtime/vm/JFRChunkWriter.hpp @@ -408,7 +408,7 @@ class VM_JFRChunkWriter { /* write start time */ _bufferWriter->writeLEB128(entry->time); - /* write duration time */ + /* write duration time which is always in ticks, in our case nanos */ _bufferWriter->writeLEB128(entry->duration); /* write event thread index */ @@ -417,11 +417,8 @@ class VM_JFRChunkWriter { /* stacktrace index */ _bufferWriter->writeLEB128(entry->stackTraceIndex); - /* write thread index */ - _bufferWriter->writeLEB128(entry->threadIndex); - - /* write time */ - _bufferWriter->writeLEB128(entry->duration); + /* write sleep time which is always in millis */ + _bufferWriter->writeLEB128(entry->sleepTime/1000000); /* write size */ _bufferWriter->writeLEB128PaddedU32(dataStart, _bufferWriter->getCursor() - dataStart); diff --git a/runtime/vm/JFRConstantPoolTypes.cpp b/runtime/vm/JFRConstantPoolTypes.cpp index 84e41d4b3e9..380244efa2e 100644 --- a/runtime/vm/JFRConstantPoolTypes.cpp +++ b/runtime/vm/JFRConstantPoolTypes.cpp @@ -1002,7 +1002,7 @@ VM_JFRConstantPoolTypes::addThreadEndEntry(J9JFREvent *threadEndData) } U_32 -VM_JFRConstantPoolTypes::addThreadSleepEntry(J9JFRThreadSleep *threadSleepData) +VM_JFRConstantPoolTypes::addThreadSleepEntry(J9JFRThreadSlept *threadSleepData) { ThreadSleepEntry *entry = (ThreadSleepEntry*)pool_newElement(_threadSleepTable); U_32 index = U_32_MAX; @@ -1013,7 +1013,8 @@ VM_JFRConstantPoolTypes::addThreadSleepEntry(J9JFRThreadSleep *threadSleepData) } entry->time = threadSleepData->startTime; - entry->duration = threadSleepData->time; + entry->duration = threadSleepData->duration; + entry->sleepTime = threadSleepData->time; entry->threadIndex = addThreadEntry(threadSleepData->vmThread); if (isResultNotOKay()) goto done; diff --git a/runtime/vm/JFRConstantPoolTypes.hpp b/runtime/vm/JFRConstantPoolTypes.hpp index 50e757b8ada..4e1a8999126 100644 --- a/runtime/vm/JFRConstantPoolTypes.hpp +++ b/runtime/vm/JFRConstantPoolTypes.hpp @@ -180,6 +180,7 @@ struct ThreadEndEntry { struct ThreadSleepEntry { I_64 time; I_64 duration; + I_64 sleepTime; U_32 threadIndex; U_32 eventThreadIndex; U_32 stackTraceIndex; @@ -459,7 +460,7 @@ class VM_JFRConstantPoolTypes { U_32 addThreadEndEntry(J9JFREvent *threadEndData); - U_32 addThreadSleepEntry(J9JFRThreadSleep *threadSleepData); + U_32 addThreadSleepEntry(J9JFRThreadSlept *threadSleepData); J9Pool *getExecutionSampleTable() { @@ -627,7 +628,7 @@ class VM_JFRConstantPoolTypes { addThreadEndEntry((J9JFREvent*) event); break; case J9JFR_EVENT_TYPE_THREAD_SLEEP: - addThreadSleepEntry((J9JFRThreadSleep*) event); + addThreadSleepEntry((J9JFRThreadSlept*) event); break; default: Assert_VM_unreachable(); diff --git a/runtime/vm/JFRUtils.hpp b/runtime/vm/JFRUtils.hpp index 3b852aa2056..4baafa96d95 100644 --- a/runtime/vm/JFRUtils.hpp +++ b/runtime/vm/JFRUtils.hpp @@ -57,7 +57,8 @@ class VM_JFRUtils { public: - static U_64 getCurrentTimeNanos(J9PortLibrary *privatePortLibrary, BuildResult &buildResult) { + static U_64 getCurrentTimeNanos(J9PortLibrary *privatePortLibrary, BuildResult &buildResult) + { UDATA success = 0; U_64 result = (U_64) j9time_current_time_nanos(&success); diff --git a/runtime/vm/jfr.cpp b/runtime/vm/jfr.cpp index 12a44961de9..b087e263a06 100644 --- a/runtime/vm/jfr.cpp +++ b/runtime/vm/jfr.cpp @@ -75,7 +75,7 @@ jfrEventSize(J9JFREvent *jfrEvent) size = sizeof(J9JFREvent); break; case J9JFR_EVENT_TYPE_THREAD_SLEEP: - size = sizeof(J9JFRThreadSleep) + (((J9JFRThreadSleep*)jfrEvent)->stackTraceSize * sizeof(UDATA)); + size = sizeof(J9JFRThreadSlept) + (((J9JFRThreadSlept*)jfrEvent)->stackTraceSize * sizeof(UDATA)); break; default: Assert_VM_unreachable(); @@ -482,20 +482,26 @@ jfrThreadEnd(J9HookInterface **hook, UDATA eventNum, void *eventData, void *user * @param userData[in] the registered user data */ static void -jfrVMSleep(J9HookInterface **hook, UDATA eventNum, void *eventData, void *userData) +jfrVMSlept(J9HookInterface **hook, UDATA eventNum, void *eventData, void *userData) { - J9VMSleepEvent *event = (J9VMSleepEvent *)eventData; + J9VMSleptEvent *event = (J9VMSleptEvent *)eventData; J9VMThread *currentThread = event->currentThread; + PORT_ACCESS_FROM_VMC(currentThread); #if defined(DEBUG) - PORT_ACCESS_FROM_VMC(currentThread); j9tty_printf(PORTLIB, "\n!!! thread sleep %p\n", currentThread); #endif /* defined(DEBUG) */ - J9JFRThreadSleep *jfrEvent = (J9JFRThreadSleep*)reserveBufferWithStackTrace(currentThread, currentThread, J9JFR_EVENT_TYPE_THREAD_SLEEP, sizeof(*jfrEvent)); + J9JFRThreadSlept *jfrEvent = (J9JFRThreadSlept*)reserveBufferWithStackTrace(currentThread, currentThread, J9JFR_EVENT_TYPE_THREAD_SLEEP, sizeof(*jfrEvent)); if (NULL != jfrEvent) { // TODO: worry about overflow? - jfrEvent->time = (event->millis * 1000) + event->nanos; + jfrEvent->time = (event->millis * 1000000) + event->nanos; + jfrEvent->duration = 0; + UDATA result = 0; + I_64 currentNanos = j9time_current_time_nanos(&result); + if (0 != result) { + jfrEvent->duration = currentNanos - event->startNanos; + } } } @@ -560,7 +566,7 @@ initializeJFR(J9JavaVM *vm) if ((*vmHooks)->J9HookRegisterWithCallSite(vmHooks, J9HOOK_VM_THREAD_END, jfrThreadEnd, OMR_GET_CALLSITE(), NULL)) { goto fail; } - if ((*vmHooks)->J9HookRegisterWithCallSite(vmHooks, J9HOOK_VM_SLEEP, jfrVMSleep, OMR_GET_CALLSITE(), NULL)) { + if ((*vmHooks)->J9HookRegisterWithCallSite(vmHooks, J9HOOK_VM_SLEPT, jfrVMSlept, OMR_GET_CALLSITE(), NULL)) { goto fail; } if ((*vmHooks)->J9HookRegisterWithCallSite(vmHooks, J9HOOK_VM_INITIALIZED, jfrVMInitialized, OMR_GET_CALLSITE(), NULL)) { @@ -631,7 +637,7 @@ tearDownJFR(J9JavaVM *vm) (*vmHooks)->J9HookUnregister(vmHooks, J9HOOK_VM_SHUTTING_DOWN, jfrVMShutdown, NULL); (*vmHooks)->J9HookUnregister(vmHooks, J9HOOK_VM_THREAD_STARTING, jfrThreadStarting, NULL); (*vmHooks)->J9HookUnregister(vmHooks, J9HOOK_VM_THREAD_END, jfrThreadEnd, NULL); - (*vmHooks)->J9HookUnregister(vmHooks, J9HOOK_VM_SLEEP, jfrVMSleep, NULL); + (*vmHooks)->J9HookUnregister(vmHooks, J9HOOK_VM_SLEPT, jfrVMSlept, NULL); (*vmHooks)->J9HookUnregister(vmHooks, J9HOOK_VM_INITIALIZED, jfrVMInitialized, NULL); /* Free global data */ diff --git a/runtime/vm/threadhelp.cpp b/runtime/vm/threadhelp.cpp index 3b28f2ba306..92254de6647 100644 --- a/runtime/vm/threadhelp.cpp +++ b/runtime/vm/threadhelp.cpp @@ -49,12 +49,12 @@ validateTimeouts(J9VMThread *vmThread, I_64 millis, I_32 nanos) if (millis < 0) { setCurrentExceptionNLS( - vmThread, + vmThread, J9VMCONSTANTPOOL_JAVALANGILLEGALARGUMENTEXCEPTION, J9NLS_JCL_TIMEOUT_VALUE_IS_NEGATIVE); } else if (nanos < 0 || nanos >= 1000000) { setCurrentExceptionNLS( - vmThread, + vmThread, J9VMCONSTANTPOOL_JAVALANGILLEGALARGUMENTEXCEPTION, J9NLS_JCL_NANOSECOND_TIMEOUT_VALUE_OUT_OF_RANGE); } else { @@ -162,15 +162,24 @@ threadSleepImpl(J9VMThread *vmThread, I_64 millis, I_32 nanos) /* An IllegalArgumentException has been set. */ rc = -1; } else { + PORT_ACCESS_FROM_JAVAVM(javaVM); + UDATA result = 0; + I_64 startNanos = (U_64) j9time_current_time_nanos(&result); + if (0 == result){ + setCurrentException(vmThread, J9VMCONSTANTPOOL_JAVALANGINTERNALERROR, NULL); + rc = -1; + } #ifdef J9VM_OPT_SIDECAR /* Increment the wait count even if the deadline is past. */ vmThread->mgmtWaitedCount++; #endif - TRIGGER_J9HOOK_VM_SLEEP(javaVM->hookInterface, vmThread, millis, nanos); - internalReleaseVMAccessSetStatus(vmThread, J9_PUBLIC_FLAGS_THREAD_SLEEPING); - rc = timeCompensationHelper(vmThread, HELPER_TYPE_THREAD_SLEEP, NULL, millis, nanos); - internalAcquireVMAccessClearStatus(vmThread, J9_PUBLIC_FLAGS_THREAD_SLEEPING); - TRIGGER_J9HOOK_VM_SLEPT(javaVM->hookInterface, vmThread); + if (0 == rc) { + TRIGGER_J9HOOK_VM_SLEEP(javaVM->hookInterface, vmThread, millis, nanos); + internalReleaseVMAccessSetStatus(vmThread, J9_PUBLIC_FLAGS_THREAD_SLEEPING); + rc = timeCompensationHelper(vmThread, HELPER_TYPE_THREAD_SLEEP, NULL, millis, nanos); + internalAcquireVMAccessClearStatus(vmThread, J9_PUBLIC_FLAGS_THREAD_SLEEPING); + TRIGGER_J9HOOK_VM_SLEPT(javaVM->hookInterface, vmThread, millis, nanos, startNanos); + } if (0 == rc) { /* Trc_JCL_sleep_Exit(vmThread); */ @@ -225,7 +234,7 @@ getMonitorForWait(J9VMThread* vmThread, j9object_t object) return NULL; } lockEA = &objectMonitor->alternateLockword; - } + } else { lockEA = J9OBJECT_MONITOR_EA(vmThread, object); } @@ -233,7 +242,7 @@ getMonitorForWait(J9VMThread* vmThread, j9object_t object) if (J9_LOCK_IS_INFLATED(lock)) { objectMonitor = J9_INFLLOCK_OBJECT_MONITOR(lock); - + monitor = objectMonitor->monitor; // Trc_JCL_foundMonitorInLockword(vmThread, monitor, object);