From 08599b639300ae7428159a7a6ff61dc5b6208378 Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Wed, 24 Jul 2019 20:40:50 -0700 Subject: [PATCH] Improvements in http in and out auto-collectors --- OpenTelemetry.sln | 17 ++- .../AspNetCoreCollectorEventSource.cs | 12 +- .../Implementation/HttpInListener.cs | 106 +++++++++++------- .../RequestsCollector.cs | 2 +- .../DependenciesCollector.cs | 2 +- .../DependenciesCollectorEventSource.cs | 18 ++- .../HttpHandlerDiagnosticListener.cs | 75 ++++++++++--- .../DiagnosticSourceListener.cs | 11 +- .../DiagnosticSourceSubscriber.cs | 2 +- .../ListenerHandler.cs | 4 +- src/OpenTelemetry/Trace/SpanBuilder.cs | 2 +- src/OpenTelemetry/Trace/Tracer.cs | 7 ++ .../BasicTests.cs | 6 +- .../BasicTests.cs | 106 +++++++++++------- .../HttpClientTests.cs | 4 +- 15 files changed, 247 insertions(+), 127 deletions(-) diff --git a/OpenTelemetry.sln b/OpenTelemetry.sln index ab2ac06e63f..4c9dd7e6c10 100644 --- a/OpenTelemetry.sln +++ b/OpenTelemetry.sln @@ -1,7 +1,7 @@  Microsoft Visual Studio Solution File, Format Version 12.00 -# Visual Studio Version 16 -VisualStudioVersion = 16.0.28407.52 +# Visual Studio 15 +VisualStudioVersion = 15.0.28307.705 MinimumVisualStudioVersion = 10.0.40219.1 Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "OpenTelemetry", "src\OpenTelemetry\OpenTelemetry.csproj", "{AE3E3DF5-4083-4C6E-A840-8271B0ACDE7E}" EndProject @@ -80,9 +80,13 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "LoggingTracer.Demo.ConsoleA EndProject Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "LoggingTracer.Demo.AspNetCore", "samples\LoggingTracer\LoggingTracer.Demo.AspNetCore\LoggingTracer.Demo.AspNetCore.csproj", "{1EB74FCE-55C5-476A-8BB0-C46B77FE1070}" EndProject -Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "OpenTelemetry.Exporter.Jaeger", "src\OpenTelemetry.Exporter.Jaeger\OpenTelemetry.Exporter.Jaeger.csproj", "{8D47E3CF-9AE3-42FE-9084-FEB72D9AD769}" +Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "OpenTelemetry.Exporter.Jaeger", "src\OpenTelemetry.Exporter.Jaeger\OpenTelemetry.Exporter.Jaeger.csproj", "{8D47E3CF-9AE3-42FE-9084-FEB72D9AD769}" EndProject -Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "OpenTelemetry.Exporter.Jaeger.Tests", "test\OpenTelemetry.Exporter.Jaeger.Tests\OpenTelemetry.Exporter.Jaeger.Tests.csproj", "{21E69213-72D5-453F-BD00-75EF36AC4965}" +Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "OpenTelemetry.Exporter.Jaeger.Tests", "test\OpenTelemetry.Exporter.Jaeger.Tests\OpenTelemetry.Exporter.Jaeger.Tests.csproj", "{21E69213-72D5-453F-BD00-75EF36AC4965}" +EndProject +Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "Thrift", "lib\Thrift\Thrift.csproj", "{ED179037-DDB3-4780-A24F-F56278623EBB}" +EndProject +Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "lib", "lib", "{9D2D6933-C28C-4541-9A25-FDAE0DA5A5D4}" EndProject Global GlobalSection(SolutionConfigurationPlatforms) = preSolution @@ -182,6 +186,10 @@ Global {21E69213-72D5-453F-BD00-75EF36AC4965}.Debug|Any CPU.Build.0 = Debug|Any CPU {21E69213-72D5-453F-BD00-75EF36AC4965}.Release|Any CPU.ActiveCfg = Release|Any CPU {21E69213-72D5-453F-BD00-75EF36AC4965}.Release|Any CPU.Build.0 = Release|Any CPU + {ED179037-DDB3-4780-A24F-F56278623EBB}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {ED179037-DDB3-4780-A24F-F56278623EBB}.Debug|Any CPU.Build.0 = Debug|Any CPU + {ED179037-DDB3-4780-A24F-F56278623EBB}.Release|Any CPU.ActiveCfg = Release|Any CPU + {ED179037-DDB3-4780-A24F-F56278623EBB}.Release|Any CPU.Build.0 = Release|Any CPU EndGlobalSection GlobalSection(SolutionProperties) = preSolution HideSolutionNode = FALSE @@ -193,6 +201,7 @@ Global {1EEF77DF-7552-4265-B64C-FA13BC40C256} = {D9C14CDA-5182-4DEA-8606-98FF1A388BD3} {607B3861-4D69-43EF-84CE-19F18CD5339A} = {D9C14CDA-5182-4DEA-8606-98FF1A388BD3} {1EB74FCE-55C5-476A-8BB0-C46B77FE1070} = {D9C14CDA-5182-4DEA-8606-98FF1A388BD3} + {ED179037-DDB3-4780-A24F-F56278623EBB} = {9D2D6933-C28C-4541-9A25-FDAE0DA5A5D4} EndGlobalSection GlobalSection(ExtensibilityGlobals) = postSolution SolutionGuid = {55639B5C-0770-4A22-AB56-859604650521} diff --git a/src/OpenTelemetry.Collector.AspNetCore/AspNetCoreCollectorEventSource.cs b/src/OpenTelemetry.Collector.AspNetCore/AspNetCoreCollectorEventSource.cs index 4f4fa6d07a9..b87cd91a9f9 100644 --- a/src/OpenTelemetry.Collector.AspNetCore/AspNetCoreCollectorEventSource.cs +++ b/src/OpenTelemetry.Collector.AspNetCore/AspNetCoreCollectorEventSource.cs @@ -38,10 +38,10 @@ public void ExceptionInCustomSampler(Exception ex) } } - [Event(1, Message = "Context is NULL in end callback. Span will not be recorded.", Level = EventLevel.Warning)] - public void NullContext() + [Event(1, Message = "Http Context is NULL in '{0}' callback. Span will not be recorded.", Level = EventLevel.Warning)] + public void NullHttpContext(string eventName) { - this.WriteEvent(1); + this.WriteEvent(1, eventName); } [Event(2, Message = "Error getting custom sampler, the default sampler will be used. Exception : {0}", Level = EventLevel.Warning)] @@ -50,6 +50,12 @@ public void ExceptionInCustomSampler(string ex) this.WriteEvent(2, ex); } + [Event(3, Message = "Current Span is null or blank in '{0}' callback. Span will not be recorded.", Level = EventLevel.Warning)] + public void NullOrBlankSpan(string callbackName) + { + this.WriteEvent(3, callbackName); + } + /// /// Returns a culture-independent string representation of the given object, /// appropriate for diagnostics tracing. diff --git a/src/OpenTelemetry.Collector.AspNetCore/Implementation/HttpInListener.cs b/src/OpenTelemetry.Collector.AspNetCore/Implementation/HttpInListener.cs index 0e7c3f0c0b5..96108837729 100644 --- a/src/OpenTelemetry.Collector.AspNetCore/Implementation/HttpInListener.cs +++ b/src/OpenTelemetry.Collector.AspNetCore/Implementation/HttpInListener.cs @@ -33,10 +33,12 @@ internal class HttpInListener : ListenerHandler private readonly PropertyFetcher beforeActionActionDescriptorFetcher = new PropertyFetcher("actionDescriptor"); private readonly PropertyFetcher beforeActionAttributeRouteInfoFetcher = new PropertyFetcher("AttributeRouteInfo"); private readonly PropertyFetcher beforeActionTemplateFetcher = new PropertyFetcher("Template"); + private readonly bool hostingSupportsW3C = false; public HttpInListener(ITracer tracer, Func samplerFactory) : base("Microsoft.AspNetCore", tracer, samplerFactory) { + this.hostingSupportsW3C = typeof(HttpRequest).Assembly.GetName().Version.Major >= 3; } public override void OnStartActivity(Activity activity, object payload) @@ -51,48 +53,65 @@ public override void OnStartActivity(Activity activity, object payload) var request = context.Request; - var ctx = this.Tracer.TextFormat.Extract( - request, - (r, name) => r.Headers[name]); + SpanContext ctx = null; + if (!this.hostingSupportsW3C) + { + ctx = this.Tracer.TextFormat.Extract( + request, + (r, name) => r.Headers[name]); + } // see the spec https://github.com/open-telemetry/OpenTelemetry-specs/blob/master/trace/HTTP.md - var path = (request.PathBase.HasValue || request.Path.HasValue) ? (request.PathBase + request.Path).ToString() : "/"; - ISpan span = this.Tracer.SpanBuilder(path) + var spanBuilder = this.Tracer.SpanBuilder(path) .SetSpanKind(SpanKind.Server) - .SetParent(ctx) - .SetSampler(this.SamplerFactory(request)) - .StartSpan(); + .SetSampler(this.SamplerFactory(request)); - this.Tracer.WithSpan(span); - - // Note, route is missing at this stage. It will be available later + if (this.hostingSupportsW3C) + { + spanBuilder.SetCreateChild(false); + } + else + { + spanBuilder.SetParent(ctx); + } - span.PutHttpHostAttribute(request.Host.Host, request.Host.Port ?? 80); - span.PutHttpMethodAttribute(request.Method); - span.PutHttpPathAttribute(path); + var span = spanBuilder.StartSpan(); + this.Tracer.WithSpan(span); - var userAgent = request.Headers["User-Agent"].FirstOrDefault(); - span.PutHttpUserAgentAttribute(userAgent); - span.PutHttpRawUrlAttribute(GetUri(request)); + if (span.IsRecordingEvents) + { + // Note, route is missing at this stage. It will be available later + span.PutHttpHostAttribute(request.Host.Host, request.Host.Port ?? 80); + span.PutHttpMethodAttribute(request.Method); + span.PutHttpPathAttribute(path); + + var userAgent = request.Headers["User-Agent"].FirstOrDefault(); + span.PutHttpUserAgentAttribute(userAgent); + span.PutHttpRawUrlAttribute(GetUri(request)); + } } public override void OnStopActivity(Activity activity, object payload) { - var context = this.stopContextFetcher.Fetch(payload) as HttpContext; + var span = this.Tracer.CurrentSpan; - if (context == null) + if (span == null || span == BlankSpan.Instance) { - AspNetCoreCollectorEventSource.Log.NullContext(); + AspNetCoreCollectorEventSource.Log.NullOrBlankSpan("HttpInListener.OnStopActivity"); return; } - var span = this.Tracer.CurrentSpan; + if (!span.IsRecordingEvents) + { + span.End(); + return; + } - if (span == null) + if (!(this.stopContextFetcher.Fetch(payload) is HttpContext context)) { - // TODO: report lost span + AspNetCoreCollectorEventSource.Log.NullHttpContext("HttpInListener.OnStopActivity"); return; } @@ -110,30 +129,33 @@ public override void OnCustom(string name, Activity activity, object payload) if (span == null) { - // TODO: report lost span + AspNetCoreCollectorEventSource.Log.NullOrBlankSpan(name); return; } - // See https://github.com/aspnet/Mvc/blob/2414db256f32a047770326d14d8b0e2afd49ba49/src/Microsoft.AspNetCore.Mvc.Core/MvcCoreDiagnosticSourceExtensions.cs#L36-L44 - // Reflection accessing: ActionDescriptor.AttributeRouteInfo.Template - // The reason to use reflection is to avoid a reference on MVC package. - // This package can be used with non-MVC apps and this logic simply wouldn't run. - // Taking reference on MVC will increase size of deployment for non-MVC apps. - var actionDescriptor = this.beforeActionActionDescriptorFetcher.Fetch(payload); - var attributeRouteInfo = this.beforeActionAttributeRouteInfoFetcher.Fetch(actionDescriptor); - var template = this.beforeActionTemplateFetcher.Fetch(attributeRouteInfo) as string; - - if (!string.IsNullOrEmpty(template)) + if (span.IsRecordingEvents) { - // override the span name that was previously set to the path part of URL. - span.UpdateName(template); - - span.PutHttpRouteAttribute(template); + // See https://github.com/aspnet/Mvc/blob/2414db256f32a047770326d14d8b0e2afd49ba49/src/Microsoft.AspNetCore.Mvc.Core/MvcCoreDiagnosticSourceExtensions.cs#L36-L44 + // Reflection accessing: ActionDescriptor.AttributeRouteInfo.Template + // The reason to use reflection is to avoid a reference on MVC package. + // This package can be used with non-MVC apps and this logic simply wouldn't run. + // Taking reference on MVC will increase size of deployment for non-MVC apps. + var actionDescriptor = this.beforeActionActionDescriptorFetcher.Fetch(payload); + var attributeRouteInfo = this.beforeActionAttributeRouteInfoFetcher.Fetch(actionDescriptor); + var template = this.beforeActionTemplateFetcher.Fetch(attributeRouteInfo) as string; + + if (!string.IsNullOrEmpty(template)) + { + // override the span name that was previously set to the path part of URL. + span.UpdateName(template); + + span.PutHttpRouteAttribute(template); + } + + // TODO: Should we get values from RouteData? + // private readonly PropertyFetcher beforActionRouteDataFetcher = new PropertyFetcher("routeData"); + // var routeData = this.beforActionRouteDataFetcher.Fetch(payload) as RouteData; } - - // TODO: Should we get values from RouteData? - // private readonly PropertyFetcher beforActionRouteDataFetcher = new PropertyFetcher("routeData"); - // var routeData = this.beforActionRouteDataFetcher.Fetch(payload) as RouteData; } } diff --git a/src/OpenTelemetry.Collector.AspNetCore/RequestsCollector.cs b/src/OpenTelemetry.Collector.AspNetCore/RequestsCollector.cs index c80122c4f17..cd4b35bbfd3 100644 --- a/src/OpenTelemetry.Collector.AspNetCore/RequestsCollector.cs +++ b/src/OpenTelemetry.Collector.AspNetCore/RequestsCollector.cs @@ -57,7 +57,7 @@ public RequestsCollector(RequestsCollectorOptions options, ITracer tracer, ISamp AspNetCoreCollectorEventSource.Log.ExceptionInCustomSampler(e); } - return s == null ? sampler : s; + return s ?? sampler; }); this.diagnosticSourceSubscriber.Subscribe(); } diff --git a/src/OpenTelemetry.Collector.Dependencies/DependenciesCollector.cs b/src/OpenTelemetry.Collector.Dependencies/DependenciesCollector.cs index e241b1b83fc..2ed0259ab94 100644 --- a/src/OpenTelemetry.Collector.Dependencies/DependenciesCollector.cs +++ b/src/OpenTelemetry.Collector.Dependencies/DependenciesCollector.cs @@ -55,7 +55,7 @@ public DependenciesCollector(DependenciesCollectorOptions options, ITracer trace DependenciesCollectorEventSource.Log.ExceptionInCustomSampler(e); } - return s == null ? sampler : s; + return s ?? sampler; }); this.diagnosticSourceSubscriber.Subscribe(); } diff --git a/src/OpenTelemetry.Collector.Dependencies/DependenciesCollectorEventSource.cs b/src/OpenTelemetry.Collector.Dependencies/DependenciesCollectorEventSource.cs index 8d5fc997183..b088d812c62 100644 --- a/src/OpenTelemetry.Collector.Dependencies/DependenciesCollectorEventSource.cs +++ b/src/OpenTelemetry.Collector.Dependencies/DependenciesCollectorEventSource.cs @@ -38,10 +38,10 @@ public void ExceptionInCustomSampler(Exception ex) } } - [Event(1, Message = "Context is NULL in end callback. Span will not be recorded.", Level = EventLevel.Warning)] - public void NullContext() + [Event(1, Message = "Span is NULL or blank in the '{0}' callback. Span will not be recorded.", Level = EventLevel.Warning)] + public void NullOrBlankSpan(string eventName) { - this.WriteEvent(1); + this.WriteEvent(1, eventName); } [Event(2, Message = "Error getting custom sampler, the default sampler will be used. Exception : {0}", Level = EventLevel.Warning)] @@ -50,6 +50,18 @@ public void ExceptionInCustomSampler(string ex) this.WriteEvent(2, ex); } + [Event(3, Message = "Current Activity is NULL the '{0}' callback. Span will not be recorded.", Level = EventLevel.Warning)] + public void NullActivity(string eventName) + { + this.WriteEvent(3, eventName); + } + + [Event(4, Message = "Unknown error processing event '{0}' from handler '{1}', Exception: {2}", Level = EventLevel.Error)] + public void UnknownErrorProcessingEvent(string handlerName, string eventName, Exception ex) + { + this.WriteEvent(4, handlerName, eventName, ToInvariantString(ex)); + } + /// /// Returns a culture-independent string representation of the given object, /// appropriate for diagnostics tracing. diff --git a/src/OpenTelemetry.Collector.Dependencies/Implementation/HttpHandlerDiagnosticListener.cs b/src/OpenTelemetry.Collector.Dependencies/Implementation/HttpHandlerDiagnosticListener.cs index aef890c8bcd..1860cee00cc 100644 --- a/src/OpenTelemetry.Collector.Dependencies/Implementation/HttpHandlerDiagnosticListener.cs +++ b/src/OpenTelemetry.Collector.Dependencies/Implementation/HttpHandlerDiagnosticListener.cs @@ -21,6 +21,8 @@ namespace OpenTelemetry.Collector.Dependencies.Implementation using System.Linq; using System.Net; using System.Net.Http; + using System.Reflection; + using System.Runtime.Versioning; using System.Threading.Tasks; using OpenTelemetry.Collector.Dependencies.Common; using OpenTelemetry.Trace; @@ -31,10 +33,23 @@ internal class HttpHandlerDiagnosticListener : ListenerHandler private readonly PropertyFetcher stopResponseFetcher = new PropertyFetcher("Response"); private readonly PropertyFetcher stopExceptionFetcher = new PropertyFetcher("Exception"); private readonly PropertyFetcher stopRequestStatusFetcher = new PropertyFetcher("RequestTaskStatus"); + private readonly bool httpClientSupportsW3C = false; public HttpHandlerDiagnosticListener(ITracer tracer, Func samplerFactory) : base("HttpHandlerDiagnosticListener", tracer, samplerFactory) { + var framework = Assembly + .GetEntryAssembly()? + .GetCustomAttribute()? + .FrameworkName; + + // Depending on the .NET version/flavor this will look like + // '.NETCoreApp,Version=v3.0', '.NETCoreApp,Version = v2.2' or '.NETFramework,Version = v4.7.1' + + if (framework != null && framework.Contains("Version=v3")) + { + this.httpClientSupportsW3C = true; + } } public override void OnStartActivity(Activity activity, object payload) @@ -45,29 +60,49 @@ public override void OnStartActivity(Activity activity, object payload) return; } + if (request.Headers.Contains("traceparent")) + { + // this request is already instrumented, we should back off + return; + } + var span = this.Tracer.SpanBuilder(request.RequestUri.AbsolutePath) .SetSpanKind(SpanKind.Client) .SetSampler(this.SamplerFactory(request)) + .SetCreateChild(false) .StartSpan(); + this.Tracer.WithSpan(span); - span.PutHttpMethodAttribute(request.Method.ToString()); - span.PutHttpHostAttribute(request.RequestUri.Host, request.RequestUri.Port); - span.PutHttpPathAttribute(request.RequestUri.AbsolutePath); - request.Headers.TryGetValues("User-Agent", out var userAgents); - span.PutHttpUserAgentAttribute(userAgents?.FirstOrDefault()); - span.PutHttpRawUrlAttribute(request.RequestUri.OriginalString); + if (span.IsRecordingEvents) + { + span.PutHttpMethodAttribute(request.Method.ToString()); + span.PutHttpHostAttribute(request.RequestUri.Host, request.RequestUri.Port); + span.PutHttpPathAttribute(request.RequestUri.AbsolutePath); + request.Headers.TryGetValues("User-Agent", out var userAgents); + span.PutHttpUserAgentAttribute(userAgents?.FirstOrDefault()); + span.PutHttpRawUrlAttribute(request.RequestUri.OriginalString); + } - this.Tracer.TextFormat.Inject(span.Context, request, (r, k, v) => r.Headers.Add(k, v)); + if (!this.httpClientSupportsW3C) + { + this.Tracer.TextFormat.Inject(span.Context, request, (r, k, v) => r.Headers.Add(k, v)); + } } public override void OnStopActivity(Activity activity, object payload) { var span = this.Tracer.CurrentSpan; - if (span == null) + if (span == null || span == BlankSpan.Instance) + { + DependenciesCollectorEventSource.Log.NullOrBlankSpan("HttpHandlerDiagnosticListener.OnStopActivity"); + return; + } + + if (!span.IsRecordingEvents) { - DependenciesCollectorEventSource.Log.NullContext(); + span.End(); return; } @@ -89,8 +124,6 @@ public override void OnStopActivity(Activity activity, object payload) if (!(this.stopResponseFetcher.Fetch(payload) is HttpResponseMessage response)) { // response could be null for DNS issues, timeouts, etc... - // TODO: how do we make sure we will not close a scope that wasn't opened? - span.End(); return; } @@ -102,25 +135,31 @@ public override void OnStopActivity(Activity activity, object payload) public override void OnException(Activity activity, object payload) { - if (!(this.stopExceptionFetcher.Fetch(payload) is Exception exc)) + var span = this.Tracer.CurrentSpan; + + if (span == null || span == BlankSpan.Instance) { - // Debug.WriteLine("response is null"); + DependenciesCollectorEventSource.Log.NullOrBlankSpan("HttpHandlerDiagnosticListener.OnException"); return; } - var span = this.Tracer.CurrentSpan; + if (!span.IsRecordingEvents) + { + span.End(); + return; + } - if (span == null) + if (!(this.stopExceptionFetcher.Fetch(payload) is Exception exc)) { - // TODO: Notify that span got lost + // Debug.WriteLine("response is null"); return; } if (exc is HttpRequestException) { // TODO: on netstandard this will be System.Net.Http.WinHttpException: The server name or address could not be resolved - if (exc.InnerException is WebException && - ((WebException)exc.InnerException).Status == WebExceptionStatus.NameResolutionFailure) + if (exc.InnerException is WebException exception && + exception.Status == WebExceptionStatus.NameResolutionFailure) { span.Status = Status.InvalidArgument; } diff --git a/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/DiagnosticSourceListener.cs b/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/DiagnosticSourceListener.cs index 0c651192bc6..d62929c5923 100644 --- a/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/DiagnosticSourceListener.cs +++ b/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/DiagnosticSourceListener.cs @@ -22,12 +22,10 @@ namespace OpenTelemetry.Collector.Dependencies.Common internal class DiagnosticSourceListener : IObserver>, IDisposable { - private readonly string sourceName; private readonly ListenerHandler handler; - public DiagnosticSourceListener(string sourceName, ListenerHandler handler) + public DiagnosticSourceListener(ListenerHandler handler) { - this.sourceName = sourceName; this.handler = handler; } @@ -45,7 +43,7 @@ public void OnNext(KeyValuePair value) { if (Activity.Current == null) { - Debug.WriteLine("Activity is null " + value.Key); + DependenciesCollectorEventSource.Log.NullActivity(value.Key); return; } @@ -68,10 +66,9 @@ public void OnNext(KeyValuePair value) this.handler.OnCustom(value.Key, Activity.Current, value.Value); } } - catch (Exception) + catch (Exception ex) { - // Debug.WriteLine(e); - // TODO: make sure to output the handler name as part of error message + DependenciesCollectorEventSource.Log.UnknownErrorProcessingEvent(this.handler?.SourceName, value.Key, ex); } } diff --git a/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/DiagnosticSourceSubscriber.cs b/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/DiagnosticSourceSubscriber.cs index 0f410f73cd3..6892b6b50ad 100644 --- a/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/DiagnosticSourceSubscriber.cs +++ b/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/DiagnosticSourceSubscriber.cs @@ -57,7 +57,7 @@ public void OnNext(DiagnosticListener value) { this.subscriptions.GetOrAdd(value.Name, name => { - var dl = new DiagnosticSourceListener(value.Name, this.handlers[value.Name](this.tracer, this.sampler)); + var dl = new DiagnosticSourceListener(this.handlers[value.Name](this.tracer, this.sampler)); dl.Subscription = value.Subscribe(dl); return dl; }); diff --git a/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/ListenerHandler.cs b/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/ListenerHandler.cs index d05ec8a681a..daf04308533 100644 --- a/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/ListenerHandler.cs +++ b/src/OpenTelemetry.Collector.Dependencies/Implementation/OpenTelemetry.Collector.Dependencies.Common/ListenerHandler.cs @@ -42,9 +42,9 @@ public virtual void OnStopActivity(Activity activity, object payload) { var span = this.Tracer.CurrentSpan; - if (span == null) + if (span == null || span == BlankSpan.Instance) { - // TODO: Notify that span got lost + DependenciesCollectorEventSource.Log.NullOrBlankSpan("ListenerHandler.OnStopActivity"); return; } diff --git a/src/OpenTelemetry/Trace/SpanBuilder.cs b/src/OpenTelemetry/Trace/SpanBuilder.cs index c8ebd6ea49a..078e4f1877e 100644 --- a/src/OpenTelemetry/Trace/SpanBuilder.cs +++ b/src/OpenTelemetry/Trace/SpanBuilder.cs @@ -242,7 +242,7 @@ public ISpan StartSpan() var span = Span.StartSpan( activityForSpan, - childTracestate, // it is updated in CreateActivityForSpan, + childTracestate, this.kind, activeTraceParams, this.options.StartEndHandler, diff --git a/src/OpenTelemetry/Trace/Tracer.cs b/src/OpenTelemetry/Trace/Tracer.cs index 9507410aff0..2541b19abf6 100644 --- a/src/OpenTelemetry/Trace/Tracer.cs +++ b/src/OpenTelemetry/Trace/Tracer.cs @@ -17,6 +17,7 @@ namespace OpenTelemetry.Trace { using System; + using System.Diagnostics; using System.Threading; using OpenTelemetry.Context; using OpenTelemetry.Context.Propagation; @@ -34,6 +35,12 @@ public sealed class Tracer : ITracer private readonly SpanBuilderOptions spanBuilderOptions; private readonly SpanExporter spanExporter; + static Tracer() + { + Activity.DefaultIdFormat = ActivityIdFormat.W3C; + Activity.ForceDefaultIdFormat = true; + } + /// /// Creates an instance of . /// diff --git a/test/OpenTelemetry.Collector.AspNetCore.Tests/BasicTests.cs b/test/OpenTelemetry.Collector.AspNetCore.Tests/BasicTests.cs index 5ea0517c6fd..240cb192c09 100644 --- a/test/OpenTelemetry.Collector.AspNetCore.Tests/BasicTests.cs +++ b/test/OpenTelemetry.Collector.AspNetCore.Tests/BasicTests.cs @@ -23,7 +23,6 @@ namespace OpenTelemetry.Collector.AspNetCore.Tests using Microsoft.Extensions.DependencyInjection; using OpenTelemetry.Trace; using OpenTelemetry.Trace.Config; - using OpenTelemetry.Trace.Internal; using Moq; using Microsoft.AspNetCore.TestHost; using System; @@ -41,11 +40,10 @@ public class BasicTests public BasicTests(WebApplicationFactory factory) { this.factory = factory; - } [Fact] - public async Task SuccesfulTemplateControllerCallGeneratesASpan() + public async Task SuccessfulTemplateControllerCallGeneratesASpan() { var startEndHandler = new Mock(); var tracer = new Tracer(startEndHandler.Object, new TraceConfig()); @@ -89,7 +87,7 @@ void ConfigureTestServices(IServiceCollection services) => } [Fact] - public async Task SuccesfulTemplateControllerCallUsesParentContext() + public async Task SuccessfulTemplateControllerCallUsesParentContext() { var startEndHandler = new Mock(); diff --git a/test/OpenTelemetry.Collector.Dependencies.Tests/BasicTests.cs b/test/OpenTelemetry.Collector.Dependencies.Tests/BasicTests.cs index ebb496df0e7..245dde74845 100644 --- a/test/OpenTelemetry.Collector.Dependencies.Tests/BasicTests.cs +++ b/test/OpenTelemetry.Collector.Dependencies.Tests/BasicTests.cs @@ -14,13 +14,13 @@ // limitations under the License. // +using System.Linq; + namespace OpenTelemetry.Collector.Dependencies.Tests { using Moq; using OpenTelemetry.Trace; using OpenTelemetry.Trace.Config; - using OpenTelemetry.Trace.Internal; - using OpenTelemetry.Context.Propagation; using OpenTelemetry.Trace.Sampler; using System; using System.Diagnostics; @@ -28,14 +28,13 @@ namespace OpenTelemetry.Collector.Dependencies.Tests using System.Threading.Tasks; using Xunit; - public partial class HttpClientTests + public partial class HttpClientTests : IDisposable { - [Fact] - public async Task HttpDepenenciesCollectorInjectsHeadersAsync() + private readonly IDisposable serverLifeTime; + private readonly string url; + public HttpClientTests() { - var startEndHandler = new Mock(); - - var serverLifeTime = TestServer.RunServer( + this.serverLifeTime = TestServer.RunServer( (ctx) => { ctx.Response.StatusCode = 200; @@ -44,45 +43,76 @@ public async Task HttpDepenenciesCollectorInjectsHeadersAsync() out var host, out var port); - var url = $"http://{host}:{port}/"; + this.url = $"http://{host}:{port}/"; + } - ActivityTraceId expectedTraceId = default; - ActivitySpanId expectedSpanId = default; + [Fact] + public async Task HttpDependenciesCollectorInjectsHeadersAsync() + { + var startEndHandler = new Mock(); + var tracer = new Tracer(startEndHandler.Object, new TraceConfig(), null, null, null); - using (serverLifeTime) + var request = new HttpRequestMessage { - var tf = new Mock(); - tf - .Setup(m => m.Inject(It.IsAny(), It.IsAny(), It.IsAny>())) - .Callback((SpanContext sc, HttpRequestMessage obj, Action setter) => - { - expectedTraceId = sc.TraceId; - expectedSpanId = sc.SpanId; - }); - - var tracer = new Tracer(startEndHandler.Object, new TraceConfig(), null, null, tf.Object); - - using (var dc = new DependenciesCollector(new DependenciesCollectorOptions(), tracer, Samplers.AlwaysSample)) - { + RequestUri = new Uri(url), + Method = new HttpMethod("GET"), + }; - using (var c = new HttpClient()) - { - var request = new HttpRequestMessage - { - RequestUri = new Uri(url), - Method = new HttpMethod("GET"), - }; - - await c.SendAsync(request); - } - } + var parent = new Activity("parent") + .SetIdFormat(ActivityIdFormat.W3C) + .Start(); + parent.TraceStateString = "k1=v1,k2=v2"; + + using (new DependenciesCollector(new DependenciesCollectorOptions(), tracer, Samplers.AlwaysSample)) + using (var c = new HttpClient()) + { + await c.SendAsync(request); } Assert.Equal(2, startEndHandler.Invocations.Count); // begin and end was called var spanData = ((Span)startEndHandler.Invocations[1].Arguments[0]).ToSpanData(); - Assert.Equal(expectedTraceId, spanData.Context.TraceId); - Assert.Equal(expectedSpanId, spanData.Context.SpanId); + Assert.Equal(parent.TraceId, spanData.Context.TraceId); + Assert.Equal(parent.SpanId, spanData.ParentSpanId); + Assert.NotEqual(parent.SpanId, spanData.Context.SpanId); + Assert.NotEqual(default, spanData.Context.SpanId); + + Assert.True(request.Headers.TryGetValues("traceparent", out var traceparents)); + Assert.True(request.Headers.TryGetValues("tracestate", out var tracestates)); + Assert.Single(traceparents); + Assert.Single(tracestates); + + Assert.Equal($"00-{spanData.Context.TraceId}-{spanData.Context.SpanId}-01", traceparents.Single()); + Assert.Equal("k1=v1,k2=v2", tracestates.Single()); + } + + [Fact] + public async Task HttpDependenciesCollectorBacksOffIfAlreadyInstrumented() + { + var startEndHandler = new Mock(); + var tracer = new Tracer(startEndHandler.Object, new TraceConfig(), null, null, null); + + var request = new HttpRequestMessage + { + RequestUri = new Uri(url), + Method = new HttpMethod("GET"), + }; + + request.Headers.Add("traceparent", "00-0123456789abcdef0123456789abcdef-0123456789abcdef-01"); + + using (new DependenciesCollector(new DependenciesCollectorOptions(), tracer, Samplers.AlwaysSample)) + using (var c = new HttpClient()) + { + await c.SendAsync(request); + } + + Assert.Equal(0, startEndHandler.Invocations.Count); + } + + public void Dispose() + { + serverLifeTime?.Dispose(); + Activity.Current = null; } } } diff --git a/test/OpenTelemetry.Collector.Dependencies.Tests/HttpClientTests.cs b/test/OpenTelemetry.Collector.Dependencies.Tests/HttpClientTests.cs index 5d2ea48299f..d22c28380d2 100644 --- a/test/OpenTelemetry.Collector.Dependencies.Tests/HttpClientTests.cs +++ b/test/OpenTelemetry.Collector.Dependencies.Tests/HttpClientTests.cs @@ -87,7 +87,7 @@ public static IEnumerable TestData [Theory] [MemberData(nameof(TestData))] - public async Task HttpOutCallsAreCollectedSuccesfullyAsync(HttpOutTestCase tc) + public async Task HttpOutCallsAreCollectedSuccessfullyAsync(HttpOutTestCase tc) { var serverLifeTime = TestServer.RunServer( (ctx) => @@ -194,7 +194,7 @@ public async Task DebugIndividualTestAsync() ] "))); - var t = (Task)this.GetType().InvokeMember(nameof(HttpOutCallsAreCollectedSuccesfullyAsync), BindingFlags.InvokeMethod, null, this, getArgumentsFromTestCaseObject(input).First()); + var t = (Task)this.GetType().InvokeMember(nameof(HttpOutCallsAreCollectedSuccessfullyAsync), BindingFlags.InvokeMethod, null, this, getArgumentsFromTestCaseObject(input).First()); await t; }