DiagnosticSourceEventSource fixes/improvements for distributed tracing (

dotnet/corefx#41943)

* DiagnosticSourceEventSource fixes for distributed tracing

1) There is no existing mechanism for DiagnosticSourceEventSource to fetch the current activity object. By convention it is not passed as an event argument, but rather stored in the async-local property Activity.Current. This was fixed by adding a well-known "*Activity" property that returns the result of Activity.Current regardless what object it is applied to.

2) DiagnosticSourceEventSource fails to evaluate properties on value types, such as DateTime.Ticks. Calling MethodInfo.CreateDelegate
needs to use a different signature for ref and value type properties and previously the code always used the ref-style signature. Fixed by adding ValueTypedFetchProperty that does the proper CreateDelegate and delegate invocation for structs.

3) There is no mechanism for DiagnosticSourceEventSource to enumerate the tags on an activity. This change adds the *Enumerate well-known property which will iterate any IEnumerable`1, invoke ToString() on each element, then join it as a string.


Commit migrated from dotnet/corefx@ef56315

src/libraries/System.Diagnostics.DiagnosticSource/src/ILLinkTrim.xml

@@ -1,9 +1,17 @@
 <linker>
   <assembly fullname="System.Diagnostics.DiagnosticSource">
     <type fullname="System.Diagnostics.DiagnosticSourceEventSource" />
-    <type fullname="System.Diagnostics.DiagnosticSourceEventSource/TransformSpec/PropertySpec/PropertyFetch/TypedFetchProperty`2">
+    <type fullname="System.Diagnostics.DiagnosticSourceEventSource/TransformSpec/PropertySpec/PropertyFetch/RefTypedFetchProperty`2">
+      <!-- Instantiated via reflection -->
+      <method name=".ctor" />
+    </type>
+    <type fullname="System.Diagnostics.DiagnosticSourceEventSource/TransformSpec/PropertySpec/PropertyFetch/ValueTypedFetchProperty`2">
+      <!-- Instantiated via reflection -->
+      <method name=".ctor" />
+    </type>
+    <type fullname="System.Diagnostics.DiagnosticSourceEventSource/TransformSpec/PropertySpec/PropertyFetch/EnumeratePropertyFetch`1">
       <!-- Instantiated via reflection -->
       <method name=".ctor" />
     </type>
   </assembly>
-</linker>
+</linker>

src/libraries/System.Diagnostics.DiagnosticSource/src/System.Diagnostics.DiagnosticSource.csproj

@@ -10,6 +10,8 @@
     <NoWarn>$(NoWarn);SA1205</NoWarn>
     <Nullable>enable</Nullable>
     <DefineConstants Condition="'$(TargetFramework)' == 'netstandard1.1' OR '$(TargetFramework)' == 'net45'">$(DefineConstants);NO_EVENTSOURCE_COMPLEX_TYPE_SUPPORT</DefineConstants>
+    <DefineConstants Condition="'$(TargetFramework)' != 'netstandard1.1'">$(DefineConstants);EVENTSOURCE_ACTIVITY_SUPPORT</DefineConstants>
+    <DefineConstants Condition="'$(TargetFramework)' != 'netstandard1.1' AND '$(TargetFramework)' != 'netstandard1.3'">$(DefineConstants);EVENTSOURCE_ENUMERATE_SUPPORT</DefineConstants>
     <DefineConstants Condition="'$(TargetsNetFx)' == 'true'">$(DefineConstants);ALLOW_PARTIALLY_TRUSTED_CALLERS;ENABLE_HTTP_HANDLER</DefineConstants>
     <Configurations>net45-Debug;net45-Release;net46-Debug;net46-Release;netcoreapp-Debug;netcoreapp-Release;netfx-Debug;netfx-Release;netstandard-Debug;netstandard-Release;netstandard1.1-Debug;netstandard1.1-Release;netstandard1.3-Debug;netstandard1.3-Release</Configurations>
   </PropertyGroup>

src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/DiagnosticSourceEventSource.cs

@@ -62,6 +62,9 @@ namespace System.Diagnostics
     ///       * PROPERTY_NAME                  - fetches a property from the DiagnosticSource payload object
     ///       * PROPERTY_NAME . PROPERTY NAME  - fetches a sub-property of the object.
     ///
+    ///       * *Activity                      - fetches Activity.Current
+    ///       * *Enumerate                     - enumerates all the items in an IEnumerable, calls ToString() on them, and joins the
+    ///                                          strings in a comma separated list.
     /// Example1:
     ///
     ///    "BridgeTestSource1/TestEvent1:cls_Point_X=cls.Point.X;cls_Point_Y=cls.Point.Y\r\n" +
@@ -801,7 +804,7 @@ public TransformSpec(string transformSpec, int startIdx, int endIdx, TransformSp
             {
                 for (PropertySpec? cur = _fetches; cur != null; cur = cur.Next)
                 {
-                    if (obj != null)
+                    if (obj != null || cur.IsStatic)
                         obj = cur.Fetch(obj);
                 }
 
@@ -821,28 +824,41 @@ public TransformSpec(string transformSpec, int startIdx, int endIdx, TransformSp
             /// </summary>
             internal class PropertySpec
             {
+                private const string CurrentActivityPropertyName = "*Activity";
+                private const string EnumeratePropertyName = "*Enumerate";
+
                 /// <summary>
                 /// Make a new PropertySpec for a property named 'propertyName'.
                 /// For convenience you can set he 'next' field to form a linked
                 /// list of PropertySpecs.
                 /// </summary>
-                public PropertySpec(string propertyName, PropertySpec? next = null)
+                public PropertySpec(string propertyName, PropertySpec? next)
                 {
                     Next = next;
                     _propertyName = propertyName;
+
+                    // detect well-known names that are static functions
+                    if (_propertyName == CurrentActivityPropertyName)
+                    {
+                        IsStatic = true;
+                    }
                 }
 
+                public bool IsStatic { get; private set; }
+
                 /// <summary>
                 /// Given an object fetch the property that this PropertySpec represents.
+                /// obj may be null when IsStatic is true, otherwise it must be non-null.
                 /// </summary>
-                public object? Fetch(object obj)
+                public object? Fetch(object? obj)
                 {
-                    Type objType = obj.GetType();
                     PropertyFetch? fetch = _fetchForExpectedType;
+                    Debug.Assert(obj != null || IsStatic);
+                    Type? objType = obj?.GetType();
                     if (fetch == null || fetch.Type != objType)
                     {
                         _fetchForExpectedType = fetch = PropertyFetch.FetcherForProperty(
-                            objType, objType.GetTypeInfo().GetDeclaredProperty(_propertyName));
+                            objType, _propertyName);
                     }
                     return fetch!.Fetch(obj);
                 }
@@ -860,48 +876,153 @@ public PropertySpec(string propertyName, PropertySpec? next = null)
                 /// </summary>
                 private class PropertyFetch
                 {
-                    protected PropertyFetch(Type type)
+                    public PropertyFetch(Type? type)
                     {
-                        Debug.Assert(type != null);
                         Type = type;
                     }
 
-                    internal Type Type { get; }
+                    /// <summary>
+                    /// The type of the object that the property is fetched from. For well-known static methods that
+                    /// aren't actually property getters this will return null.
+                    /// </summary>
+                    internal Type? Type { get; }
 
                     /// <summary>
-                    /// Create a property fetcher from a .NET Reflection PropertyInfo class that
-                    /// represents a property of a particular type.
+                    /// Create a property fetcher for a propertyName
                     /// </summary>
-                    public static PropertyFetch? FetcherForProperty(Type type, PropertyInfo? propertyInfo)
+                    public static PropertyFetch FetcherForProperty(Type? type, string propertyName)
                     {
-                        if (propertyInfo == null)
+                        if (propertyName == null)
                             return new PropertyFetch(type);     // returns null on any fetch.
+                        if (propertyName == CurrentActivityPropertyName)
+                        {
+#if EVENTSOURCE_ACTIVITY_SUPPORT
+                            return new CurrentActivityPropertyFetch();
+#else
+                            // In netstandard1.1 the Activity.Current API doesn't exist
+                            Logger.Message($"{CurrentActivityPropertyName} not supported for this TFM");
+                            return new PropertyFetch(type);
+#endif
+                        }
+
+                        Debug.Assert(type != null, "Type should only be null for the well-known static fetchers already checked");
+                        TypeInfo typeInfo = type.GetTypeInfo();
+                        if (propertyName == EnumeratePropertyName)
+                        {
+#if !EVENTSOURCE_ENUMERATE_SUPPORT
+                            // In netstandard1.1 and 1.3 the reflection APIs needed to implement Enumerate support aren't
+                            // available
+                            Logger.Message($"{EnumeratePropertyName} not supported for this TFM");
+                            return new PropertyFetch(type);
+#else
+                            // If there are multiple implementations of IEnumerable<T>, this arbitrarily uses the first one
+                            foreach (Type iFaceType in typeInfo.GetInterfaces())
+                            {
+                                TypeInfo iFaceTypeInfo = iFaceType.GetTypeInfo();
+                                if (!iFaceTypeInfo.IsGenericType ||
+                                    iFaceTypeInfo.GetGenericTypeDefinition() != typeof(IEnumerable<>))
+                                {
+                                    continue;
+                                }
+
+                                Type elemType = iFaceTypeInfo.GetGenericArguments()[0];
+                                Type instantiatedTypedPropertyFetcher = typeof(EnumeratePropertyFetch<>)
+                                    .GetTypeInfo().MakeGenericType(elemType);
+                                return (PropertyFetch)Activator.CreateInstance(instantiatedTypedPropertyFetcher, type)!;
+                            }
 
-                        var typedPropertyFetcher = typeof(TypedFetchProperty<,>);
-                        var instantiatedTypedPropertyFetcher = typedPropertyFetcher.GetTypeInfo().MakeGenericType(
-                            propertyInfo.DeclaringType!, propertyInfo.PropertyType);
-                        return (PropertyFetch?)Activator.CreateInstance(instantiatedTypedPropertyFetcher, type, propertyInfo);
+                            // no implemenation of IEnumerable<T> found, return a null fetcher
+                            Logger.Message($"*Enumerate applied to non-enumerable type {type}");
+                            return new PropertyFetch(type);
+#endif
+                        }
+                        else
+                        {
+                            PropertyInfo? propertyInfo = typeInfo.GetDeclaredProperty(propertyName);
+                            if (propertyInfo == null)
+                            {
+                                Logger.Message($"Property {propertyName} not found on {type}");
+                                return new PropertyFetch(type);
+                            }
+                            Type typedPropertyFetcher = typeInfo.IsValueType ?
+                                typeof(ValueTypedFetchProperty<,>) : typeof(RefTypedFetchProperty<,>);
+                            Type instantiatedTypedPropertyFetcher = typedPropertyFetcher.GetTypeInfo().MakeGenericType(
+                                propertyInfo.DeclaringType!, propertyInfo.PropertyType);
+                            return (PropertyFetch)Activator.CreateInstance(instantiatedTypedPropertyFetcher, type, propertyInfo)!;
+                        }
                     }
 
                     /// <summary>
                     /// Given an object, fetch the property that this propertyFech represents.
                     /// </summary>
-                    public virtual object? Fetch(object obj) { return null; }
+                    public virtual object? Fetch(object? obj) { return null; }
 
                     #region private
 
-                    private sealed class TypedFetchProperty<TObject, TProperty> : PropertyFetch
+                    private sealed class RefTypedFetchProperty<TObject, TProperty> : PropertyFetch
                     {
-                        public TypedFetchProperty(Type type, PropertyInfo property) : base(type)
+                        public RefTypedFetchProperty(Type type, PropertyInfo property) : base(type)
                         {
+                            Debug.Assert(typeof(TObject).GetTypeInfo().IsAssignableFrom(type.GetTypeInfo()));
                             _propertyFetch = (Func<TObject, TProperty>)property.GetMethod!.CreateDelegate(typeof(Func<TObject, TProperty>));
                         }
-                        public override object? Fetch(object obj)
+                        public override object? Fetch(object? obj)
                         {
+                            Debug.Assert(obj is TObject);
                             return _propertyFetch((TObject)obj);
                         }
                         private readonly Func<TObject, TProperty> _propertyFetch;
                     }
+
+                    private delegate TProperty StructFunc<TStruct, TProperty>(ref TStruct thisArg);
+
+                    // Value types methods require that the first argument is passed by reference. This requires a different delegate signature
+                    // from the reference type case.
+                    private sealed class ValueTypedFetchProperty<TStruct, TProperty> : PropertyFetch
+                    {
+                        public ValueTypedFetchProperty(Type type, PropertyInfo property) : base(type)
+                        {
+                            Debug.Assert(typeof(TStruct) == type);
+                            _propertyFetch = (StructFunc<TStruct, TProperty>)property.GetMethod!.CreateDelegate(typeof(StructFunc<TStruct, TProperty>));
+                        }
+                        public override object? Fetch(object? obj)
+                        {
+                            Debug.Assert(obj is TStruct);
+                            // It is uncommon for property getters to mutate the struct, but if they do the change will be lost.
+                            // We are calling the getter on an unboxed copy
+                            TStruct structObj = (TStruct)obj;
+                            return _propertyFetch(ref structObj);
+                        }
+                        private readonly StructFunc<TStruct, TProperty> _propertyFetch;
+                    }
+
+
+#if EVENTSOURCE_ACTIVITY_SUPPORT
+                    /// <summary>
+                    /// A fetcher that returns the result of Activity.Current
+                    /// </summary>
+                    private sealed class CurrentActivityPropertyFetch : PropertyFetch
+                    {
+                        public CurrentActivityPropertyFetch() : base(null) { }
+                        public override object? Fetch(object? obj)
+                        {
+                            return Activity.Current;
+                        }
+                    }
+#endif
+
+                    /// <summary>
+                    /// A fetcher that enumerates and formats an IEnumerable
+                    /// </summary>
+                    private sealed class EnumeratePropertyFetch<ElementType> : PropertyFetch
+                    {
+                        public EnumeratePropertyFetch(Type type) : base(type) { }
+                        public override object? Fetch(object? obj)
+                        {
+                            Debug.Assert(obj is IEnumerable<ElementType>);
+                            return string.Join(",", (IEnumerable<ElementType>)obj);
+                        }
+                    }
                     #endregion
                 }
 

src/libraries/System.Diagnostics.DiagnosticSource/tests/DiagnosticSourceEventSourceBridgeTests.cs

@@ -771,6 +771,95 @@ public void IndexGetters_DontThrow()
                 }
             }).Dispose();
         }
+
+        [Fact]
+        public void ActivityObjectsAreInspectable()
+        {
+            RemoteExecutor.Invoke(() =>
+            {
+                using (var eventListener = new TestDiagnosticSourceEventListener())
+                using (var diagnosticListener = new DiagnosticListener("MySource"))
+                {
+                    string activityProps =
+                        "-DummyProp" +
+                        ";ActivityId=*Activity.Id" +
+                        ";ActivityStartTime=*Activity.StartTimeUtc.Ticks" +
+                        ";ActivityDuration=*Activity.Duration.Ticks" +
+                        ";ActivityOperationName=*Activity.OperationName" +
+                        ";ActivityIdFormat=*Activity.IdFormat" +
+                        ";ActivityParentId=*Activity.ParentId" +
+                        ";ActivityTags=*Activity.Tags.*Enumerate" +
+                        ";ActivityTraceId=*Activity.TraceId" +
+                        ";ActivitySpanId=*Activity.SpanId" +
+                        ";ActivityTraceStateString=*Activity.TraceStateString" +
+                        ";ActivityParentSpanId=*Activity.ParentSpanId";
+                    eventListener.Enable(
+                        "MySource/TestActivity1.Start@Activity1Start:" + activityProps + "\r\n" +
+                        "MySource/TestActivity1.Stop@Activity1Stop:" + activityProps + "\r\n" +
+                        "MySource/TestActivity2.Start@Activity2Start:" + activityProps + "\r\n" +
+                        "MySource/TestActivity2.Stop@Activity2Stop:" + activityProps + "\r\n"
+                        );
+
+                    Activity activity1 = new Activity("TestActivity1");
+                    activity1.SetIdFormat(ActivityIdFormat.W3C);
+                    activity1.TraceStateString = "hi_there";
+                    activity1.AddTag("one", "1");
+                    activity1.AddTag("two", "2");
+
+                    diagnosticListener.StartActivity(activity1, new { DummyProp = "val" });
+                    Assert.Equal(1, eventListener.EventCount);
+                    AssertActivityMatchesEvent(activity1, eventListener.LastEvent, isStart: true);
+
+                    Activity activity2 = new Activity("TestActivity2");
+                    diagnosticListener.StartActivity(activity2, new { DummyProp = "val" });
+                    Assert.Equal(2, eventListener.EventCount);
+                    AssertActivityMatchesEvent(activity2, eventListener.LastEvent, isStart: true);
+
+                    diagnosticListener.StopActivity(activity2, new { DummyProp = "val" });
+                    Assert.Equal(3, eventListener.EventCount);
+                    AssertActivityMatchesEvent(activity2, eventListener.LastEvent, isStart: false);
+
+                    diagnosticListener.StopActivity(activity1, new { DummyProp = "val" });
+                    Assert.Equal(4, eventListener.EventCount);
+                    AssertActivityMatchesEvent(activity1, eventListener.LastEvent, isStart: false);
+
+                }
+            }).Dispose();
+        }
+
+        private void AssertActivityMatchesEvent(Activity a, DiagnosticSourceEvent e, bool isStart)
+        {
+            Assert.Equal("MySource", e.SourceName);
+            Assert.Equal(a.OperationName + (isStart ? ".Start" : ".Stop"), e.EventName);
+            Assert.Equal("val", e.Arguments["DummyProp"]);
+            Assert.Equal(a.Id, e.Arguments["ActivityId"]);
+            Assert.Equal(a.StartTimeUtc.Ticks.ToString(), e.Arguments["ActivityStartTime"]);
+            if (!isStart)
+            {
+                Assert.Equal(a.Duration.Ticks.ToString(), e.Arguments["ActivityDuration"]);
+            }
+            Assert.Equal(a.OperationName, e.Arguments["ActivityOperationName"]);
+            if (a.ParentId == null)
+            {
+                Assert.True(!e.Arguments.ContainsKey("ActivityParentId"));
+            }
+            else
+            {
+                Assert.Equal(a.ParentId, e.Arguments["ActivityParentId"]);
+            }
+            Assert.Equal(a.IdFormat.ToString(), e.Arguments["ActivityIdFormat"]);
+            if (a.IdFormat == ActivityIdFormat.W3C)
+            {
+                Assert.Equal(a.TraceId.ToString(), e.Arguments["ActivityTraceId"]);
+                Assert.Equal(a.SpanId.ToString(), e.Arguments["ActivitySpanId"]);
+                Assert.Equal(a.TraceStateString, e.Arguments["ActivityTraceStateString"]);
+                if(a.ParentSpanId != default)
+                {
+                    Assert.Equal(a.ParentSpanId.ToString(), e.Arguments["ActivityParentSpanId"]);
+                }
+            }
+            Assert.Equal(string.Join(',', a.Tags), e.Arguments["ActivityTags"]);
+        }
     }
 
     /****************************************************************************/