Properly handle self-describing events. (#1999)

microsoft · Mar 2, 2024 · 541dfc2 · 541dfc2
1 parent c1c7266
commit 541dfc2
Show file tree

Hide file tree

Showing 3 changed files with 33 additions and 3 deletions.
diff --git a/src/TraceEvent/DynamicTraceEventParser.cs b/src/TraceEvent/DynamicTraceEventParser.cs
@@ -1038,7 +1038,8 @@ protected internal override Delegate Target
             get { return m_target; }
             set
             {
-                Debug.Assert(m_target == null);
+                // value can be set to null when cloning and converting to a template for live session dispatch
+                Debug.Assert(m_target == null || value == null);
                 m_target = (Action<TraceEvent>)value;
             }
         }

diff --git a/src/TraceEvent/TraceEvent.cs b/src/TraceEvent/TraceEvent.cs
@@ -1383,6 +1383,7 @@ public virtual unsafe TraceEvent Clone()
             }
             return ret;
         }
+
         /// <summary>
         /// Pretty print the event.  It uses XML syntax.. 
         /// </summary>
@@ -2012,6 +2013,15 @@ internal int ThreadIDforStacks()
         /// </summary>
         protected internal virtual void SetState(object state) { }
 
+        protected internal TraceEvent CloneToTemplate()
+        {
+            TraceEvent ret = Clone();
+            ret.traceEventSource = null;
+            ret.eventRecord = null;
+            ret.Target = null;
+            return ret;
+        }
+
         #endregion
         #region Private
         private static char HexDigit(int digit)
@@ -3647,7 +3657,6 @@ internal TraceEvent Lookup(TraceEventNativeMethods.EVENT_RECORD* eventRecord)
                         curTemplate.eventRecord = eventRecord;
                         curTemplate.userData = eventRecord->UserData;
                         curTemplate.eventIndex = currentID;
-                        currentID = currentID + 1;      // TODO overflow. 
 
                         if ((((int)currentID) & 0xFFFF) == 0) // Every 64K events allow Thread.Interrupt.  
                         {
@@ -3685,6 +3694,7 @@ internal TraceEvent Lookup(TraceEventNativeMethods.EVENT_RECORD* eventRecord)
                                 (curTemplate.ProviderGuid == GCDynamicTraceEventParser.ProviderGuid && gcDynamicTemplateEventHeaderMatch));
                         }
 #endif
+                        currentID = currentID + 1;      // TODO overflow.
                         return curTemplate;
                     }
                     else
@@ -3704,7 +3714,6 @@ internal TraceEvent Lookup(TraceEventNativeMethods.EVENT_RECORD* eventRecord)
             unhandledEventTemplate.userData = eventRecord->UserData;
             unhandledEventTemplate.eventIndex = currentID;
             unhandledEventTemplate.lookupAsClassic = unhandledEventTemplate.IsClassicProvider;
-            currentID = currentID + 1;                  // TODO overflow.
             if ((((int)currentID) & 0xFFFF) == 0)       // Every 64K events allow Thread.Interrupt.  
             {
                 System.Threading.Thread.Sleep(0);
@@ -3739,6 +3748,7 @@ internal TraceEvent Lookup(TraceEventNativeMethods.EVENT_RECORD* eventRecord)
                 }
                 while (lastChanceHandlerChecked < lastChanceHandlers.Length);
             }
+            currentID = currentID + 1;                  // TODO overflow.
             return unhandledEventTemplate;
         }
         internal unsafe TraceEvent LookupTemplate(Guid guid, TraceEventID eventID_)

diff --git a/src/TraceEvent/TraceLog.cs b/src/TraceEvent/TraceLog.cs
@@ -642,6 +642,19 @@ private static void RemoveAllButLastEntries<T>(ref GrowableArray<T> growableArra
         /// </summary>
         private unsafe void DispatchClonedEvent(TraceEvent toSend)
         {
+            // Self describing metadata doesn't make it to realTimeSource because TraceLog overwrites the event's extended data.
+            // To address this, we use the event from the raw source, which contains the metadata,
+            // and convert it to a template that can be registered with realTimeSource.
+            realTimeSource.RegisterUnhandledEventImpl(te =>
+            {
+                if (toSend.containsSelfDescribingMetadata)
+                {
+                    var template = toSend.CloneToTemplate();
+                    realTimeSource.Dynamic.OnNewEventDefintion(template, true);
+                    return true;
+                }
+                return false;
+            });
             TraceEvent eventInRealTimeSource = realTimeSource.Lookup(toSend.eventRecord);
             eventInRealTimeSource.userData = toSend.userData;
             eventInRealTimeSource.eventIndex = toSend.eventIndex;           // Lookup assigns the EventIndex, but we want to keep the original.
@@ -1115,6 +1128,12 @@ private unsafe void SetupCallbacks(TraceEventDispatcher rawEvents)
             rawEvents.Clr.GCFinalizeObject += doNothing;
             rawEvents.Clr.MethodJittingStarted += doNothing;
 
+            // This is required to ensure that self-describing metadata gets ingested before the event's extended data gets overwritten by the TraceLog.
+            if (IsRealTime)
+            {
+                rawEvents.Dynamic.All += doNothing;
+            }
+
             //kernelParser.AddCallbackForEvents<PageFaultTraceData>(doNothing);        // Lots of page fault ones
             //kernelParser.AddCallbackForEvents<PageAccessTraceData>(doNothing);
             //kernelParser.PerfInfoSysClEnter += doNothing;