Add public method converting from QPC timestamp into TraceEvent times…

…tamp. (#1442)

* Add public method converting from QPC timestamp into TraceEvent TimeStamp.

New events like ExecutionCheckpoint carries an EventPipe QPC timestamp
that can be used to calculate time spans between interesting checkpoints
and regular EventPipe events. In order to be able to compare times,
EventPipeEventSource needs to expose method that can convert a QPC
timestamp into a timestamp on same format as used by TraceEvent open
up the ability to compare TraceEvent.TimeStamp with timestamps returned
from EventPipeEventSource.QPCTimeToTimeStamp.

* Add test.

* Add baseline file.

* Add parsing of ExecutionCheckpoint into ClrTraceEventParser.

* Update test baseline.

src/TraceEvent/EventPipe/EventPipeEventSource.cs

@@ -83,6 +83,11 @@ private EventPipeEventSource(PinnedStreamReader streamReader, string name)
             StackCache = new StackCache();
         }
 
+        public DateTime QPCTimeToTimeStamp(long QPCTime)
+        {
+            return base.QPCTimeToDateTimeUTC(QPCTime).ToLocalTime();
+        }
+
         #region private
         // I put these in the private section because they are overrides, and thus don't ADD to the API.
         public override int EventsLost => _eventsLost;

src/TraceEvent/Parsers/ClrTraceEventParser.cs

@@ -1164,7 +1164,6 @@ public event Action<EmptyTraceData> ExceptionStop
                 source.UnregisterEventTemplate(value, 256, ProviderGuid);
             }
         }
-
         public event Action<ContentionStartTraceData> ContentionStart
         {
             add
@@ -1964,6 +1963,16 @@ public event Action<JitInstrumentationDataVerboseTraceData> JitInstrumentationDa
                 source.UnregisterEventTemplate(value, 12, JitInstrumentationDataTaskGuid);
             }
         }
+        public event Action<ExecutionCheckpointTraceData> ExecutionCheckpointExecutionCheckpoint {
+            add
+            {
+                RegisterTemplate(ExecutionCheckpointTemplate(value));
+            }
+            remove
+            {
+                source.UnregisterEventTemplate(value, 300, ExecutionCheckpointTaskGuid);
+            }
+        }
 
         #region private
         protected override string GetProviderName() { return ProviderName; }
@@ -2080,13 +2089,17 @@ static private JitInstrumentationDataVerboseTraceData JitInstrumentationDataVerb
         {                  // action, eventid, taskid, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName
             return new JitInstrumentationDataVerboseTraceData(action, 298, 34, "JitInstrumentationDataVerbose", JitInstrumentationDataTaskGuid, 12, "InstrumentationData", ProviderGuid, ProviderName);
         }
+        static private ExecutionCheckpointTraceData ExecutionCheckpointTemplate(Action<ExecutionCheckpointTraceData> action)
+        {                  // action, eventid, taskid, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName
+            return new ExecutionCheckpointTraceData(action, 300, 35, "ExecutionCheckpoint", ExecutionCheckpointTaskGuid, 11, "ExecutionCheckpoint", ProviderGuid, ProviderName);
+        }
 
         static private volatile TraceEvent[] s_templates;
         protected internal override void EnumerateTemplates(Func<string, string, EventFilterResponse> eventsToObserve, Action<TraceEvent> callback)
         {
             if (s_templates == null)
             {
-                var templates = new TraceEvent[139];
+                var templates = new TraceEvent[140];
                 templates[0] = new GCStartTraceData(null, 1, 1, "GC", GCTaskGuid, 1, "Start", ProviderGuid, ProviderName);
                 templates[1] = new GCEndTraceData(null, 2, 1, "GC", GCTaskGuid, 2, "Stop", ProviderGuid, ProviderName);
                 templates[2] = new GCNoUserDataTraceData(null, 3, 1, "GC", GCTaskGuid, 132, "RestartEEStop", ProviderGuid, ProviderName);
@@ -2234,6 +2247,8 @@ protected internal override void EnumerateTemplates(Func<string, string, EventFi
                 templates[137] = JitInstrumentationDataTemplate(null);
                 templates[138] = JitInstrumentationDataVerboseTemplate(null);
 
+                templates[139] = ExecutionCheckpointTemplate(null);
+
                 s_templates = templates;
             }
 
@@ -2300,6 +2315,7 @@ protected internal override void EnumerateTemplates(Func<string, string, EventFi
         private static readonly Guid TieredCompilationTaskGuid = new Guid(unchecked((int)0xa77f474d), unchecked((short)0x9d0d), unchecked((short)0x4311), 0xb9, 0x8e, 0xcf, 0xbc, 0xf8, 0x4b, 0x9e, 0xf);
         private static readonly Guid TypeLoadTaskGuid = new Guid(unchecked((int)0x9db1562b), unchecked((short)0x512f), unchecked((short)0x475d), 0x8d, 0x4c, 0x0c, 0x6d, 0x97, 0xc1, 0xe7, 0x3c);
         private static readonly Guid JitInstrumentationDataTaskGuid = new Guid(unchecked((int)0xf8666925), unchecked((short)0x22c8), unchecked((short)0x4b70), 0xa1, 0x31, 0x07, 0x38, 0x13, 0x7e, 0x7f, 0x25);
+        private static readonly Guid ExecutionCheckpointTaskGuid = new Guid(unchecked((int)0x598832c8), unchecked((short)0xdf4d), unchecked((short)0x4e9e), 0xab, 0xe6, 0x2c, 0x7b, 0xf0, 0xba, 0x2d, 0xa2);
 
         // TODO remove if project N's Guids are harmonized with the desktop 
         private void RegisterTemplate(TraceEvent template)
@@ -12353,6 +12369,73 @@ public override object PayloadValue(int index)
         #endregion
     }
 
+    public sealed class ExecutionCheckpointTraceData : TraceEvent
+    {
+        public int ClrInstanceID { get { return GetInt16At(0); } }
+        public string CheckpointName { get { return GetUnicodeStringAt(2); } }
+        public long CheckpointTimestamp { get { return GetInt64At(SkipUnicodeString(2)); } }
+
+        #region Private
+        internal ExecutionCheckpointTraceData(Action<ExecutionCheckpointTraceData> action, int eventID, int task, string taskName, Guid taskGuid, int opcode, string opcodeName, Guid providerGuid, string providerName)
+            : base(eventID, task, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName)
+        {
+            Action = action;
+        }
+        protected internal override void Dispatch()
+        {
+            Action(this);
+        }
+        protected internal override void Validate()
+        {
+            Debug.Assert(!(Version == 0 && EventDataLength != SkipUnicodeString(2) + 8));
+            Debug.Assert(!(Version > 0 && EventDataLength < SkipUnicodeString(2) + 8));
+        }
+        protected internal override Delegate Target {
+            get { return Action; }
+            set { Action = (Action<ExecutionCheckpointTraceData>)value; }
+        }
+        public override StringBuilder ToXml(StringBuilder sb)
+        {
+            Prefix(sb);
+            XmlAttrib(sb, "ClrInstanceID", ClrInstanceID);
+            XmlAttrib(sb, "Name", CheckpointName);
+            XmlAttrib(sb, "Timestamp", CheckpointTimestamp);
+            sb.Append("/>");
+            return sb;
+        }
+
+        public override string[] PayloadNames {
+            get
+            {
+                if (payloadNames == null)
+                    payloadNames = new string[] { "ClrInstanceID", "Name", "Timestamp" };
+                return payloadNames;
+            }
+        }
+
+        public override object PayloadValue(int index)
+        {
+            switch (index)
+            {
+                case 0:
+                    return ClrInstanceID;
+                case 1:
+                    return CheckpointName;
+                case 2:
+                    return CheckpointTimestamp;
+                default:
+                    Debug.Assert(false, "Bad field index");
+                    return null;
+            }
+        }
+
+        public static ulong GetKeywords() { return 536870912; }
+        public static string GetProviderName() { return "Microsoft-Windows-DotNETRuntime"; }
+        public static Guid GetProviderGuid() { return new Guid("e13c0d23-ccbc-4e12-931b-d9cc2eee27e4"); }
+        private event Action<ExecutionCheckpointTraceData> Action;
+        #endregion
+    }
+
     [Flags]
     public enum AppDomainFlags
     {
@@ -13030,6 +13113,16 @@ public event Action<TieredCompilationSettingsTraceData> TieredCompilationRundown
                 source.UnregisterEventTemplate(value, 11, TieredCompilationRundownTaskGuid);
             }
         }
+        public event Action<ExecutionCheckpointTraceData> ExecutionCheckpointRundownExecutionCheckpointDCEnd {
+            add
+            {
+                source.RegisterEventTemplate(ExecutionCheckpointDCEndTemplate(value));
+            }
+            remove
+            {
+                source.UnregisterEventTemplate(value, 300, ExecutionCheckpointRundownTaskGuid);
+            }
+        }
 
         #region Event ID Definitions
         private const TraceEventID ClrStackWalkEventID = (TraceEventID)0;
@@ -13052,6 +13145,8 @@ public event Action<TieredCompilationSettingsTraceData> TieredCompilationRundown
         private const TraceEventID LoaderThreadDCStopEventID = (TraceEventID)159;
         private const TraceEventID RuntimeStartEventID = (TraceEventID)187;
         private const TraceEventID CodeSymbolsRundownStartEventID = (TraceEventID)188;
+        private const TraceEventID TieredCompilationSettingsDCStartEventID = (TraceEventID)280;
+        private const TraceEventID ExecutionCheckpointDCEndEventID = (TraceEventID)300;
         #endregion
 
         public sealed class DCStartEndTraceData : TraceEvent
@@ -13119,12 +13214,17 @@ static private TieredCompilationSettingsTraceData TieredCompilationSettingsDCSta
             return new TieredCompilationSettingsTraceData(action, 280, 31, "TieredCompilationRundown", TieredCompilationRundownTaskGuid, 11, "SettingsDCStart", ProviderGuid, ProviderName);
         }
 
+        static private ExecutionCheckpointTraceData ExecutionCheckpointDCEndTemplate(Action<ExecutionCheckpointTraceData> action)
+        {                  // action, eventid, taskid, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName
+            return new ExecutionCheckpointTraceData(action, 300, 35, "ExecutionCheckpointRundown", ExecutionCheckpointRundownTaskGuid, 11, "ExecutionCheckpointDCEnd", ProviderGuid, ProviderName);
+        }
+
         static private volatile TraceEvent[] s_templates;
         protected internal override void EnumerateTemplates(Func<string, string, EventFilterResponse> eventsToObserve, Action<TraceEvent> callback)
         {
             if (s_templates == null)
             {
-                var templates = new TraceEvent[23];
+                var templates = new TraceEvent[24];
                 templates[0] = new MethodILToNativeMapTraceData(null, 149, 1, "Method", MethodTaskGuid, 41, "ILToNativeMapDCStart", ProviderGuid, ProviderName);
                 templates[1] = new MethodILToNativeMapTraceData(null, 150, 1, "Method", MethodTaskGuid, 42, "ILToNativeMapDCStop", ProviderGuid, ProviderName);
                 templates[2] = new ClrStackWalkTraceData(null, 0, 11, "ClrStack", ClrStackTaskGuid, 82, "Walk", ProviderGuid, ProviderName);
@@ -13151,6 +13251,8 @@ protected internal override void EnumerateTemplates(Func<string, string, EventFi
                 // New style
                 templates[22] = TieredCompilationSettingsDCStartTemplate(null);
 
+                templates[23] = ExecutionCheckpointDCEndTemplate(null);
+
                 s_templates = templates;
             }
             foreach (var template in s_templates)
@@ -13164,6 +13266,7 @@ protected internal override void EnumerateTemplates(Func<string, string, EventFi
         private static readonly Guid RuntimeTaskGuid = new Guid(unchecked((int)0xcd7d3e32), unchecked((short)0x65fe), unchecked((short)0x40cd), 0x92, 0x25, 0xa2, 0x57, 0x7d, 0x20, 0x3f, 0xc3);
         private static readonly Guid CodeSymbolsRundownTaskGuid = new Guid(unchecked((int)0x86b6c496), unchecked((short)0x0d9e), unchecked((short)0x4ba6), 0x81, 0x93, 0xca, 0x58, 0xe6, 0xe8, 0xc5, 0x15);
         private static readonly Guid TieredCompilationRundownTaskGuid = new Guid(unchecked((int)0xa1673472), unchecked((short)0x564), unchecked((short)0x48ea), 0xa9, 0x5d, 0xb4, 0x9d, 0x41, 0x73, 0xf1, 0x5);
+        private static readonly Guid ExecutionCheckpointRundownTaskGuid = new Guid(unchecked((int)0xdff63eca), unchecked((short)0xadaa), unchecked((short)0x431f), 0x8f, 0x91, 0x72, 0x82, 0x0c, 0x72, 0x17, 0xdb);
         #endregion
     }
 

src/TraceEvent/TraceEvent.Tests/EventPipeParsing.cs

@@ -513,6 +513,42 @@ public void WellKnownDiagnosticSourceEventsHavePayloads()
             Assert.Equal(7, diagSourceEventCount);
         }
 
+        [Fact]
+        public void ExecutionCheckpointEventsAndTimeStamping()
+        {
+            PrepareTestData();
+
+            const string eventPipeFileName = "eventpipe-dotnetcore6.0-win-x64-executioncheckpoints.nettrace";
+
+            string eventPipeFilePath = Path.Combine(UnZippedDataDir, eventPipeFileName);
+
+            var checkpoints = new Dictionary<string, double>();
+            checkpoints.Add("RuntimeInit", -15.97);
+            checkpoints.Add("RuntimeSuspend", 11.91);
+            checkpoints.Add("RuntimeResumed", 12.20);
+
+            UnicodeEncoding unicode = new UnicodeEncoding();
+            using (var source = new EventPipeEventSource(eventPipeFilePath))
+            {
+                var rundown = new ClrRundownTraceEventParser(source);
+                rundown.ExecutionCheckpointRundownExecutionCheckpointDCEnd += delegate (ExecutionCheckpointTraceData data)
+                {
+                    var timestamp = source.QPCTimeToTimeStamp(data.CheckpointTimestamp);
+                    var diff = Math.Round((timestamp - source.SessionStartTime).TotalMilliseconds, 2);
+
+                    // Asserts
+                    Assert.True(checkpoints.ContainsKey(data.CheckpointName));
+                    Assert.True(checkpoints[data.CheckpointName] == diff);
+
+                    checkpoints.Remove(data.CheckpointName);
+                };
+
+                source.Process();
+
+                Assert.True(checkpoints.Count == 0);
+            }
+        }
+
         private void Dynamic_All(TraceEvent obj)
         {
             throw new NotImplementedException();

src/TraceEvent/TraceEvent.Tests/inputs/eventpipe-dotnetcore6.0-win-x64-executioncheckpoints.nettrace.baseline.txt

@@ -0,0 +1 @@
+Microsoft-Windows-DotNETRuntimeRundown/ExecutionCheckpointRundown/ExecutionCheckpointDCEnd, 3, <Event MSec=  "1753.7906" PID="9832" PName="Process(9832)" TID="25112" EventName="ExecutionCheckpointRundown/ExecutionCheckpointDCEnd" ClrInstanceID="9" Name="RuntimeInit" Timestamp="11,111,925,598,665"/>