|
| 1 | +--- |
| 2 | +title: Collect a distributed trace - .NET |
| 3 | +description: A tutorial to collect distributed traces in .NET applications |
| 4 | +ms.topic: tutorial |
| 5 | +ms.date: 03/14/2021 |
| 6 | +--- |
| 7 | + |
| 8 | +# Collect a distributed trace |
| 9 | + |
| 10 | +**This article applies to: ✔️** .NET Core 5.0 and later versions **or** any .NET application using the |
| 11 | +[DiagnosticSource NuGet package](https://www.nuget.org/packages/System.Diagnostics.DiagnosticSource/5.0.1) version 5 or later |
| 12 | + |
| 13 | +.NET applications can be instrumented using the <xref:System.Diagnostics.Activity?displayProperty=nameWithType> API to produce |
| 14 | +distributed tracing telemetry. In this tutorial you will record this instrumented telemetry with different telemetry collection |
| 15 | +libraries so that it is available to diagnose application issues. See |
| 16 | +[the instrumentation tutorial](distributed-tracing-instrumentation-walkthroughs.md) if you need to add new instrumentation. |
| 17 | + |
| 18 | +## Collect using OpenTelemetry |
| 19 | + |
| 20 | +### Prerequisites |
| 21 | + |
| 22 | +- [.NET Core 3.1 SDK](https://dotnet.microsoft.com/download/dotnet) or a later version |
| 23 | + |
| 24 | +### Create an example application |
| 25 | + |
| 26 | +First you will create an example application that has some distributed trace instrumentation but nothing is being collected. |
| 27 | + |
| 28 | +```dotnetcli |
| 29 | +dotnet new console |
| 30 | +``` |
| 31 | + |
| 32 | +Applications that target .NET 5 and later already have the necessary distributed tracing APIs included. For apps targeting older |
| 33 | +.NET versions add the [System.Diagnostics.DiagnosticSource NuGet package](https://www.nuget.org/packages/System.Diagnostics.DiagnosticSource/) |
| 34 | +version 5.0.1 or greater. |
| 35 | +```dotnetcli |
| 36 | +dotnet add package System.Diagnostics.DiagnosticSource --version 5.0.1 |
| 37 | +``` |
| 38 | + |
| 39 | +Replace the contents of the generated Program.cs with this example source: |
| 40 | +```C# |
| 41 | +using System; |
| 42 | +using System.Diagnostics; |
| 43 | +using System.Net.Http; |
| 44 | +using System.Threading.Tasks; |
| 45 | + |
| 46 | +namespace Sample.DistributedTracing |
| 47 | +{ |
| 48 | + class Program |
| 49 | + { |
| 50 | + static ActivitySource s_source = new ActivitySource("Sample.DistributedTracing"); |
| 51 | + |
| 52 | + static async Task Main(string[] args) |
| 53 | + { |
| 54 | + await DoSomeWork(); |
| 55 | + Console.WriteLine("Example work done"); |
| 56 | + } |
| 57 | + |
| 58 | + static async Task DoSomeWork() |
| 59 | + { |
| 60 | + using (Activity a = s_source.StartActivity("SomeWork")) |
| 61 | + { |
| 62 | + await StepOne(); |
| 63 | + await StepTwo(); |
| 64 | + } |
| 65 | + } |
| 66 | + |
| 67 | + static async Task StepOne() |
| 68 | + { |
| 69 | + using (Activity a = s_source.StartActivity("StepOne")) |
| 70 | + { |
| 71 | + await Task.Delay(500); |
| 72 | + } |
| 73 | + } |
| 74 | + |
| 75 | + static async Task StepTwo() |
| 76 | + { |
| 77 | + using (Activity a = s_source.StartActivity("StepTwo")) |
| 78 | + { |
| 79 | + await Task.Delay(1000); |
| 80 | + } |
| 81 | + } |
| 82 | + } |
| 83 | +} |
| 84 | +``` |
| 85 | + |
| 86 | +Running the app does not log anything yet |
| 87 | +```dotnetcli |
| 88 | +> dotnet run |
| 89 | +Example work done |
| 90 | +``` |
| 91 | + |
| 92 | +### Add logging using OpenTelemetry |
| 93 | + |
| 94 | +Add the [OpenTelemetry](https://www.nuget.org/packages/OpenTelemetry/) and |
| 95 | +[OpenTelemetry.Exporter.Console](https://www.nuget.org/packages/OpenTelemetry.Exporter.Console/) NuGet packages. |
| 96 | + |
| 97 | +```dotnetcli |
| 98 | +dotnet add package OpenTelemetry |
| 99 | +dotnet add package OpenTelemetry.Exporter.Console |
| 100 | +``` |
| 101 | + |
| 102 | +Update Program.cs with additional using statments: |
| 103 | +```C# |
| 104 | +using OpenTelemetry; |
| 105 | +using OpenTelemetry.Trace; |
| 106 | +using System; |
| 107 | +using System.Diagnostics; |
| 108 | +using System.Threading.Tasks; |
| 109 | +``` |
| 110 | + |
| 111 | +And update Main() to create the OpenTelemetry TracerProvider: |
| 112 | +```C# |
| 113 | + public static async Task Main() |
| 114 | + { |
| 115 | + using var tracerProvider = Sdk.CreateTracerProviderBuilder() |
| 116 | + .SetSampler(new AlwaysOnSampler()) |
| 117 | + // Add more libraries |
| 118 | + .AddSource("Sample.DistributedTracing") |
| 119 | + // Add more exporters |
| 120 | + .AddConsoleExporter() |
| 121 | + .Build(); |
| 122 | + |
| 123 | + await DoSomeWork(); |
| 124 | + Console.WriteLine("Example work done"); |
| 125 | + } |
| 126 | +``` |
| 127 | + |
| 128 | +Now the app logs distributed trace information to the console: |
| 129 | +```dotnetcli |
| 130 | +> dotnet run |
| 131 | +Activity.Id: 00-35c0e68b0dac3c49be08a9d9cab32579-0b7477e11aa20d40-01 |
| 132 | +Activity.ParentId: 00-35c0e68b0dac3c49be08a9d9cab32579-d95f666d24193f40-01 |
| 133 | +Activity.DisplayName: StepOne |
| 134 | +Activity.Kind: Internal |
| 135 | +Activity.StartTime: 2021-03-15T01:58:10.7661575Z |
| 136 | +Activity.Duration: 00:00:00.5013965 |
| 137 | +Resource associated with Activity: |
| 138 | + service.name: unknown_service:temp |
| 139 | +
|
| 140 | +Activity.Id: 00-35c0e68b0dac3c49be08a9d9cab32579-7ba0fc6d480c9841-01 |
| 141 | +Activity.ParentId: 00-35c0e68b0dac3c49be08a9d9cab32579-d95f666d24193f40-01 |
| 142 | +Activity.DisplayName: StepTwo |
| 143 | +Activity.Kind: Internal |
| 144 | +Activity.StartTime: 2021-03-15T01:58:11.2894853Z |
| 145 | +Activity.Duration: 00:00:01.0188689 |
| 146 | +Resource associated with Activity: |
| 147 | + service.name: unknown_service:temp |
| 148 | +
|
| 149 | +Activity.Id: 00-35c0e68b0dac3c49be08a9d9cab32579-d95f666d24193f40-01 |
| 150 | +Activity.DisplayName: SomeWork |
| 151 | +Activity.Kind: Internal |
| 152 | +Activity.StartTime: 2021-03-15T01:58:10.7647839Z |
| 153 | +Activity.Duration: 00:00:01.5450288 |
| 154 | +Resource associated with Activity: |
| 155 | + service.name: unknown_service:temp |
| 156 | +
|
| 157 | +Example work done |
| 158 | +``` |
| 159 | + |
| 160 | +The console exporter is helpful for quick examples or local development but in a production deployment |
| 161 | +you will probably want to send logs to a central logging store. OpenTelemetry supports a variety |
| 162 | +of different logging destinations using different |
| 163 | +[exporters](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/glossary.md#exporter-library). |
| 164 | +See the [OpenTelemetry getting started](https://github.com/open-telemetry/opentelemetry-dotnet#getting-started) |
| 165 | +instructions for more information on configuring OpenTelemetry. |
| 166 | + |
| 167 | +## Collect using Application Insights |
| 168 | + |
| 169 | +Distributed tracing telemetry is automatically captured after configuring the Application Insights SDK |
| 170 | +([.NET](https://docs.microsoft.com/en-us/azure/azure-monitor/app/asp-net), [.NET Core](https://docs.microsoft.com/en-us/azure/azure-monitor/app/asp-net-core)) |
| 171 | +or by enabling [code-less instrumentation](https://docs.microsoft.com/en-us/azure/azure-monitor/app/codeless-overview). |
| 172 | + |
| 173 | +See the [Application Insights distributed tracing documentation](https://docs.microsoft.com/en-us/azure/azure-monitor/app/distributed-tracing) for more |
| 174 | +information. |
| 175 | + |
| 176 | +> [!NOTE] |
| 177 | +> Currently Application Insights only supports collecting specific well-known Activity instrumentation and will ignore new user added Activities. Application |
| 178 | +> Insights offers [TrackDependency](https://docs.microsoft.com/en-us/azure/azure-monitor/app/api-custom-events-metrics#trackdependency) as a vendor |
| 179 | +> specific API for adding custom distributed tracing information. |
| 180 | +
|
| 181 | + |
| 182 | +## Collect using a custom logging implementation |
| 183 | + |
| 184 | +### Prerequisites |
| 185 | + |
| 186 | +- [.NET Core 3.1 SDK](https://dotnet.microsoft.com/download/dotnet) or a later version |
| 187 | + |
| 188 | +### Create an example application |
| 189 | + |
| 190 | +```dotnetcli |
| 191 | +dotnet new console |
| 192 | +``` |
| 193 | + |
| 194 | +Applications that target .NET 5 and later already have the necessary distributed tracing APIs included. For apps targeting older |
| 195 | +.NET versions add the [System.Diagnostics.DiagnosticSource NuGet package](https://www.nuget.org/packages/System.Diagnostics.DiagnosticSource/) |
| 196 | +version 5.0.1 or greater. |
| 197 | +```dotnetcli |
| 198 | +dotnet add package System.Diagnostics.DiagnosticSource --version 5.0.1 |
| 199 | +``` |
| 200 | + |
| 201 | +Replace the contents of the generated Program.cs with this example source: |
| 202 | +```C# |
| 203 | +using System; |
| 204 | +using System.Diagnostics; |
| 205 | +using System.Net.Http; |
| 206 | +using System.Threading.Tasks; |
| 207 | + |
| 208 | +namespace Sample.DistributedTracing |
| 209 | +{ |
| 210 | + class Program |
| 211 | + { |
| 212 | + static ActivitySource s_source = new ActivitySource("Sample.DistributedTracing"); |
| 213 | + |
| 214 | + static async Task Main(string[] args) |
| 215 | + { |
| 216 | + await DoSomeWork(); |
| 217 | + Console.WriteLine("Example work done"); |
| 218 | + } |
| 219 | + |
| 220 | + static async Task DoSomeWork() |
| 221 | + { |
| 222 | + using (Activity a = s_source.StartActivity("SomeWork")) |
| 223 | + { |
| 224 | + await StepOne(); |
| 225 | + await StepTwo(); |
| 226 | + } |
| 227 | + } |
| 228 | + |
| 229 | + static async Task StepOne() |
| 230 | + { |
| 231 | + using (Activity a = s_source.StartActivity("StepOne")) |
| 232 | + { |
| 233 | + await Task.Delay(500); |
| 234 | + } |
| 235 | + } |
| 236 | + |
| 237 | + static async Task StepTwo() |
| 238 | + { |
| 239 | + using (Activity a = s_source.StartActivity("StepTwo")) |
| 240 | + { |
| 241 | + await Task.Delay(1000); |
| 242 | + } |
| 243 | + } |
| 244 | + } |
| 245 | +} |
| 246 | +``` |
| 247 | + |
| 248 | +Running the app does not log anything yet |
| 249 | +```dotnetcli |
| 250 | +> dotnet run |
| 251 | +Example work done |
| 252 | +``` |
| 253 | + |
| 254 | +### Add code to log the Activities |
| 255 | + |
| 256 | +Update Main() with this code that logs Activities: |
| 257 | +```C# |
| 258 | + static async Task Main(string[] args) |
| 259 | + { |
| 260 | + Activity.DefaultIdFormat = ActivityIdFormat.W3C; |
| 261 | + Console.WriteLine(" {0,-15} {1,-60} {2,-15}", "OperationName", "Id", "Duration"); |
| 262 | + ActivitySource.AddActivityListener(new ActivityListener() |
| 263 | + { |
| 264 | + ShouldListenTo = (source) => true, |
| 265 | + Sample = (ref ActivityCreationOptions<ActivityContext> options) => ActivitySamplingResult.AllDataAndRecorded, |
| 266 | + ActivityStarted = activity => Console.WriteLine("Started: {0,-15} {1,-60}", activity.OperationName, activity.Id), |
| 267 | + ActivityStopped = activity => Console.WriteLine("Stopped: {0,-15} {1,-60} {2,-15}", activity.OperationName, activity.Id, activity.Duration) |
| 268 | + }); |
| 269 | + |
| 270 | + await DoSomeWork(); |
| 271 | + Console.WriteLine("Example work done"); |
| 272 | + } |
| 273 | +``` |
| 274 | + |
| 275 | +The output now includes logging: |
| 276 | +```dotnetcli |
| 277 | +> dotnet run |
| 278 | + OperationName Id Duration |
| 279 | +Started: SomeWork 00-bdb5faffc2fc1548b6ba49a31c4a0ae0-c447fb302059784f-01 |
| 280 | +Started: StepOne 00-bdb5faffc2fc1548b6ba49a31c4a0ae0-a7c77a4e9a02dc4a-01 |
| 281 | +Stopped: StepOne 00-bdb5faffc2fc1548b6ba49a31c4a0ae0-a7c77a4e9a02dc4a-01 00:00:00.5093849 |
| 282 | +Started: StepTwo 00-bdb5faffc2fc1548b6ba49a31c4a0ae0-9210ad536cae9e4e-01 |
| 283 | +Stopped: StepTwo 00-bdb5faffc2fc1548b6ba49a31c4a0ae0-9210ad536cae9e4e-01 00:00:01.0111847 |
| 284 | +Stopped: SomeWork 00-bdb5faffc2fc1548b6ba49a31c4a0ae0-c447fb302059784f-01 00:00:01.5236391 |
| 285 | +Example work done |
| 286 | +``` |
| 287 | + |
| 288 | +Setting <xref:System.Diagnostics.Activity.DefaultIdFormat?displayProperty=nameWithType> is optional |
| 289 | +but helps ensure the sample produces similar output on different .NET runtime versions. .NET 5.0 uses |
| 290 | +the W3C ID format by default but earlier .NET versions default to using |
| 291 | +<xref:System.Diagnostics.ActivityIdFormat.Hierarchical?displayProperty=nameWithType> as a precaution |
| 292 | +to avoid compatibility issues with older distributed tracing systems. See |
| 293 | +[Activity IDs](distributed-tracing-concepts.md#activity-ids) for more details. |
| 294 | + |
| 295 | +<xref:System.Diagnostics.ActivityListener?displayProperty=nameWithType> is used to receive callbacks |
| 296 | +during the lifetime of an Activity. |
| 297 | + - <xref:System.Diagnostics.ActivityListener.ShouldListenTo?displayProperty=nameWithType> - Each |
| 298 | +Activity is associated with an ActivitySource which acts as a namespace for a set of Activities. |
| 299 | +This callback is invoked once for each ActivitySource in the process. Returning true indicates |
| 300 | +the listener should be notified about Activities associated with this source. |
| 301 | + - <xref:System.Diagnostics.ActivityListener.Sample?displayProperty=nameWithType> - By default |
| 302 | +<xref:System.Diagnostics.ActivitySource.StartActivity?displayProperty=nameWithType> does not |
| 303 | +create an Activity object unless some ActivityListener indicates it should be sampled. Returning |
| 304 | +<xref:System.Diagnostics.ActivitySamplingResult.AllDataAndRecorded?displayProperty=nameWithType> |
| 305 | +indicates that the Activity should be created, |
| 306 | +<xref:System.Diagnostics.Activity.IsAllDataRequested?displayProperty=nameWithType> should be set |
| 307 | +to true, and <xref:System.Diagnostics.Activity.ActivityTraceFlags?displayProperty=nameWithType> |
| 308 | +will have the <xref:System.Diagnostics.ActivityTraceFlags.Recorded?displayProperty=nameWithType> |
| 309 | +flag set. IsAllDataRequested can be observed by the instrumented code as a hint that a listener |
| 310 | +wants to ensure that auxilliary Activity information such as Tags and Events are populated. |
| 311 | +The Recorded flag is encoded in the W3C ID and is a hint to other processes involved in the |
| 312 | +distributed trace that this trace should be logged. |
| 313 | + - <xref:System.Diagnostics.ActivityListener.ActivityStarted?displayProperty=nameWithType> and |
| 314 | +<xref:System.Diagnostics.ActivityListener.ActivityStopped?displayProperty=nameWithType> are |
| 315 | +called when an Activity is started and stopped respectively. These callbacks provide an |
| 316 | +oportunity to log any relevant information about the Activity. When an Activity has just |
| 317 | +started much of the data may still be incomplete and it will be filled in before the Activity |
| 318 | +stops. |
| 319 | + |
| 320 | +Once an ActivityListener has been created and the callbacks are populated, invoking |
| 321 | +<xref:System.Diagnostics.ActivitySource.AddActivityListener?displayProperty=nameWithType> |
| 322 | +initiates invoking the callbacks. Call |
| 323 | +<xref:System.Diagnostics.ActivityListener.Dispose?displayProperty=nameWithType> to |
| 324 | +stop the flow of callbacks. Beware that in multi-threaded code callback notifications in |
| 325 | +progress could be received while Dispose() is running or even very shortly after it has |
| 326 | +returned. |
0 commit comments