diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/System.Diagnostics.DiagnosticSource.sln b/src/libraries/System.Diagnostics.DiagnosticSource/System.Diagnostics.DiagnosticSource.sln index 4eee73d4ce..4307c7ae90 100644 --- a/src/libraries/System.Diagnostics.DiagnosticSource/System.Diagnostics.DiagnosticSource.sln +++ b/src/libraries/System.Diagnostics.DiagnosticSource/System.Diagnostics.DiagnosticSource.sln @@ -1,41 +1,50 @@ - Microsoft Visual Studio Solution File, Format Version 12.00 # Visual Studio 14 -VisualStudioVersion = 14.0.24720.0 +VisualStudioVersion = 14.0.25420.1 MinimumVisualStudioVersion = 10.0.40219.1 -Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "System.Diagnostics.DiagnosticSource.Tests", "tests\System.Diagnostics.DiagnosticSource.Tests.csproj", "{82B54697-0251-47A1-8546-FC507D0F3B08}" +Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "System.Diagnostics.DiagnosticSource.Tests", "tests\System.Diagnostics.DiagnosticSource.Tests.csproj", "{A7922FA3-306A-41B9-B8DC-CC4DBE685A85}" ProjectSection(ProjectDependencies) = postProject {F24D3391-2928-4E83-AADE-B34423498750} = {F24D3391-2928-4E83-AADE-B34423498750} EndProjectSection EndProject Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "System.Diagnostics.DiagnosticSource", "src\System.Diagnostics.DiagnosticSource.csproj", "{F24D3391-2928-4E83-AADE-B34423498750}" + ProjectSection(ProjectDependencies) = postProject + {3DF9A5D5-3D4B-4378-9B55-CFA6AC0114D9} = {3DF9A5D5-3D4B-4378-9B55-CFA6AC0114D9} + EndProjectSection +EndProject +Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "System.Diagnostics.DiagnosticSource", "ref\System.Diagnostics.DiagnosticSource.csproj", "{3DF9A5D5-3D4B-4378-9B55-CFA6AC0114D9}" +EndProject +Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "tests", "tests", "{1A2F9F4A-A032-433E-B914-ADD5992BB178}" +EndProject +Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "src", "src", "{E107E9C1-E893-4E87-987E-04EF0DCEAEFD}" +EndProject +Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "ref", "ref", "{2E666815-2EDB-464B-9DF6-380BF4789AD4}" EndProject Global GlobalSection(SolutionConfigurationPlatforms) = preSolution - DebugNETCoreAppnetstandard1.1netstandard1.3|AnyCPU = DebugNETCoreAppnetstandard1.1netstandard1.3|AnyCPU - ReleaseNETCoreAppnetstandard1.1netstandard1.3|AnyCPU = ReleaseNETCoreAppnetstandard1.1netstandard1.3|AnyCPU - DebugNETCoreAppnetstandard1.3netstandard1.3|AnyCPU = DebugNETCoreAppnetstandard1.3netstandard1.3|AnyCPU - ReleaseNETCoreAppnetstandard1.3netstandard1.3|AnyCPU = ReleaseNETCoreAppnetstandard1.3netstandard1.3|AnyCPU + Debug|Any CPU = Debug|Any CPU + Release|Any CPU = Release|Any CPU EndGlobalSection GlobalSection(ProjectConfigurationPlatforms) = postSolution - {82B54697-0251-47A1-8546-FC507D0F3B08}.DebugNETCoreAppnetstandard1.1netstandard1.3|AnyCPU.ActiveCfg = netstandard1.3-Debug|Any CPU - {82B54697-0251-47A1-8546-FC507D0F3B08}.DebugNETCoreAppnetstandard1.1netstandard1.3|AnyCPU.Build.0 = netstandard1.3-Debug|Any CPU - {82B54697-0251-47A1-8546-FC507D0F3B08}.ReleaseNETCoreAppnetstandard1.1netstandard1.3|AnyCPU.ActiveCfg = netstandard1.3-Release|Any CPU - {82B54697-0251-47A1-8546-FC507D0F3B08}.ReleaseNETCoreAppnetstandard1.1netstandard1.3|AnyCPU.Build.0 = netstandard1.3-Release|Any CPU - {82B54697-0251-47A1-8546-FC507D0F3B08}.DebugNETCoreAppnetstandard1.3netstandard1.3|AnyCPU.ActiveCfg = netstandard1.3-Debug|Any CPU - {82B54697-0251-47A1-8546-FC507D0F3B08}.DebugNETCoreAppnetstandard1.3netstandard1.3|AnyCPU.Build.0 = netstandard1.3-Debug|Any CPU - {82B54697-0251-47A1-8546-FC507D0F3B08}.ReleaseNETCoreAppnetstandard1.3netstandard1.3|AnyCPU.ActiveCfg = netstandard1.3-Release|Any CPU - {82B54697-0251-47A1-8546-FC507D0F3B08}.ReleaseNETCoreAppnetstandard1.3netstandard1.3|AnyCPU.Build.0 = netstandard1.3-Release|Any CPU - {F24D3391-2928-4E83-AADE-B34423498750}.DebugNETCoreAppnetstandard1.1netstandard1.3|AnyCPU.ActiveCfg = netstandard1.1-Debug|Any CPU - {F24D3391-2928-4E83-AADE-B34423498750}.DebugNETCoreAppnetstandard1.1netstandard1.3|AnyCPU.Build.0 = netstandard1.1-Debug|Any CPU - {F24D3391-2928-4E83-AADE-B34423498750}.ReleaseNETCoreAppnetstandard1.1netstandard1.3|AnyCPU.ActiveCfg = netstandard1.1-Release|Any CPU - {F24D3391-2928-4E83-AADE-B34423498750}.ReleaseNETCoreAppnetstandard1.1netstandard1.3|AnyCPU.Build.0 = netstandard1.1-Release|Any CPU - {F24D3391-2928-4E83-AADE-B34423498750}.DebugNETCoreAppnetstandard1.3netstandard1.3|AnyCPU.ActiveCfg = netstandard1.3-Debug|Any CPU - {F24D3391-2928-4E83-AADE-B34423498750}.DebugNETCoreAppnetstandard1.3netstandard1.3|AnyCPU.Build.0 = netstandard1.3-Debug|Any CPU - {F24D3391-2928-4E83-AADE-B34423498750}.ReleaseNETCoreAppnetstandard1.3netstandard1.3|AnyCPU.ActiveCfg = netstandard1.3-Release|Any CPU - {F24D3391-2928-4E83-AADE-B34423498750}.ReleaseNETCoreAppnetstandard1.3netstandard1.3|AnyCPU.Build.0 = netstandard1.3-Release|Any CPU + {A7922FA3-306A-41B9-B8DC-CC4DBE685A85}.Debug|Any CPU.ActiveCfg = netstandard-Debug|Any CPU + {A7922FA3-306A-41B9-B8DC-CC4DBE685A85}.Debug|Any CPU.Build.0 = netstandard-Debug|Any CPU + {A7922FA3-306A-41B9-B8DC-CC4DBE685A85}.Release|Any CPU.ActiveCfg = netstandard-Release|Any CPU + {A7922FA3-306A-41B9-B8DC-CC4DBE685A85}.Release|Any CPU.Build.0 = netstandard-Release|Any CPU + {F24D3391-2928-4E83-AADE-B34423498750}.Debug|Any CPU.ActiveCfg = netcoreapp-Debug|Any CPU + {F24D3391-2928-4E83-AADE-B34423498750}.Debug|Any CPU.Build.0 = netcoreapp-Debug|Any CPU + {F24D3391-2928-4E83-AADE-B34423498750}.Release|Any CPU.ActiveCfg = netcoreapp-Release|Any CPU + {F24D3391-2928-4E83-AADE-B34423498750}.Release|Any CPU.Build.0 = netcoreapp-Release|Any CPU + {3DF9A5D5-3D4B-4378-9B55-CFA6AC0114D9}.Debug|Any CPU.ActiveCfg = netstandard-Debug|Any CPU + {3DF9A5D5-3D4B-4378-9B55-CFA6AC0114D9}.Debug|Any CPU.Build.0 = netstandard-Debug|Any CPU + {3DF9A5D5-3D4B-4378-9B55-CFA6AC0114D9}.Release|Any CPU.ActiveCfg = netstandard-Release|Any CPU + {3DF9A5D5-3D4B-4378-9B55-CFA6AC0114D9}.Release|Any CPU.Build.0 = netstandard-Release|Any CPU EndGlobalSection GlobalSection(SolutionProperties) = preSolution HideSolutionNode = FALSE EndGlobalSection + GlobalSection(NestedProjects) = preSolution + {A7922FA3-306A-41B9-B8DC-CC4DBE685A85} = {1A2F9F4A-A032-433E-B914-ADD5992BB178} + {F24D3391-2928-4E83-AADE-B34423498750} = {E107E9C1-E893-4E87-987E-04EF0DCEAEFD} + {3DF9A5D5-3D4B-4378-9B55-CFA6AC0114D9} = {2E666815-2EDB-464B-9DF6-380BF4789AD4} + EndGlobalSection EndGlobal diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/dir.props b/src/libraries/System.Diagnostics.DiagnosticSource/dir.props index cfbc7971a2..7091ba2d80 100644 --- a/src/libraries/System.Diagnostics.DiagnosticSource/dir.props +++ b/src/libraries/System.Diagnostics.DiagnosticSource/dir.props @@ -4,5 +4,7 @@ 4.0.2.0 true + true + false \ No newline at end of file diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/ref/Configurations.props b/src/libraries/System.Diagnostics.DiagnosticSource/ref/Configurations.props new file mode 100644 index 0000000000..2af2d81f0a --- /dev/null +++ b/src/libraries/System.Diagnostics.DiagnosticSource/ref/Configurations.props @@ -0,0 +1,10 @@ + + + + + net45; + netstandard; + netstandard1.1; + + + \ No newline at end of file diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/ref/System.Diagnostics.DiagnosticSource.csproj b/src/libraries/System.Diagnostics.DiagnosticSource/ref/System.Diagnostics.DiagnosticSource.csproj index bfaf6957d5..7eb3d060fa 100644 --- a/src/libraries/System.Diagnostics.DiagnosticSource/ref/System.Diagnostics.DiagnosticSource.csproj +++ b/src/libraries/System.Diagnostics.DiagnosticSource/ref/System.Diagnostics.DiagnosticSource.csproj @@ -3,12 +3,20 @@ true + {3DF9A5D5-3D4B-4378-9B55-CFA6AC0114D9} + + + + + + - - + + + \ No newline at end of file diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/ref/System.Diagnostics.DiagnosticSourceActivity.cs b/src/libraries/System.Diagnostics.DiagnosticSource/ref/System.Diagnostics.DiagnosticSourceActivity.cs new file mode 100644 index 0000000000..ac8273cad4 --- /dev/null +++ b/src/libraries/System.Diagnostics.DiagnosticSource/ref/System.Diagnostics.DiagnosticSourceActivity.cs @@ -0,0 +1,34 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. +// ------------------------------------------------------------------------------ +// Changes to this file must follow the http://aka.ms/api-review process. +// ------------------------------------------------------------------------------ + +namespace System.Diagnostics { + public partial class Activity { + public Activity(string operationName) {} + public string OperationName { get { throw null; } } + public string Id {get { throw null; } private set {} } + public DateTime StartTimeUtc {get { throw null; } private set {} } + public Activity Parent {get { throw null; } private set {} } + public string ParentId {get { throw null; } private set {} } + public TimeSpan Duration {get { throw null; } private set {} } + public System.Collections.Generic.IEnumerable> Tags { get { throw null; } } + public System.Collections.Generic.IEnumerable> Baggage { get { throw null; } } + public string GetBaggageItem(string key) {throw null;} + public Activity AddTag(string key, string value) {throw null;} + public Activity AddBaggage(string key, string value) {throw null;} + public Activity SetParentId(string parentId) {throw null;} + public Activity SetStartTime(DateTime startTimeUtc) {throw null;} + public Activity SetEndTime(DateTime endTimeUtc) {throw null;} + public Activity Start() {throw null;} + public void Stop() {} + public static Activity Current {get { throw null; } private set {} } + } + public abstract partial class DiagnosticSource { + public Activity StartActivity(Activity activity, object args) {throw null;} + public void StopActivity(Activity activity, object args) {} + } +} + diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/src/ActivityUserGuide.md b/src/libraries/System.Diagnostics.DiagnosticSource/src/ActivityUserGuide.md new file mode 100644 index 0000000000..e768ccaf77 --- /dev/null +++ b/src/libraries/System.Diagnostics.DiagnosticSource/src/ActivityUserGuide.md @@ -0,0 +1,251 @@ +# Activity User Guide + +This document describes Activity, a class that allows storing and accessing diagnostics context and consuming it with logging system. + +This document provides Activity architecture [overview](#overview) and [usage](#activity-usage). + +# Overview +When application starts procesing an operation e.g. HTTP request or task from queue, it creates an `Activity` to track it through the system as the request is processed. Examples of context stored in `Activity` could be HTTP request path, method, user-agent, or correlation id: all the details important to be logged along with every trace. +When application calls external dependency to complete an operation, it may need to pass some of the context (e.g. correlation id) along with dependency call to be able to correlate logs from multiple services. + +`Activity` provides [Tags](#tags) to represent context which is needed for logging only and [Baggage](#baggage) to represent context which needs to be propagated to external dependencies. It has other properties described in [Activity Reference](#activity-reference). + +Every `Activity` has an `Id`, defining particular request in application, which is generated when Actvitity is started. + +`Activity` (except root one) has a [Parent](#parent) (in-process or external). E.g. application calls external dependency while processing incoming request, so there is an Activity for dependency call and it has Parent Activity representing incoming call. +External dependency Activity Id is passed along with the request, so the dependency may use it as ParentId for it's activities and thus allow unique mapping between child and parent calls. Parent is assigned when activity is started. + +Activities may be created and started/stopped by platform code or frameworks; applications need to be notified about activities events and need to have access to current activity being processed. +Therefore code which creates activity also writes corresponding event to `DiagnosticSource`: +- DO - create new `DiagnosticListener` for specific Activity type to allow filtering by activity. E.g Incoming and Outgoing Http Requests should be different DiagnosticListeners. Follow [DiagnosticSource User Guilde](https://github.com/dotnet/corefx/blob/master/src/System.Diagnostics.DiagnosticSource/src/DiagnosticSourceUsersGuide.md) to peek a name. +- DO - Guard Activity creation and start with call to `DiagnosticSource.IsEnabled` to avoid creating activities if no one listens to them and enable event name-based filtering or sampling. +- DO - Use `DiagnosticSource.StartActivity(Actvity)` and `DiagnosticSource.StopActivity(Actvity)` methods instead of Activity methods to ensure Activity events are always written to `DiagnosticSource`. +- DO - pass necessary context to `DiagnosticListener`, so application may enrich Activity. In case of HTTP incoming request, application needs `HttpContext` to add custom tags (method, path, user-agent, etc) +- CONSIDER - keeping baggage as small as possible +- DO NOT - add sensitive information to baggage, since it may be propagated out of the process boundaries +- DO - write activity [Id](#id) with every telemetry event, ParentId, Tags and Baggage should be written at least once per operation and could be found by Id. Note that tags and baggage could be changed through the lifetime of activity, and it makes sense to write them when activity stops. Duration should only be logged when activity stops. + +Current Activity is exposed as statis variable and flows with async calls so in every Start/Stop event callback it is accurate and may be used to log these events. + +Applications may access `Activity.Current` anywhere in the code to log events along with the context stored in Activity. +# Activity Usage +At the moment application writes log record, it can access `Activity.Current` to get all required details from it. + +## Creating Activities +```C# + Activity activity = new Activity("Http_In"); +``` +Activity can be created with operation name. This is an coarse name that is useful for grouping and filtering log records. + +After Activity is created you can add additional details: [Start time](#starttimeutc), [Tags](#tags) and [Baggage](#baggage) +```C# + activity.SetStartTime(GetHighPrecisionTimestamp()) + .AddTag("Path", request.Path) + .AddBaggage("CorrelationId", request.Headers["x-ms-correlation-id"]); +``` +When activity is built, it's time to start it and continue with request processing. + +## Starting and Stoping Activity + +Activity.Start() and Stop() methods maitain [Activity.Current](current) which flows with async calls and available during request processing. +When activity is started, it assigned with an [Id](id) and [Parent](parent). + +```C# + public void OnIncomingRequest(DiagnosticListener httpListener, HttpContext request) + { + if (httpListener.IsEnabled("Http_In")) + { + Activity activity = new Activity("Http_In"); + activity.SetStartTime(GetHighPrecisionTimestamp()) + //add tags, baggage, etc.. + activity.SetParentId(context.Request.headers["x-ms-request-id"]) + foreach (var header in context.Request.Headers) + if (header.Key.StartsWith("x-baggage-") + activity.AddBaggage(header.Key, header.Value); + + httpListener.StartActivity(activity, httpContext); + try { + //process request ... + } finally { + activity.SetEndTime(GetHighPrecisionTimestamp()); + //stop activity + httpListener.StopActivity(activity, highPrecisionStopTime); + } + } + } +``` +**Note** +- instead of Activity.Start() and Stop() methods, in above example we call `DiagnosticSource.StartActivity()` and `StopActivity()` methods that write events to DiagnosticSource. +- Activities creation is guarded with `DiagnosticSource.IsEnabled` and will only happen if someone listens to this `DiagnosticSource` thus eliminating any unnecessary performance impact. +- DateTime.UtcNow in practice is [precise to 16 milliseconds](https://blogs.msdn.microsoft.com/ericlippert/2010/04/08/precision-and-accuracy-of-datetime/). If you are interested in better preceision, call [SetStartTime](#setstarttime) and [SetEndTime](#setendtime) with high precesion timestamp, which you may achieve with combination of DateTime and Stopwatch + + +## Creating child Activities +When application calls external web-service, new activity is created to represent external operation. This activity may have Parent (if this request is part of incoming request processing), assigned to it during Start(). + +```C# + public void OnOutgoingRequest(DiagnosticListener httpListener, HttpRequestMessage request) + { + if (httpListener.IsEnabled(request.RequestUri.ToString())) + { + var activity = new Activity("Http_Out"); + httpListener.StartActivity(activity, request); + + request.Headers.Add("x-ms-request-id", activity.Id); + foreach (var baggage in activity.Baggage) + request.Headers.Add(baggage.Key, baggage.Value); + try { + //process request ... + } finally { + activity.SetEndTime(GetHighPrecisionTimestamp()); + //stop activity + httpListener.StopActivity(activity, value.Value, DateTimeStopwatch.GetTime(timestamp)); + } + } + } +``` + +New Activity will inherit Baggage from parent. Above example demonstrates how baggage could be propagated to downstream web-service in HTTP request headers. + +Similarly to incoming request processing, activity creation should be guarded with `DiagnosticSource.IsEnabled()` call, however allowing to filter headers injection based on request Uri. +Note that different DiagnosticSources should be used for incoming and outgoing HTTP activities allowing to implement separate filtering for events. + +## Listening to Activity Events +Application may listen to activity events and log them. It can access `Activity.Current` to get information about current activity. +This follows normal [DiagnosticListener conventions](https://github.com/dotnet/corefx/blob/master/src/System.Diagnostics.DiagnosticSource/src/DiagnosticSourceUsersGuide.md) + +Application may also add tags and baggage to current activity when processing Activity start callback. +Note in the [Incoming Request Sample](#starting-and-stoping-activity), we pass `HttpContext` to DiagnosticSource, so application may access request properties to enrich current activity. + +### Subscribe to DiagnosticSource +``` + DiagnosticListener.AllListeners.Subscribe(delegate (DiagnosticListener listener) + { + if (listener.Name == "MyActivitySource") + { + listener.Subscribe(delegate (KeyValuePair value) + { + if (value.Key.EndsWith("Start")) + LogActivityStart(); + else if (value.Key.EndsWith("Stop")) + LogActivityStop(); + }); + } + } +``` + +### Log Events + +``` + public void LogActivityStart() + { + var document = new Dictionary + { + ["Message"] = $"Activity {activity.OperationName} was started", + ["LogLevel"] = LogLevel.Info, + ["Id"] = activity.Id, + ["ParentId"] = activity.ParentId, + ["StartTime"] = activity.StartTimeUtc, + } + //log tags and baggage if needed + ...// send document to log storage + } + + public void LogActivityStop() + { + var document = new Dictionary + { + ["Message"] = $"Activity {activity.OperationName} is being stopped", + ["LogLevel"] = LogLevel.Info, + ["Id"] = activity.Id, + ["ParentId"] = activity.ParentId, + ["Duration"] = activity.Duration + }; + foreach (var kv in activity.Tags) + document[kv.Key] = kv.Value; + foreach (var kv in activity.Baggage) + document[kv.Key] = kv.Value; + ...// send document to log storage + } + + public void Log(LogLevel level, string message) + { + var document = new Dictionary + { + ["Message"] = message, + ["LogLevel"] = logLevel, + }; + + if (Activity.Current != null) + { + document["Id"] = activity.Id; + //add tags, baggage and ParentId if needed + } + ...// send document to log storage + } +``` + +It's crucial that Activity Id is logged along with every event. ParentId, Tags and Baggage must be logged at least once for every activity and may be logged with every telemetry event to simplify querying and aggregation. Duration is only available after SetEndTime is called and should be logged when Activity Stop event is received. + +# Reference +## Activity +### Tags +`IEnumerable> Tags { get; }` - Represents information to be logged along with activity. Good examples of tags are instance/machine name, incoming request HTTP method, path, user/user-agent, etc. Tags are **not passed** to the children of Activity. +Typical tag usage includes adding a few custom tags and enumeration through them to fill log event payload. Getting tag by it's key is not supported. + +### Baggage +`IEnumerable> Baggage { get; }` - Represents information to be logged woth activity AND passed to it's children. Examples of baggage include correlation id, sampling and feature flags. +Baggage is serialized and **passed it along with external dependency request**. +Typical Baggage usage includes adding a few baggage properties and enumeration through them to fill log event payload. + +### OperationName +`string OperationName { get; }` - Coarset name for an activity + +### StartTimeUtc +`DateTime StartTimeUtc { get; private set; }` - DateTime in UTC (Greenwitch Mean Time) when activity was started. DateTime.UtcNow if not specified + +### Duration +`TimeSpan Duration { get; private set; }` - Represent Activity duration if activity was stopped, TimeSpan.Zero otherwise + +### Id +`string Id { get; private set; }` - Represents particular activity identifier. Filtering to a particular Id insures that you get only log records related to specific request within the operation. It is assigned when activity is started. +Id is passed to external dependencies and considered as [ParentId](#parentid) for new external activity. + +### ParentId +`string ParentId { get; private set; }` - Activity may have either in-process [Parent](#parent) or Id of external Parent if it was deserialized from request. ParentId together with Id represent parent-child relationship in logs and allows to uniquely map outgoing and incoming requests. + +### Current +`static Activity Current { get; }` - Returns current Activity which flows across async calls + +### Parent +`Activity Parent { get; private set; }` - If activity was created from another activity in the same process, you can get that Activity with the Parent accessor. However this can be null if the Activity is root activity or parent is from outside the process. + +### Start() +`Activity Start()` - Starts Activity: sets Activity.Current and Parent for the activity. + +### Stop() +`void Stop()` - Stops Activity: sets Activity.Current and Duration for the activity. Uses timestamp provided in [SetEndTime](#setendtime) or DateTime.UtcNow. + +### AddBaggage() +`Activity AddBaggage(string key, string value)` - adds baggage item, see [Baggage](#baggage) + +### GetBaggageItem() +`string GetBaggageItem(string key)` - returns value of [Baggage](#baggage) key-value pair with given key, null if key does not exist + +### AddTag() +`Activity AddTag(string key, string value)` - adds tag, see [Tags](#tags) + +### SetParentId() +`Activity SetParentId(string key, string value)` - sets parent Id, see [ParentId](#parentid) + +### SetStartTime +`Activity SetStartTime(DateTime startTimeUtc)` - sets start time, see [StartTimeUtc](#starttimeutc) + +### SetEndTime +`Activity SetEndTime(DateTime endTimeUtc)` - sets [Duration](#duration) as a difference between endTimeUtc and [StartTimeUtc](#starttimeutc) + +##DiagnosticSource +### StartActivity +`static Activity StartActivity(Activity activity, object args)` - Starts activity and writes DiagnosticSource event message OperationName.Start with args payload +### StopActivity +`static Activity StopActivity(Activity activity, object args)` - Stops activity and writes DiagnosticSource event OperationName.Stop with args payload diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/src/Configurations.props b/src/libraries/System.Diagnostics.DiagnosticSource/src/Configurations.props index 69e325d440..d236034a26 100644 --- a/src/libraries/System.Diagnostics.DiagnosticSource/src/Configurations.props +++ b/src/libraries/System.Diagnostics.DiagnosticSource/src/Configurations.props @@ -2,8 +2,11 @@ + net45-Windows_NT; netstandard1.1; netstandard1.3; + netstandard; + netcoreapp; \ No newline at end of file diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/src/System.Diagnostics.DiagnosticSource.csproj b/src/libraries/System.Diagnostics.DiagnosticSource/src/System.Diagnostics.DiagnosticSource.csproj index 43febeae77..6f2a1fecad 100644 --- a/src/libraries/System.Diagnostics.DiagnosticSource/src/System.Diagnostics.DiagnosticSource.csproj +++ b/src/libraries/System.Diagnostics.DiagnosticSource/src/System.Diagnostics.DiagnosticSource.csproj @@ -1,13 +1,10 @@ - + {F24D3391-2928-4E83-AADE-B34423498750} - System.Diagnostics.DiagnosticSource - $(OutputPath)$(AssemblyName).xml + $(OutputPath)$(MSBuildProjectName).xml true - - netstandard1.3;net46 netstandard1.1;portable-net45+win8+wpa81 - + ;NO_EVENTSOURCE_COMPLEX_TYPE_SUPPORT - - - - + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + - + - + \ No newline at end of file diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Current.net45.cs b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Current.net45.cs new file mode 100644 index 0000000000..3a2a64d79e --- /dev/null +++ b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Current.net45.cs @@ -0,0 +1,32 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. + +using System.Runtime.Remoting.Messaging; +using System.Threading; + +namespace System.Diagnostics +{ + public partial class Activity + { + /// + /// Returns the current operation (Activity) for the current thread. This flows + /// across async calls. + /// + public static Activity Current + { + get + { + return (Activity)CallContext.LogicalGetData(FieldKey); + } + private set + { + CallContext.LogicalSetData(FieldKey, value); + } + } + + #region private + private static readonly string FieldKey = $"{typeof(Activity).FullName}.Value.{AppDomain.CurrentDomain.Id}"; + #endregion + } +} diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Current.net46.cs b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Current.net46.cs new file mode 100644 index 0000000000..58aeef813d --- /dev/null +++ b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Current.net46.cs @@ -0,0 +1,25 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. + +using System.Threading; + +namespace System.Diagnostics +{ + public partial class Activity + { + /// + /// Returns the current operation (Activity) for the current thread. This flows + /// across async calls. + /// + public static Activity Current + { + get { return s_current.Value; } + private set { s_current.Value = value; } + } + +#region private + private static readonly AsyncLocal s_current = new AsyncLocal(); +#endregion // private + } +} diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Id.MachineName.cs b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Id.MachineName.cs new file mode 100644 index 0000000000..b693ff2d22 --- /dev/null +++ b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Id.MachineName.cs @@ -0,0 +1,13 @@ +namespace System.Diagnostics +{ + public partial class Activity + { + #region private + private string generateUniquePrefix() + { + int uniqNum = (int)Stopwatch.GetTimestamp(); + return $"{s_rootIdPrefix}{Environment.MachineName}_{uniqNum:x}"; + } + #endregion + } +} diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Id.Random.cs b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Id.Random.cs new file mode 100644 index 0000000000..9b5a62c093 --- /dev/null +++ b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.Id.Random.cs @@ -0,0 +1,15 @@ +namespace System.Diagnostics +{ + public partial class Activity + { + #region private + private string generateUniquePrefix() + { + byte[] bytes = new byte[8]; + s_random.Value.NextBytes(bytes); + + return $"{s_rootIdPrefix}{BitConverter.ToUInt64(bytes, 0):x}"; + } + #endregion + } +} diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.cs b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.cs new file mode 100644 index 0000000000..cee254eb4b --- /dev/null +++ b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.cs @@ -0,0 +1,360 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. + +using System.Collections.Generic; +using System.Threading; + +namespace System.Diagnostics +{ + /// + /// Activity represents operation with context to be used for logging. + /// Activity has operation name, Id, start time and duration, tags and baggage. + /// + /// Current activity can be accessed with static AsyncLocal variable Activity.Current. + /// + /// Activities should be created with constructor, configured as necessarily + /// and then started with Activity.Start method which maintaines parent-child + /// relationships for the activities and sets Activity.Current. + /// + /// When activity is finished, it should be stopped with static Activity.Stop method. + /// + public partial class Activity + { + /// + /// An operation name is a COARSEST name that is useful grouping/filtering. + /// The name is typically a compile time constant. Names of Rest APIs are + /// reasonable, but arguments (e.g. specific accounts etc), should not be in + /// the name but rather in the tags. + /// + public string OperationName { get; } + + /// + /// This is an ID that is specific to a particular request. Filtering + /// to a particular ID insures that you get only one request that matches. + /// It is typically assigned the system itself. + /// + public string Id { get; private set; } + + /// + /// The time that operation started. Typcially when Start() is called + /// (but you can pass a value to Start() if necessary. This use UTC (Greenwitch Mean Time) + /// + public DateTime StartTimeUtc { get; private set; } + + /// + /// If the Activity that created this activity is from the same process you can get + /// that Activit with Parent. However this can be null if the Activity has no + /// parent (a root activity) or if the Parent is from outside the process. (see ParentId for more) + /// + public Activity Parent { get; private set; } + + /// + /// If the parent for this activity comes from outside the process, the activity + /// does not have a Parent Activity but MAY have a ParentId (which was serialized from + /// from the parent) . This accessor fetches the parent ID if it exists at all. + /// Note this can be null if this is a root Activity (it has no parent) + /// + public string ParentId { get; private set; } + + /// + /// Tags are string-string key-value pairs that represent information that will + /// be logged along with the Activity to the logging system. This information + /// however is NOT passed on to the children of this activity. (see Baggage) + /// + public IEnumerable> Tags + { + get + { + for (var tags = _tags; tags != null; tags = tags.Next) + yield return tags.keyValue; + } + } + + /// + /// Baggage is string-string key-value pairs that represent information that will + /// be passed along to children of this activity. Baggage is serialized + /// when requests leave the process (along with the ID). Typically Baggage is + /// used to do fine-grained control over logging of the activty and any children. + /// In general, if you are not using the data at runtime, you should be using Tags + /// instead. + /// + public IEnumerable> Baggage + { + get + { + for (var activity = this; activity != null; activity = activity.Parent) + for (var baggage = activity._baggage; baggage != null; baggage = baggage.Next) + yield return baggage.keyValue; + } + } + + /// + /// Returns the value of the key-value pair added to the activity with 'WithBaggage'. + /// Returns null if that key does not exist. + /// + public string GetBaggageItem(string key) + { + foreach (var keyValue in Baggage) + if (key == keyValue.Key) + return keyValue.Value; + return null; + } + + /* Constructors Builder methods */ + + /// + /// Note that Activity has a 'builder' pattern, where you call the constructor, a number of 'With*' APIs and then + /// call 'Activity.Start' to build the activity. You MUST call Start before using it + /// + /// Operations name + public Activity(string operationName) + { + if (string.IsNullOrEmpty(operationName)) + throw new ArgumentException($"{nameof(operationName)} must not be null or empty"); + OperationName = operationName; + } + + /// + /// Update the Activity to have a tag with an additional 'key' and value 'value'. + /// This shows up in the 'Tags' eumeration. It is meant for information that + /// is useful to log but not needed for runtime control (for the latter, use Baggage) + /// + /// 'this' for convinient chaining + public Activity AddTag(string key, string value) + { + _tags = new KeyValueListNode() { keyValue = new KeyValuePair(key, value), Next = _tags }; + return this; + } + + /// + /// Update the Activity to have baggage with an additional 'key' and value 'value'. + /// This shows up in the 'Baggage' eumeration as well as the 'GetBaggageItem' API. + /// Baggage is mean for information that is needed for runtime control. For information + /// that is simply useful to show up in the log with the activity use Tags. + /// Returns 'this' for convinient chaining. + /// + /// 'this' for convinient chaining + public Activity AddBaggage(string key, string value) + { + _baggage = new KeyValueListNode() { keyValue = new KeyValuePair(key, value), Next = _baggage }; + return this; + } + + /// + /// Updates the Activity To indicate that the activity with ID 'parentID' + /// caused this activity. This is only intended to be used at 'boundary' + /// scenarios where an activity from another process loggically started + /// this activity. The Parent ID shows up the Tags (as well as the ParentID + /// property), and can be used to reconstruct the causal tree. + /// Returns 'this' for convinient chaining. + /// + public Activity SetParentId(string parentId) + { + if (Parent != null) + throw new InvalidOperationException( + $"Trying to set {nameof(ParentId)} on activity which has {nameof(Parent)}"); + + if (ParentId != null) + throw new InvalidOperationException( + $"{nameof(ParentId)} is already set"); + + if (string.IsNullOrEmpty(parentId)) + throw new ArgumentException($"{nameof(parentId)} must not be null or empty"); + + ParentId = parentId; + return this; + } + + /// + /// Update the Activity to set start time + /// + /// Activity start time in UTC (Greenwitch Mean Time) + /// 'this' for convinient chaining + public Activity SetStartTime(DateTime startTimeUtc) + { + if (startTimeUtc.Kind != DateTimeKind.Utc) + throw new InvalidOperationException($"{nameof(startTimeUtc)} is not UTC"); + StartTimeUtc = startTimeUtc; + return this; + } + /// + /// Update the Activity to set + /// as a difference between + /// and given stop timestamp + /// + /// Activity stop time in UTC (Greenwitch Mean Time) + /// 'this' for convinient chaining + public Activity SetEndTime(DateTime endTimeUtc) + { + if (endTimeUtc.Kind != DateTimeKind.Utc) + throw new InvalidOperationException($"{nameof(endTimeUtc)} is not UTC"); + + Duration = endTimeUtc - StartTimeUtc; + return this; + } + + /// + /// If the Activity has ended (Stop was called) then this is the delta + /// between start and end. If the activity is not ended then this is + /// TimeSpan.Zero. + /// + public TimeSpan Duration { get; private set; } + + /// + /// Starts activity: sets to hold and sets Current to this Activity. + /// If was not set previously, sets it to DateTime.UtcNow. + /// Use DiagnosticSource.Start to start activity and write start event. + /// + /// Started activity for convinient chaining + /// + /// + public Activity Start() + { + if (Id != null) + throw new InvalidOperationException("Trying to start an Activity that was already started"); + + if (ParentId == null) + { + var parent = Current; + if (parent != null) + { + ParentId = parent.Id; + Parent = parent; + } + } + + if (StartTimeUtc == default(DateTime)) + StartTimeUtc = DateTime.UtcNow; + + Id = GenerateId(); + + Current = this; + return this; + } + + /// + /// Stops activity: sets Current to Parent. + /// If end time was not set previously, sets as a difference between DateTime.UtcNow and + /// Use DiagnosticSource.Stop to stop activity and write stop event. + /// + /// + /// + public void Stop() + { + if (Id == null) + throw new InvalidOperationException("Trying to stop an Activity that was not started"); + + if (!isFinished) + { + isFinished = true; + + if (Duration == TimeSpan.Zero) + SetEndTime(DateTime.UtcNow); + + Current = Parent; + } + } + + #region private + + private string GenerateId() + { + string ret; + if (Parent != null) + { + // Normal start within the process + Debug.Assert(!string.IsNullOrEmpty(Parent.Id)); + ret = appendSuffix(Parent.Id, Interlocked.Increment(ref Parent._currentChildId).ToString()); + } + else if (ParentId != null) + { + // Start from outside the process (e.g. incoming HTTP) + Debug.Assert(ParentId.Length != 0); + ret = appendSuffix(ParentId, "I_" + Interlocked.Increment(ref s_currentRootId)); + } + else + { + // A Root Activity (no parent). + ret = generateRootId(); + } + // Useful place to place a conditional breakpoint. + return ret; + } + + + private string appendSuffix(string parentId, string suffix) + { +#if DEBUG + suffix = OperationName + "_" + suffix; +#endif + if (parentId.Length + suffix.Length <= 127) + return parentId + s_idDelimiter + suffix; + + //Id overflow: + //find position in RequestId to trim + int trimPosition = parentId.Length - 1; + while (trimPosition > 0) + { + if ((parentId[trimPosition] == s_idDelimiter || parentId[trimPosition] == s_overflowDelimiter) + && trimPosition <= 119) //overflow suffix length is 8 + 1 for #. + break; + trimPosition--; + } + + //ParentId is not valid Request-Id, let's generate proper one. + if (trimPosition == 0) + return generateRootId(); + + //generate overflow suffix + byte[] bytes = new byte[4]; + s_random.Value.NextBytes(bytes); + + return parentId.Substring(0, trimPosition) + + s_overflowDelimiter + + BitConverter.ToUInt32(bytes, 0).ToString("x8"); + } + + private string generateRootId() + { + if (s_uniqPrefix == null) + { + // Here we make an ID to represent the Process/AppDomain. Ideally we use process ID but + // it is unclear if we have that ID handy. Currently we use low bits of high freq tick + // as a unique random number (which is not bad, but loses randomness for startup scenarios). + Interlocked.CompareExchange(ref s_uniqPrefix, generateUniquePrefix(), null); + } + +#if DEBUG + string ret = s_uniqPrefix + OperationName + s_idDelimiter + Interlocked.Increment(ref s_currentRootId); +#else // To keep things short, we drop the operation name + string ret = s_uniqPrefix + s_idDelimiter + Interlocked.Increment(ref s_currentRootId); +#endif + return ret; + } + + // Used to generate an ID + private int _currentChildId; // A unique number for all children of this activity. + private static int s_currentRootId; // A unique number inside the appdomain. + private static string s_uniqPrefix; + + private static char s_idDelimiter = '.'; + private static char s_overflowDelimiter = '#'; + private static char s_rootIdPrefix = '/'; + + private static readonly Lazy s_random = new Lazy(); + /// + /// Having our own key-value linked list allows us to be more efficient + /// + private class KeyValueListNode + { + public KeyValuePair keyValue; + public KeyValueListNode Next; + } + + private KeyValueListNode _tags; + private KeyValueListNode _baggage; + private bool isFinished; +#endregion // private + } +} diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/DiagnosticSource.cs b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/DiagnosticSource.cs index 4e4346bb97..d7e25c628e 100644 --- a/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/DiagnosticSource.cs +++ b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/DiagnosticSource.cs @@ -14,7 +14,7 @@ namespace System.Diagnostics /// https://github.com/dotnet/corefx/blob/master/src/System.Diagnostics.DiagnosticSource/src/DiagnosticSourceUsersGuide.md /// for instructions on its use. /// - public abstract class DiagnosticSource + public abstract partial class DiagnosticSource { /// /// Write is a generic way of logging complex payloads. Each notification diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/DiagnosticSourceActivity.cs b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/DiagnosticSourceActivity.cs new file mode 100644 index 0000000000..8ad372c81a --- /dev/null +++ b/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/DiagnosticSourceActivity.cs @@ -0,0 +1,45 @@ +namespace System.Diagnostics +{ + public abstract partial class DiagnosticSource + { + /// + /// Starts an Activity and writes start event. + /// + /// Activity describes logical operation, its context and parent relation; + /// Current activity flows through the operation processing. + /// + /// This method starts given Activity (maintains global Current Activity + /// and Parent for the given activity) and notifies consumers that new Activity + /// was started. Consumers could access + /// to add context and/or augument telemetry. + /// + /// Producers may pass additional details to the consumer in the payload. + /// + /// Activity to be started + /// An object that represent the value being passed as a payload for the event. + /// Started Activity for convenient chaining + /// + public Activity StartActivity(Activity activity, object args) + { + activity.Start(); + Write(activity.OperationName + ".Start", args); + return activity; + } + + /// + /// Stops given Activity: maintains global Current Activity and notifies consumers + /// that Activity was stopped. Consumers could access + /// to add context and/or augument telemetry. + /// + /// Producers may pass additional details to the consumer in the payload. + /// + /// Activity to be stoped + /// An object that represent the value being passed as a payload for the event. + /// + public void StopActivity(Activity activity, object args) + { + Write(activity.OperationName + ".Stop", args); + activity.Stop(); + } + } +} diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/tests/ActivityTests.cs b/src/libraries/System.Diagnostics.DiagnosticSource/tests/ActivityTests.cs new file mode 100644 index 0000000000..6e02480de7 --- /dev/null +++ b/src/libraries/System.Diagnostics.DiagnosticSource/tests/ActivityTests.cs @@ -0,0 +1,364 @@ +using System.Collections.Generic; +using System.Linq; +using System.Text; +using System.Threading.Tasks; +using Xunit; + +namespace System.Diagnostics.Tests +{ + public class ActivityTests + { + /// + /// Tests Activity constructor + /// + [Fact] + public void DefaultActivity() + { + string activityName = "activity"; + var activity = new Activity(activityName); + Assert.Equal(activityName, activity.OperationName); + Assert.Null(activity.Id); + Assert.Equal(TimeSpan.Zero, activity.Duration); + Assert.Null(activity.Parent); + Assert.Null(activity.ParentId); + Assert.Equal(0, activity.Baggage.ToList().Count); + Assert.Equal(0, activity.Tags.ToList().Count); + } + + /// + /// Tests baggage operations + /// + [Fact] + public void Baggage() + { + var activity = new Activity("activity"); + Assert.Null(activity.GetBaggageItem("some baggage")); + + Assert.Equal(activity, activity.AddBaggage("some baggage", "value")); + Assert.Equal("value", activity.GetBaggageItem("some baggage")); + + var baggage = activity.Baggage.ToList(); + Assert.Equal(1, baggage.Count); + } + + /// + /// Tests Tags operations + /// + [Fact] + public void Tags() + { + var activity = new Activity("activity"); + + Assert.Equal(activity, activity.AddTag("some tag", "value")); + + var tags = activity.Tags.ToList(); + Assert.Equal(1, tags.Count); + Assert.Equal(tags[0].Key, "some tag"); + Assert.Equal(tags[0].Value, "value"); + } + + /// + /// Tests activity SetParentId + /// + [Fact] + public void SetParentId() + { + var parent = new Activity("parent"); + Assert.Throws(() => parent.SetParentId(null)); + Assert.Throws(() => parent.SetParentId("")); + parent.SetParentId("1"); + Assert.Equal("1", parent.ParentId); + Assert.Throws(() => parent.SetParentId("2")); + + parent.Start(); + var child = new Activity("child"); + child.Start(); + Assert.Throws(() => child.SetParentId("3")); + } + + /// + /// Tests activity SetParentId + /// + [Fact] + public void ActivityIdOverflow() + { + //check parentId /abc.1.1...1.1.1.1.1 (126 bytes) and check last .1.1.1.1 is replaced with #overflow_suffix 8 bytes long + var parentId = new StringBuilder("/abc"); + while (parentId.Length < 126) + parentId.Append(".1"); + + var activity = new Activity("activity") + .SetParentId(parentId.ToString()) + .Start(); + + Assert.Equal( + parentId.ToString().Substring(0, parentId.Length - 8), + activity.Id.Substring(0, activity.Id.Length - 9)); + Assert.Equal('#', activity.Id[activity.Id.Length - 9]); + + //check parentId /abc.1.1...1.012345678 (128 bytes) and check last .012345678 is replaced with #overflow_suffix 8 bytes long + parentId = new StringBuilder("/abc"); + while (parentId.Length < 118) + parentId.Append(".1"); + parentId.Append(".012345678"); + + activity = new Activity("activity") + .SetParentId(parentId.ToString()) + .Start(); + + //last .012345678 will be replaced with #overflow_suffix 8 bytes long + Assert.Equal( + parentId.ToString().Substring(0, parentId.Length - 10), + activity.Id.Substring(0, activity.Id.Length - 9)); + Assert.Equal('#', activity.Id[activity.Id.Length - 9]); + } + + /// + /// Tests activity start and stop + /// Checks Activity.Current correctness, Id generation + /// + [Fact] + public void StartStop() + { + var activity = new Activity("activity"); + Assert.Equal(null, Activity.Current); + activity.Start(); + Assert.Equal(activity, Activity.Current); + Assert.Null(activity.Parent); + Assert.NotNull(activity.Id); + Assert.NotEqual(default(DateTime), activity.StartTimeUtc); + + activity.Stop(); + Assert.Equal(null, Activity.Current); + } + + /// + /// Tests Id generation + /// + [Fact] + public void IdGenerationInternalParent() + { + var parent = new Activity("parent"); + parent.Start(); + var child1 = new Activity("child1"); + var child2 = new Activity("child2"); + //start 2 children in different execution contexts + var t1 = Task.Run(() => child1.Start()); + var t2 = Task.Run(() => child2.Start()); + Task.WhenAll(t1, t2).Wait(); +#if DEBUG + Assert.Equal($"{parent.Id}.{child1.OperationName}_1", child1.Id); + Assert.Equal($"{parent.Id}.{child2.OperationName}_2", child2.Id); +#else + Assert.Equal(parent.Id + ".1", child1.Id); + Assert.Equal(parent.Id + ".2", child2.Id); +#endif + child1.Stop(); + child2.Stop(); + var child3 = new Activity("child3"); + child3.Start(); +#if DEBUG + Assert.Equal($"{parent.Id}.{child3.OperationName}_3", child3.Id); +#else + Assert.Equal(parent.Id + ".3", child3.Id); +#endif + } + + /// + /// Tests Id generation + /// + [Fact] + public void IdGenerationExternalParentId() + { + var child1 = new Activity("child1"); + child1.SetParentId("123"); + child1.Start(); + child1.Stop(); + var child2 = new Activity("child2"); + child2.SetParentId("123"); + child2.Start(); + Assert.NotEqual(child2.Id, child1.Id); + } + + /// + /// Tests Activity Start and Stop with timestamp + /// + [Fact] + public void StartStopWithTimestamp() + { + var activity = new Activity("activity"); + Assert.Throws(() => activity.SetStartTime(DateTime.Now)); + + var startTime = DateTime.UtcNow.AddSeconds(-1); + activity.SetStartTime(startTime); + + activity.Start(); + Assert.Equal(startTime, activity.StartTimeUtc); + + Assert.Throws(() => activity.SetEndTime(DateTime.Now)); + var stopTime = DateTime.UtcNow; + activity.SetEndTime(stopTime); + Assert.Equal(stopTime - startTime, activity.Duration); + } + + /// + /// Tests Activity Stop without timestamp + /// + [Fact] + public void StopWithoutTimestamp() + { + var startTime = DateTime.UtcNow.AddSeconds(-1); + var activity = new Activity("activity") + .SetStartTime(startTime); + + activity.Start(); + Assert.Equal(startTime, activity.StartTimeUtc); + + activity.Stop(); + Assert.True(activity.Duration.TotalSeconds >= 1); + } + + /// + /// Tests Activity stack: creates a parent activity and child activity + /// Verifies + /// - Activity.Parent and ParentId corectness + /// - Baggage propagated from parent + /// - Tags are not propagated + /// Stops child and checks Activity,Current is set to parent + /// + [Fact] + public void ParentChild() + { + var parent = new Activity("parent") + .AddBaggage("id1", "baggage from parent") + .AddTag("tag1", "tag from parent"); + + parent.Start(); + + Assert.Equal(parent, Activity.Current); + + var child = new Activity("child"); + child.Start(); + Assert.Equal(parent, child.Parent); + Assert.Equal(parent.Id, child.ParentId); + + //baggage from parent + Assert.Equal("baggage from parent", child.GetBaggageItem("id1")); + + //no tags from parent + var childTags = child.Tags.ToList(); + Assert.Equal(0, childTags.Count); + + child.Stop(); + Assert.Equal(parent, Activity.Current); + + parent.Stop(); + Assert.Equal(null, Activity.Current); + } + + /// + /// Tests wrong stop order, when parent is stopped before child + /// + [Fact] + public void StopParent() + { + var parent = new Activity("parent"); + parent.Start(); + var child = new Activity("child"); + child.Start(); + + parent.Stop(); + Assert.Equal(null, Activity.Current); + } + + /// + /// Tests that activity can not be stated twice + /// + [Fact] + public void StartTwice() + { + var activity = new Activity("activity"); + activity.Start(); + Assert.Throws(() => activity.Start()); + } + + /// + /// Tests that activity that has not been started can not be stopped + /// + [Fact] + public void StopNotStarted() + { + Assert.Throws(() => new Activity("activity").Stop()); + } + + /// + /// Tests that second activity stop does not update Activity.Current + /// + [Fact] + public void StopTwice() + { + var parent = new Activity("parent"); + parent.Start(); + + var child1 = new Activity("child1"); + child1.Start(); + child1.Stop(); + + var child2 = new Activity("child2"); + child2.Start(); + + child1.Stop(); + + Assert.Equal(child2, Activity.Current); + } + + [Fact] + public void DiagnosticSourceStartStop() + { + using (DiagnosticListener listener = new DiagnosticListener("Testing")) + { + DiagnosticSource source = listener; + var observer = new TestObserver(); + + using (listener.Subscribe(observer)) + { + var arguments = new { args = "arguments" }; + + var activity = new Activity("activity"); + + source.StartActivity(activity, arguments); + Assert.Equal(activity.OperationName + ".Start", observer.EventName); + Assert.Equal(arguments, observer.EventObject); + + observer.Reset(); + + source.StopActivity(activity, arguments); + Assert.Equal(activity.OperationName + ".Stop", observer.EventName); + Assert.Equal(arguments, observer.EventObject); + } + } + } + + private class TestObserver : IObserver> + { + public string EventName { get; private set; } + public object EventObject { get; private set; } + + public void OnNext(KeyValuePair value) + { + EventName = value.Key; + EventObject = value.Value; + } + + public void Reset() + { + EventName = null; + EventObject = null; + } + + public void OnCompleted() { } + + public void OnError(Exception error) { } + } + } +} diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/tests/Configurations.props b/src/libraries/System.Diagnostics.DiagnosticSource/tests/Configurations.props index c3266e1e93..e87ef9f56b 100644 --- a/src/libraries/System.Diagnostics.DiagnosticSource/tests/Configurations.props +++ b/src/libraries/System.Diagnostics.DiagnosticSource/tests/Configurations.props @@ -2,7 +2,11 @@ + net45-Windows_NT; + netstandard1.1; netstandard1.3; + netstandard1.5; + netstandard; \ No newline at end of file diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/tests/DiagnosticSourceEventSourceBridgeTests.cs b/src/libraries/System.Diagnostics.DiagnosticSource/tests/DiagnosticSourceEventSourceBridgeTests.cs index d0e0c39f2b..a34e197b35 100644 --- a/src/libraries/System.Diagnostics.DiagnosticSource/tests/DiagnosticSourceEventSourceBridgeTests.cs +++ b/src/libraries/System.Diagnostics.DiagnosticSource/tests/DiagnosticSourceEventSourceBridgeTests.cs @@ -2,10 +2,8 @@ // The .NET Foundation licenses this file to you under the MIT license. // See the LICENSE file in the project root for more information. -using System; using System.Collections.Generic; using Xunit; -using System.Threading.Tasks; using System.Diagnostics.Tracing; using System.Text; @@ -16,6 +14,8 @@ namespace System.Diagnostics.Tests { + //Complex types are not supported on EventSource for .NET 4.5 + [SkipOnTargetFramework(TargetFrameworkMonikers.NetFramework45)] public class DiagnosticSourceEventSourceBridgeTests { /// @@ -657,7 +657,7 @@ public TestDiagnosticSourceEventListener() // Here just for debugging. Lets you see the last 3 events that were sent. public DiagnosticSourceEvent SecondLast; public DiagnosticSourceEvent ThirdLast; -#endif +#endif /// /// Sets the EventCount to 0 and LastEvent to null @@ -666,7 +666,7 @@ public void ResetEventCountAndLastEvent() { EventCount = 0; LastEvent = null; -#if DEBUG +#if DEBUG SecondLast = null; ThirdLast = null; #endif @@ -677,7 +677,7 @@ public void ResetEventCountAndLastEvent() /// public Predicate Filter; - #region private +#region private private void UpdateLastEvent(DiagnosticSourceEvent anEvent) { if (Filter != null && !Filter(anEvent)) @@ -691,7 +691,7 @@ private void UpdateLastEvent(DiagnosticSourceEvent anEvent) EventCount++; LastEvent = anEvent; } - #endregion +#endregion } /// @@ -826,4 +826,4 @@ protected override void OnEventSourceCreated(EventSource eventSource) EventSource _diagnosticSourceEventSource; #endregion } -} +} \ No newline at end of file diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/tests/System.Diagnostics.DiagnosticSource.Tests.builds b/src/libraries/System.Diagnostics.DiagnosticSource/tests/System.Diagnostics.DiagnosticSource.Tests.builds index 216a65acfa..fa10042e93 100644 --- a/src/libraries/System.Diagnostics.DiagnosticSource/tests/System.Diagnostics.DiagnosticSource.Tests.builds +++ b/src/libraries/System.Diagnostics.DiagnosticSource/tests/System.Diagnostics.DiagnosticSource.Tests.builds @@ -7,6 +7,10 @@ Windows_NT netcore50;net46 + + Windows_NT + net45 + \ No newline at end of file diff --git a/src/libraries/System.Diagnostics.DiagnosticSource/tests/System.Diagnostics.DiagnosticSource.Tests.csproj b/src/libraries/System.Diagnostics.DiagnosticSource/tests/System.Diagnostics.DiagnosticSource.Tests.csproj index 38073e58ee..e457319324 100644 --- a/src/libraries/System.Diagnostics.DiagnosticSource/tests/System.Diagnostics.DiagnosticSource.Tests.csproj +++ b/src/libraries/System.Diagnostics.DiagnosticSource/tests/System.Diagnostics.DiagnosticSource.Tests.csproj @@ -1,14 +1,22 @@ - + - {82B54697-0251-47A1-8546-FC507D0F3B08} + {A7922FA3-306A-41B9-B8DC-CC4DBE685A85} - - + + + + + + + + + + - + \ No newline at end of file