Add eventsource collector and console logger implementation (Azure#7577)

eng/Directory.Build.Data.props

@@ -114,7 +114,7 @@
     <DelaySign>false</DelaySign>
     <PublicSign>false</PublicSign>
     <ImportDefaultReferences>false</ImportDefaultReferences>
-    <UseProjectReferenceToAzureCore>false</UseProjectReferenceToAzureCore>
+    <UseProjectReferenceToAzureCore>true</UseProjectReferenceToAzureCore>
     <LangVersion>preview</LangVersion>
     <DocumentationFile>$(IntermediateOutputPath)$(TargetFramework)\$(MSBuildProjectName).xml</DocumentationFile>
   </PropertyGroup>

sdk/appconfiguration/Azure.Data.AppConfiguration/samples/Sample4_Logging.cs

@@ -5,15 +5,15 @@
 using Azure.Core.Testing;
 using NUnit.Framework;
 using System;
-using System.Diagnostics;
 using System.Diagnostics.Tracing;
+using Azure.Core.Diagnostics;
 
 namespace Azure.Data.AppConfiguration.Samples
 {
     [LiveOnly]
     public partial class ConfigurationSamples
     {
-        // ConfigurationClient logs lots of useful information automatically to .NET's EventSource.
+        // AzureEventSourceListener logs lots of useful information automatically to .NET's EventSource.
         // This sample illustrate how to control and access the log information.
         [Test]
         public void Logging()
@@ -24,8 +24,7 @@ public void Logging()
             var client = new ConfigurationClient(connectionString);
 
             // Setup a listener to monitor logged events.
-            var listener = new ConsoleEventListener();
-            listener.EnableEvents(EventLevel.LogAlways);
+            using AzureEventSourceListener listener = AzureEventSourceListener.CreateConsoleLogger(EventLevel.LogAlways);
 
             Response<ConfigurationSetting> setResponse = client.Set(new ConfigurationSetting("some_key", "some_value"));
             if (setResponse.GetRawResponse().Status != 200)
@@ -37,40 +36,4 @@ public void Logging()
             client.Delete("some_key");
         }
     }
-
-    public class ConsoleEventListener : EventListener
-    {
-        private const string SOURCE_NAME = "AzureSDK";
-
-        private EventLevel _enabled;
-        private EventSource _source;
-
-        protected override void OnEventSourceCreated(EventSource eventSource)
-        {
-            base.OnEventSourceCreated(eventSource);
-            if (eventSource.Name == SOURCE_NAME) {
-                _source = eventSource;
-                if (_enabled != default) {
-                    EnableEvents(_source, _enabled);
-                }
-            }
-        }
-
-        public void EnableEvents(EventLevel level)
-        {
-            _enabled = level;
-            if (_source != null) {
-                EnableEvents(_source, _enabled);
-            }
-        }
-
-        protected override void OnEventWritten(EventWrittenEventArgs eventData)
-        {
-            if (eventData.EventSource.Name == SOURCE_NAME) {
-                var formatted = eventData.EventName + " : " + eventData.Payload[0].ToString();
-                Console.WriteLine(formatted);
-                Debug.WriteLine(formatted);
-            }
-        }
-    }
 }

sdk/core/Azure.Core/src/Diagnostics/AzureEventSourceListener.cs

@@ -0,0 +1,67 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System;
+using System.Collections.Generic;
+using System.Diagnostics;
+using System.Diagnostics.Tracing;
+using System.Globalization;
+using Azure.Core.Shared;
+
+namespace Azure.Core.Diagnostics
+{
+    public class AzureEventSourceListener: EventListener
+    {
+        public const string TraitName = "AzureEventSource";
+        public const string TraitValue = "true";
+
+        private readonly List<EventSource> _eventSources = new List<EventSource>();
+
+        private readonly Action<EventWrittenEventArgs, string> _log;
+        private readonly EventLevel _level;
+
+        public AzureEventSourceListener(Action<EventWrittenEventArgs, string> log, EventLevel level)
+        {
+            _log = log;
+            _level = level;
+
+            foreach (EventSource eventSource in _eventSources)
+            {
+                OnEventSourceCreated(eventSource);
+            }
+
+            _eventSources.Clear();
+        }
+
+        protected sealed override void OnEventSourceCreated(EventSource eventSource)
+        {
+            base.OnEventSourceCreated(eventSource);
+
+            if (_log == null)
+            {
+                _eventSources.Add(eventSource);
+            }
+
+            if (eventSource.GetTrait(TraitName) == TraitValue)
+            {
+                EnableEvents(eventSource, _level);
+            }
+        }
+
+        protected sealed override void OnEventWritten(EventWrittenEventArgs eventData)
+        {
+            _log(eventData, EventSourceEventFormatting.Format(eventData));
+        }
+
+        public static AzureEventSourceListener CreateConsoleLogger(EventLevel level = EventLevel.Informational)
+        {
+            return new AzureEventSourceListener((eventData, text) => Console.WriteLine("[{1}] {0}: {2}", eventData.EventSource.Name, eventData.Level, text), level);
+        }
+
+        public static AzureEventSourceListener CreateTraceLogger(EventLevel level = EventLevel.Informational)
+        {
+            return new AzureEventSourceListener(
+                (eventData, text) => Trace.WriteLine(string.Format(CultureInfo.InvariantCulture, "[{0}] {1}", eventData.Level, text), eventData.EventSource.Name), level);
+        }
+    }
+}

sdk/core/Azure.Core/src/Diagnostics/HttpPipelineEventSource.cs

@@ -11,16 +11,12 @@
 using System.Threading.Tasks;
 using Azure.Core.Http;
 
-// TODO (pri 2): we should log correction/activity
-// TODO (pri 2): we should log exceptions
 namespace Azure.Core.Diagnostics
 {
-    // TODO (pri 2): make the type internal
     [EventSource(Name = EventSourceName)]
     internal sealed class HttpPipelineEventSource : EventSource
     {
-        // TODO (pri 3): do we want the same source name for all SDk components?
-        private const string EventSourceName = "AzureSDK";
+        private const string EventSourceName = "Azure-Core";
 
         private const int MaxEventPayloadSize = 10 * 1024;
         private const int CopyBufferSize = 8 * 1024;
@@ -41,11 +37,10 @@ internal sealed class HttpPipelineEventSource : EventSource
         private const int ErrorResponseContentTextBlockEvent = 16;
         private const int RequestRetryingEvent = 10;
 
-        private HttpPipelineEventSource() : base(EventSourceName) { }
+        private HttpPipelineEventSource() : base(EventSourceName, EventSourceSettings.Default, AzureEventSourceListener.TraitName, AzureEventSourceListener.TraitValue) { }
 
         internal static readonly HttpPipelineEventSource Singleton = new HttpPipelineEventSource();
 
-        // TODO (pri 2): this logs just the URI. We need more
         [NonEvent]
         public void Request(Request request)
         {

sdk/core/Azure.Core/src/Shared/EventSourceEventFormatting.cs

@@ -0,0 +1,61 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System;
+using System.Diagnostics.Tracing;
+using System.Globalization;
+using System.Linq;
+using System.Text;
+
+namespace Azure.Core.Shared
+{
+    internal class EventSourceEventFormatting
+    {
+        public static string Format(EventWrittenEventArgs eventData)
+        {
+            var payloadArray = eventData.Payload.ToArray();
+
+            ProcessPayloadArray(payloadArray);
+
+            if (eventData.Message != null)
+            {
+                return string.Format(CultureInfo.InvariantCulture, eventData.Message, payloadArray);
+            }
+
+            var stringBuilder = new StringBuilder();
+            stringBuilder.Append(eventData.EventName);
+
+            for (int i = 0; i < eventData.PayloadNames.Count; i++)
+            {
+                stringBuilder.AppendLine();
+                stringBuilder.Append(eventData.PayloadNames[i]).Append(" = ").Append(payloadArray[i]);
+            }
+
+            return stringBuilder.ToString();
+        }
+
+        private static void ProcessPayloadArray(object[] payloadArray)
+        {
+            for (int i = 0; i < payloadArray.Length; i++)
+            {
+                payloadArray[i] = FormatValue(payloadArray[i]);
+            }
+        }
+
+        private static object FormatValue(object o)
+        {
+            if (o is byte[] bytes)
+            {
+                var stringBuilder = new StringBuilder();
+                foreach (byte b in bytes)
+                {
+                    stringBuilder.AppendFormat(CultureInfo.InvariantCulture, "{0:X2}", b);
+                }
+
+                return stringBuilder.ToString();
+            }
+
+            return o;
+        }
+    }
+}

sdk/core/Azure.Core/tests/AzureEventSourceListenerTests.cs

@@ -0,0 +1,99 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System;
+using System.Collections.Generic;
+using System.Diagnostics.Tracing;
+using System.Linq;
+using Azure.Core.Diagnostics;
+using Azure.Core.Testing;
+using NUnit.Framework;
+
+namespace Azure.Core.Tests
+{
+    [NonParallelizable]
+    public class AzureEventSourceListenerTests
+    {
+        [Test]
+        public void CallsCallbackWhenMessageIsLogged()
+        {
+            var invocations = new List<(EventWrittenEventArgs, string)>();
+            using var _ = new AzureEventSourceListener(
+                (args, s) =>
+                {
+                    invocations.Add((args, s));
+                }, EventLevel.Verbose);
+
+            HttpPipelineEventSource.Singleton.Request(new MockRequest());
+
+            Assert.AreEqual(1, invocations.Count);
+            var singleInvocation = invocations.Single();
+
+            Assert.AreEqual("Request", singleInvocation.Item1.EventName);
+            Assert.NotNull(singleInvocation.Item2);
+        }
+
+        [Test]
+        public void FormatsUsingMessageWhenAvailable()
+        {
+            (EventWrittenEventArgs e, string message) = ExpectSingleEvent(() => TestSource.Log.LogWithMessage("a message"));
+            Assert.AreEqual("Logging a message", message);
+        }
+
+        [Test]
+        public void FormatsByteArrays()
+        {
+            (EventWrittenEventArgs e, string message) = ExpectSingleEvent(() => TestSource.Log.LogWithByteArray(new byte[] { 0, 1, 233}));
+            Assert.AreEqual("Logging 0001E9", message);
+        }
+
+        [Test]
+        public void FormatsAsKeyValuesIfNoMessage()
+        {
+            (EventWrittenEventArgs e, string message) = ExpectSingleEvent(() => TestSource.Log.LogWithoutMessage("a message", 5));
+            Assert.AreEqual("LogWithoutMessage" + Environment.NewLine +
+                            "message = a message" + Environment.NewLine +
+                            "other = 5", message);
+        }
+
+        private static (EventWrittenEventArgs, string) ExpectSingleEvent(Action logDelegate)
+        {
+            var invocations = new List<(EventWrittenEventArgs, string)>();
+            using var _ = new AzureEventSourceListener(
+                (args, s) =>
+                {
+                    invocations.Add((args, s));
+                }, EventLevel.Verbose);
+            logDelegate();
+            Assert.AreEqual(1, invocations.Count);
+            return invocations.Single();
+        }
+
+        private class TestSource : EventSource
+        {
+            internal static TestSource Log { get; } = new TestSource();
+
+            private TestSource() : base("Test-source", EventSourceSettings.Default, "AzureEventSource", "true")
+            {
+            }
+
+            [Event(1, Message = "Logging {0}", Level = EventLevel.Critical)]
+            public void LogWithMessage(string message)
+            {
+                WriteEvent(1, message);
+            }
+
+            [Event(2, Level = EventLevel.Critical)]
+            public void LogWithoutMessage(string message, int other)
+            {
+                WriteEvent(2, message, other);
+            }
+
+            [Event(3, Message = "Logging {0}", Level = EventLevel.Critical)]
+            public void LogWithByteArray(byte[] b)
+            {
+                WriteEvent(3, b);
+            }
+        }
+    }
+}

sdk/core/Azure.Core/tests/EventSourceTests.cs

@@ -61,8 +61,8 @@ public void MatchesNameAndGuid()
 
             // Assert
             Assert.NotNull(eventSourceType);
-            Assert.AreEqual("AzureSDK", EventSource.GetName(eventSourceType));
-            Assert.AreEqual(Guid.Parse("1015ab6c-4cd8-53d6-aec3-9b937011fa95"), EventSource.GetGuid(eventSourceType));
+            Assert.AreEqual("Azure-Core", EventSource.GetName(eventSourceType));
+            Assert.AreEqual(Guid.Parse("44cbc7c6-6776-5f3c-36c1-75cd3ef19ea9"), EventSource.GetGuid(eventSourceType));
             Assert.IsNotEmpty(EventSource.GenerateManifest(eventSourceType, "assemblyPathToIncludeInManifest"));
         }