From 264a74f3438bda1eb655d2a3668b0ce8ea1a6224 Mon Sep 17 00:00:00 2001 From: John Salem Date: Fri, 4 Jun 2021 18:57:21 -0700 Subject: [PATCH 01/21] Add JIT time metric * add per thread privately * add test for counter * add test for priuvate metric (currently failing due to linker I think) --- .../src/ILLink/ILLink.Descriptors.Shared.xml | 4 ++ .../RuntimeHelpers.CoreCLR.cs | 6 ++ src/coreclr/vm/ecalllist.h | 2 + src/coreclr/vm/jitinterface.cpp | 37 ++++++++++ src/coreclr/vm/jitinterface.h | 2 + .../Diagnostics/Tracing/RuntimeEventSource.cs | 2 + .../tracing/eventcounter/perthreadjittime.cs | 71 +++++++++++++++++++ .../eventcounter/perthreadjittime.csproj | 17 +++++ .../tracing/eventcounter/runtimecounters.cs | 3 +- 9 files changed, 143 insertions(+), 1 deletion(-) create mode 100644 src/tests/tracing/eventcounter/perthreadjittime.cs create mode 100644 src/tests/tracing/eventcounter/perthreadjittime.csproj diff --git a/src/coreclr/System.Private.CoreLib/src/ILLink/ILLink.Descriptors.Shared.xml b/src/coreclr/System.Private.CoreLib/src/ILLink/ILLink.Descriptors.Shared.xml index 4384581b1d1321..c3ec4cd4258209 100644 --- a/src/coreclr/System.Private.CoreLib/src/ILLink/ILLink.Descriptors.Shared.xml +++ b/src/coreclr/System.Private.CoreLib/src/ILLink/ILLink.Descriptors.Shared.xml @@ -36,6 +36,10 @@ + + + + diff --git a/src/coreclr/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.CoreCLR.cs b/src/coreclr/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.CoreCLR.cs index b4d95defcaa5bb..1277216b3f5c0f 100644 --- a/src/coreclr/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.CoreCLR.cs +++ b/src/coreclr/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.CoreCLR.cs @@ -361,6 +361,12 @@ private static unsafe void DispatchTailCalls( [MethodImpl(MethodImplOptions.InternalCall)] internal static extern int GetMethodsJittedCount(); + + [MethodImpl(MethodImplOptions.InternalCall)] + internal static extern long GetNanosecondsInJit(); + + [MethodImpl(MethodImplOptions.InternalCall)] + internal static extern long GetNanosecondsInJitForThread(); } // Helper class to assist with unsafe pinning of arbitrary objects. // It's used by VM code. diff --git a/src/coreclr/vm/ecalllist.h b/src/coreclr/vm/ecalllist.h index 48a2d7d322e574..147fb889ff1955 100644 --- a/src/coreclr/vm/ecalllist.h +++ b/src/coreclr/vm/ecalllist.h @@ -878,6 +878,8 @@ FCFuncStart(gRuntimeHelpers) FCFuncElement("GetTailCallInfo", TailCallHelp::GetTailCallInfo) FCFuncElement("GetILBytesJitted", GetJittedBytes) FCFuncElement("GetMethodsJittedCount", GetJittedMethodsCount) + FCFuncElement("GetNanosecondsInJit", GetNanosecondsInJit) + FCFuncElement("GetNanosecondsInJitForThread", GetNanosecondsInJitForThread) FCFuncEnd() FCFuncStart(gMngdFixedArrayMarshalerFuncs) diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index 02fae7f99f2bba..dab80f8a6fa444 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -104,6 +104,8 @@ GARY_IMPL(VMHELPDEF, hlpDynamicFuncTable, DYNAMIC_CORINFO_HELP_COUNT); uint64_t g_cbILJitted = 0; uint32_t g_cMethodsJitted = 0; +thread_local int64_t g_cNanosecondsInJitForThread = 0; +int64_t g_cNanosecondsInJit = 0; #ifndef CROSSGEN_COMPILE FCIMPL0(INT64, GetJittedBytes) @@ -121,6 +123,22 @@ FCIMPL0(INT32, GetJittedMethodsCount) return g_cMethodsJitted; } FCIMPLEND + +FCIMPL0(INT64, GetNanosecondsInJit) +{ + FCALL_CONTRACT; + + return g_cNanosecondsInJit; +} +FCIMPLEND + +FCIMPL0(INT64, GetNanosecondsInJitForThread) +{ + FCALL_CONTRACT; + + return g_cNanosecondsInJitForThread; +} +FCIMPLEND #endif /*********************************************************************/ @@ -13015,9 +13033,21 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, MethodDesc* ftn = nativeCodeVersion.GetMethodDesc(); PCODE ret = NULL; + int64_t jitStartTimestamp = 0; + int64_t jitEndTimestamp = 0; + int64_t jitTimeNs = 0; + static int64_t qpcFrequency = 1; + LARGE_INTEGER qpcValue; COOPERATIVE_TRANSITION_BEGIN(); + if (qpcFrequency == 1) + if (QueryPerformanceFrequency (&qpcValue)) + qpcFrequency = static_cast(qpcValue.QuadPart) / 1000000000 /* ns per s */; + + if (QueryPerformanceCounter (&qpcValue)) + jitStartTimestamp = static_cast(qpcValue.QuadPart); + #ifdef FEATURE_PREJIT if (g_pConfig->RequireZaps() == EEConfig::REQUIRE_ZAPS_ALL && @@ -13379,6 +13409,13 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, printf("."); #endif // _DEBUG + if (QueryPerformanceCounter (&qpcValue)) + jitEndTimestamp = static_cast(qpcValue.QuadPart); + + jitTimeNs = jitEndTimestamp - jitStartTimestamp; + jitTimeNs /= qpcFrequency; + FastInterlockExchangeAddLong((LONG64*)&g_cNanosecondsInJit, jitTimeNs); + FastInterlockExchangeAddLong((LONG64*)&g_cNanosecondsInJitForThread, jitTimeNs); FastInterlockExchangeAddLong((LONG64*)&g_cbILJitted, methodInfo.ILCodeSize); FastInterlockIncrement((LONG*)&g_cMethodsJitted); diff --git a/src/coreclr/vm/jitinterface.h b/src/coreclr/vm/jitinterface.h index eda60f61cc65e7..b5d9fb4add76c0 100644 --- a/src/coreclr/vm/jitinterface.h +++ b/src/coreclr/vm/jitinterface.h @@ -1157,6 +1157,8 @@ bool __stdcall TrackAllocationsEnabled(); FCDECL0(INT64, GetJittedBytes); FCDECL0(INT32, GetJittedMethodsCount); +FCDECL0(INT64, GetNanosecondsInJit); +FCDECL0(INT64, GetNanosecondsInJitForThread); #endif // JITINTERFACE_H diff --git a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs index fe47aae73fde21..233edd5d9cb580 100644 --- a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs +++ b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs @@ -39,6 +39,7 @@ internal sealed partial class RuntimeEventSource : EventSource private PollingCounter? _assemblyCounter; private PollingCounter? _ilBytesJittedCounter; private PollingCounter? _methodsJittedCounter; + private IncrementingPollingCounter? _jitTimeCounter; public static void Initialize() { @@ -85,6 +86,7 @@ protected override void OnEventCommand(EventCommandEventArgs command) _assemblyCounter ??= new PollingCounter("assembly-count", this, () => System.Reflection.Assembly.GetAssemblyCount()) { DisplayName = "Number of Assemblies Loaded" }; _ilBytesJittedCounter ??= new PollingCounter("il-bytes-jitted", this, () => System.Runtime.CompilerServices.RuntimeHelpers.GetILBytesJitted()) { DisplayName = "IL Bytes Jitted", DisplayUnits = "B" }; _methodsJittedCounter ??= new PollingCounter("methods-jitted-count", this, () => System.Runtime.CompilerServices.RuntimeHelpers.GetMethodsJittedCount()) { DisplayName = "Number of Methods Jitted" }; + _jitTimeCounter ??= new IncrementingPollingCounter("nanoseconds-in-jit", this, () => System.Runtime.CompilerServices.RuntimeHelpers.GetNanosecondsInJit()) { DisplayName = "Nanoseconds spent in JIT", DisplayUnits = "ns", DisplayRateTimeScale = new TimeSpan(0, 0, 1) }; } } diff --git a/src/tests/tracing/eventcounter/perthreadjittime.cs b/src/tests/tracing/eventcounter/perthreadjittime.cs new file mode 100644 index 00000000000000..31edc75d96123c --- /dev/null +++ b/src/tests/tracing/eventcounter/perthreadjittime.cs @@ -0,0 +1,71 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Reflection; +using System.Runtime.CompilerServices; +using System.Threading; + +namespace PerTHreadJitTime +{ + public class MyClass + { + public int MyMethod(int n) + { + int ret = 0; + for (int i = 0; i < n; i++) + ret += i; + return ret; + } + } + + public class MyOtherClass + { + public int MyOtherMethod(int n) + { + int ret = 1; + for (int i = 0; i < n; i++) + ret *= i; + return ret; + } + } + + public class Program + { + public static int Main(string[] args) + { + long threadOneJitTime = 0; + long threadTwoJitTime = 0; + + MethodInfo getNanosecondsInJitForThread = typeof(RuntimeHelpers).GetMethod("GetNanosecondsInJitForThread", BindingFlags.NonPublic | BindingFlags.Static | BindingFlags.FlattenHierarchy); + if (getNanosecondsInJitForThread is null) + { + foreach (var m in typeof(RuntimeHelpers).GetMembers(BindingFlags.NonPublic | BindingFlags.Static | BindingFlags.FlattenHierarchy)) + Console.WriteLine($"\t{m}"); + } + + Thread[] threads = new Thread[2]; + threads[0] = new Thread(() => { + var mc = new MyClass(); + int n = mc.MyMethod(100); + threadOneJitTime = (long)getNanosecondsInJitForThread.Invoke(null, null); + }); + threads[1] = new Thread(() => { + var moc = new MyOtherClass(); + int n = moc.MyOtherMethod(10); + threadTwoJitTime = (long)getNanosecondsInJitForThread.Invoke(null, null); + }); + + foreach (Thread t in threads) + t.Start(); + + foreach (Thread t in threads) + t.Join(); + + Console.WriteLine($"Thread One JIT Time: {threadOneJitTime}"); + Console.WriteLine($"Thread Two JIT Time: {threadTwoJitTime}"); + + return (threadOneJitTime > 0 && threadTwoJitTime > 0) ? 100 : -1; + } + } +} \ No newline at end of file diff --git a/src/tests/tracing/eventcounter/perthreadjittime.csproj b/src/tests/tracing/eventcounter/perthreadjittime.csproj new file mode 100644 index 00000000000000..6aeb6accfdb082 --- /dev/null +++ b/src/tests/tracing/eventcounter/perthreadjittime.csproj @@ -0,0 +1,17 @@ + + + Exe + BuildAndRun + true + 0 + true + + true + + true + + + + + + diff --git a/src/tests/tracing/eventcounter/runtimecounters.cs b/src/tests/tracing/eventcounter/runtimecounters.cs index eaa7c87d6d8ab1..f7040eab84b065 100644 --- a/src/tests/tracing/eventcounter/runtimecounters.cs +++ b/src/tests/tracing/eventcounter/runtimecounters.cs @@ -42,7 +42,8 @@ public RuntimeCounterListener() { "poh-size", false }, { "assembly-count", false }, { "il-bytes-jitted", false }, - { "methods-jitted-count", false } + { "methods-jitted-count", false }, + { "nanoseconds-in-jit", false } }; } private Dictionary observedRuntimeCounters; From 8c2ef385517a7443a997df701768a33f8d197171 Mon Sep 17 00:00:00 2001 From: John Salem Date: Thu, 1 Jul 2021 16:35:24 -0700 Subject: [PATCH 02/21] implement coreclr side --- .../System.Private.CoreLib.csproj | 1 + .../src/ILLink/ILLink.Descriptors.Shared.xml | 4 -- .../RuntimeHelpers.CoreCLR.cs | 12 ----- .../src/System/Runtime/JitInfo.CoreCLR.cs | 33 ++++++++++++++ src/coreclr/vm/ecalllist.h | 11 +++-- src/coreclr/vm/jitinterface.cpp | 45 ++++++++----------- src/coreclr/vm/jitinterface.h | 7 ++- .../System.Private.CoreLib.Shared.projitems | 1 + .../Diagnostics/Tracing/RuntimeEventSource.cs | 6 +-- .../src/System/Runtime/JitInfo.cs | 19 ++++++++ .../tracing/eventcounter/runtimecounters.cs | 2 +- 11 files changed, 87 insertions(+), 54 deletions(-) create mode 100644 src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs create mode 100644 src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs diff --git a/src/coreclr/System.Private.CoreLib/System.Private.CoreLib.csproj b/src/coreclr/System.Private.CoreLib/System.Private.CoreLib.csproj index 626f0eec24b22e..a035f549759c31 100644 --- a/src/coreclr/System.Private.CoreLib/System.Private.CoreLib.csproj +++ b/src/coreclr/System.Private.CoreLib/System.Private.CoreLib.csproj @@ -213,6 +213,7 @@ + diff --git a/src/coreclr/System.Private.CoreLib/src/ILLink/ILLink.Descriptors.Shared.xml b/src/coreclr/System.Private.CoreLib/src/ILLink/ILLink.Descriptors.Shared.xml index c3ec4cd4258209..4384581b1d1321 100644 --- a/src/coreclr/System.Private.CoreLib/src/ILLink/ILLink.Descriptors.Shared.xml +++ b/src/coreclr/System.Private.CoreLib/src/ILLink/ILLink.Descriptors.Shared.xml @@ -36,10 +36,6 @@ - - - - diff --git a/src/coreclr/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.CoreCLR.cs b/src/coreclr/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.CoreCLR.cs index 1277216b3f5c0f..7e53a8916f92d7 100644 --- a/src/coreclr/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.CoreCLR.cs +++ b/src/coreclr/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.CoreCLR.cs @@ -355,18 +355,6 @@ private static unsafe void DispatchTailCalls( } } } - - [MethodImpl(MethodImplOptions.InternalCall)] - internal static extern long GetILBytesJitted(); - - [MethodImpl(MethodImplOptions.InternalCall)] - internal static extern int GetMethodsJittedCount(); - - [MethodImpl(MethodImplOptions.InternalCall)] - internal static extern long GetNanosecondsInJit(); - - [MethodImpl(MethodImplOptions.InternalCall)] - internal static extern long GetNanosecondsInJitForThread(); } // Helper class to assist with unsafe pinning of arbitrary objects. // It's used by VM code. diff --git a/src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs b/src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs new file mode 100644 index 00000000000000..e4563b543f018d --- /dev/null +++ b/src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs @@ -0,0 +1,33 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Runtime.CompilerServices; +using System.Runtime.InteropServices; +using Internal.Runtime.CompilerServices; + +namespace System.Runtime +{ + public static partial class JitInfo + { + /// + /// Get the number of bytes of IL that have been compiled. If is true, + /// then this value is scoped to the current thread, otherwise, this is a global value. + /// + /// Whether the returned value should be specific to the current thread. Default: false + /// The number of bytes of IL the JIT has compiled. + [MethodImpl(MethodImplOptions.InternalCall)] + public static extern long GetCompiledILBytes(bool currentThread = false); + + /// + /// Get the number of methods that have been compiled. If is true, + /// then this value is scoped to the current thread, otherwise, this is a global value. + /// + /// Whether the returned value should be specific to the current thread. Default: false + /// The number of methods the JIT has compiled. + [MethodImpl(MethodImplOptions.InternalCall)] + public static extern int GetCompiledMethodCount(bool currentThread = false); + + [MethodImpl(MethodImplOptions.InternalCall)] + internal static extern long GetCompilationTimeInTicks(bool currentThread = false); + } +} \ No newline at end of file diff --git a/src/coreclr/vm/ecalllist.h b/src/coreclr/vm/ecalllist.h index 147fb889ff1955..16b6ab5226b845 100644 --- a/src/coreclr/vm/ecalllist.h +++ b/src/coreclr/vm/ecalllist.h @@ -831,6 +831,12 @@ FCFuncStart(gInterlockedFuncs) QCFuncElement("_MemoryBarrierProcessWide", COMInterlocked::MemoryBarrierProcessWide) FCFuncEnd() +FCFuncStart(gJitInfoFuncs) + FCFuncElement("GetCompiledILBytes", GetCompiledILBytes) + FCFuncElement("GetCompiledMethodCount", GetCompiledMethodCount) + FCFuncElement("GetCompilationTimeInTicks", GetCompilationTimeInTicks) +FCFuncEnd() + FCFuncStart(gVarArgFuncs) FCFuncElementSig(COR_CTOR_METHOD_NAME, &gsig_IM_IntPtr_PtrVoid_RetVoid, VarArgsNative::Init2) FCFuncElementSig(COR_CTOR_METHOD_NAME, &gsig_IM_IntPtr_RetVoid, VarArgsNative::Init) @@ -876,10 +882,6 @@ FCFuncStart(gRuntimeHelpers) QCFuncElement("AllocateTypeAssociatedMemory", RuntimeTypeHandle::AllocateTypeAssociatedMemory) FCFuncElement("AllocTailCallArgBuffer", TailCallHelp::AllocTailCallArgBuffer) FCFuncElement("GetTailCallInfo", TailCallHelp::GetTailCallInfo) - FCFuncElement("GetILBytesJitted", GetJittedBytes) - FCFuncElement("GetMethodsJittedCount", GetJittedMethodsCount) - FCFuncElement("GetNanosecondsInJit", GetNanosecondsInJit) - FCFuncElement("GetNanosecondsInJitForThread", GetNanosecondsInJitForThread) FCFuncEnd() FCFuncStart(gMngdFixedArrayMarshalerFuncs) @@ -1160,6 +1162,7 @@ FCClassElement("IReflect", "System.Reflection", gStdMngIReflectFuncs) FCClassElement("InterfaceMarshaler", "System.StubHelpers", gInterfaceMarshalerFuncs) #endif FCClassElement("Interlocked", "System.Threading", gInterlockedFuncs) +FCClassElement("JitInfo", "System.Runtime", gJitInfoFuncs) #if TARGET_UNIX FCClassElement("Kernel32", "", gPalKernel32Funcs) #endif diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index dab80f8a6fa444..bacacefe32b64b 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -104,39 +104,33 @@ GARY_IMPL(VMHELPDEF, hlpDynamicFuncTable, DYNAMIC_CORINFO_HELP_COUNT); uint64_t g_cbILJitted = 0; uint32_t g_cMethodsJitted = 0; -thread_local int64_t g_cNanosecondsInJitForThread = 0; -int64_t g_cNanosecondsInJit = 0; +int64_t g_cQPCTicksInJit = 0; +thread_local uint64_t g_cbILJittedForThread = 0; +thread_local uint32_t g_cMethodsJittedForThread = 0; +thread_local int64_t g_cQPCTicksInJitForThread = 0; #ifndef CROSSGEN_COMPILE -FCIMPL0(INT64, GetJittedBytes) +FCIMPL1(int64_t, GetCompiledILBytes, bool currentThread) { FCALL_CONTRACT; - return g_cbILJitted; + return currentThread ? g_cbILJittedForThread : g_cbILJitted; } FCIMPLEND -FCIMPL0(INT32, GetJittedMethodsCount) +FCIMPL1(int32_t, GetCompiledMethodCount, bool currentThread) { FCALL_CONTRACT; - return g_cMethodsJitted; + return currentThread ? g_cMethodsJittedForThread : g_cMethodsJitted; } FCIMPLEND -FCIMPL0(INT64, GetNanosecondsInJit) +FCIMPL1(int64_t, GetCompilationTimeInTicks, bool currentThread) { FCALL_CONTRACT; - return g_cNanosecondsInJit; -} -FCIMPLEND - -FCIMPL0(INT64, GetNanosecondsInJitForThread) -{ - FCALL_CONTRACT; - - return g_cNanosecondsInJitForThread; + return currentThread ? g_cQPCTicksInJitForThread : g_cQPCTicksInJit; } FCIMPLEND #endif @@ -13035,16 +13029,11 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, PCODE ret = NULL; int64_t jitStartTimestamp = 0; int64_t jitEndTimestamp = 0; - int64_t jitTimeNs = 0; - static int64_t qpcFrequency = 1; + int64_t jitTimeQPCTicks = 0; LARGE_INTEGER qpcValue; COOPERATIVE_TRANSITION_BEGIN(); - if (qpcFrequency == 1) - if (QueryPerformanceFrequency (&qpcValue)) - qpcFrequency = static_cast(qpcValue.QuadPart) / 1000000000 /* ns per s */; - if (QueryPerformanceCounter (&qpcValue)) jitStartTimestamp = static_cast(qpcValue.QuadPart); @@ -13412,12 +13401,16 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, if (QueryPerformanceCounter (&qpcValue)) jitEndTimestamp = static_cast(qpcValue.QuadPart); - jitTimeNs = jitEndTimestamp - jitStartTimestamp; - jitTimeNs /= qpcFrequency; - FastInterlockExchangeAddLong((LONG64*)&g_cNanosecondsInJit, jitTimeNs); - FastInterlockExchangeAddLong((LONG64*)&g_cNanosecondsInJitForThread, jitTimeNs); + jitTimeQPCTicks = jitEndTimestamp - jitStartTimestamp; + + FastInterlockExchangeAddLong((LONG64*)&g_cQPCTicksInJit, jitTimeQPCTicks); + FastInterlockExchangeAddLong((LONG64*)&g_cQPCTicksInJitForThread, jitTimeQPCTicks); + FastInterlockExchangeAddLong((LONG64*)&g_cbILJitted, methodInfo.ILCodeSize); + FastInterlockExchangeAddLong((LONG64*)&g_cbILJittedForThread, methodInfo.ILCodeSize); + FastInterlockIncrement((LONG*)&g_cMethodsJitted); + FastInterlockIncrement((LONG*)&g_cMethodsJittedForThread); COOPERATIVE_TRANSITION_END(); return ret; diff --git a/src/coreclr/vm/jitinterface.h b/src/coreclr/vm/jitinterface.h index b5d9fb4add76c0..b0ca13865802e7 100644 --- a/src/coreclr/vm/jitinterface.h +++ b/src/coreclr/vm/jitinterface.h @@ -1155,10 +1155,9 @@ CORJIT_FLAGS GetDebuggerCompileFlags(Module* pModule, CORJIT_FLAGS flags); bool __stdcall TrackAllocationsEnabled(); -FCDECL0(INT64, GetJittedBytes); -FCDECL0(INT32, GetJittedMethodsCount); -FCDECL0(INT64, GetNanosecondsInJit); -FCDECL0(INT64, GetNanosecondsInJitForThread); +FCDECL1(int64_t, GetCompiledILBytes, bool currentThread); +FCDECL1(int32_t, GetCompiledMethodCount, bool currentThread); +FCDECL1(int64_t, GetCompilationTimeInTicks, bool currentThread); #endif // JITINTERFACE_H diff --git a/src/libraries/System.Private.CoreLib/src/System.Private.CoreLib.Shared.projitems b/src/libraries/System.Private.CoreLib/src/System.Private.CoreLib.Shared.projitems index 22a9b4141336e2..68a4817514f4f2 100644 --- a/src/libraries/System.Private.CoreLib/src/System.Private.CoreLib.Shared.projitems +++ b/src/libraries/System.Private.CoreLib/src/System.Private.CoreLib.Shared.projitems @@ -852,6 +852,7 @@ + diff --git a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs index 233edd5d9cb580..6d57c82ef6cc40 100644 --- a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs +++ b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs @@ -84,9 +84,9 @@ protected override void OnEventCommand(EventCommandEventArgs command) _lohSizeCounter ??= new PollingCounter("loh-size", this, () => GC.GetGenerationSize(3)) { DisplayName = "LOH Size", DisplayUnits = "B" }; _pohSizeCounter ??= new PollingCounter("poh-size", this, () => GC.GetGenerationSize(4)) { DisplayName = "POH (Pinned Object Heap) Size", DisplayUnits = "B" }; _assemblyCounter ??= new PollingCounter("assembly-count", this, () => System.Reflection.Assembly.GetAssemblyCount()) { DisplayName = "Number of Assemblies Loaded" }; - _ilBytesJittedCounter ??= new PollingCounter("il-bytes-jitted", this, () => System.Runtime.CompilerServices.RuntimeHelpers.GetILBytesJitted()) { DisplayName = "IL Bytes Jitted", DisplayUnits = "B" }; - _methodsJittedCounter ??= new PollingCounter("methods-jitted-count", this, () => System.Runtime.CompilerServices.RuntimeHelpers.GetMethodsJittedCount()) { DisplayName = "Number of Methods Jitted" }; - _jitTimeCounter ??= new IncrementingPollingCounter("nanoseconds-in-jit", this, () => System.Runtime.CompilerServices.RuntimeHelpers.GetNanosecondsInJit()) { DisplayName = "Nanoseconds spent in JIT", DisplayUnits = "ns", DisplayRateTimeScale = new TimeSpan(0, 0, 1) }; + _ilBytesJittedCounter ??= new PollingCounter("il-bytes-jitted", this, () => System.Runtime.JitInfo.GetCompiledILBytes()) { DisplayName = "IL Bytes Jitted", DisplayUnits = "B" }; + _methodsJittedCounter ??= new PollingCounter("methods-jitted-count", this, () => System.Runtime.JitInfo.GetCompiledMethodCount()) { DisplayName = "Number of Methods Jitted" }; + _jitTimeCounter ??= new IncrementingPollingCounter("time-in-jit", this, () => System.Runtime.JitInfo.GetCompilationTime().TotalMilliseconds) { DisplayName = "Time spent in JIT", DisplayUnits = "ms", DisplayRateTimeScale = new TimeSpan(0, 0, 1) }; } } diff --git a/src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs b/src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs new file mode 100644 index 00000000000000..e42e9d6fb7bcb2 --- /dev/null +++ b/src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs @@ -0,0 +1,19 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +namespace System.Runtime +{ + public static partial class JitInfo + { + /// + /// Get the amount of time the JIT Compiler has spent compiling methods. If is true, + /// then this value is scoped to the current thread, otherwise, this is a global value. + /// + /// Whether the returned value should be specific to the current thread. Default: false + /// The amount of time the JIT Compiler has spent compiling methods. + public static TimeSpan GetCompilationTime(bool currentThread = false) + { + return TimeSpan.FromTicks(GetCompilationTimeInTicks(currentThread)); + } + } +} \ No newline at end of file diff --git a/src/tests/tracing/eventcounter/runtimecounters.cs b/src/tests/tracing/eventcounter/runtimecounters.cs index f7040eab84b065..bdab454300ade0 100644 --- a/src/tests/tracing/eventcounter/runtimecounters.cs +++ b/src/tests/tracing/eventcounter/runtimecounters.cs @@ -43,7 +43,7 @@ public RuntimeCounterListener() { "assembly-count", false }, { "il-bytes-jitted", false }, { "methods-jitted-count", false }, - { "nanoseconds-in-jit", false } + { "time-in-jit", false } }; } private Dictionary observedRuntimeCounters; From e63ed013f0c5480be31c34d585d796cbce611738 Mon Sep 17 00:00:00 2001 From: John Salem Date: Thu, 1 Jul 2021 16:35:39 -0700 Subject: [PATCH 03/21] implement mono side --- .../Diagnostics/Tracing/EventPipe.Mono.cs | 3 +- .../CompilerServices/RuntimeHelpers.Mono.cs | 9 ------ .../src/System/Runtime/JitInfo.Mono.cs | 32 +++++++++++++++++++ src/mono/mono/metadata/icall-eventpipe.c | 26 +++++++++++++-- src/mono/mono/metadata/object-internals.h | 2 +- src/mono/mono/mini/mini.h | 3 +- .../tracing/eventcounter/perthreadjittime.cs | 11 ++----- 7 files changed, 62 insertions(+), 24 deletions(-) create mode 100644 src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs diff --git a/src/mono/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventPipe.Mono.cs b/src/mono/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventPipe.Mono.cs index 7f3db11f9e5e9f..8d3ed1968d5f46 100644 --- a/src/mono/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventPipe.Mono.cs +++ b/src/mono/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventPipe.Mono.cs @@ -76,7 +76,8 @@ internal enum RuntimeCounters GC_LARGE_OBJECT_SIZE_BYTES, GC_LAST_PERCENT_TIME_IN_GC, JIT_IL_BYTES_JITTED, - JIT_METHODS_JITTED + JIT_METHODS_JITTED, + JIT_TICKS_IN_JIT } #if FEATURE_PERFTRACING diff --git a/src/mono/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.Mono.cs b/src/mono/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.Mono.cs index cbaba0038eb504..ca14c4a823f9ec 100644 --- a/src/mono/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.Mono.cs +++ b/src/mono/System.Private.CoreLib/src/System/Runtime/CompilerServices/RuntimeHelpers.Mono.cs @@ -154,15 +154,6 @@ public static object GetUninitializedObject( return GetUninitializedObjectInternal(new RuntimeTypeHandle(rt).Value); } - internal static long GetILBytesJitted() - { - return (long)EventPipeInternal.GetRuntimeCounterValue(EventPipeInternal.RuntimeCounters.JIT_IL_BYTES_JITTED); - } - - internal static int GetMethodsJittedCount() - { - return (int)EventPipeInternal.GetRuntimeCounterValue(EventPipeInternal.RuntimeCounters.JIT_METHODS_JITTED); - } [MethodImplAttribute(MethodImplOptions.InternalCall)] private static extern unsafe void PrepareMethod(IntPtr method, IntPtr* instantiations, int ninst); diff --git a/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs b/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs new file mode 100644 index 00000000000000..0ed5f331e8eca6 --- /dev/null +++ b/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs @@ -0,0 +1,32 @@ +namespace System.Runtime +{ + public static partial class JitInfo + { + /// + /// Get the number of bytes of IL that have been compiled. If is true, + /// then this value is scoped to the current thread, otherwise, this is a global value. + /// + /// Whether the returned value should be specific to the current thread. Default: false + /// The number of bytes of IL the JIT has compiled. + public static long GetCompiledILBytes(bool currentThread = false) + { + return currentThread ? 0 : (long)EventPipeInternal.GetRuntimeCounterValue(EventPipeInternal.RuntimeCounters.JIT_IL_BYTES_JITTED); + } + + /// + /// Get the number of methods that have been compiled. If is true, + /// then this value is scoped to the current thread, otherwise, this is a global value. + /// + /// Whether the returned value should be specific to the current thread. Default: false + /// The number of methods the JIT has compiled. + public static int GetCompiledMethodCount(bool currentThread = false) + { + return currentThread ? 0 : (int)EventPipeInternal.GetRuntimeCounterValue(EventPipeInternal.RuntimeCounters.JIT_METHODS_JITTED); + } + + public static long GetCompilationTimeInTicks(bool currentThread = false) + { + return currentThread ? 0 : (long)EventPipeInternal.GetRuntimeCounterValue(EventPipeInternal.RuntimeCounters.JIT_TICKS_IN_JIT); + } + } +} \ No newline at end of file diff --git a/src/mono/mono/metadata/icall-eventpipe.c b/src/mono/mono/metadata/icall-eventpipe.c index 904b328ce87d50..b8e60d807f7891 100644 --- a/src/mono/mono/metadata/icall-eventpipe.c +++ b/src/mono/mono/metadata/icall-eventpipe.c @@ -237,7 +237,8 @@ typedef enum { EP_RT_COUNTERS_GC_LARGE_OBJECT_SIZE_BYTES, EP_RT_COUNTERS_GC_LAST_PERCENT_TIME_IN_GC, EP_RT_COUNTERS_JIT_IL_BYTES_JITTED, - EP_RT_COUNTERS_JIT_METOHODS_JITTED + EP_RT_COUNTERS_JIT_METOHODS_JITTED, + EP_RT_COUNTERS_JIT_TICKS_IN_JIT } EventPipeRuntimeCounters; static @@ -265,9 +266,10 @@ get_il_bytes_jitted (void) gint64 methods_compiled = 0; gint64 cil_code_size_bytes = 0; gint64 native_code_size_bytes = 0; + gint64 jit_time = 0; if (mono_get_runtime_callbacks ()->get_jit_stats) - mono_get_runtime_callbacks ()->get_jit_stats (&methods_compiled, &cil_code_size_bytes, &native_code_size_bytes); + mono_get_runtime_callbacks ()->get_jit_stats (&methods_compiled, &cil_code_size_bytes, &native_code_size_bytes, &jit_time); return cil_code_size_bytes; } @@ -279,9 +281,10 @@ get_methods_jitted (void) gint64 methods_compiled = 0; gint64 cil_code_size_bytes = 0; gint64 native_code_size_bytes = 0; + gint64 jit_time = 0; if (mono_get_runtime_callbacks ()->get_jit_stats) - mono_get_runtime_callbacks ()->get_jit_stats (&methods_compiled, &cil_code_size_bytes, &native_code_size_bytes); + mono_get_runtime_callbacks ()->get_jit_stats (&methods_compiled, &cil_code_size_bytes, &native_code_size_bytes, &jit_time); return (gint32)methods_compiled; } @@ -296,6 +299,21 @@ get_exception_count (void) return excepion_count; } +static +inline +gint64 +get_ticks_in_jit (void) +{ + gint64 methods_compiled = 0; + gint64 cil_code_size_bytes = 0; + gint64 native_code_size_bytes = 0; + gint64 jit_time = 0; + + if (mono_get_runtime_callbacks ()->get_jit_stats) + mono_get_runtime_callbacks ()->get_jit_stats (&methods_compiled, &cil_code_size_bytes, &native_code_size_bytes, &jit_time); + return jit_time; +} + guint64 ves_icall_System_Diagnostics_Tracing_EventPipeInternal_GetRuntimeCounterValue (gint32 id) { EventPipeRuntimeCounters counterID = (EventPipeRuntimeCounters)id; @@ -316,6 +334,8 @@ guint64 ves_icall_System_Diagnostics_Tracing_EventPipeInternal_GetRuntimeCounter return (guint64)get_il_bytes_jitted (); case EP_RT_COUNTERS_JIT_METOHODS_JITTED : return (guint64)get_methods_jitted (); + case EP_RT_COUNTERS_JIT_TICKS_IN_JIT : + return (gint64)get_ticks_in_jit (); default: return 0; } diff --git a/src/mono/mono/metadata/object-internals.h b/src/mono/mono/metadata/object-internals.h index e985bdbe0498aa..20f6b9f6613194 100644 --- a/src/mono/mono/metadata/object-internals.h +++ b/src/mono/mono/metadata/object-internals.h @@ -642,7 +642,7 @@ typedef struct { void (*metadata_update_init) (MonoError *error); void (*metadata_update_published) (MonoAssemblyLoadContext *alc, uint32_t generation); #endif - void (*get_jit_stats)(gint64 *methods_compiled, gint64 *cil_code_size_bytes, gint64 *native_code_size_bytes); + void (*get_jit_stats)(gint64 *methods_compiled, gint64 *cil_code_size_bytes, gint64 *native_code_size_bytes, gint64 *jit_time); void (*get_exception_stats)(guint32 *exception_count); } MonoRuntimeCallbacks; diff --git a/src/mono/mono/mini/mini.h b/src/mono/mono/mini/mini.h index eea7742708de4d..ff5fd04d362855 100644 --- a/src/mono/mono/mini/mini.h +++ b/src/mono/mono/mini/mini.h @@ -1724,11 +1724,12 @@ typedef struct { extern MonoJitStats mono_jit_stats; static inline void -get_jit_stats (gint64 *methods_compiled, gint64 *cil_code_size_bytes, gint64 *native_code_size_bytes) +get_jit_stats (gint64 *methods_compiled, gint64 *cil_code_size_bytes, gint64 *native_code_size_bytes, gint64 *jit_time) { *methods_compiled = mono_jit_stats.methods_compiled; *cil_code_size_bytes = mono_jit_stats.cil_code_size; *native_code_size_bytes = mono_jit_stats.native_code_size; + *jit_time = mono_jit_stats.jit_time; } guint32 diff --git a/src/tests/tracing/eventcounter/perthreadjittime.cs b/src/tests/tracing/eventcounter/perthreadjittime.cs index 31edc75d96123c..78e73b1e4300a1 100644 --- a/src/tests/tracing/eventcounter/perthreadjittime.cs +++ b/src/tests/tracing/eventcounter/perthreadjittime.cs @@ -37,23 +37,16 @@ public static int Main(string[] args) long threadOneJitTime = 0; long threadTwoJitTime = 0; - MethodInfo getNanosecondsInJitForThread = typeof(RuntimeHelpers).GetMethod("GetNanosecondsInJitForThread", BindingFlags.NonPublic | BindingFlags.Static | BindingFlags.FlattenHierarchy); - if (getNanosecondsInJitForThread is null) - { - foreach (var m in typeof(RuntimeHelpers).GetMembers(BindingFlags.NonPublic | BindingFlags.Static | BindingFlags.FlattenHierarchy)) - Console.WriteLine($"\t{m}"); - } - Thread[] threads = new Thread[2]; threads[0] = new Thread(() => { var mc = new MyClass(); int n = mc.MyMethod(100); - threadOneJitTime = (long)getNanosecondsInJitForThread.Invoke(null, null); + threadOneJitTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); }); threads[1] = new Thread(() => { var moc = new MyOtherClass(); int n = moc.MyOtherMethod(10); - threadTwoJitTime = (long)getNanosecondsInJitForThread.Invoke(null, null); + threadTwoJitTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); }); foreach (Thread t in threads) From 38459be756dfb3d4730c2e9cc63afc171de9b6d9 Mon Sep 17 00:00:00 2001 From: John Salem Date: Thu, 1 Jul 2021 17:22:11 -0700 Subject: [PATCH 04/21] fix merge error breaking build --- .../src/System.Private.CoreLib.Shared.projitems | 1 - 1 file changed, 1 deletion(-) diff --git a/src/libraries/System.Private.CoreLib/src/System.Private.CoreLib.Shared.projitems b/src/libraries/System.Private.CoreLib/src/System.Private.CoreLib.Shared.projitems index 30fc690e761d3b..65997c88fd5d3f 100644 --- a/src/libraries/System.Private.CoreLib/src/System.Private.CoreLib.Shared.projitems +++ b/src/libraries/System.Private.CoreLib/src/System.Private.CoreLib.Shared.projitems @@ -858,7 +858,6 @@ - From 85bfac91ff37fa11636ec6225c41b03e871bfbdd Mon Sep 17 00:00:00 2001 From: John Salem Date: Thu, 1 Jul 2021 17:22:22 -0700 Subject: [PATCH 05/21] PR feedback --- src/coreclr/vm/jitinterface.cpp | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index 2f1b451b20658e..d0ddfb0a2ea47e 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -13049,8 +13049,8 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, COOPERATIVE_TRANSITION_BEGIN(); - if (QueryPerformanceCounter (&qpcValue)) - jitStartTimestamp = static_cast(qpcValue.QuadPart); + QueryPerformanceCounter(&qpcValue); + jitStartTimestamp = static_cast(qpcValue.QuadPart); #ifdef FEATURE_PREJIT @@ -13413,8 +13413,8 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, printf("."); #endif // _DEBUG - if (QueryPerformanceCounter (&qpcValue)) - jitEndTimestamp = static_cast(qpcValue.QuadPart); + QueryPerformanceCounter(&qpcValue); + jitEndTimestamp = static_cast(qpcValue.QuadPart); jitTimeQPCTicks = jitEndTimestamp - jitStartTimestamp; From 0e16d4a9dfc3accc314378761fba5411d74c85e4 Mon Sep 17 00:00:00 2001 From: John Salem Date: Fri, 2 Jul 2021 09:20:33 -0700 Subject: [PATCH 06/21] Feedback and build fix * Fix mono build by adding mono partial class to csproj * PR feedback * no interlocked* for thread_local * use CLR_BOOL * use LARGE_INTEGER and only static_cast once * correct ticks calculation * convert Stopwatch methods to internal * use same conversion as S.D.Stopwatch --- src/coreclr/vm/jitinterface.cpp | 25 ++++++++----------- src/coreclr/vm/jitinterface.h | 6 ++--- .../src/System/Diagnostics/Stopwatch.Unix.cs | 4 +-- .../System/Diagnostics/Stopwatch.Windows.cs | 4 +-- .../src/System/Runtime/JitInfo.cs | 15 ++++++++++- .../System.Private.CoreLib.csproj | 1 + .../src/System/Runtime/JitInfo.Mono.cs | 5 ++++ .../tracing/eventcounter/perthreadjittime.cs | 3 ++- 8 files changed, 40 insertions(+), 23 deletions(-) diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index d0ddfb0a2ea47e..fd6c607d62d323 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -110,7 +110,7 @@ thread_local uint32_t g_cMethodsJittedForThread = 0; thread_local int64_t g_cQPCTicksInJitForThread = 0; #ifndef CROSSGEN_COMPILE -FCIMPL1(int64_t, GetCompiledILBytes, bool currentThread) +FCIMPL1(INT64, GetCompiledILBytes, CLR_BOOL currentThread) { FCALL_CONTRACT; @@ -118,7 +118,7 @@ FCIMPL1(int64_t, GetCompiledILBytes, bool currentThread) } FCIMPLEND -FCIMPL1(int32_t, GetCompiledMethodCount, bool currentThread) +FCIMPL1(INT32, GetCompiledMethodCount, CLR_BOOL currentThread) { FCALL_CONTRACT; @@ -126,7 +126,7 @@ FCIMPL1(int32_t, GetCompiledMethodCount, bool currentThread) } FCIMPLEND -FCIMPL1(int64_t, GetCompilationTimeInTicks, bool currentThread) +FCIMPL1(INT64, GetCompilationTimeInTicks, CLR_BOOL currentThread) { FCALL_CONTRACT; @@ -13042,15 +13042,13 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, MethodDesc* ftn = nativeCodeVersion.GetMethodDesc(); PCODE ret = NULL; - int64_t jitStartTimestamp = 0; - int64_t jitEndTimestamp = 0; + LARGE_INTEGER jitStartTimestamp; + LARGE_INTEGER jitEndTimestamp; int64_t jitTimeQPCTicks = 0; - LARGE_INTEGER qpcValue; COOPERATIVE_TRANSITION_BEGIN(); - QueryPerformanceCounter(&qpcValue); - jitStartTimestamp = static_cast(qpcValue.QuadPart); + QueryPerformanceCounter(&jitStartTimestamp); #ifdef FEATURE_PREJIT @@ -13413,19 +13411,18 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, printf("."); #endif // _DEBUG - QueryPerformanceCounter(&qpcValue); - jitEndTimestamp = static_cast(qpcValue.QuadPart); + QueryPerformanceCounter(&jitEndTimestamp); - jitTimeQPCTicks = jitEndTimestamp - jitStartTimestamp; + jitTimeQPCTicks = static_cast(jitEndTimestamp.QuadPart - jitStartTimestamp.QuadPart); FastInterlockExchangeAddLong((LONG64*)&g_cQPCTicksInJit, jitTimeQPCTicks); - FastInterlockExchangeAddLong((LONG64*)&g_cQPCTicksInJitForThread, jitTimeQPCTicks); + g_cQPCTicksInJitForThread += jitTimeQPCTicks; FastInterlockExchangeAddLong((LONG64*)&g_cbILJitted, methodInfo.ILCodeSize); - FastInterlockExchangeAddLong((LONG64*)&g_cbILJittedForThread, methodInfo.ILCodeSize); + g_cbILJittedForThread += methodInfo.ILCodeSize; FastInterlockIncrement((LONG*)&g_cMethodsJitted); - FastInterlockIncrement((LONG*)&g_cMethodsJittedForThread); + g_cMethodsJittedForThread++; COOPERATIVE_TRANSITION_END(); return ret; diff --git a/src/coreclr/vm/jitinterface.h b/src/coreclr/vm/jitinterface.h index ebd23d42ee75e8..96f93f28fef4dc 100644 --- a/src/coreclr/vm/jitinterface.h +++ b/src/coreclr/vm/jitinterface.h @@ -1157,9 +1157,9 @@ CORJIT_FLAGS GetDebuggerCompileFlags(Module* pModule, CORJIT_FLAGS flags); bool __stdcall TrackAllocationsEnabled(); -FCDECL1(int64_t, GetCompiledILBytes, bool currentThread); -FCDECL1(int32_t, GetCompiledMethodCount, bool currentThread); -FCDECL1(int64_t, GetCompilationTimeInTicks, bool currentThread); +FCDECL1(INT64, GetCompiledILBytes, CLR_BOOL currentThread); +FCDECL1(INT32, GetCompiledMethodCount, CLR_BOOL currentThread); +FCDECL1(INT64, GetCompilationTimeInTicks, CLR_BOOL currentThread); #endif // JITINTERFACE_H diff --git a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Unix.cs b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Unix.cs index 487923148aa0df..2e2198090faa1e 100644 --- a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Unix.cs +++ b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Unix.cs @@ -5,13 +5,13 @@ namespace System.Diagnostics { public partial class Stopwatch { - private static long QueryPerformanceFrequency() + internal static long QueryPerformanceFrequency() { const long SecondsToNanoSeconds = 1000000000; return SecondsToNanoSeconds; } - private static long QueryPerformanceCounter() + internal static long QueryPerformanceCounter() { return (long)Interop.Sys.GetTimestamp(); } diff --git a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Windows.cs b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Windows.cs index 0bbe3311c8c4b8..efbb9fab1371dd 100644 --- a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Windows.cs +++ b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Windows.cs @@ -5,7 +5,7 @@ namespace System.Diagnostics { public partial class Stopwatch { - private static unsafe long QueryPerformanceFrequency() + internal static unsafe long QueryPerformanceFrequency() { long resolution; @@ -16,7 +16,7 @@ private static unsafe long QueryPerformanceFrequency() return resolution; } - private static unsafe long QueryPerformanceCounter() + internal static unsafe long QueryPerformanceCounter() { long timestamp; diff --git a/src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs b/src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs index e42e9d6fb7bcb2..af0672fdfc9750 100644 --- a/src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs +++ b/src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs @@ -5,6 +5,18 @@ namespace System.Runtime { public static partial class JitInfo { + private const long TicksPerMillisecond = 10000; + private const long TicksPerSecond = TicksPerMillisecond * 1000; + + // "Frequency" stores the frequency of the high-resolution performance counter, + // if one exists. Otherwise it will store TicksPerSecond. + // The frequency cannot change while the system is running, + // so we only need to initialize it once. + public static readonly long Frequency = System.Diagnostics.Stopwatch.QueryPerformanceFrequency(); + + // pre calculating the tick frequency for quickly converting from QPC ticks to DateTime ticks + private static readonly double s_tickFrequency = (double)TicksPerSecond / Frequency; + /// /// Get the amount of time the JIT Compiler has spent compiling methods. If is true, /// then this value is scoped to the current thread, otherwise, this is a global value. @@ -13,7 +25,8 @@ public static partial class JitInfo /// The amount of time the JIT Compiler has spent compiling methods. public static TimeSpan GetCompilationTime(bool currentThread = false) { - return TimeSpan.FromTicks(GetCompilationTimeInTicks(currentThread)); + // See System.Diagnostics.Stopwatch.GetElapsedDateTimeTicks() + return TimeSpan.FromTicks((long)(GetCompilationTimeInTicks(currentThread) * s_tickFrequency)); } } } \ No newline at end of file diff --git a/src/mono/System.Private.CoreLib/System.Private.CoreLib.csproj b/src/mono/System.Private.CoreLib/System.Private.CoreLib.csproj index 21d6492b7189f5..a4269376e91839 100644 --- a/src/mono/System.Private.CoreLib/System.Private.CoreLib.csproj +++ b/src/mono/System.Private.CoreLib/System.Private.CoreLib.csproj @@ -243,6 +243,7 @@ + diff --git a/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs b/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs index 0ed5f331e8eca6..a9f4e18c476d66 100644 --- a/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs +++ b/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs @@ -1,3 +1,8 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Diagnostics.Tracing; + namespace System.Runtime { public static partial class JitInfo diff --git a/src/tests/tracing/eventcounter/perthreadjittime.cs b/src/tests/tracing/eventcounter/perthreadjittime.cs index 78e73b1e4300a1..ff6d6dcfb9ed23 100644 --- a/src/tests/tracing/eventcounter/perthreadjittime.cs +++ b/src/tests/tracing/eventcounter/perthreadjittime.cs @@ -58,7 +58,8 @@ public static int Main(string[] args) Console.WriteLine($"Thread One JIT Time: {threadOneJitTime}"); Console.WriteLine($"Thread Two JIT Time: {threadTwoJitTime}"); - return (threadOneJitTime > 0 && threadTwoJitTime > 0) ? 100 : -1; + // The currentThread = true values are 0 on Mono. Allow that to pass as well. + return (threadOneJitTime >= 0 && threadTwoJitTime >= 0) ? 100 : -1; } } } \ No newline at end of file From 064fd0cb950aacc61a522553ec5cac6829ea7ec1 Mon Sep 17 00:00:00 2001 From: John Salem Date: Fri, 2 Jul 2021 16:10:25 -0700 Subject: [PATCH 07/21] PR feedback + adding ref source * normalize ticks to 100ns in native code * add NormalizedTimer class * added source ref * change ret value to long --- .../src/System/Runtime/JitInfo.CoreCLR.cs | 3 +- src/coreclr/vm/jitinterface.cpp | 14 ++-- src/coreclr/vm/util.cpp | 2 + src/coreclr/vm/util.hpp | 80 +++++++++++++++++++ .../src/System/Diagnostics/Stopwatch.Unix.cs | 4 +- .../System/Diagnostics/Stopwatch.Windows.cs | 4 +- .../src/System/Runtime/JitInfo.cs | 19 ++--- .../System.Runtime/ref/System.Runtime.cs | 6 ++ .../tests/System.Runtime.Tests.csproj | 1 + .../tests/System/Runtime/JitInfoTests.cs | 21 +++++ .../src/System/Runtime/JitInfo.Mono.cs | 5 +- src/mono/mono/metadata/icall-eventpipe.c | 4 +- .../tracing/eventcounter/perthreadjittime.cs | 65 --------------- .../eventcounter/perthreadjittime.csproj | 17 ---- 14 files changed, 131 insertions(+), 114 deletions(-) create mode 100644 src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs delete mode 100644 src/tests/tracing/eventcounter/perthreadjittime.cs delete mode 100644 src/tests/tracing/eventcounter/perthreadjittime.csproj diff --git a/src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs b/src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs index e4563b543f018d..2b1712fd65feb8 100644 --- a/src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs +++ b/src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs @@ -25,8 +25,9 @@ public static partial class JitInfo /// Whether the returned value should be specific to the current thread. Default: false /// The number of methods the JIT has compiled. [MethodImpl(MethodImplOptions.InternalCall)] - public static extern int GetCompiledMethodCount(bool currentThread = false); + public static extern long GetCompiledMethodCount(bool currentThread = false); + // Normalized to 100ns ticks on vm side [MethodImpl(MethodImplOptions.InternalCall)] internal static extern long GetCompilationTimeInTicks(bool currentThread = false); } diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index fd6c607d62d323..abf0d5af15ab7b 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -13042,13 +13042,11 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, MethodDesc* ftn = nativeCodeVersion.GetMethodDesc(); PCODE ret = NULL; - LARGE_INTEGER jitStartTimestamp; - LARGE_INTEGER jitEndTimestamp; - int64_t jitTimeQPCTicks = 0; + NormalizedTimer timer; COOPERATIVE_TRANSITION_BEGIN(); - QueryPerformanceCounter(&jitStartTimestamp); + timer.Start(); #ifdef FEATURE_PREJIT @@ -13411,12 +13409,10 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, printf("."); #endif // _DEBUG - QueryPerformanceCounter(&jitEndTimestamp); + timer.Stop(); - jitTimeQPCTicks = static_cast(jitEndTimestamp.QuadPart - jitStartTimestamp.QuadPart); - - FastInterlockExchangeAddLong((LONG64*)&g_cQPCTicksInJit, jitTimeQPCTicks); - g_cQPCTicksInJitForThread += jitTimeQPCTicks; + FastInterlockExchangeAddLong((LONG64*)&g_cQPCTicksInJit, timer.Elapsed100nsTicks()); + g_cQPCTicksInJitForThread += timer.Elapsed100nsTicks(); FastInterlockExchangeAddLong((LONG64*)&g_cbILJitted, methodInfo.ILCodeSize); g_cbILJittedForThread += methodInfo.ILCodeSize; diff --git a/src/coreclr/vm/util.cpp b/src/coreclr/vm/util.cpp index 64130d699ea936..5787ec6d705b76 100644 --- a/src/coreclr/vm/util.cpp +++ b/src/coreclr/vm/util.cpp @@ -2272,4 +2272,6 @@ HRESULT GetFileVersion( // S_OK or error } #endif // !TARGET_UNIX +Volatile NormalizedTimer::s_frequency = -1; + #endif // !DACCESS_COMPILE diff --git a/src/coreclr/vm/util.hpp b/src/coreclr/vm/util.hpp index 19f7932f178290..987fa9bd846131 100644 --- a/src/coreclr/vm/util.hpp +++ b/src/coreclr/vm/util.hpp @@ -918,6 +918,86 @@ class COMCharacter { static BOOL nativeIsDigit(WCHAR c); }; +// ====================================================================================== +// Simple, reusable 100ns timer for normalizing ticks. For use in Q/FCalls to avoid discrepency with +// tick frequency between native and managed. +class NormalizedTimer +{ +private: + LARGE_INTEGER startTimestamp = { .QuadPart = 0 }; + LARGE_INTEGER stopTimestamp = { .QuadPart = 0 }; + int64_t cachedElapsed100nsTicks = 0; + bool shouldRecalculate = true; + bool isRunning = false; + static const int64_t NormalizedTicksPerSecond = 10000000 /* 100ns ticks per second (1e7) */; + static Volatile s_frequency; + + inline + void Lap() + { + startTimestamp = stopTimestamp; + stopTimestamp.QuadPart = 0; + isRunning = true; + shouldRecalculate = true; + } +public: + // ====================================================================================== + // Start the timer + inline + void Start() + { + QueryPerformanceCounter(&startTimestamp); + stopTimestamp.QuadPart = 0; + isRunning = true; + shouldRecalculate = true; + } + + // ====================================================================================== + // stop the timer. If called before starting, sets the start time to the same as the stop + inline + void Stop() + { + QueryPerformanceCounter(&stopTimestamp); + // protect against stop before start + if (!isRunning) + startTimestamp = stopTimestamp; + + isRunning = false; + shouldRecalculate = true; + } + + // ====================================================================================== + // Return elapsed ticks. This will stop a running timer. + // Will return 0 if called out of order. + // Only recalculated this value if it has been stopped/started since previous calculation. + inline + int64_t Elapsed100nsTicks(bool shouldContinue = false) + { + if (s_frequency == -1) + { + int64_t frequency; + LARGE_INTEGER qpfValue; + QueryPerformanceFrequency(&qpfValue); + frequency = static_cast(qpfValue.QuadPart); + frequency /= NormalizedTicksPerSecond; + InterlockedExchange64(&s_frequency, frequency); + } + + if (shouldRecalculate) + { + if (isRunning) + Stop(); + + cachedElapsed100nsTicks = static_cast(stopTimestamp.QuadPart - startTimestamp.QuadPart) / s_frequency; + + if (shouldContinue) + Lap(); + } + + return cachedElapsed100nsTicks; + } +}; + #ifdef _DEBUG #define FORCEINLINE_NONDEBUG #else diff --git a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Unix.cs b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Unix.cs index 2e2198090faa1e..487923148aa0df 100644 --- a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Unix.cs +++ b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Unix.cs @@ -5,13 +5,13 @@ namespace System.Diagnostics { public partial class Stopwatch { - internal static long QueryPerformanceFrequency() + private static long QueryPerformanceFrequency() { const long SecondsToNanoSeconds = 1000000000; return SecondsToNanoSeconds; } - internal static long QueryPerformanceCounter() + private static long QueryPerformanceCounter() { return (long)Interop.Sys.GetTimestamp(); } diff --git a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Windows.cs b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Windows.cs index efbb9fab1371dd..0bbe3311c8c4b8 100644 --- a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Windows.cs +++ b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Stopwatch.Windows.cs @@ -5,7 +5,7 @@ namespace System.Diagnostics { public partial class Stopwatch { - internal static unsafe long QueryPerformanceFrequency() + private static unsafe long QueryPerformanceFrequency() { long resolution; @@ -16,7 +16,7 @@ internal static unsafe long QueryPerformanceFrequency() return resolution; } - internal static unsafe long QueryPerformanceCounter() + private static unsafe long QueryPerformanceCounter() { long timestamp; diff --git a/src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs b/src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs index af0672fdfc9750..9176bdd84eb5a2 100644 --- a/src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs +++ b/src/libraries/System.Private.CoreLib/src/System/Runtime/JitInfo.cs @@ -3,20 +3,11 @@ namespace System.Runtime { + /// + /// A static class for getting information about the Just In Time compiler. + /// public static partial class JitInfo { - private const long TicksPerMillisecond = 10000; - private const long TicksPerSecond = TicksPerMillisecond * 1000; - - // "Frequency" stores the frequency of the high-resolution performance counter, - // if one exists. Otherwise it will store TicksPerSecond. - // The frequency cannot change while the system is running, - // so we only need to initialize it once. - public static readonly long Frequency = System.Diagnostics.Stopwatch.QueryPerformanceFrequency(); - - // pre calculating the tick frequency for quickly converting from QPC ticks to DateTime ticks - private static readonly double s_tickFrequency = (double)TicksPerSecond / Frequency; - /// /// Get the amount of time the JIT Compiler has spent compiling methods. If is true, /// then this value is scoped to the current thread, otherwise, this is a global value. @@ -25,8 +16,8 @@ public static partial class JitInfo /// The amount of time the JIT Compiler has spent compiling methods. public static TimeSpan GetCompilationTime(bool currentThread = false) { - // See System.Diagnostics.Stopwatch.GetElapsedDateTimeTicks() - return TimeSpan.FromTicks((long)(GetCompilationTimeInTicks(currentThread) * s_tickFrequency)); + // TimeSpan.FromTicks() takes 100ns ticks + return TimeSpan.FromTicks(GetCompilationTimeInTicks(currentThread)); } } } \ No newline at end of file diff --git a/src/libraries/System.Runtime/ref/System.Runtime.cs b/src/libraries/System.Runtime/ref/System.Runtime.cs index 47e45170b40c9f..74b0b5dbd845fc 100644 --- a/src/libraries/System.Runtime/ref/System.Runtime.cs +++ b/src/libraries/System.Runtime/ref/System.Runtime.cs @@ -9623,6 +9623,12 @@ public static partial class GCSettings public static System.Runtime.GCLargeObjectHeapCompactionMode LargeObjectHeapCompactionMode { get { throw null; } set { } } public static System.Runtime.GCLatencyMode LatencyMode { get { throw null; } set { } } } + public static partial class JitInfo + { + public static long GetCompiledILBytes(bool currentThread=false) { throw null; } + public static long GetCompiledMethodCount(bool currentThread=false) { throw null; } + public static TimeSpan GetCompilationTime(bool currentThread=false) { throw null; } + } public sealed partial class MemoryFailPoint : System.Runtime.ConstrainedExecution.CriticalFinalizerObject, System.IDisposable { public MemoryFailPoint(int sizeInMegabytes) { } diff --git a/src/libraries/System.Runtime/tests/System.Runtime.Tests.csproj b/src/libraries/System.Runtime/tests/System.Runtime.Tests.csproj index 780fcbfc161453..0ddd60961c3654 100644 --- a/src/libraries/System.Runtime/tests/System.Runtime.Tests.csproj +++ b/src/libraries/System.Runtime/tests/System.Runtime.Tests.csproj @@ -216,6 +216,7 @@ + diff --git a/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs new file mode 100644 index 00000000000000..d810aecabcb3cd --- /dev/null +++ b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs @@ -0,0 +1,21 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using Xunit; + +namespace System.Runtime.Tests +{ + // NOTE: DependentHandle is already heavily tested indirectly through ConditionalWeakTable<,>. + // This class contains some specific tests for APIs that are only relevant when used directly. + public class JitInfoTests + { + // TODO(josalem): disable test on iOS/Android/browser + [Fact] + public void JitInfoIsPopulated() + { + Assert.True(System.Runtime.JitInfo.GetCompilationTime() > TimeSpan.Zero); + Assert.True(System.Runtime.JitInfo.GetCompiledILBytes() > 0); + Assert.True(System.Runtime.JitInfo.GetCompiledMethodCount() > 0); + } + } +} diff --git a/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs b/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs index a9f4e18c476d66..13659f1fad26ca 100644 --- a/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs +++ b/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs @@ -24,11 +24,12 @@ public static long GetCompiledILBytes(bool currentThread = false) /// /// Whether the returned value should be specific to the current thread. Default: false /// The number of methods the JIT has compiled. - public static int GetCompiledMethodCount(bool currentThread = false) + public static long GetCompiledMethodCount(bool currentThread = false) { - return currentThread ? 0 : (int)EventPipeInternal.GetRuntimeCounterValue(EventPipeInternal.RuntimeCounters.JIT_METHODS_JITTED); + return currentThread ? 0 : (long)EventPipeInternal.GetRuntimeCounterValue(EventPipeInternal.RuntimeCounters.JIT_METHODS_JITTED); } + // normalized to 100ns ticks on vm side public static long GetCompilationTimeInTicks(bool currentThread = false) { return currentThread ? 0 : (long)EventPipeInternal.GetRuntimeCounterValue(EventPipeInternal.RuntimeCounters.JIT_TICKS_IN_JIT); diff --git a/src/mono/mono/metadata/icall-eventpipe.c b/src/mono/mono/metadata/icall-eventpipe.c index b8e60d807f7891..20cfde816f0cf0 100644 --- a/src/mono/mono/metadata/icall-eventpipe.c +++ b/src/mono/mono/metadata/icall-eventpipe.c @@ -275,7 +275,7 @@ get_il_bytes_jitted (void) static inline -gint32 +gint64 get_methods_jitted (void) { gint64 methods_compiled = 0; @@ -285,7 +285,7 @@ get_methods_jitted (void) if (mono_get_runtime_callbacks ()->get_jit_stats) mono_get_runtime_callbacks ()->get_jit_stats (&methods_compiled, &cil_code_size_bytes, &native_code_size_bytes, &jit_time); - return (gint32)methods_compiled; + return methods_compiled; } static diff --git a/src/tests/tracing/eventcounter/perthreadjittime.cs b/src/tests/tracing/eventcounter/perthreadjittime.cs deleted file mode 100644 index ff6d6dcfb9ed23..00000000000000 --- a/src/tests/tracing/eventcounter/perthreadjittime.cs +++ /dev/null @@ -1,65 +0,0 @@ -// Licensed to the .NET Foundation under one or more agreements. -// The .NET Foundation licenses this file to you under the MIT license. - -using System; -using System.Reflection; -using System.Runtime.CompilerServices; -using System.Threading; - -namespace PerTHreadJitTime -{ - public class MyClass - { - public int MyMethod(int n) - { - int ret = 0; - for (int i = 0; i < n; i++) - ret += i; - return ret; - } - } - - public class MyOtherClass - { - public int MyOtherMethod(int n) - { - int ret = 1; - for (int i = 0; i < n; i++) - ret *= i; - return ret; - } - } - - public class Program - { - public static int Main(string[] args) - { - long threadOneJitTime = 0; - long threadTwoJitTime = 0; - - Thread[] threads = new Thread[2]; - threads[0] = new Thread(() => { - var mc = new MyClass(); - int n = mc.MyMethod(100); - threadOneJitTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); - }); - threads[1] = new Thread(() => { - var moc = new MyOtherClass(); - int n = moc.MyOtherMethod(10); - threadTwoJitTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); - }); - - foreach (Thread t in threads) - t.Start(); - - foreach (Thread t in threads) - t.Join(); - - Console.WriteLine($"Thread One JIT Time: {threadOneJitTime}"); - Console.WriteLine($"Thread Two JIT Time: {threadTwoJitTime}"); - - // The currentThread = true values are 0 on Mono. Allow that to pass as well. - return (threadOneJitTime >= 0 && threadTwoJitTime >= 0) ? 100 : -1; - } - } -} \ No newline at end of file diff --git a/src/tests/tracing/eventcounter/perthreadjittime.csproj b/src/tests/tracing/eventcounter/perthreadjittime.csproj deleted file mode 100644 index 6aeb6accfdb082..00000000000000 --- a/src/tests/tracing/eventcounter/perthreadjittime.csproj +++ /dev/null @@ -1,17 +0,0 @@ - - - Exe - BuildAndRun - true - 0 - true - - true - - true - - - - - - From 780d8a9a81f9825fa16e4b13bb015cc5e06c9a2d Mon Sep 17 00:00:00 2001 From: John Salem Date: Fri, 2 Jul 2021 17:29:13 -0700 Subject: [PATCH 08/21] * use constructor instead of intiializer * use double for frequency in case clock resolution is larger than 100ns --- src/coreclr/vm/util.cpp | 2 +- src/coreclr/vm/util.hpp | 34 ++++++++++++++++++++-------------- 2 files changed, 21 insertions(+), 15 deletions(-) diff --git a/src/coreclr/vm/util.cpp b/src/coreclr/vm/util.cpp index 5787ec6d705b76..fe51593c0efa7d 100644 --- a/src/coreclr/vm/util.cpp +++ b/src/coreclr/vm/util.cpp @@ -2272,6 +2272,6 @@ HRESULT GetFileVersion( // S_OK or error } #endif // !TARGET_UNIX -Volatile NormalizedTimer::s_frequency = -1; +Volatile NormalizedTimer::s_frequency = -1.0; #endif // !DACCESS_COMPILE diff --git a/src/coreclr/vm/util.hpp b/src/coreclr/vm/util.hpp index 987fa9bd846131..985ce371bb6bb2 100644 --- a/src/coreclr/vm/util.hpp +++ b/src/coreclr/vm/util.hpp @@ -924,13 +924,13 @@ class COMCharacter { class NormalizedTimer { private: - LARGE_INTEGER startTimestamp = { .QuadPart = 0 }; - LARGE_INTEGER stopTimestamp = { .QuadPart = 0 }; + LARGE_INTEGER startTimestamp; + LARGE_INTEGER stopTimestamp; int64_t cachedElapsed100nsTicks = 0; bool shouldRecalculate = true; bool isRunning = false; static const int64_t NormalizedTicksPerSecond = 10000000 /* 100ns ticks per second (1e7) */; - static Volatile s_frequency; + static Volatile s_frequency; inline void Lap() @@ -941,6 +941,22 @@ class NormalizedTimer shouldRecalculate = true; } public: + NormalizedTimer() + { + if (s_frequency.Load() == -1) + { + double frequency; + LARGE_INTEGER qpfValue; + QueryPerformanceFrequency(&qpfValue); + frequency = static_cast(qpfValue.QuadPart); + frequency /= NormalizedTicksPerSecond; + s_frequency.Store(frequency); + } + + startTimestamp.QuadPart = 0; + startTimestamp.QuadPart = 0; + } + // ====================================================================================== // Start the timer inline @@ -973,22 +989,12 @@ class NormalizedTimer inline int64_t Elapsed100nsTicks(bool shouldContinue = false) { - if (s_frequency == -1) - { - int64_t frequency; - LARGE_INTEGER qpfValue; - QueryPerformanceFrequency(&qpfValue); - frequency = static_cast(qpfValue.QuadPart); - frequency /= NormalizedTicksPerSecond; - InterlockedExchange64(&s_frequency, frequency); - } - if (shouldRecalculate) { if (isRunning) Stop(); - cachedElapsed100nsTicks = static_cast(stopTimestamp.QuadPart - startTimestamp.QuadPart) / s_frequency; + cachedElapsed100nsTicks = static_cast((stopTimestamp.QuadPart - startTimestamp.QuadPart) / s_frequency); if (shouldContinue) Lap(); From 1471a6478476106e12f77dde3d727fce184913b4 Mon Sep 17 00:00:00 2001 From: John Salem Date: Fri, 2 Jul 2021 18:03:00 -0700 Subject: [PATCH 09/21] fix helper function visibility --- .../src/System/Runtime/JitInfo.CoreCLR.cs | 2 +- .../System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs b/src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs index 2b1712fd65feb8..f1dafd58a819f9 100644 --- a/src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs +++ b/src/coreclr/System.Private.CoreLib/src/System/Runtime/JitInfo.CoreCLR.cs @@ -29,6 +29,6 @@ public static partial class JitInfo // Normalized to 100ns ticks on vm side [MethodImpl(MethodImplOptions.InternalCall)] - internal static extern long GetCompilationTimeInTicks(bool currentThread = false); + private static extern long GetCompilationTimeInTicks(bool currentThread = false); } } \ No newline at end of file diff --git a/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs b/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs index 13659f1fad26ca..c22549cdf85856 100644 --- a/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs +++ b/src/mono/System.Private.CoreLib/src/System/Runtime/JitInfo.Mono.cs @@ -30,7 +30,7 @@ public static long GetCompiledMethodCount(bool currentThread = false) } // normalized to 100ns ticks on vm side - public static long GetCompilationTimeInTicks(bool currentThread = false) + private static long GetCompilationTimeInTicks(bool currentThread = false) { return currentThread ? 0 : (long)EventPipeInternal.GetRuntimeCounterValue(EventPipeInternal.RuntimeCounters.JIT_TICKS_IN_JIT); } From 0dd2832f37254a66bc1f3396c1cebdf9abb8f181 Mon Sep 17 00:00:00 2001 From: John Salem Date: Tue, 6 Jul 2021 15:27:58 -0700 Subject: [PATCH 10/21] Fix test failure * test was attempting to parse ints when the interval can be a double --- src/tests/tracing/eventcounter/regression-25709.cs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/tests/tracing/eventcounter/regression-25709.cs b/src/tests/tracing/eventcounter/regression-25709.cs index 9498ca4752350e..16447debe895b7 100644 --- a/src/tests/tracing/eventcounter/regression-25709.cs +++ b/src/tests/tracing/eventcounter/regression-25709.cs @@ -19,7 +19,7 @@ public class SimpleEventListener : EventListener { private readonly EventLevel _level = EventLevel.Verbose; - public int MaxIncrement { get; private set; } = 0; + public double MaxIncrement { get; private set; } = 0; public SimpleEventListener() { @@ -38,7 +38,7 @@ protected override void OnEventSourceCreated(EventSource source) protected override void OnEventWritten(EventWrittenEventArgs eventData) { - int increment = 0; + double increment = 0; bool isExceptionCounter = false; for (int i = 0; i < eventData.Payload.Count; i++) @@ -52,7 +52,7 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData) isExceptionCounter = true; if (payload.Key.Equals("Increment")) { - increment = Int32.Parse(payload.Value.ToString()); + increment = double.Parse(payload.Value.ToString()); } } if (isExceptionCounter) From a7aa30a5ae94b445b6b8b67fdfc6a3c0bf927081 Mon Sep 17 00:00:00 2001 From: John Salem Date: Tue, 6 Jul 2021 17:55:05 -0700 Subject: [PATCH 11/21] Improve test: * skip on aot platforms * add current thread test for coreclr --- .../tests/System/Runtime/JitInfoTests.cs | 52 +++++++++++++++++-- 1 file changed, 49 insertions(+), 3 deletions(-) diff --git a/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs index d810aecabcb3cd..f3dba360be3d28 100644 --- a/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs +++ b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs @@ -1,21 +1,67 @@ // Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. +using Microsoft.DotNet.XUnitExtensions; +using System.Threading; using Xunit; namespace System.Runtime.Tests { - // NOTE: DependentHandle is already heavily tested indirectly through ConditionalWeakTable<,>. - // This class contains some specific tests for APIs that are only relevant when used directly. public class JitInfoTests { - // TODO(josalem): disable test on iOS/Android/browser + private const TestPlatforms AotPlatforms = TestPlatforms.Browser | TestPlatforms.iOS | TestPlatforms.tvOS | TestPlatforms.Android; + [Fact] + [SkipOnPlatform(AotPlatforms, "JitInfo metrics will be 0 in AOT scenarios.")] public void JitInfoIsPopulated() { + Func theFunc = () => "JIT compile this!"; + Assert.True(theFunc().Equals("JIT compile this!")); Assert.True(System.Runtime.JitInfo.GetCompilationTime() > TimeSpan.Zero); Assert.True(System.Runtime.JitInfo.GetCompiledILBytes() > 0); Assert.True(System.Runtime.JitInfo.GetCompiledMethodCount() > 0); } + + [Fact] + [SkipOnMono("Mono does not track thread specific JIT information")] + public void JitInfoCurrentThreadIsPopulated() + { + TimeSpan t1_compilationTime = TimeSpan.Zero; + long t1_compiledILBytes = 0; + long t1_compiledMethodCount = 0; + + TimeSpan t2_compilationTime = TimeSpan.Zero; + long t2_compiledILBytes = 0; + long t2_compiledMethodCount = 0; + + var t1 = new Thread(() => { + Func theFunc = () => "JIT compile this!"; + Assert.True(theFunc().Equals("JIT compile this!")); + t1_compilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); + t1_compiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true); + t1_compiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(currentThread: true); + }); + + var t2 = new Thread(() => { + Func theFunc2 = () => "Also JIT compile this!"; + Assert.True(theFunc2().Equals("Also JIT compile this!")); + t2_compilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); + t2_compiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true); + t2_compiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(currentThread: true); + }); + + t1.Start(); + t2.Start(); + t1.Join(); + t2.Join(); + + Assert.True(t1_compilationTime > TimeSpan.Zero); + Assert.True(t1_compiledILBytes > 0); + Assert.True(t1_compiledMethodCount > 0); + + Assert.True(t2_compilationTime > TimeSpan.Zero); + Assert.True(t2_compiledILBytes > 0); + Assert.True(t2_compiledMethodCount > 0); + } } } From 5df31dfb63932423c0b572088385864b19a9fe08 Mon Sep 17 00:00:00 2001 From: John Salem Date: Wed, 7 Jul 2021 10:43:01 -0700 Subject: [PATCH 12/21] Further test improvements --- .../tests/System/Runtime/JitInfoTests.cs | 23 +++++++++++-------- 1 file changed, 14 insertions(+), 9 deletions(-) diff --git a/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs index f3dba360be3d28..d2421fbf3136e0 100644 --- a/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs +++ b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs @@ -17,9 +17,14 @@ public void JitInfoIsPopulated() { Func theFunc = () => "JIT compile this!"; Assert.True(theFunc().Equals("JIT compile this!")); - Assert.True(System.Runtime.JitInfo.GetCompilationTime() > TimeSpan.Zero); - Assert.True(System.Runtime.JitInfo.GetCompiledILBytes() > 0); - Assert.True(System.Runtime.JitInfo.GetCompiledMethodCount() > 0); + + TimeSpan compilationTime = System.Runtime.JitInfo.GetCompilationTime(); + long compiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(); + long compiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(); + + Assert.True(compilationTime > TimeSpan.Zero, $"Compilation time not greater than 0! ({compilationTime})"); + Assert.True(compiledILBytes > 0, $"Compiled IL bytes not greater than 0! ({compiledILBytes})"); + Assert.True(compiledMethodCount > 0, $"Compiled method count not greater than 0! ({compiledMethodCount})"); } [Fact] @@ -55,13 +60,13 @@ public void JitInfoCurrentThreadIsPopulated() t1.Join(); t2.Join(); - Assert.True(t1_compilationTime > TimeSpan.Zero); - Assert.True(t1_compiledILBytes > 0); - Assert.True(t1_compiledMethodCount > 0); + Assert.True(t1_compilationTime > TimeSpan.Zero, $"Thread 1 compilation time not greater than 0! ({t1_compilationTime})"); + Assert.True(t1_compiledILBytes > 0, $"Thread 1 compiled IL bytes not greater than 0! ({t1_compiledILBytes})"); + Assert.True(t1_compiledMethodCount > 0, $"Thread 1 compiled method count not greater than 0! ({t1_compiledMethodCount})"); - Assert.True(t2_compilationTime > TimeSpan.Zero); - Assert.True(t2_compiledILBytes > 0); - Assert.True(t2_compiledMethodCount > 0); + Assert.True(t2_compilationTime > TimeSpan.Zero, $"Thread 2 compilation time not greater than 0! ({t2_compilationTime})"); + Assert.True(t2_compiledILBytes > 0, $"Thread 2 compiled IL bytes not greater than 0! ({t2_compiledILBytes})"); + Assert.True(t2_compiledMethodCount > 0, $"Thread 3 compiled method count not greater than 0! ({t2_compiledMethodCount}"); } } } From 450296c01923c4bb1220c5dd66b640252b16fb96 Mon Sep 17 00:00:00 2001 From: John Salem Date: Wed, 7 Jul 2021 16:03:48 -0700 Subject: [PATCH 13/21] Fix mismatched variable sizes: * match all variables as int64_t * extern global variables --- src/coreclr/vm/jitinterface.cpp | 28 ++++++++++++++-------------- src/coreclr/vm/jitinterface.h | 10 +++++++++- 2 files changed, 23 insertions(+), 15 deletions(-) diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index abf0d5af15ab7b..3f28ca0cb318bb 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -102,27 +102,27 @@ GARY_IMPL(VMHELPDEF, hlpDynamicFuncTable, DYNAMIC_CORINFO_HELP_COUNT); #else // DACCESS_COMPILE -uint64_t g_cbILJitted = 0; -uint32_t g_cMethodsJitted = 0; -int64_t g_cQPCTicksInJit = 0; -thread_local uint64_t g_cbILJittedForThread = 0; -thread_local uint32_t g_cMethodsJittedForThread = 0; -thread_local int64_t g_cQPCTicksInJitForThread = 0; +Volatile g_cbILJitted = 0; +Volatile g_cMethodsJitted = 0; +Volatile g_c100nsTicksInJit = 0; +thread_local int64_t g_cbILJittedForThread = 0; +thread_local int64_t g_cMethodsJittedForThread = 0; +thread_local int64_t g_c100nsTicksInJitForThread = 0; #ifndef CROSSGEN_COMPILE FCIMPL1(INT64, GetCompiledILBytes, CLR_BOOL currentThread) { FCALL_CONTRACT; - return currentThread ? g_cbILJittedForThread : g_cbILJitted; + return currentThread ? g_cbILJittedForThread : g_cbILJitted.Load(); } FCIMPLEND -FCIMPL1(INT32, GetCompiledMethodCount, CLR_BOOL currentThread) +FCIMPL1(INT64, GetCompiledMethodCount, CLR_BOOL currentThread) { FCALL_CONTRACT; - return currentThread ? g_cMethodsJittedForThread : g_cMethodsJitted; + return currentThread ? g_cMethodsJittedForThread : g_cMethodsJitted.Load(); } FCIMPLEND @@ -130,7 +130,7 @@ FCIMPL1(INT64, GetCompilationTimeInTicks, CLR_BOOL currentThread) { FCALL_CONTRACT; - return currentThread ? g_cQPCTicksInJitForThread : g_cQPCTicksInJit; + return currentThread ? g_c100nsTicksInJitForThread : g_c100nsTicksInJit.Load(); } FCIMPLEND #endif @@ -13411,13 +13411,13 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, timer.Stop(); - FastInterlockExchangeAddLong((LONG64*)&g_cQPCTicksInJit, timer.Elapsed100nsTicks()); - g_cQPCTicksInJitForThread += timer.Elapsed100nsTicks(); + InterlockedExchangeAdd64((LONG64*)&g_c100nsTicksInJit, timer.Elapsed100nsTicks()); + g_c100nsTicksInJitForThread += timer.Elapsed100nsTicks(); - FastInterlockExchangeAddLong((LONG64*)&g_cbILJitted, methodInfo.ILCodeSize); + InterlockedExchangeAdd64((LONG64*)&g_cbILJitted, methodInfo.ILCodeSize); g_cbILJittedForThread += methodInfo.ILCodeSize; - FastInterlockIncrement((LONG*)&g_cMethodsJitted); + InterlockedIncrement64((LONG64*)&g_cMethodsJitted); g_cMethodsJittedForThread++; COOPERATIVE_TRANSITION_END(); diff --git a/src/coreclr/vm/jitinterface.h b/src/coreclr/vm/jitinterface.h index 96f93f28fef4dc..33225f97c5eace 100644 --- a/src/coreclr/vm/jitinterface.h +++ b/src/coreclr/vm/jitinterface.h @@ -1157,8 +1157,16 @@ CORJIT_FLAGS GetDebuggerCompileFlags(Module* pModule, CORJIT_FLAGS flags); bool __stdcall TrackAllocationsEnabled(); + +extern Volatile g_cbILJitted; +extern Volatile g_cMethodsJitted; +extern Volatile g_c100nsTicksInJit; +extern thread_local int64_t g_cbILJittedForThread; +extern thread_local int64_t g_cMethodsJittedForThread; +extern thread_local int64_t g_c100nsTicksInJitForThread; + FCDECL1(INT64, GetCompiledILBytes, CLR_BOOL currentThread); -FCDECL1(INT32, GetCompiledMethodCount, CLR_BOOL currentThread); +FCDECL1(INT64, GetCompiledMethodCount, CLR_BOOL currentThread); FCDECL1(INT64, GetCompilationTimeInTicks, CLR_BOOL currentThread); #endif // JITINTERFACE_H From ca806ad729b1a3900151f255c1ef74717b38342f Mon Sep 17 00:00:00 2001 From: John Salem Date: Wed, 7 Jul 2021 16:42:18 -0700 Subject: [PATCH 14/21] * Simplify NormalizedTimer * update variable naming --- src/coreclr/vm/jitinterface.cpp | 22 ++++++++++++---------- src/coreclr/vm/jitinterface.h | 6 +++--- src/coreclr/vm/util.hpp | 33 +++++++-------------------------- 3 files changed, 22 insertions(+), 39 deletions(-) diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index 3f28ca0cb318bb..55f85d84071623 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -105,16 +105,16 @@ GARY_IMPL(VMHELPDEF, hlpDynamicFuncTable, DYNAMIC_CORINFO_HELP_COUNT); Volatile g_cbILJitted = 0; Volatile g_cMethodsJitted = 0; Volatile g_c100nsTicksInJit = 0; -thread_local int64_t g_cbILJittedForThread = 0; -thread_local int64_t g_cMethodsJittedForThread = 0; -thread_local int64_t g_c100nsTicksInJitForThread = 0; +thread_local int64_t t_cbILJittedForThread = 0; +thread_local int64_t t_cMethodsJittedForThread = 0; +thread_local int64_t t_c100nsTicksInJitForThread = 0; #ifndef CROSSGEN_COMPILE FCIMPL1(INT64, GetCompiledILBytes, CLR_BOOL currentThread) { FCALL_CONTRACT; - return currentThread ? g_cbILJittedForThread : g_cbILJitted.Load(); + return currentThread ? t_cbILJittedForThread : g_cbILJitted.Load(); } FCIMPLEND @@ -122,7 +122,7 @@ FCIMPL1(INT64, GetCompiledMethodCount, CLR_BOOL currentThread) { FCALL_CONTRACT; - return currentThread ? g_cMethodsJittedForThread : g_cMethodsJitted.Load(); + return currentThread ? t_cMethodsJittedForThread : g_cMethodsJitted.Load(); } FCIMPLEND @@ -130,7 +130,7 @@ FCIMPL1(INT64, GetCompilationTimeInTicks, CLR_BOOL currentThread) { FCALL_CONTRACT; - return currentThread ? g_c100nsTicksInJitForThread : g_c100nsTicksInJit.Load(); + return currentThread ? t_c100nsTicksInJitForThread : g_c100nsTicksInJit.Load(); } FCIMPLEND #endif @@ -13043,6 +13043,7 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, PCODE ret = NULL; NormalizedTimer timer; + int64_t c100nsTicksInJit = 0; COOPERATIVE_TRANSITION_BEGIN(); @@ -13410,15 +13411,16 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, #endif // _DEBUG timer.Stop(); + c100nsTicksInJit = timer.Elapsed100nsTicks(); - InterlockedExchangeAdd64((LONG64*)&g_c100nsTicksInJit, timer.Elapsed100nsTicks()); - g_c100nsTicksInJitForThread += timer.Elapsed100nsTicks(); + InterlockedExchangeAdd64((LONG64*)&g_c100nsTicksInJit, c100nsTicksInJit); + t_c100nsTicksInJitForThread += c100nsTicksInJit; InterlockedExchangeAdd64((LONG64*)&g_cbILJitted, methodInfo.ILCodeSize); - g_cbILJittedForThread += methodInfo.ILCodeSize; + t_cbILJittedForThread += methodInfo.ILCodeSize; InterlockedIncrement64((LONG64*)&g_cMethodsJitted); - g_cMethodsJittedForThread++; + t_cMethodsJittedForThread++; COOPERATIVE_TRANSITION_END(); return ret; diff --git a/src/coreclr/vm/jitinterface.h b/src/coreclr/vm/jitinterface.h index 33225f97c5eace..ed6c433d94b807 100644 --- a/src/coreclr/vm/jitinterface.h +++ b/src/coreclr/vm/jitinterface.h @@ -1161,9 +1161,9 @@ bool __stdcall TrackAllocationsEnabled(); extern Volatile g_cbILJitted; extern Volatile g_cMethodsJitted; extern Volatile g_c100nsTicksInJit; -extern thread_local int64_t g_cbILJittedForThread; -extern thread_local int64_t g_cMethodsJittedForThread; -extern thread_local int64_t g_c100nsTicksInJitForThread; +extern thread_local int64_t t_cbILJittedForThread; +extern thread_local int64_t t_cMethodsJittedForThread; +extern thread_local int64_t t_c100nsTicksInJitForThread; FCDECL1(INT64, GetCompiledILBytes, CLR_BOOL currentThread); FCDECL1(INT64, GetCompiledMethodCount, CLR_BOOL currentThread); diff --git a/src/coreclr/vm/util.hpp b/src/coreclr/vm/util.hpp index 985ce371bb6bb2..31837a1abc65b7 100644 --- a/src/coreclr/vm/util.hpp +++ b/src/coreclr/vm/util.hpp @@ -924,22 +924,13 @@ class COMCharacter { class NormalizedTimer { private: + static const int64_t NormalizedTicksPerSecond = 10000000 /* 100ns ticks per second (1e7) */; + static Volatile s_frequency; + LARGE_INTEGER startTimestamp; LARGE_INTEGER stopTimestamp; - int64_t cachedElapsed100nsTicks = 0; - bool shouldRecalculate = true; bool isRunning = false; - static const int64_t NormalizedTicksPerSecond = 10000000 /* 100ns ticks per second (1e7) */; - static Volatile s_frequency; - inline - void Lap() - { - startTimestamp = stopTimestamp; - stopTimestamp.QuadPart = 0; - isRunning = true; - shouldRecalculate = true; - } public: NormalizedTimer() { @@ -965,7 +956,6 @@ class NormalizedTimer QueryPerformanceCounter(&startTimestamp); stopTimestamp.QuadPart = 0; isRunning = true; - shouldRecalculate = true; } // ====================================================================================== @@ -979,7 +969,6 @@ class NormalizedTimer startTimestamp = stopTimestamp; isRunning = false; - shouldRecalculate = true; } // ====================================================================================== @@ -987,20 +976,12 @@ class NormalizedTimer // Will return 0 if called out of order. // Only recalculated this value if it has been stopped/started since previous calculation. inline - int64_t Elapsed100nsTicks(bool shouldContinue = false) + int64_t Elapsed100nsTicks() { - if (shouldRecalculate) - { - if (isRunning) - Stop(); - - cachedElapsed100nsTicks = static_cast((stopTimestamp.QuadPart - startTimestamp.QuadPart) / s_frequency); - - if (shouldContinue) - Lap(); - } + if (isRunning) + Stop(); - return cachedElapsed100nsTicks; + return static_cast((stopTimestamp.QuadPart - startTimestamp.QuadPart) / s_frequency); } }; From dcfdfb788ec452a77d3902cdab97a0883fd421e6 Mon Sep 17 00:00:00 2001 From: John Salem Date: Thu, 8 Jul 2021 10:42:45 -0700 Subject: [PATCH 15/21] PR feedback * Removed Volatile from globals since they are all accessed either via InterlockedExchange or VolatileLoad * Added no tearing helper function for 32 bit systems * updated tests to compare before and after * added tests for AOT and Mono specific behaviors * furether simplified NormalizedTimer class with asserts --- src/coreclr/vm/jitinterface.cpp | 24 +++- src/coreclr/vm/jitinterface.h | 6 +- src/coreclr/vm/util.hpp | 24 +++- .../tests/System/Runtime/JitInfoTests.cs | 131 +++++++++++++----- 4 files changed, 136 insertions(+), 49 deletions(-) diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index 55f85d84071623..60bfb5f44569fb 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -102,19 +102,31 @@ GARY_IMPL(VMHELPDEF, hlpDynamicFuncTable, DYNAMIC_CORINFO_HELP_COUNT); #else // DACCESS_COMPILE -Volatile g_cbILJitted = 0; -Volatile g_cMethodsJitted = 0; -Volatile g_c100nsTicksInJit = 0; +int64_t g_cbILJitted = 0; +int64_t g_cMethodsJitted = 0; +int64_t g_c100nsTicksInJit = 0; thread_local int64_t t_cbILJittedForThread = 0; thread_local int64_t t_cMethodsJittedForThread = 0; thread_local int64_t t_c100nsTicksInJitForThread = 0; +// This prevents tearing of 64 bit values on 32 bit systems +static inline +int64_t AtomicLoad64WithoutTearing(int64_t *valueRef) +{ + WRAPPER_NO_CONTRACT; +#if TARGET_64BIT + return VolatileLoad(valueRef); +#else + return InterlockedCompareExchangeT((int64_T*)valueRef, 0, 0); +#endif // TARGET_64BIT +} + #ifndef CROSSGEN_COMPILE FCIMPL1(INT64, GetCompiledILBytes, CLR_BOOL currentThread) { FCALL_CONTRACT; - return currentThread ? t_cbILJittedForThread : g_cbILJitted.Load(); + return currentThread ? t_cbILJittedForThread : AtomicLoad64WithoutTearing(&g_cbILJitted); } FCIMPLEND @@ -122,7 +134,7 @@ FCIMPL1(INT64, GetCompiledMethodCount, CLR_BOOL currentThread) { FCALL_CONTRACT; - return currentThread ? t_cMethodsJittedForThread : g_cMethodsJitted.Load(); + return currentThread ? t_cMethodsJittedForThread : AtomicLoad64WithoutTearing(&g_cMethodsJitted); } FCIMPLEND @@ -130,7 +142,7 @@ FCIMPL1(INT64, GetCompilationTimeInTicks, CLR_BOOL currentThread) { FCALL_CONTRACT; - return currentThread ? t_c100nsTicksInJitForThread : g_c100nsTicksInJit.Load(); + return currentThread ? t_c100nsTicksInJitForThread : AtomicLoad64WithoutTearing(&g_c100nsTicksInJit); } FCIMPLEND #endif diff --git a/src/coreclr/vm/jitinterface.h b/src/coreclr/vm/jitinterface.h index ed6c433d94b807..5ac3783ab251fb 100644 --- a/src/coreclr/vm/jitinterface.h +++ b/src/coreclr/vm/jitinterface.h @@ -1158,9 +1158,9 @@ CORJIT_FLAGS GetDebuggerCompileFlags(Module* pModule, CORJIT_FLAGS flags); bool __stdcall TrackAllocationsEnabled(); -extern Volatile g_cbILJitted; -extern Volatile g_cMethodsJitted; -extern Volatile g_c100nsTicksInJit; +extern int64_t g_cbILJitted; +extern int64_t g_cMethodsJitted; +extern int64_t g_c100nsTicksInJit; extern thread_local int64_t t_cbILJittedForThread; extern thread_local int64_t t_cMethodsJittedForThread; extern thread_local int64_t t_c100nsTicksInJitForThread; diff --git a/src/coreclr/vm/util.hpp b/src/coreclr/vm/util.hpp index 31837a1abc65b7..4da40a3ead16dc 100644 --- a/src/coreclr/vm/util.hpp +++ b/src/coreclr/vm/util.hpp @@ -929,11 +929,15 @@ class NormalizedTimer LARGE_INTEGER startTimestamp; LARGE_INTEGER stopTimestamp; + +#if _DEBUG bool isRunning = false; +#endif // _DEBUG public: NormalizedTimer() { + LIMITED_METHOD_CONTRACT; if (s_frequency.Load() == -1) { double frequency; @@ -953,9 +957,13 @@ class NormalizedTimer inline void Start() { + LIMITED_METHOD_CONTRACT; + _ASSERTE(!isRunning); QueryPerformanceCounter(&startTimestamp); - stopTimestamp.QuadPart = 0; + +#if _DEBUG isRunning = true; +#endif // _DEBUG } // ====================================================================================== @@ -963,12 +971,13 @@ class NormalizedTimer inline void Stop() { + LIMITED_METHOD_CONTRACT; + _ASSERTE(isRunning); QueryPerformanceCounter(&stopTimestamp); - // protect against stop before start - if (!isRunning) - startTimestamp = stopTimestamp; +#if _DEBUG isRunning = false; +#endif // _DEBUG } // ====================================================================================== @@ -978,9 +987,10 @@ class NormalizedTimer inline int64_t Elapsed100nsTicks() { - if (isRunning) - Stop(); - + LIMITED_METHOD_CONTRACT; + _ASSERTE(!isRunning); + _ASSERTE(startTimestamp.QuadPart > 0); + _ASSERTE(stopTimestamp.QuadPart > 0); return static_cast((stopTimestamp.QuadPart - startTimestamp.QuadPart) / s_frequency); } }; diff --git a/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs index d2421fbf3136e0..6350701fe3e501 100644 --- a/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs +++ b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs @@ -15,58 +15,123 @@ public class JitInfoTests [SkipOnPlatform(AotPlatforms, "JitInfo metrics will be 0 in AOT scenarios.")] public void JitInfoIsPopulated() { + TimeSpan beforeCompilationTime = System.Runtime.JitInfo.GetCompilationTime(); + long beforeCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(); + long beforeCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(); + + Func theFunc = () => "JIT compile this!"; + Assert.True(theFunc().Equals("JIT compile this!")); + + TimeSpan afterCompilationTime = System.Runtime.JitInfo.GetCompilationTime(); + long afterCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(); + long afterCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(); + + Assert.True(beforeCompilationTime > TimeSpan.Zero, $"Compilation time not greater than 0! ({beforeCompilationTime})"); + Assert.True(beforeCompiledILBytes > 0, $"Compiled IL bytes not greater than 0! ({beforeCompiledILBytes})"); + Assert.True(beforeCompiledMethodCount > 0, $"Compiled method count not greater than 0! ({beforeCompiledMethodCount})"); + + Assert.True(afterCompilationTime > beforeCompilationTime, $"CompilationTime: after not greater than before! (after: {afterCompilationTime}, before: {beforeCompilationTime})"); + Assert.True(afterCompiledILBytes > beforeCompiledILBytes, $"Compiled IL bytes: after not greater than before! (after: {afterCompiledILBytes}, before: {beforeCompiledILBytes})"); + Assert.True(afterCompiledMethodCount > beforeCompiledMethodCount, $"Compiled method count: after not greater than before! (after: {afterCompiledMethodCount}, before: {beforeCompiledMethodCount})"); + } + + [Fact] + [SkipOnPlatform(~AotPlatforms, "JitInfo metrics will be 0 in AOT scenarios.")] + public void JitInfoIsNotPopulated() + { + TimeSpan beforeCompilationTime = System.Runtime.JitInfo.GetCompilationTime(); + long beforeCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(); + long beforeCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(); + Func theFunc = () => "JIT compile this!"; Assert.True(theFunc().Equals("JIT compile this!")); - TimeSpan compilationTime = System.Runtime.JitInfo.GetCompilationTime(); - long compiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(); - long compiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(); + TimeSpan afterCompilationTime = System.Runtime.JitInfo.GetCompilationTime(); + long afterCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(); + long afterCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(); - Assert.True(compilationTime > TimeSpan.Zero, $"Compilation time not greater than 0! ({compilationTime})"); - Assert.True(compiledILBytes > 0, $"Compiled IL bytes not greater than 0! ({compiledILBytes})"); - Assert.True(compiledMethodCount > 0, $"Compiled method count not greater than 0! ({compiledMethodCount})"); + Assert.True(beforeCompilationTime == TimeSpan.Zero, $"Before Compilation time not eqeual to 0! ({beforeCompilationTime})"); + Assert.True(beforeCompiledILBytes == 0, $"Before Compiled IL bytes not eqeual to 0! ({beforeCompiledILBytes})"); + Assert.True(beforeCompiledMethodCount == 0, $"Before Compiled method count not eqeual to 0! ({beforeCompiledMethodCount})"); + + Assert.True(afterCompilationTime == TimeSpan.Zero, $"After Compilation time not eqeual to 0! ({afterCompilationTime})"); + Assert.True(afterCompiledILBytes == 0, $"After Compiled IL bytes not eqeual to 0! ({afterCompiledILBytes})"); + Assert.True(afterCompiledMethodCount == 0, $"After Compiled method count not eqeual to 0! ({afterCompiledMethodCount})"); } [Fact] [SkipOnMono("Mono does not track thread specific JIT information")] public void JitInfoCurrentThreadIsPopulated() { - TimeSpan t1_compilationTime = TimeSpan.Zero; - long t1_compiledILBytes = 0; - long t1_compiledMethodCount = 0; + TimeSpan t1_beforeCompilationTime = TimeSpan.Zero; + long t1_beforeCompiledILBytes = 0; + long t1_beforeCompiledMethodCount = 0; - TimeSpan t2_compilationTime = TimeSpan.Zero; - long t2_compiledILBytes = 0; - long t2_compiledMethodCount = 0; + TimeSpan t1_afterCompilationTime = TimeSpan.Zero; + long t1_afterCompiledILBytes = 0; + long t1_afterCompiledMethodCount = 0; - var t1 = new Thread(() => { - Func theFunc = () => "JIT compile this!"; - Assert.True(theFunc().Equals("JIT compile this!")); - t1_compilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); - t1_compiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true); - t1_compiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(currentThread: true); - }); + TimeSpan t2_beforeCompilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); + long t2_beforeCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true); + long t2_beforeCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(currentThread: true); - var t2 = new Thread(() => { - Func theFunc2 = () => "Also JIT compile this!"; - Assert.True(theFunc2().Equals("Also JIT compile this!")); - t2_compilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); - t2_compiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true); - t2_compiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(currentThread: true); + var t1 = new Thread(() => { + t1_beforeCompilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); + t1_beforeCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true); + t1_beforeCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(currentThread: true); + Func theFunc2 = () => "JIT compile this!"; + Assert.True(theFunc2().Equals("JIT compile this!")); + t1_afterCompilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); + t1_afterCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true); + t1_afterCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(currentThread: true); }); t1.Start(); - t2.Start(); t1.Join(); - t2.Join(); - Assert.True(t1_compilationTime > TimeSpan.Zero, $"Thread 1 compilation time not greater than 0! ({t1_compilationTime})"); - Assert.True(t1_compiledILBytes > 0, $"Thread 1 compiled IL bytes not greater than 0! ({t1_compiledILBytes})"); - Assert.True(t1_compiledMethodCount > 0, $"Thread 1 compiled method count not greater than 0! ({t1_compiledMethodCount})"); + Func theFunc = () => "JIT compile this!"; + Assert.True(theFunc().Equals("JIT compile this!")); + + TimeSpan t2_afterCompilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); + long t2_afterCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true); + long t2_afterCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(currentThread: true); + + Assert.True(t2_beforeCompilationTime > TimeSpan.Zero, $"Thread 2 Compilation time not greater than 0! ({t2_beforeCompilationTime})"); + Assert.True(t2_beforeCompiledILBytes > 0, $"Thread 2 Compiled IL bytes not greater than 0! ({t2_beforeCompiledILBytes})"); + Assert.True(t2_beforeCompiledMethodCount > 0, $"Thread 2 Compiled method count not greater than 0! ({t2_beforeCompiledMethodCount})"); + + Assert.True(t2_afterCompilationTime > t2_beforeCompilationTime, $"CompilationTime: after not greater than before! (after: {t2_afterCompilationTime}, before: {t2_beforeCompilationTime})"); + Assert.True(t2_afterCompiledILBytes > t2_beforeCompiledILBytes, $"Compiled IL bytes: after not greater than before! (after: {t2_afterCompiledILBytes}, before: {t2_beforeCompiledILBytes})"); + Assert.True(t2_afterCompiledMethodCount > t2_beforeCompiledMethodCount, $"Compiled method count: after not greater than before! (after: {t2_afterCompiledMethodCount}, before: {t2_beforeCompiledMethodCount})"); + + Assert.True(t1_beforeCompilationTime > TimeSpan.Zero, $"Thread 1 before compilation time not greater than 0! ({t1_beforeCompilationTime})"); + Assert.True(t1_beforeCompiledILBytes > 0, $"Thread 1 before compiled IL bytes not greater than 0! ({t1_beforeCompiledILBytes})"); + Assert.True(t1_beforeCompiledMethodCount > 0, $"Thread 1 before compiled method count not greater than 0! ({t1_beforeCompiledMethodCount})"); + + Assert.True(t1_afterCompilationTime > t1_beforeCompilationTime, $"Thread 1 compilation time: after not greater than before! (after: {t1_afterCompilationTime}, before: {t1_beforeCompilationTime})"); + Assert.True(t1_afterCompiledILBytes > t1_beforeCompiledILBytes, $"Thread 1 compiled IL bytes: after not greater than before! (after: {t1_afterCompiledILBytes}, before: {t1_beforeCompiledILBytes})"); + Assert.True(t1_afterCompiledMethodCount > t1_beforeCompiledMethodCount, $"Thread 1 compiled method count: after not greater than before! (after: {t1_afterCompiledMethodCount}, before: {t1_beforeCompiledMethodCount})"); + + Assert.True(t1_afterCompilationTime != t2_afterCompilationTime, $"Thread 1 compilation time: equal to other thread! (t1: {t1_afterCompilationTime}, t2: {t2_beforeCompilationTime})"); + Assert.True(t1_afterCompiledILBytes != t2_afterCompiledILBytes, $"Thread 1 compiled IL bytes: equal to other thread! (t1: {t1_afterCompiledILBytes}, t2: {t2_beforeCompiledILBytes})"); + Assert.True(t1_afterCompiledMethodCount != t2_afterCompiledMethodCount, $"Thread 1 compiled method count: equal to other thread! (t1: {t1_afterCompiledMethodCount}, t2: {t2_beforeCompiledMethodCount})"); + } + + [Fact] + [SkipOnCoreClr("CoreCLR does track thread specific JIT information")] + public void JitInfoCurrentThreadIsNotPopulated() + { + TimeSpan compilationTime = TimeSpan.Zero; + long compiledILBytes = 0; + long compiledMethodCount = 0; + + compilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); + compiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true); + compiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(currentThread: true); - Assert.True(t2_compilationTime > TimeSpan.Zero, $"Thread 2 compilation time not greater than 0! ({t2_compilationTime})"); - Assert.True(t2_compiledILBytes > 0, $"Thread 2 compiled IL bytes not greater than 0! ({t2_compiledILBytes})"); - Assert.True(t2_compiledMethodCount > 0, $"Thread 3 compiled method count not greater than 0! ({t2_compiledMethodCount}"); + Assert.True(compilationTime == TimeSpan.Zero, $"compilation time not equal to 0! ({compilationTime})"); + Assert.True(compiledILBytes == 0, $"compiled IL bytes not equal to 0! ({compiledILBytes})"); + Assert.True(compiledMethodCount == 0, $"compiled method count not equal to 0! ({compiledMethodCount})"); } } } From 61f90db7aef64a86774ca06098070adaeaba7aae Mon Sep 17 00:00:00 2001 From: John Salem Date: Thu, 8 Jul 2021 10:46:53 -0700 Subject: [PATCH 16/21] Fix typo in mono icalls --- src/mono/mono/metadata/icall-eventpipe.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/mono/mono/metadata/icall-eventpipe.c b/src/mono/mono/metadata/icall-eventpipe.c index 20cfde816f0cf0..7165efd3805890 100644 --- a/src/mono/mono/metadata/icall-eventpipe.c +++ b/src/mono/mono/metadata/icall-eventpipe.c @@ -237,7 +237,7 @@ typedef enum { EP_RT_COUNTERS_GC_LARGE_OBJECT_SIZE_BYTES, EP_RT_COUNTERS_GC_LAST_PERCENT_TIME_IN_GC, EP_RT_COUNTERS_JIT_IL_BYTES_JITTED, - EP_RT_COUNTERS_JIT_METOHODS_JITTED, + EP_RT_COUNTERS_JIT_METHODS_JITTED, EP_RT_COUNTERS_JIT_TICKS_IN_JIT } EventPipeRuntimeCounters; @@ -332,7 +332,7 @@ guint64 ves_icall_System_Diagnostics_Tracing_EventPipeInternal_GetRuntimeCounter return (guint64)gc_last_percent_time_in_gc (); case EP_RT_COUNTERS_JIT_IL_BYTES_JITTED : return (guint64)get_il_bytes_jitted (); - case EP_RT_COUNTERS_JIT_METOHODS_JITTED : + case EP_RT_COUNTERS_JIT_METHODS_JITTED : return (guint64)get_methods_jitted (); case EP_RT_COUNTERS_JIT_TICKS_IN_JIT : return (gint64)get_ticks_in_jit (); From 39e8859b07fba4eb703d0e55b253ebfc712fa283 Mon Sep 17 00:00:00 2001 From: John Salem Date: Thu, 8 Jul 2021 11:06:52 -0700 Subject: [PATCH 17/21] fix typo --- src/coreclr/vm/jitinterface.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index 60bfb5f44569fb..aeaf868ea18b0e 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -117,7 +117,7 @@ int64_t AtomicLoad64WithoutTearing(int64_t *valueRef) #if TARGET_64BIT return VolatileLoad(valueRef); #else - return InterlockedCompareExchangeT((int64_T*)valueRef, 0, 0); + return InterlockedCompareExchangeT((int64_t*)valueRef, 0, 0); #endif // TARGET_64BIT } From 35467500bc5797a0cb010586653a5c4dfdb7dde7 Mon Sep 17 00:00:00 2001 From: John Salem Date: Thu, 8 Jul 2021 11:07:59 -0700 Subject: [PATCH 18/21] remove unneeded cast --- src/coreclr/vm/jitinterface.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index aeaf868ea18b0e..44932686dc525c 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -117,7 +117,7 @@ int64_t AtomicLoad64WithoutTearing(int64_t *valueRef) #if TARGET_64BIT return VolatileLoad(valueRef); #else - return InterlockedCompareExchangeT((int64_t*)valueRef, 0, 0); + return InterlockedCompareExchangeT(valueRef, 0, 0); #endif // TARGET_64BIT } From 108d64d3da665279260a9550a2317bb6199191a0 Mon Sep 17 00:00:00 2001 From: John Salem Date: Thu, 8 Jul 2021 11:55:46 -0700 Subject: [PATCH 19/21] Force interpretation of T as int64_t on x86 --- src/coreclr/vm/jitinterface.cpp | 10 +++++----- src/coreclr/vm/jitinterface.h | 6 +++--- 2 files changed, 8 insertions(+), 8 deletions(-) diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index 44932686dc525c..ed26e187bfe376 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -102,22 +102,22 @@ GARY_IMPL(VMHELPDEF, hlpDynamicFuncTable, DYNAMIC_CORINFO_HELP_COUNT); #else // DACCESS_COMPILE -int64_t g_cbILJitted = 0; -int64_t g_cMethodsJitted = 0; -int64_t g_c100nsTicksInJit = 0; +Volatile g_cbILJitted = 0; +Volatile g_cMethodsJitted = 0; +Volatile g_c100nsTicksInJit = 0; thread_local int64_t t_cbILJittedForThread = 0; thread_local int64_t t_cMethodsJittedForThread = 0; thread_local int64_t t_c100nsTicksInJitForThread = 0; // This prevents tearing of 64 bit values on 32 bit systems static inline -int64_t AtomicLoad64WithoutTearing(int64_t *valueRef) +int64_t AtomicLoad64WithoutTearing(int64_t volatile *valueRef) { WRAPPER_NO_CONTRACT; #if TARGET_64BIT return VolatileLoad(valueRef); #else - return InterlockedCompareExchangeT(valueRef, 0, 0); + return InterlockedCompareExchangeT((LONG64 volatile *)valueRef, (LONG64)0, (LONG64)0); #endif // TARGET_64BIT } diff --git a/src/coreclr/vm/jitinterface.h b/src/coreclr/vm/jitinterface.h index 5ac3783ab251fb..ed6c433d94b807 100644 --- a/src/coreclr/vm/jitinterface.h +++ b/src/coreclr/vm/jitinterface.h @@ -1158,9 +1158,9 @@ CORJIT_FLAGS GetDebuggerCompileFlags(Module* pModule, CORJIT_FLAGS flags); bool __stdcall TrackAllocationsEnabled(); -extern int64_t g_cbILJitted; -extern int64_t g_cMethodsJitted; -extern int64_t g_c100nsTicksInJit; +extern Volatile g_cbILJitted; +extern Volatile g_cMethodsJitted; +extern Volatile g_c100nsTicksInJit; extern thread_local int64_t t_cbILJittedForThread; extern thread_local int64_t t_cMethodsJittedForThread; extern thread_local int64_t t_c100nsTicksInJitForThread; From 6ff8b305dd837a4c210cb0d6fee3e958211957b2 Mon Sep 17 00:00:00 2001 From: John Salem Date: Thu, 8 Jul 2021 14:59:17 -0700 Subject: [PATCH 20/21] update test to special case interpreter --- .../tests/System/Runtime/JitInfoTests.cs | 28 ++++++++++++++----- 1 file changed, 21 insertions(+), 7 deletions(-) diff --git a/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs index 6350701fe3e501..bda8879c3be00f 100644 --- a/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs +++ b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs @@ -26,13 +26,27 @@ public void JitInfoIsPopulated() long afterCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(); long afterCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(); - Assert.True(beforeCompilationTime > TimeSpan.Zero, $"Compilation time not greater than 0! ({beforeCompilationTime})"); - Assert.True(beforeCompiledILBytes > 0, $"Compiled IL bytes not greater than 0! ({beforeCompiledILBytes})"); - Assert.True(beforeCompiledMethodCount > 0, $"Compiled method count not greater than 0! ({beforeCompiledMethodCount})"); - - Assert.True(afterCompilationTime > beforeCompilationTime, $"CompilationTime: after not greater than before! (after: {afterCompilationTime}, before: {beforeCompilationTime})"); - Assert.True(afterCompiledILBytes > beforeCompiledILBytes, $"Compiled IL bytes: after not greater than before! (after: {afterCompiledILBytes}, before: {beforeCompiledILBytes})"); - Assert.True(afterCompiledMethodCount > beforeCompiledMethodCount, $"Compiled method count: after not greater than before! (after: {afterCompiledMethodCount}, before: {beforeCompiledMethodCount})"); + if (PlatformDetection.IsMonoInterpreter) + { + // special case the Mono interpreter where compilation time may be >0 but before and after will most likely be the same + Assert.True(beforeCompilationTime >= TimeSpan.Zero, $"Compilation time not greater than 0! ({beforeCompilationTime})"); + Assert.True(beforeCompiledILBytes >= 0, $"Compiled IL bytes not greater than 0! ({beforeCompiledILBytes})"); + Assert.True(beforeCompiledMethodCount >= 0, $"Compiled method count not greater than 0! ({beforeCompiledMethodCount})"); + + Assert.True(afterCompilationTime >= beforeCompilationTime, $"CompilationTime: after not greater than before! (after: {afterCompilationTime}, before: {beforeCompilationTime})"); + Assert.True(afterCompiledILBytes >= beforeCompiledILBytes, $"Compiled IL bytes: after not greater than before! (after: {afterCompiledILBytes}, before: {beforeCompiledILBytes})"); + Assert.True(afterCompiledMethodCount >= beforeCompiledMethodCount, $"Compiled method count: after not greater than before! (after: {afterCompiledMethodCount}, before: {beforeCompiledMethodCount})"); + } + else + { + Assert.True(beforeCompilationTime > TimeSpan.Zero, $"Compilation time not greater than 0! ({beforeCompilationTime})"); + Assert.True(beforeCompiledILBytes > 0, $"Compiled IL bytes not greater than 0! ({beforeCompiledILBytes})"); + Assert.True(beforeCompiledMethodCount > 0, $"Compiled method count not greater than 0! ({beforeCompiledMethodCount})"); + + Assert.True(afterCompilationTime > beforeCompilationTime, $"CompilationTime: after not greater than before! (after: {afterCompilationTime}, before: {beforeCompilationTime})"); + Assert.True(afterCompiledILBytes > beforeCompiledILBytes, $"Compiled IL bytes: after not greater than before! (after: {afterCompiledILBytes}, before: {beforeCompiledILBytes})"); + Assert.True(afterCompiledMethodCount > beforeCompiledMethodCount, $"Compiled method count: after not greater than before! (after: {afterCompiledMethodCount}, before: {beforeCompiledMethodCount})"); + } } [Fact] From 45d846bed94948597231666b9a8870c7669fe74f Mon Sep 17 00:00:00 2001 From: John Salem Date: Mon, 12 Jul 2021 11:48:53 -0700 Subject: [PATCH 21/21] Update tests based on PR feedback * use ref emit dynamic method * adds IsNotMonoAot platform detection --- .../TestUtilities/System/PlatformDetection.cs | 1 + .../tests/System/Runtime/JitInfoTests.cs | 51 ++++++++++++++----- 2 files changed, 39 insertions(+), 13 deletions(-) diff --git a/src/libraries/Common/tests/TestUtilities/System/PlatformDetection.cs b/src/libraries/Common/tests/TestUtilities/System/PlatformDetection.cs index aa44cfe53f1b02..52d3e96feebe25 100644 --- a/src/libraries/Common/tests/TestUtilities/System/PlatformDetection.cs +++ b/src/libraries/Common/tests/TestUtilities/System/PlatformDetection.cs @@ -26,6 +26,7 @@ public static partial class PlatformDetection public static bool IsNotMonoRuntime => !IsMonoRuntime; public static bool IsMonoInterpreter => GetIsRunningOnMonoInterpreter(); public static bool IsMonoAOT => Environment.GetEnvironmentVariable("MONO_AOT_MODE") == "aot"; + public static bool IsNotMonoAOT => Environment.GetEnvironmentVariable("MONO_AOT_MODE") != "aot"; public static bool IsFreeBSD => RuntimeInformation.IsOSPlatform(OSPlatform.Create("FREEBSD")); public static bool IsNetBSD => RuntimeInformation.IsOSPlatform(OSPlatform.Create("NETBSD")); public static bool IsAndroid => RuntimeInformation.IsOSPlatform(OSPlatform.Create("ANDROID")); diff --git a/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs index bda8879c3be00f..f0a7eca83ee67b 100644 --- a/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs +++ b/src/libraries/System.Runtime/tests/System/Runtime/JitInfoTests.cs @@ -2,6 +2,8 @@ // The .NET Foundation licenses this file to you under the MIT license. using Microsoft.DotNet.XUnitExtensions; +using System.Reflection; +using System.Reflection.Emit; using System.Threading; using Xunit; @@ -9,18 +11,41 @@ namespace System.Runtime.Tests { public class JitInfoTests { - private const TestPlatforms AotPlatforms = TestPlatforms.Browser | TestPlatforms.iOS | TestPlatforms.tvOS | TestPlatforms.Android; + private long MakeAndInvokeDynamicSquareMethod(int input) + { + // example ref emit dynamic method from https://docs.microsoft.com/en-us/dotnet/framework/reflection-and-codedom/how-to-define-and-execute-dynamic-methods + Type[] methodArgs = {typeof(int)}; - [Fact] - [SkipOnPlatform(AotPlatforms, "JitInfo metrics will be 0 in AOT scenarios.")] + DynamicMethod squareIt = new DynamicMethod( + "SquareIt", + typeof(long), + methodArgs, + typeof(JitInfoTests).Module); + + ILGenerator il = squareIt.GetILGenerator(); + il.Emit(OpCodes.Ldarg_0); + il.Emit(OpCodes.Conv_I8); + il.Emit(OpCodes.Dup); + il.Emit(OpCodes.Mul); + il.Emit(OpCodes.Ret); + + Func invokeSquareIt = + (Func) + squareIt.CreateDelegate(typeof(Func)); + + return invokeSquareIt(input); + + } + + [ConditionalFact(typeof(PlatformDetection), nameof(PlatformDetection.IsNotMonoAOT))] // JitInfo metrics will be 0 in AOT scenarios public void JitInfoIsPopulated() { TimeSpan beforeCompilationTime = System.Runtime.JitInfo.GetCompilationTime(); long beforeCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(); long beforeCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(); - Func theFunc = () => "JIT compile this!"; - Assert.True(theFunc().Equals("JIT compile this!")); + long square = MakeAndInvokeDynamicSquareMethod(100); + Assert.True(square == 10000); TimeSpan afterCompilationTime = System.Runtime.JitInfo.GetCompilationTime(); long afterCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(); @@ -49,16 +74,16 @@ public void JitInfoIsPopulated() } } - [Fact] - [SkipOnPlatform(~AotPlatforms, "JitInfo metrics will be 0 in AOT scenarios.")] + + [ConditionalFact(typeof(PlatformDetection), nameof(PlatformDetection.IsMonoAOT))] // JitInfo metrics will be 0 in AOT scenarios public void JitInfoIsNotPopulated() { TimeSpan beforeCompilationTime = System.Runtime.JitInfo.GetCompilationTime(); long beforeCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(); long beforeCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(); - Func theFunc = () => "JIT compile this!"; - Assert.True(theFunc().Equals("JIT compile this!")); + long square = MakeAndInvokeDynamicSquareMethod(100); + Assert.True(square == 10000); TimeSpan afterCompilationTime = System.Runtime.JitInfo.GetCompilationTime(); long afterCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(); @@ -93,8 +118,8 @@ public void JitInfoCurrentThreadIsPopulated() t1_beforeCompilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); t1_beforeCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true); t1_beforeCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(currentThread: true); - Func theFunc2 = () => "JIT compile this!"; - Assert.True(theFunc2().Equals("JIT compile this!")); + long square = MakeAndInvokeDynamicSquareMethod(100); + Assert.True(square == 10000); t1_afterCompilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); t1_afterCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true); t1_afterCompiledMethodCount = System.Runtime.JitInfo.GetCompiledMethodCount(currentThread: true); @@ -103,8 +128,8 @@ public void JitInfoCurrentThreadIsPopulated() t1.Start(); t1.Join(); - Func theFunc = () => "JIT compile this!"; - Assert.True(theFunc().Equals("JIT compile this!")); + long square = MakeAndInvokeDynamicSquareMethod(100); + Assert.True(square == 10000); TimeSpan t2_afterCompilationTime = System.Runtime.JitInfo.GetCompilationTime(currentThread: true); long t2_afterCompiledILBytes = System.Runtime.JitInfo.GetCompiledILBytes(currentThread: true);