From 2406193474da1d7f5130bf51e32efe8d569696d9 Mon Sep 17 00:00:00 2001 From: Christian Weiss Date: Sat, 12 Dec 2020 07:36:22 +0100 Subject: [PATCH] big refactoring (#82) --- .../CoreFx/HttpHandlerDiagnosticsBenchmark.cs | 2 +- .../OrdersApi/Controllers/OrdersController.cs | 12 +- samples/net5.0/OrdersApi/Program.cs | 10 - .../JaegerServiceCollectionExtensions.cs | 2 +- .../OrdersApi/Controllers/OrdersController.cs | 12 +- .../JaegerServiceCollectionExtensions.cs | 2 +- .../OrdersApi/Controllers/OrdersController.cs | 12 +- samples/netcoreapp3.1/OrdersApi/Program.cs | 10 - .../JaegerServiceCollectionExtensions.cs | 2 +- .../AspNetCore/AspNetCoreDiagnosticOptions.cs | 31 +- .../AspNetCore/AspNetCoreDiagnostics.cs | 267 ++++++++++++++++-- .../AspNetCore/HostingEventProcessor.cs | 128 --------- .../AspNetCore/MvcEventProcessor.cs | 119 -------- .../Configuration/DiagnosticOptions.cs | 22 ++ .../OpenTracingBuilderExtensions.cs | 108 ++++--- .../ServiceCollectionExtensions.cs | 4 +- .../CoreFx/GenericDiagnosticOptions.cs | 27 -- .../EntityFrameworkCoreDiagnosticOptions.cs | 27 +- .../EntityFrameworkCoreDiagnostics.cs | 62 +++- .../GenericDiagnosticOptions.cs | 11 + .../GenericDiagnostics.cs | 28 +- .../HttpHandlerDiagnosticOptions.cs | 4 +- .../HttpHandlerDiagnostics.cs | 67 ++++- .../HttpHeadersInjectAdapter.cs | 2 +- ...Observer.cs => DiagnosticEventObserver.cs} | 51 +++- .../Internal/DiagnosticManager.cs | 5 +- .../Internal/DiagnosticObserver.cs | 5 - .../Internal/GenericEventOptions.cs | 127 --------- .../Internal/GenericEventProcessor.cs | 11 +- .../MicrosoftSqlClientDiagnosticOptions.cs | 31 +- .../MicrosoftSqlClientDiagnostics.cs | 50 +++- .../SqlClientDiagnosticOptions.cs | 4 +- .../SqlClientDiagnostics.cs | 56 +++- .../AspNetCore/HostingTest1_0.cs | 2 +- .../CoreFx/HttpHandlerDiagnosticTest.cs | 4 +- 35 files changed, 715 insertions(+), 602 deletions(-) delete mode 100644 src/OpenTracing.Contrib.NetCore/AspNetCore/HostingEventProcessor.cs delete mode 100644 src/OpenTracing.Contrib.NetCore/AspNetCore/MvcEventProcessor.cs create mode 100644 src/OpenTracing.Contrib.NetCore/Configuration/DiagnosticOptions.cs delete mode 100644 src/OpenTracing.Contrib.NetCore/CoreFx/GenericDiagnosticOptions.cs create mode 100644 src/OpenTracing.Contrib.NetCore/GenericListeners/GenericDiagnosticOptions.cs rename src/OpenTracing.Contrib.NetCore/{CoreFx => GenericListeners}/GenericDiagnostics.cs (75%) rename src/OpenTracing.Contrib.NetCore/{CoreFx => HttpHandler}/HttpHandlerDiagnosticOptions.cs (95%) rename src/OpenTracing.Contrib.NetCore/{CoreFx => HttpHandler}/HttpHandlerDiagnostics.cs (72%) rename src/OpenTracing.Contrib.NetCore/{CoreFx => HttpHandler}/HttpHeadersInjectAdapter.cs (94%) rename src/OpenTracing.Contrib.NetCore/Internal/{DiagnosticListenerObserver.cs => DiagnosticEventObserver.cs} (60%) delete mode 100644 src/OpenTracing.Contrib.NetCore/Internal/GenericEventOptions.cs rename src/OpenTracing.Contrib.NetCore/{CoreFx => SystemSqlClient}/SqlClientDiagnosticOptions.cs (94%) rename src/OpenTracing.Contrib.NetCore/{CoreFx => SystemSqlClient}/SqlClientDiagnostics.cs (53%) diff --git a/benchmarks/OpenTracing.Contrib.NetCore.Benchmarks/CoreFx/HttpHandlerDiagnosticsBenchmark.cs b/benchmarks/OpenTracing.Contrib.NetCore.Benchmarks/CoreFx/HttpHandlerDiagnosticsBenchmark.cs index 48e29bc..2b2947b 100644 --- a/benchmarks/OpenTracing.Contrib.NetCore.Benchmarks/CoreFx/HttpHandlerDiagnosticsBenchmark.cs +++ b/benchmarks/OpenTracing.Contrib.NetCore.Benchmarks/CoreFx/HttpHandlerDiagnosticsBenchmark.cs @@ -28,7 +28,7 @@ public void GlobalSetup() .AddOpenTracingCoreServices(builder => { builder.AddBenchmarkTracer(Mode); - builder.AddCoreFx(); + builder.AddHttpHandler(); }) .BuildServiceProvider(); diff --git a/samples/net5.0/OrdersApi/Controllers/OrdersController.cs b/samples/net5.0/OrdersApi/Controllers/OrdersController.cs index 4fa83b6..a2f286a 100644 --- a/samples/net5.0/OrdersApi/Controllers/OrdersController.cs +++ b/samples/net5.0/OrdersApi/Controllers/OrdersController.cs @@ -1,12 +1,14 @@ using System; using System.Collections.Generic; +using System.Linq; using System.Net.Http; using System.Threading.Tasks; -using Shared; using Microsoft.AspNetCore.Mvc; +using Microsoft.EntityFrameworkCore; using Newtonsoft.Json; using OpenTracing; using OrdersApi.DataStore; +using Shared; namespace Samples.OrdersApi.Controllers { @@ -24,6 +26,14 @@ public OrdersController(OrdersDbContext dbContext, HttpClient httpClient, ITrace _tracer = tracer ?? throw new ArgumentNullException(nameof(tracer)); } + [HttpGet] + public async Task Index() + { + var orders = await _dbContext.Orders.ToListAsync(); + + return Ok(orders.Select(x => new { x.OrderId }).ToList()); + } + [HttpPost] public async Task Index([FromBody] PlaceOrderCommand cmd) { diff --git a/samples/net5.0/OrdersApi/Program.cs b/samples/net5.0/OrdersApi/Program.cs index e2ec2c4..57f53a6 100644 --- a/samples/net5.0/OrdersApi/Program.cs +++ b/samples/net5.0/OrdersApi/Program.cs @@ -34,16 +34,6 @@ public static IHostBuilder CreateHostBuilder(string[] args) // We don't need any tracing data for our health endpoint. options.Hosting.IgnorePatterns.Add(ctx => ctx.Request.Path == "/health"); }); - - builder.ConfigureEntityFrameworkCore(options => - { - options.IgnorePatterns.Add(cmd => cmd.Command.CommandText == "SELECT 1"); - }); - - builder.ConfigureMicrosoftSqlClient(options => - { - options.IgnorePatterns.Add(cmd => cmd.CommandText == "SELECT 1"); - }); }); }); } diff --git a/samples/net5.0/Shared/JaegerServiceCollectionExtensions.cs b/samples/net5.0/Shared/JaegerServiceCollectionExtensions.cs index 74d6523..2e8cb57 100644 --- a/samples/net5.0/Shared/JaegerServiceCollectionExtensions.cs +++ b/samples/net5.0/Shared/JaegerServiceCollectionExtensions.cs @@ -6,7 +6,7 @@ using Jaeger.Senders.Thrift; using Microsoft.Extensions.Logging; using OpenTracing; -using OpenTracing.Contrib.NetCore.CoreFx; +using OpenTracing.Contrib.NetCore.Configuration; using OpenTracing.Util; namespace Microsoft.Extensions.DependencyInjection diff --git a/samples/netcoreapp2.1/OrdersApi/Controllers/OrdersController.cs b/samples/netcoreapp2.1/OrdersApi/Controllers/OrdersController.cs index 4fa83b6..a2f286a 100644 --- a/samples/netcoreapp2.1/OrdersApi/Controllers/OrdersController.cs +++ b/samples/netcoreapp2.1/OrdersApi/Controllers/OrdersController.cs @@ -1,12 +1,14 @@ using System; using System.Collections.Generic; +using System.Linq; using System.Net.Http; using System.Threading.Tasks; -using Shared; using Microsoft.AspNetCore.Mvc; +using Microsoft.EntityFrameworkCore; using Newtonsoft.Json; using OpenTracing; using OrdersApi.DataStore; +using Shared; namespace Samples.OrdersApi.Controllers { @@ -24,6 +26,14 @@ public OrdersController(OrdersDbContext dbContext, HttpClient httpClient, ITrace _tracer = tracer ?? throw new ArgumentNullException(nameof(tracer)); } + [HttpGet] + public async Task Index() + { + var orders = await _dbContext.Orders.ToListAsync(); + + return Ok(orders.Select(x => new { x.OrderId }).ToList()); + } + [HttpPost] public async Task Index([FromBody] PlaceOrderCommand cmd) { diff --git a/samples/netcoreapp2.1/Shared/JaegerServiceCollectionExtensions.cs b/samples/netcoreapp2.1/Shared/JaegerServiceCollectionExtensions.cs index 689c787..c0756e4 100644 --- a/samples/netcoreapp2.1/Shared/JaegerServiceCollectionExtensions.cs +++ b/samples/netcoreapp2.1/Shared/JaegerServiceCollectionExtensions.cs @@ -4,7 +4,7 @@ using Jaeger.Samplers; using Microsoft.Extensions.Logging; using OpenTracing; -using OpenTracing.Contrib.NetCore.CoreFx; +using OpenTracing.Contrib.NetCore.Configuration; using OpenTracing.Util; namespace Microsoft.Extensions.DependencyInjection diff --git a/samples/netcoreapp3.1/OrdersApi/Controllers/OrdersController.cs b/samples/netcoreapp3.1/OrdersApi/Controllers/OrdersController.cs index 4fa83b6..a2f286a 100644 --- a/samples/netcoreapp3.1/OrdersApi/Controllers/OrdersController.cs +++ b/samples/netcoreapp3.1/OrdersApi/Controllers/OrdersController.cs @@ -1,12 +1,14 @@ using System; using System.Collections.Generic; +using System.Linq; using System.Net.Http; using System.Threading.Tasks; -using Shared; using Microsoft.AspNetCore.Mvc; +using Microsoft.EntityFrameworkCore; using Newtonsoft.Json; using OpenTracing; using OrdersApi.DataStore; +using Shared; namespace Samples.OrdersApi.Controllers { @@ -24,6 +26,14 @@ public OrdersController(OrdersDbContext dbContext, HttpClient httpClient, ITrace _tracer = tracer ?? throw new ArgumentNullException(nameof(tracer)); } + [HttpGet] + public async Task Index() + { + var orders = await _dbContext.Orders.ToListAsync(); + + return Ok(orders.Select(x => new { x.OrderId }).ToList()); + } + [HttpPost] public async Task Index([FromBody] PlaceOrderCommand cmd) { diff --git a/samples/netcoreapp3.1/OrdersApi/Program.cs b/samples/netcoreapp3.1/OrdersApi/Program.cs index e2ec2c4..57f53a6 100644 --- a/samples/netcoreapp3.1/OrdersApi/Program.cs +++ b/samples/netcoreapp3.1/OrdersApi/Program.cs @@ -34,16 +34,6 @@ public static IHostBuilder CreateHostBuilder(string[] args) // We don't need any tracing data for our health endpoint. options.Hosting.IgnorePatterns.Add(ctx => ctx.Request.Path == "/health"); }); - - builder.ConfigureEntityFrameworkCore(options => - { - options.IgnorePatterns.Add(cmd => cmd.Command.CommandText == "SELECT 1"); - }); - - builder.ConfigureMicrosoftSqlClient(options => - { - options.IgnorePatterns.Add(cmd => cmd.CommandText == "SELECT 1"); - }); }); }); } diff --git a/samples/netcoreapp3.1/Shared/JaegerServiceCollectionExtensions.cs b/samples/netcoreapp3.1/Shared/JaegerServiceCollectionExtensions.cs index 74d6523..2e8cb57 100644 --- a/samples/netcoreapp3.1/Shared/JaegerServiceCollectionExtensions.cs +++ b/samples/netcoreapp3.1/Shared/JaegerServiceCollectionExtensions.cs @@ -6,7 +6,7 @@ using Jaeger.Senders.Thrift; using Microsoft.Extensions.Logging; using OpenTracing; -using OpenTracing.Contrib.NetCore.CoreFx; +using OpenTracing.Contrib.NetCore.Configuration; using OpenTracing.Util; namespace Microsoft.Extensions.DependencyInjection diff --git a/src/OpenTracing.Contrib.NetCore/AspNetCore/AspNetCoreDiagnosticOptions.cs b/src/OpenTracing.Contrib.NetCore/AspNetCore/AspNetCoreDiagnosticOptions.cs index fa24158..ebd5a5d 100644 --- a/src/OpenTracing.Contrib.NetCore/AspNetCore/AspNetCoreDiagnosticOptions.cs +++ b/src/OpenTracing.Contrib.NetCore/AspNetCore/AspNetCoreDiagnosticOptions.cs @@ -2,8 +2,37 @@ namespace OpenTracing.Contrib.NetCore.Configuration { - public class AspNetCoreDiagnosticOptions + public class AspNetCoreDiagnosticOptions : DiagnosticOptions { public HostingOptions Hosting { get; } = new HostingOptions(); + + public AspNetCoreDiagnosticOptions() + { + // We create separate spans for MVC actions & results so we don't need these additional events by default. + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.BeforeOnResourceExecuting"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.BeforeOnActionExecution"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.BeforeOnActionExecuting"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.AfterOnActionExecuting"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.BeforeActionMethod"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.BeforeControllerActionMethod"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.AfterControllerActionMethod"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.AfterActionMethod"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.BeforeOnActionExecuted"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.AfterOnActionExecuted"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.AfterOnActionExecution"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.BeforeOnActionExecuted"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.AfterOnActionExecuted"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.AfterOnActionExecution"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.BeforeOnResultExecuting"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.AfterOnResultExecuting"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.BeforeOnResultExecuted"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.AfterOnResultExecuted"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.BeforeOnResourceExecuted"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.AfterOnResourceExecuted"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.AfterOnResourceExecuting"); + + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.Razor.BeginInstrumentationContext"); + IgnoredEvents.Add("Microsoft.AspNetCore.Mvc.Razor.EndInstrumentationContext"); + } } } diff --git a/src/OpenTracing.Contrib.NetCore/AspNetCore/AspNetCoreDiagnostics.cs b/src/OpenTracing.Contrib.NetCore/AspNetCore/AspNetCoreDiagnostics.cs index a71b577..27ce0f3 100644 --- a/src/OpenTracing.Contrib.NetCore/AspNetCore/AspNetCoreDiagnostics.cs +++ b/src/OpenTracing.Contrib.NetCore/AspNetCore/AspNetCoreDiagnostics.cs @@ -1,8 +1,16 @@ using System; +using System.Collections.Generic; +using Microsoft.AspNetCore.Http; +using Microsoft.AspNetCore.Http.Extensions; +using Microsoft.AspNetCore.Mvc; +using Microsoft.AspNetCore.Mvc.Abstractions; +using Microsoft.AspNetCore.Mvc.Controllers; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; using OpenTracing.Contrib.NetCore.Configuration; using OpenTracing.Contrib.NetCore.Internal; +using OpenTracing.Propagation; +using OpenTracing.Tag; namespace OpenTracing.Contrib.NetCore.AspNetCore { @@ -13,46 +21,265 @@ namespace OpenTracing.Contrib.NetCore.AspNetCore /// for everything so we also only create one observer to ensure best performance. /// Hosting events: https://github.com/aspnet/Hosting/blob/dev/src/Microsoft.AspNetCore.Hosting/Internal/HostingApplicationDiagnostics.cs /// - internal sealed class AspNetCoreDiagnostics : DiagnosticListenerObserver + internal sealed class AspNetCoreDiagnostics : DiagnosticEventObserver { public const string DiagnosticListenerName = "Microsoft.AspNetCore"; - private readonly HostingEventProcessor _hostingEventProcessor; - private readonly MvcEventProcessor _mvcEventProcessor; + private const string HostingScopeItemsKey = "ot-HttpRequestIn"; + private const string ActionScopeItemsKey = "ot-MvcAction"; + private const string ActionResultScopeItemsKey = "ot-MvcActionResult"; + + private const string ActionComponent = "AspNetCore.MvcAction"; + private const string ActionTagActionName = "action"; + private const string ActionTagControllerName = "controller"; + + private const string ResultComponent = "AspNetCore.MvcResult"; + private const string ResultTagType = "result.type"; + + private static readonly PropertyFetcher _httpRequestIn_start_HttpContextFetcher = new PropertyFetcher("HttpContext"); + private static readonly PropertyFetcher _httpRequestIn_stop_HttpContextFetcher = new PropertyFetcher("HttpContext"); + private static readonly PropertyFetcher _unhandledException_HttpContextFetcher = new PropertyFetcher("httpContext"); + private static readonly PropertyFetcher _unhandledException_ExceptionFetcher = new PropertyFetcher("exception"); + private static readonly PropertyFetcher _beforeAction_httpContextFetcher = new PropertyFetcher("httpContext"); + private static readonly PropertyFetcher _beforeAction_ActionDescriptorFetcher = new PropertyFetcher("actionDescriptor"); + private static readonly PropertyFetcher _afterAction_httpContextFetcher = new PropertyFetcher("httpContext"); + private static readonly PropertyFetcher _beforeActionResult_actionContextFetcher = new PropertyFetcher("actionContext"); + private static readonly PropertyFetcher _beforeActionResult_ResultFetcher = new PropertyFetcher("result"); + private static readonly PropertyFetcher _afterActionResult_actionContextFetcher = new PropertyFetcher("actionContext"); + + internal static readonly string NoHostSpecified = string.Empty; + + private readonly AspNetCoreDiagnosticOptions _options; + + public AspNetCoreDiagnostics(ILoggerFactory loggerFactory, ITracer tracer, IOptions options) + : base(loggerFactory, tracer, options?.Value) + { + _options = options?.Value ?? throw new ArgumentNullException(nameof(options)); + } protected override string GetListenerName() => DiagnosticListenerName; - public AspNetCoreDiagnostics(ILoggerFactory loggerFactory, ITracer tracer, - IOptions options, IOptions genericEventOptions) - : base(loggerFactory, tracer, genericEventOptions.Value) + protected override bool IsSupportedEvent(string eventName) { - if (options?.Value == null) - throw new ArgumentNullException(nameof(options)); + return eventName switch + { + // We don't want to get the old deprecated Hosting events. + "Microsoft.AspNetCore.Hosting.BeginRequest" => false, + "Microsoft.AspNetCore.Hosting.EndRequest" => false, + _ => true, + }; + } - _hostingEventProcessor = new HostingEventProcessor(Tracer, Logger, options.Value.Hosting); - _mvcEventProcessor = new MvcEventProcessor(Tracer, Logger, options.Value.Hosting.IgnorePatterns); + protected override IEnumerable HandledEventNames() + { + yield return "Microsoft.AspNetCore.Hosting.HttpRequestIn.Start"; + yield return "Microsoft.AspNetCore.Hosting.UnhandledException"; + yield return "Microsoft.AspNetCore.Hosting.HttpRequestIn.Stop"; + yield return "Microsoft.AspNetCore.Mvc.BeforeAction"; + yield return "Microsoft.AspNetCore.Mvc.AfterAction"; + yield return "Microsoft.AspNetCore.Mvc.BeforeActionResult"; + yield return "Microsoft.AspNetCore.Mvc.AfterActionResult"; } - protected override bool IsEnabled(string eventName) + protected override void HandleEvent(string eventName, object untypedArg) { switch (eventName) { - // We don't want to get the old deprecated Hosting events. - case "Microsoft.AspNetCore.Hosting.BeginRequest": return false; - case "Microsoft.AspNetCore.Hosting.EndRequest": return false; - default: return true; + case "Microsoft.AspNetCore.Hosting.HttpRequestIn.Start": + { + var httpContext = (HttpContext)_httpRequestIn_start_HttpContextFetcher.Fetch(untypedArg); + + if (Tracer.ActiveSpan == null && !_options.StartRootSpans) + { + if (IsLogLevelTraceEnabled) + { + Logger.LogTrace("Ignoring request due to missing parent span"); + } + return; + } + + if (ShouldIgnore(httpContext)) + { + if (IsLogLevelTraceEnabled) + { + Logger.LogTrace("Ignoring request"); + } + } + else + { + var request = httpContext.Request; + + ISpanContext extractedSpanContext = null; + + if (_options.Hosting.ExtractEnabled?.Invoke(httpContext) ?? true) + { + extractedSpanContext = Tracer.Extract(BuiltinFormats.HttpHeaders, new RequestHeadersExtractAdapter(request.Headers)); + } + + string operationName = _options.Hosting.OperationNameResolver(httpContext); + + IScope scope = Tracer.BuildSpan(operationName) + .AsChildOf(extractedSpanContext) + .WithTag(Tags.Component, _options.Hosting.ComponentName) + .WithTag(Tags.SpanKind, Tags.SpanKindServer) + .WithTag(Tags.HttpMethod, request.Method) + .WithTag(Tags.HttpUrl, GetDisplayUrl(request)) + .StartActive(); + + _options.Hosting.OnRequest?.Invoke(scope.Span, httpContext); + + httpContext.Items[HostingScopeItemsKey] = scope; + } + } + break; + + case "Microsoft.AspNetCore.Hosting.UnhandledException": + { + var httpContext = (HttpContext)_unhandledException_HttpContextFetcher.Fetch(untypedArg); + var exception = (Exception)_unhandledException_ExceptionFetcher.Fetch(untypedArg); + + var scope = httpContext.Items[HostingScopeItemsKey] as IScope; + if (scope != null) + { + var span = scope.Span; + + span.SetException(exception); + + _options.Hosting.OnError?.Invoke(span, exception, httpContext); + } + } + break; + + case "Microsoft.AspNetCore.Hosting.HttpRequestIn.Stop": + { + var httpContext = (HttpContext)_httpRequestIn_stop_HttpContextFetcher.Fetch(untypedArg); + + var scope = httpContext.Items[HostingScopeItemsKey] as IScope; + if (scope != null) + { + httpContext.Items.Remove(HostingScopeItemsKey); + + scope.Span.SetTag(Tags.HttpStatus, httpContext.Response.StatusCode); + scope.Dispose(); + } + + httpContext.Items.Remove(ActionResultScopeItemsKey); + httpContext.Items.Remove(ActionScopeItemsKey); + } + break; + + case "Microsoft.AspNetCore.Mvc.BeforeAction": + { + var httpContext = (HttpContext)_beforeAction_httpContextFetcher.Fetch(untypedArg); + + // We only create this span if the entire request should be traced. + var scope = httpContext.Items[HostingScopeItemsKey] as IScope; + if (scope != null) + { + // NOTE: This event is the start of the action pipeline. The action has been selected, the route + // has been selected but no filters have run and model binding hasn't occured. + + var actionDescriptor = (ActionDescriptor)_beforeAction_ActionDescriptorFetcher.Fetch(untypedArg); + var controllerActionDescriptor = actionDescriptor as ControllerActionDescriptor; + + string operationName = controllerActionDescriptor != null + ? $"Action {controllerActionDescriptor.ControllerTypeInfo.FullName}/{controllerActionDescriptor.ActionName}" + : $"Action {actionDescriptor.DisplayName}"; + + var actionScope = Tracer.BuildSpan(operationName) + .AsChildOf(scope.Span) + .WithTag(Tags.Component, ActionComponent) + .WithTag(ActionTagControllerName, controllerActionDescriptor?.ControllerTypeInfo.FullName) + .WithTag(ActionTagActionName, controllerActionDescriptor?.ActionName) + .StartActive(); + + httpContext.Items[ActionScopeItemsKey] = actionScope; + } + } + break; + + case "Microsoft.AspNetCore.Mvc.AfterAction": + { + var httpContext = (HttpContext)_afterAction_httpContextFetcher.Fetch(untypedArg); + var scope = httpContext.Items[ActionScopeItemsKey] as IScope; + if (scope != null) + { + httpContext.Items.Remove(ActionScopeItemsKey); + scope.Dispose(); + } + } + break; + + case "Microsoft.AspNetCore.Mvc.BeforeActionResult": + { + var httpContext = ((ActionContext)_beforeActionResult_actionContextFetcher.Fetch(untypedArg)).HttpContext; + + // We only create this span if the entire request should be traced. + var scope = httpContext.Items[HostingScopeItemsKey] as IScope; + if (scope != null) + { + // NOTE: This event is the start of the result pipeline. The action has been executed, but + // we haven't yet determined which view (if any) will handle the request + + object result = _beforeActionResult_ResultFetcher.Fetch(untypedArg); + + string resultType = result.GetType().Name; + string operationName = $"Result {resultType}"; + + var actionResultScope = Tracer.BuildSpan(operationName) + .AsChildOf(scope.Span) + .WithTag(Tags.Component, ResultComponent) + .WithTag(ResultTagType, resultType) + .StartActive(); + + httpContext.Items[ActionResultScopeItemsKey] = actionResultScope; + } + } + break; + + case "Microsoft.AspNetCore.Mvc.AfterActionResult": + { + var httpContext = ((ActionContext)_afterActionResult_actionContextFetcher.Fetch(untypedArg)).HttpContext; + var scope = httpContext.Items[ActionResultScopeItemsKey] as IScope; + if (scope != null) + { + httpContext.Items.Remove(ActionResultScopeItemsKey); + scope.Dispose(); + } + + } + break; + + default: + HandleUnknownEvent(eventName, untypedArg); + break; } } - protected override void OnNext(string eventName, object untypedArg) + private static string GetDisplayUrl(HttpRequest request) { - bool eventProcessed = _hostingEventProcessor.ProcessEvent(eventName, untypedArg) - || _mvcEventProcessor.ProcessEvent(eventName, untypedArg); + if (request.Host.HasValue) + { + return request.GetDisplayUrl(); + } + + // HTTP 1.0 requests are not required to provide a Host to be valid + // Since this is just for display, we can provide a string that is + // not an actual Uri with only the fields that are specified. + // request.GetDisplayUrl(), used above, will throw an exception + // if request.Host is null. + return $"{request.Scheme}://{NoHostSpecified}{request.PathBase.Value}{request.Path.Value}{request.QueryString.Value}"; + } - if (!eventProcessed) + private bool ShouldIgnore(HttpContext httpContext) + { + foreach (Func ignore in _options.Hosting.IgnorePatterns) { - ProcessUnhandledEvent(eventName, untypedArg); + if (ignore(httpContext)) + return true; } + + return false; } } } diff --git a/src/OpenTracing.Contrib.NetCore/AspNetCore/HostingEventProcessor.cs b/src/OpenTracing.Contrib.NetCore/AspNetCore/HostingEventProcessor.cs deleted file mode 100644 index 6020e3f..0000000 --- a/src/OpenTracing.Contrib.NetCore/AspNetCore/HostingEventProcessor.cs +++ /dev/null @@ -1,128 +0,0 @@ -using System; -using Microsoft.AspNetCore.Http; -using Microsoft.AspNetCore.Http.Extensions; -using Microsoft.Extensions.Logging; -using OpenTracing.Contrib.NetCore.Internal; -using OpenTracing.Propagation; -using OpenTracing.Tag; - -namespace OpenTracing.Contrib.NetCore.AspNetCore -{ - internal class HostingEventProcessor - { - private static readonly PropertyFetcher _httpRequestIn_start_HttpContextFetcher = new PropertyFetcher("HttpContext"); - private static readonly PropertyFetcher _httpRequestIn_stop_HttpContextFetcher = new PropertyFetcher("HttpContext"); - private static readonly PropertyFetcher _unhandledException_HttpContextFetcher = new PropertyFetcher("httpContext"); - private static readonly PropertyFetcher _unhandledException_ExceptionFetcher = new PropertyFetcher("exception"); - - internal static readonly string NoHostSpecified = string.Empty; - - private readonly ITracer _tracer; - private readonly ILogger _logger; - private readonly HostingOptions _options; - - public HostingEventProcessor(ITracer tracer, ILogger logger, HostingOptions options) - { - _tracer = tracer ?? throw new ArgumentNullException(nameof(tracer)); - _logger = logger ?? throw new ArgumentNullException(nameof(logger)); - _options = options ?? throw new ArgumentNullException(nameof(options)); - } - - public bool ProcessEvent(string eventName, object arg) - { - switch (eventName) - { - case "Microsoft.AspNetCore.Hosting.HttpRequestIn.Start": - { - var httpContext = (HttpContext)_httpRequestIn_start_HttpContextFetcher.Fetch(arg); - - if (ShouldIgnore(httpContext)) - { - _logger.LogDebug("Ignoring request"); - } - else - { - var request = httpContext.Request; - - ISpanContext extractedSpanContext = null; - - if (_options.ExtractEnabled?.Invoke(httpContext) ?? true) - { - extractedSpanContext = _tracer.Extract(BuiltinFormats.HttpHeaders, new RequestHeadersExtractAdapter(request.Headers)); - } - - string operationName = _options.OperationNameResolver(httpContext); - - IScope scope = _tracer.BuildSpan(operationName) - .AsChildOf(extractedSpanContext) - .WithTag(Tags.Component, _options.ComponentName) - .WithTag(Tags.SpanKind, Tags.SpanKindServer) - .WithTag(Tags.HttpMethod, request.Method) - .WithTag(Tags.HttpUrl, GetDisplayUrl(request)) - .StartActive(); - - _options.OnRequest?.Invoke(scope.Span, httpContext); - } - } - return true; - - case "Microsoft.AspNetCore.Hosting.UnhandledException": - { - ISpan span = _tracer.ActiveSpan; - if (span != null) - { - var exception = (Exception)_unhandledException_ExceptionFetcher.Fetch(arg); - - span.SetException(exception); - - var httpContext = (HttpContext)_unhandledException_HttpContextFetcher.Fetch(arg); - - _options.OnError?.Invoke(span, exception, httpContext); - } - } - return true; - - case "Microsoft.AspNetCore.Hosting.HttpRequestIn.Stop": - { - IScope scope = _tracer.ScopeManager.Active; - if (scope != null) - { - var httpContext = (HttpContext)_httpRequestIn_stop_HttpContextFetcher.Fetch(arg); - - scope.Span.SetTag(Tags.HttpStatus, httpContext.Response.StatusCode); - scope.Dispose(); - } - } - return true; - - default: return false; - } - } - - private static string GetDisplayUrl(HttpRequest request) - { - if (request.Host.HasValue) - { - return request.GetDisplayUrl(); - } - - // HTTP 1.0 requests are not required to provide a Host to be valid - // Since this is just for display, we can provide a string that is - // not an actual Uri with only the fields that are specified. - // request.GetDisplayUrl(), used above, will throw an exception - // if request.Host is null. - return $"{request.Scheme}://{NoHostSpecified}{request.PathBase.Value}{request.Path.Value}{request.QueryString.Value}"; - } - - private bool ShouldIgnore(HttpContext httpContext) - { - foreach (Func ignore in _options.IgnorePatterns) - { - if (ignore(httpContext)) - return true; - } - - return false; - } - } -} diff --git a/src/OpenTracing.Contrib.NetCore/AspNetCore/MvcEventProcessor.cs b/src/OpenTracing.Contrib.NetCore/AspNetCore/MvcEventProcessor.cs deleted file mode 100644 index 5627442..0000000 --- a/src/OpenTracing.Contrib.NetCore/AspNetCore/MvcEventProcessor.cs +++ /dev/null @@ -1,119 +0,0 @@ -using System; -using System.Collections.Generic; -using System.Linq; -using Microsoft.AspNetCore.Http; -using Microsoft.AspNetCore.Mvc; -using Microsoft.AspNetCore.Mvc.Abstractions; -using Microsoft.AspNetCore.Mvc.Controllers; -using Microsoft.Extensions.Logging; -using OpenTracing.Contrib.NetCore.Internal; -using OpenTracing.Tag; - -namespace OpenTracing.Contrib.NetCore.AspNetCore -{ - internal sealed class MvcEventProcessor - { - private const string ActionComponent = "AspNetCore.MvcAction"; - private const string ActionTagActionName = "action"; - private const string ActionTagControllerName = "controller"; - - private const string ResultComponent = "AspNetCore.MvcResult"; - private const string ResultTagType = "result.type"; - - private static readonly PropertyFetcher _beforeAction_httpContextFetcher = new PropertyFetcher("httpContext"); - private static readonly PropertyFetcher _beforeAction_ActionDescriptorFetcher = new PropertyFetcher("actionDescriptor"); - private static readonly PropertyFetcher _beforeActionResult_actionContextFetcher = new PropertyFetcher("actionContext"); - private static readonly PropertyFetcher _beforeActionResult_ResultFetcher = new PropertyFetcher("result"); - - private readonly ITracer _tracer; - private readonly ILogger _logger; - private readonly IList> _ignorePatterns; - - public MvcEventProcessor(ITracer tracer, ILogger logger, IList> ignorePatterns) - { - _ignorePatterns = ignorePatterns; - _tracer = tracer ?? throw new ArgumentNullException(nameof(tracer)); - _logger = logger ?? throw new ArgumentNullException(nameof(logger)); - } - - public bool ProcessEvent(string eventName, object arg) - { - switch (eventName) - { - case "Microsoft.AspNetCore.Mvc.BeforeAction": - { - var httpContext = (HttpContext)_beforeAction_httpContextFetcher.Fetch(arg); - - if (ShouldIgnore(httpContext)) - { - _logger.LogDebug("Ignoring request"); - } - else - { - // NOTE: This event is the start of the action pipeline. The action has been selected, the route - // has been selected but no filters have run and model binding hasn't occured. - - var actionDescriptor = (ActionDescriptor)_beforeAction_ActionDescriptorFetcher.Fetch(arg); - var controllerActionDescriptor = actionDescriptor as ControllerActionDescriptor; - - string operationName = controllerActionDescriptor != null - ? $"Action {controllerActionDescriptor.ControllerTypeInfo.FullName}/{controllerActionDescriptor.ActionName}" - : $"Action {actionDescriptor.DisplayName}"; - - _tracer.BuildSpan(operationName) - .WithTag(Tags.Component, ActionComponent) - .WithTag(ActionTagControllerName, controllerActionDescriptor?.ControllerTypeInfo.FullName) - .WithTag(ActionTagActionName, controllerActionDescriptor?.ActionName) - .StartActive(); - } - } - return true; - - case "Microsoft.AspNetCore.Mvc.AfterAction": - { - _tracer.ScopeManager.Active?.Dispose(); - } - return true; - - case "Microsoft.AspNetCore.Mvc.BeforeActionResult": - { - var httpContext = ((ActionContext) _beforeActionResult_actionContextFetcher.Fetch(arg)).HttpContext; - - if (ShouldIgnore(httpContext)) - { - _logger.LogDebug("Ignoring request"); - } - else - { - // NOTE: This event is the start of the result pipeline. The action has been executed, but - // we haven't yet determined which view (if any) will handle the request - - object result = _beforeActionResult_ResultFetcher.Fetch(arg); - - string resultType = result.GetType().Name; - string operationName = $"Result {resultType}"; - - _tracer.BuildSpan(operationName) - .WithTag(Tags.Component, ResultComponent) - .WithTag(ResultTagType, resultType) - .StartActive(); - } - } - return true; - - case "Microsoft.AspNetCore.Mvc.AfterActionResult": - { - _tracer.ScopeManager.Active?.Dispose(); - } - return true; - - default: return false; - } - } - - private bool ShouldIgnore(HttpContext httpContext) - { - return _ignorePatterns.Any(ignore => ignore(httpContext)); - } - } -} diff --git a/src/OpenTracing.Contrib.NetCore/Configuration/DiagnosticOptions.cs b/src/OpenTracing.Contrib.NetCore/Configuration/DiagnosticOptions.cs new file mode 100644 index 0000000..ee585c9 --- /dev/null +++ b/src/OpenTracing.Contrib.NetCore/Configuration/DiagnosticOptions.cs @@ -0,0 +1,22 @@ +using System.Collections.Generic; + +namespace OpenTracing.Contrib.NetCore.Configuration +{ + public abstract class DiagnosticOptions + { + /// + /// Defines whether or not generic events from this DiagnostSource should be logged as events. + /// + public bool LogEvents { get; set; } = true; + + /// + /// Defines specific event names that should NOT be logged as events. Set to `false` if you don't want any events to be logged. + /// + public HashSet IgnoredEvents { get; } = new HashSet(); + + /// + /// Defines whether or not a span should be created if there is no parent span. + /// + public bool StartRootSpans { get; set; } = true; + } +} diff --git a/src/OpenTracing.Contrib.NetCore/Configuration/OpenTracingBuilderExtensions.cs b/src/OpenTracing.Contrib.NetCore/Configuration/OpenTracingBuilderExtensions.cs index b6a2aa9..38f3b4c 100644 --- a/src/OpenTracing.Contrib.NetCore/Configuration/OpenTracingBuilderExtensions.cs +++ b/src/OpenTracing.Contrib.NetCore/Configuration/OpenTracingBuilderExtensions.cs @@ -3,11 +3,13 @@ using Microsoft.Extensions.Logging; using OpenTracing.Contrib.NetCore.AspNetCore; using OpenTracing.Contrib.NetCore.Configuration; -using OpenTracing.Contrib.NetCore.CoreFx; using OpenTracing.Contrib.NetCore.EntityFrameworkCore; +using OpenTracing.Contrib.NetCore.GenericListeners; +using OpenTracing.Contrib.NetCore.HttpHandler; using OpenTracing.Contrib.NetCore.Internal; using OpenTracing.Contrib.NetCore.Logging; using OpenTracing.Contrib.NetCore.MicrosoftSqlClient; +using OpenTracing.Contrib.NetCore.SystemSqlClient; namespace Microsoft.Extensions.DependencyInjection { @@ -27,7 +29,7 @@ internal static IOpenTracingBuilder AddDiagnosticSubscriber /// Adds instrumentation for ASP.NET Core. /// - public static IOpenTracingBuilder AddAspNetCore(this IOpenTracingBuilder builder) + public static IOpenTracingBuilder AddAspNetCore(this IOpenTracingBuilder builder, Action options = null) { if (builder == null) throw new ArgumentNullException(nameof(builder)); @@ -35,15 +37,12 @@ public static IOpenTracingBuilder AddAspNetCore(this IOpenTracingBuilder builder builder.AddDiagnosticSubscriber(); builder.ConfigureGenericDiagnostics(genericOptions => genericOptions.IgnoredListenerNames.Add(AspNetCoreDiagnostics.DiagnosticListenerName)); - return builder; - } + // Our default behavior for ASP.NET is that we only want spans if the request itself is traced + builder.ConfigureEntityFrameworkCore(opt => opt.StartRootSpans = false); + builder.ConfigureHttpHandler(opt => opt.StartRootSpans = false); + builder.ConfigureMicrosoftSqlClient(opt => opt.StartRootSpans = false); + builder.ConfigureSystemSqlClient(opt => opt.StartRootSpans = false); - /// - /// Adds instrumentation for ASP.NET Core. - /// - public static IOpenTracingBuilder AddAspNetCore(this IOpenTracingBuilder builder, Action options) - { - AddAspNetCore(builder); return ConfigureAspNetCore(builder, options); } @@ -61,25 +60,20 @@ public static IOpenTracingBuilder ConfigureAspNetCore(this IOpenTracingBuilder b } /// - /// Adds instrumentation for the .NET framework BCL. + /// Adds instrumentation for System.Net.Http. /// - public static IOpenTracingBuilder AddCoreFx(this IOpenTracingBuilder builder) + public static IOpenTracingBuilder AddHttpHandler(this IOpenTracingBuilder builder, Action options = null) { if (builder == null) throw new ArgumentNullException(nameof(builder)); - builder.AddDiagnosticSubscriber(); - builder.AddDiagnosticSubscriber(); builder.ConfigureGenericDiagnostics(options => options.IgnoredListenerNames.Add(HttpHandlerDiagnostics.DiagnosticListenerName)); - builder.AddDiagnosticSubscriber(); - builder.ConfigureGenericDiagnostics(options => options.IgnoredListenerNames.Add(SqlClientDiagnostics.DiagnosticListenerName)); - - return builder; + return ConfigureHttpHandler(builder, options); } - public static IOpenTracingBuilder ConfigureGenericDiagnostics(this IOpenTracingBuilder builder, Action options) + public static IOpenTracingBuilder ConfigureHttpHandler(this IOpenTracingBuilder builder, Action options) { if (builder == null) throw new ArgumentNullException(nameof(builder)); @@ -92,7 +86,24 @@ public static IOpenTracingBuilder ConfigureGenericDiagnostics(this IOpenTracingB return builder; } - public static IOpenTracingBuilder ConfigureGenericEvents(this IOpenTracingBuilder builder, Action options) + /// + /// Adds instrumentation for Entity Framework Core. + /// + public static IOpenTracingBuilder AddEntityFrameworkCore(this IOpenTracingBuilder builder, Action options = null) + { + if (builder == null) + throw new ArgumentNullException(nameof(builder)); + + builder.AddDiagnosticSubscriber(); + builder.ConfigureGenericDiagnostics(genericOptions => genericOptions.IgnoredListenerNames.Add(EntityFrameworkCoreDiagnostics.DiagnosticListenerName)); + + return ConfigureEntityFrameworkCore(builder, options); + } + + /// + /// Configuration options for the instrumentation of Entity Framework Core. + /// + public static IOpenTracingBuilder ConfigureEntityFrameworkCore(this IOpenTracingBuilder builder, Action options) { if (builder == null) throw new ArgumentNullException(nameof(builder)); @@ -105,7 +116,18 @@ public static IOpenTracingBuilder ConfigureGenericEvents(this IOpenTracingBuilde return builder; } - public static IOpenTracingBuilder ConfigureSqlClientDiagnostics(this IOpenTracingBuilder builder, Action options) + + /// + /// Adds instrumentation for generic DiagnosticListeners. + /// + public static IOpenTracingBuilder AddGenericDiagnostics(this IOpenTracingBuilder builder, Action options = null) + { + builder.AddDiagnosticSubscriber(); + + return ConfigureGenericDiagnostics(builder, options); + } + + public static IOpenTracingBuilder ConfigureGenericDiagnostics(this IOpenTracingBuilder builder, Action options) { if (builder == null) throw new ArgumentNullException(nameof(builder)); @@ -118,10 +140,23 @@ public static IOpenTracingBuilder ConfigureSqlClientDiagnostics(this IOpenTracin return builder; } + /// + /// Disables tracing for all diagnostic listeners that don't have an explicit implementation. + /// + public static IOpenTracingBuilder RemoveGenericDiagnostics(this IOpenTracingBuilder builder) + { + if (builder == null) + throw new ArgumentNullException(nameof(builder)); + + builder.Services.RemoveAll(); + + return builder; + } + /// /// Adds instrumentation for Microsoft.Data.SqlClient. /// - public static IOpenTracingBuilder AddMicrosoftSqlClient(this IOpenTracingBuilder builder) + public static IOpenTracingBuilder AddMicrosoftSqlClient(this IOpenTracingBuilder builder, Action options = null) { if (builder == null) throw new ArgumentNullException(nameof(builder)); @@ -129,7 +164,7 @@ public static IOpenTracingBuilder AddMicrosoftSqlClient(this IOpenTracingBuilder builder.AddDiagnosticSubscriber(); builder.ConfigureGenericDiagnostics(genericOptions => genericOptions.IgnoredListenerNames.Add(MicrosoftSqlClientDiagnostics.DiagnosticListenerName)); - return builder; + return ConfigureMicrosoftSqlClient(builder, options); } /// @@ -149,32 +184,20 @@ public static IOpenTracingBuilder ConfigureMicrosoftSqlClient(this IOpenTracingB } /// - /// Adds instrumentation for Entity Framework Core. + /// Adds instrumentation for System.Data.SqlClient. /// - public static IOpenTracingBuilder AddEntityFrameworkCore(this IOpenTracingBuilder builder) + public static IOpenTracingBuilder AddSystemSqlClient(this IOpenTracingBuilder builder, Action options = null) { if (builder == null) throw new ArgumentNullException(nameof(builder)); - builder.AddDiagnosticSubscriber(); - builder.ConfigureGenericDiagnostics(genericOptions => genericOptions.IgnoredListenerNames.Add(EntityFrameworkCoreDiagnostics.DiagnosticListenerName)); + builder.AddDiagnosticSubscriber(); + builder.ConfigureGenericDiagnostics(options => options.IgnoredListenerNames.Add(SqlClientDiagnostics.DiagnosticListenerName)); - return builder; + return ConfigureSystemSqlClient(builder, options); } - /// - /// Adds instrumentation for Entity Framework Core. - /// - public static IOpenTracingBuilder AddEntityFrameworkCore(this IOpenTracingBuilder builder, Action options) - { - AddEntityFrameworkCore(builder); - return ConfigureEntityFrameworkCore(builder, options); - } - - /// - /// Configuration options for the instrumentation of Entity Framework Core. - /// - public static IOpenTracingBuilder ConfigureEntityFrameworkCore(this IOpenTracingBuilder builder, Action options) + public static IOpenTracingBuilder ConfigureSystemSqlClient(this IOpenTracingBuilder builder, Action options) { if (builder == null) throw new ArgumentNullException(nameof(builder)); @@ -198,6 +221,9 @@ public static IOpenTracingBuilder AddLoggerProvider(this IOpenTracingBuilder bui // All interesting request-specific logs are instrumented via DiagnosticSource. options.AddFilter("Microsoft.AspNetCore.Hosting", LogLevel.None); + // The "Information"-level in ASP.NET Core is too verbose. + options.AddFilter("Microsoft.AspNetCore", LogLevel.Warning); + // EF Core is sending everything to DiagnosticSource AND ILogger so we completely disable the category. options.AddFilter("Microsoft.EntityFrameworkCore", LogLevel.None); }); diff --git a/src/OpenTracing.Contrib.NetCore/Configuration/ServiceCollectionExtensions.cs b/src/OpenTracing.Contrib.NetCore/Configuration/ServiceCollectionExtensions.cs index dc6d904..b1e5862 100644 --- a/src/OpenTracing.Contrib.NetCore/Configuration/ServiceCollectionExtensions.cs +++ b/src/OpenTracing.Contrib.NetCore/Configuration/ServiceCollectionExtensions.cs @@ -21,10 +21,12 @@ public static IServiceCollection AddOpenTracing(this IServiceCollection services return services.AddOpenTracingCoreServices(otBuilder => { - otBuilder.AddCoreFx(); otBuilder.AddLoggerProvider(); otBuilder.AddEntityFrameworkCore(); + otBuilder.AddGenericDiagnostics(); + otBuilder.AddHttpHandler(); otBuilder.AddMicrosoftSqlClient(); + otBuilder.AddSystemSqlClient(); if (AssemblyExists("Microsoft.AspNetCore.Hosting")) { diff --git a/src/OpenTracing.Contrib.NetCore/CoreFx/GenericDiagnosticOptions.cs b/src/OpenTracing.Contrib.NetCore/CoreFx/GenericDiagnosticOptions.cs deleted file mode 100644 index 4a38a09..0000000 --- a/src/OpenTracing.Contrib.NetCore/CoreFx/GenericDiagnosticOptions.cs +++ /dev/null @@ -1,27 +0,0 @@ -using System.Collections.Generic; - -namespace OpenTracing.Contrib.NetCore.CoreFx -{ - public sealed class GenericDiagnosticOptions - { - public HashSet IgnoredListenerNames { get; } = new HashSet(); - - public Dictionary> IgnoredEvents { get; } = new Dictionary>(); - - public void IgnoreEvent(string diagnosticListenerName, string eventName) - { - if (diagnosticListenerName == null || eventName == null) - return; - - HashSet ignoredListenerEvents; - - if (!IgnoredEvents.TryGetValue(diagnosticListenerName, out ignoredListenerEvents)) - { - ignoredListenerEvents = new HashSet(); - IgnoredEvents.Add(diagnosticListenerName, ignoredListenerEvents); - } - - ignoredListenerEvents.Add(eventName); - } - } -} diff --git a/src/OpenTracing.Contrib.NetCore/EntityFrameworkCore/EntityFrameworkCoreDiagnosticOptions.cs b/src/OpenTracing.Contrib.NetCore/EntityFrameworkCore/EntityFrameworkCoreDiagnosticOptions.cs index 2f267cb..4200aaa 100644 --- a/src/OpenTracing.Contrib.NetCore/EntityFrameworkCore/EntityFrameworkCoreDiagnosticOptions.cs +++ b/src/OpenTracing.Contrib.NetCore/EntityFrameworkCore/EntityFrameworkCoreDiagnosticOptions.cs @@ -2,9 +2,9 @@ using System.Collections.Generic; using Microsoft.EntityFrameworkCore.Diagnostics; -namespace OpenTracing.Contrib.NetCore.EntityFrameworkCore +namespace OpenTracing.Contrib.NetCore.Configuration { - public class EntityFrameworkCoreDiagnosticOptions + public class EntityFrameworkCoreDiagnosticOptions : DiagnosticOptions { // NOTE: Everything here that references any EFCore types MUST NOT be initialized in the constructor as that would throw on applications that don't reference EFCore. @@ -14,6 +14,29 @@ public class EntityFrameworkCoreDiagnosticOptions private List> _ignorePatterns; private Func _operationNameResolver; + public EntityFrameworkCoreDiagnosticOptions() + { + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.ChangeTracking.StartedTracking"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.ChangeTracking.DetectChangesStarting"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.ChangeTracking.DetectChangesCompleted"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.ChangeTracking.ForeignKeyChangeDetected"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.ChangeTracking.StateChanged"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.ChangeTracking.ValueGenerated"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Command.CommandCreating"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Command.CommandCreated"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Command.DataReaderDisposing"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Connection.ConnectionOpening"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Connection.ConnectionOpened"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Connection.ConnectionClosing"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Connection.ConnectionClosed"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Transaction.TransactionStarting"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Transaction.TransactionStarted"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Transaction.TransactionCommitting"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Transaction.TransactionCommitted"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Database.Transaction.TransactionDisposed"); + IgnoredEvents.Add("Microsoft.EntityFrameworkCore.Infrastructure.ContextDisposed"); + } + /// /// A list of delegates that define whether or not a given EF Core command should be ignored. /// diff --git a/src/OpenTracing.Contrib.NetCore/EntityFrameworkCore/EntityFrameworkCoreDiagnostics.cs b/src/OpenTracing.Contrib.NetCore/EntityFrameworkCore/EntityFrameworkCoreDiagnostics.cs index 682eb92..b524b20 100644 --- a/src/OpenTracing.Contrib.NetCore/EntityFrameworkCore/EntityFrameworkCoreDiagnostics.cs +++ b/src/OpenTracing.Contrib.NetCore/EntityFrameworkCore/EntityFrameworkCoreDiagnostics.cs @@ -1,13 +1,16 @@ using System; +using System.Collections.Concurrent; +using System.Collections.Generic; using Microsoft.EntityFrameworkCore.Diagnostics; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; +using OpenTracing.Contrib.NetCore.Configuration; using OpenTracing.Contrib.NetCore.Internal; using OpenTracing.Tag; namespace OpenTracing.Contrib.NetCore.EntityFrameworkCore { - internal sealed class EntityFrameworkCoreDiagnostics : DiagnosticListenerObserver + internal sealed class EntityFrameworkCoreDiagnostics : DiagnosticEventObserver { // https://github.com/aspnet/EntityFrameworkCore/blob/dev/src/EFCore/DbLoggerCategory.cs public const string DiagnosticListenerName = "Microsoft.EntityFrameworkCore"; @@ -16,17 +19,26 @@ internal sealed class EntityFrameworkCoreDiagnostics : DiagnosticListenerObserve private const string TagIsAsync = "db.async"; private readonly EntityFrameworkCoreDiagnosticOptions _options; - - protected override string GetListenerName() => DiagnosticListenerName; + private readonly ConcurrentDictionary _scopeStorage; public EntityFrameworkCoreDiagnostics(ILoggerFactory loggerFactory, ITracer tracer, - IOptions options, IOptions genericEventOptions) - : base(loggerFactory, tracer, genericEventOptions.Value) + IOptions options) + : base(loggerFactory, tracer, options?.Value) { _options = options?.Value ?? throw new ArgumentNullException(nameof(options)); + _scopeStorage = new ConcurrentDictionary(); + } + + protected override string GetListenerName() => DiagnosticListenerName; + + protected override IEnumerable HandledEventNames() + { + yield return "Microsoft.EntityFrameworkCore.Database.Command.CommandExecuting"; + yield return "Microsoft.EntityFrameworkCore.Database.Command.CommandExecuted"; + yield return "Microsoft.EntityFrameworkCore.Database.Command.CommandError"; } - protected override void OnNext(string eventName, object untypedArg) + protected override void HandleEvent(string eventName, object untypedArg) { switch (eventName) { @@ -34,15 +46,30 @@ protected override void OnNext(string eventName, object untypedArg) { CommandEventData args = (CommandEventData)untypedArg; + var activeSpan = Tracer.ActiveSpan; + + if (activeSpan == null && !_options.StartRootSpans) + { + if (IsLogLevelTraceEnabled) + { + Logger.LogTrace("Ignoring EF command due to missing parent span"); + } + return; + } + if (IgnoreEvent(args)) { - Logger.LogDebug("Ignoring EF command due to IgnorePatterns"); + if (IsLogLevelTraceEnabled) + { + Logger.LogTrace("Ignoring EF command due to IgnorePatterns"); + } return; } string operationName = _options.OperationNameResolver(args); - Tracer.BuildSpan(operationName) + var scope = Tracer.BuildSpan(operationName) + .AsChildOf(activeSpan) .WithTag(Tags.SpanKind, Tags.SpanKindClient) .WithTag(Tags.Component, _options.ComponentName) .WithTag(Tags.DbInstance, args.Command.Connection.Database) @@ -50,12 +77,19 @@ protected override void OnNext(string eventName, object untypedArg) .WithTag(TagMethod, args.ExecuteMethod.ToString()) .WithTag(TagIsAsync, args.IsAsync) .StartActive(); + + _scopeStorage.TryAdd(args.CommandId, scope); } break; case "Microsoft.EntityFrameworkCore.Database.Command.CommandExecuted": { - DisposeActiveScope(isScopeRequired: false); + CommandExecutedEventData args = (CommandExecutedEventData)untypedArg; + + if (_scopeStorage.TryRemove(args.CommandId, out var scope)) + { + scope.Dispose(); + } } break; @@ -65,14 +99,16 @@ protected override void OnNext(string eventName, object untypedArg) // The "CommandExecuted" event is NOT called in case of an exception, // so we have to dispose the scope here as well! - DisposeActiveScope(isScopeRequired: false, exception: args.Exception); + if (_scopeStorage.TryRemove(args.CommandId, out var scope)) + { + scope.Span.SetException(args.Exception); + scope.Dispose(); + } } break; default: - { - ProcessUnhandledEvent(eventName, untypedArg); - } + HandleUnknownEvent(eventName, untypedArg); break; } } diff --git a/src/OpenTracing.Contrib.NetCore/GenericListeners/GenericDiagnosticOptions.cs b/src/OpenTracing.Contrib.NetCore/GenericListeners/GenericDiagnosticOptions.cs new file mode 100644 index 0000000..3711476 --- /dev/null +++ b/src/OpenTracing.Contrib.NetCore/GenericListeners/GenericDiagnosticOptions.cs @@ -0,0 +1,11 @@ +using System.Collections.Generic; + +namespace OpenTracing.Contrib.NetCore.Configuration +{ + public sealed class GenericDiagnosticOptions + { + public HashSet IgnoredListenerNames { get; } = new HashSet(); + + public Dictionary> IgnoredEvents { get; } = new Dictionary>(); + } +} diff --git a/src/OpenTracing.Contrib.NetCore/CoreFx/GenericDiagnostics.cs b/src/OpenTracing.Contrib.NetCore/GenericListeners/GenericDiagnostics.cs similarity index 75% rename from src/OpenTracing.Contrib.NetCore/CoreFx/GenericDiagnostics.cs rename to src/OpenTracing.Contrib.NetCore/GenericListeners/GenericDiagnostics.cs index b2fbde0..88990c6 100644 --- a/src/OpenTracing.Contrib.NetCore/CoreFx/GenericDiagnostics.cs +++ b/src/OpenTracing.Contrib.NetCore/GenericListeners/GenericDiagnostics.cs @@ -3,9 +3,10 @@ using System.Diagnostics; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; +using OpenTracing.Contrib.NetCore.Configuration; using OpenTracing.Contrib.NetCore.Internal; -namespace OpenTracing.Contrib.NetCore.CoreFx +namespace OpenTracing.Contrib.NetCore.GenericListeners { /// /// A subscriber that logs ALL events to . @@ -13,29 +14,23 @@ namespace OpenTracing.Contrib.NetCore.CoreFx internal sealed class GenericDiagnostics : DiagnosticObserver { private readonly GenericDiagnosticOptions _options; - private readonly GenericEventOptions _genericEventOptions; - public GenericDiagnostics(ILoggerFactory loggerFactory, ITracer tracer, IOptions options, - IOptions genericEventOptions) + public GenericDiagnostics(ILoggerFactory loggerFactory, ITracer tracer, IOptions options) : base(loggerFactory, tracer) { _options = options?.Value ?? throw new ArgumentNullException(nameof(options)); - _genericEventOptions = genericEventOptions.Value; } public override IDisposable SubscribeIfMatch(DiagnosticListener diagnosticListener) { - if (_genericEventOptions.IgnoreAll) + if (_options.IgnoredListenerNames.Contains(diagnosticListener.Name)) { return null; } - if (!_options.IgnoredListenerNames.Contains(diagnosticListener.Name)) - { - return new GenericDiagnosticsSubscription(this, diagnosticListener, _genericEventOptions); - } + _options.IgnoredEvents.TryGetValue(diagnosticListener.Name, out var ignoredListenerEvents); - return null; + return new GenericDiagnosticsSubscription(this, diagnosticListener, ignoredListenerEvents); } private class GenericDiagnosticsSubscription : IObserver>, IDisposable @@ -49,18 +44,13 @@ private class GenericDiagnosticsSubscription : IObserver ignoredEvents) { _subscriber = subscriber; + _ignoredEvents = ignoredEvents; _listenerName = diagnosticListener.Name; - subscriber._options.IgnoredEvents.TryGetValue(diagnosticListener.Name, out _ignoredEvents); - - if (!genericEventOptions.IsIgnored(diagnosticListener.Name)) - { - _genericEventProcessor = new GenericEventProcessor(_listenerName, _subscriber.Tracer, subscriber.Logger, - genericEventOptions); - } + _genericEventProcessor = new GenericEventProcessor(_listenerName, _subscriber.Tracer, subscriber.Logger); _subscription = diagnosticListener.Subscribe(this, IsEnabled); } diff --git a/src/OpenTracing.Contrib.NetCore/CoreFx/HttpHandlerDiagnosticOptions.cs b/src/OpenTracing.Contrib.NetCore/HttpHandler/HttpHandlerDiagnosticOptions.cs similarity index 95% rename from src/OpenTracing.Contrib.NetCore/CoreFx/HttpHandlerDiagnosticOptions.cs rename to src/OpenTracing.Contrib.NetCore/HttpHandler/HttpHandlerDiagnosticOptions.cs index 5f78415..0b002a4 100644 --- a/src/OpenTracing.Contrib.NetCore/CoreFx/HttpHandlerDiagnosticOptions.cs +++ b/src/OpenTracing.Contrib.NetCore/HttpHandler/HttpHandlerDiagnosticOptions.cs @@ -2,9 +2,9 @@ using System.Collections.Generic; using System.Net.Http; -namespace OpenTracing.Contrib.NetCore.CoreFx +namespace OpenTracing.Contrib.NetCore.Configuration { - public class HttpHandlerDiagnosticOptions + public class HttpHandlerDiagnosticOptions : DiagnosticOptions { public const string PropertyIgnore = "ot-ignore"; diff --git a/src/OpenTracing.Contrib.NetCore/CoreFx/HttpHandlerDiagnostics.cs b/src/OpenTracing.Contrib.NetCore/HttpHandler/HttpHandlerDiagnostics.cs similarity index 72% rename from src/OpenTracing.Contrib.NetCore/CoreFx/HttpHandlerDiagnostics.cs rename to src/OpenTracing.Contrib.NetCore/HttpHandler/HttpHandlerDiagnostics.cs index a2353d9..fa6267c 100644 --- a/src/OpenTracing.Contrib.NetCore/CoreFx/HttpHandlerDiagnostics.cs +++ b/src/OpenTracing.Contrib.NetCore/HttpHandler/HttpHandlerDiagnostics.cs @@ -4,18 +4,19 @@ using System.Threading.Tasks; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; +using OpenTracing.Contrib.NetCore.Configuration; using OpenTracing.Contrib.NetCore.Internal; using OpenTracing.Propagation; using OpenTracing.Tag; -namespace OpenTracing.Contrib.NetCore.CoreFx +namespace OpenTracing.Contrib.NetCore.HttpHandler { /// /// Instruments outgoing HTTP calls that use . /// See https://github.com/dotnet/corefx/blob/master/src/System.Net.Http/src/System/Net/Http/DiagnosticsHandler.cs /// and https://github.com/dotnet/corefx/blob/master/src/System.Net.Http/src/System/Net/Http/DiagnosticsHandlerLoggingStrings.cs /// - internal sealed class HttpHandlerDiagnostics : DiagnosticListenerObserver + internal sealed class HttpHandlerDiagnostics : DiagnosticEventObserver { public const string DiagnosticListenerName = "HttpHandlerDiagnosticListener"; @@ -30,32 +31,66 @@ internal sealed class HttpHandlerDiagnostics : DiagnosticListenerObserver private readonly HttpHandlerDiagnosticOptions _options; - protected override string GetListenerName() => DiagnosticListenerName; - public HttpHandlerDiagnostics(ILoggerFactory loggerFactory, ITracer tracer, - IOptions options, IOptions genericEventOptions) - : base(loggerFactory, tracer, genericEventOptions.Value) + IOptions options) + : base(loggerFactory, tracer, options?.Value) { _options = options?.Value ?? throw new ArgumentNullException(nameof(options)); } - protected override void OnNext(string eventName, object arg) + protected override string GetListenerName() => DiagnosticListenerName; + + protected override bool IsSupportedEvent(string eventName) + { + return eventName switch + { + // We don't want to get the old deprecated events. + // https://github.com/dotnet/runtime/blob/master/src/libraries/System.Net.Http/src/System/Net/Http/DiagnosticsHandlerLoggingStrings.cs + "System.Net.Http.Request" => false, + "System.Net.Http.Response" => false, + _ => true, + }; + } + + protected override IEnumerable HandledEventNames() + { + yield return "System.Net.Http.HttpRequestOut.Start"; + yield return "System.Net.Http.Exception"; + yield return "System.Net.Http.HttpRequestOut.Stop"; + } + + protected override void HandleEvent(string eventName, object untypedArg) { switch (eventName) { case "System.Net.Http.HttpRequestOut.Start": { - var request = (HttpRequestMessage)_activityStart_RequestFetcher.Fetch(arg); + var request = (HttpRequestMessage)_activityStart_RequestFetcher.Fetch(untypedArg); + + var activeSpan = Tracer.ActiveSpan; + + if (activeSpan == null && !_options.StartRootSpans) + { + if (IsLogLevelTraceEnabled) + { + Logger.LogTrace("Ignoring Request due to missing parent span"); + } + return; + } if (IgnoreRequest(request)) { - Logger.LogDebug("Ignoring Request {RequestUri}", request.RequestUri); + if (IsLogLevelTraceEnabled) + { + Logger.LogTrace("Ignoring Request {RequestUri}", request.RequestUri); + } return; } string operationName = _options.OperationNameResolver(request); ISpan span = Tracer.BuildSpan(operationName) + .AsChildOf(activeSpan) .WithTag(Tags.SpanKind, Tags.SpanKindClient) .WithTag(Tags.Component, _options.ComponentName) .WithTag(Tags.HttpMethod, request.Method.ToString()) @@ -78,12 +113,12 @@ protected override void OnNext(string eventName, object arg) case "System.Net.Http.Exception": { - var request = (HttpRequestMessage)_exception_RequestFetcher.Fetch(arg); + var request = (HttpRequestMessage)_exception_RequestFetcher.Fetch(untypedArg); var requestOptions = GetRequestOptions(request); if (requestOptions.TryGetValue(PropertiesKey, out object objSpan) && objSpan is ISpan span) { - var exception = (Exception)_exception_ExceptionFetcher.Fetch(arg); + var exception = (Exception)_exception_ExceptionFetcher.Fetch(untypedArg); span.SetException(exception); @@ -94,15 +129,15 @@ protected override void OnNext(string eventName, object arg) case "System.Net.Http.HttpRequestOut.Stop": { - var request = (HttpRequestMessage)_activityStop_RequestFetcher.Fetch(arg); + var request = (HttpRequestMessage)_activityStop_RequestFetcher.Fetch(untypedArg); var requestOptions = GetRequestOptions(request); if (requestOptions.TryGetValue(PropertiesKey, out object objSpan) && objSpan is ISpan span) { requestOptions.Remove(PropertiesKey); - var response = (HttpResponseMessage)_activityStop_ResponseFetcher.Fetch(arg); - var requestTaskStatus = (TaskStatus)_activityStop_RequestTaskStatusFetcher.Fetch(arg); + var response = (HttpResponseMessage)_activityStop_ResponseFetcher.Fetch(untypedArg); + var requestTaskStatus = (TaskStatus)_activityStop_RequestTaskStatusFetcher.Fetch(untypedArg); if (response != null) { @@ -118,6 +153,10 @@ protected override void OnNext(string eventName, object arg) } } break; + + default: + HandleUnknownEvent(eventName, untypedArg); + break; } } diff --git a/src/OpenTracing.Contrib.NetCore/CoreFx/HttpHeadersInjectAdapter.cs b/src/OpenTracing.Contrib.NetCore/HttpHandler/HttpHeadersInjectAdapter.cs similarity index 94% rename from src/OpenTracing.Contrib.NetCore/CoreFx/HttpHeadersInjectAdapter.cs rename to src/OpenTracing.Contrib.NetCore/HttpHandler/HttpHeadersInjectAdapter.cs index e030b63..4b93401 100644 --- a/src/OpenTracing.Contrib.NetCore/CoreFx/HttpHeadersInjectAdapter.cs +++ b/src/OpenTracing.Contrib.NetCore/HttpHandler/HttpHeadersInjectAdapter.cs @@ -4,7 +4,7 @@ using System.Net.Http.Headers; using OpenTracing.Propagation; -namespace OpenTracing.Contrib.NetCore.CoreFx +namespace OpenTracing.Contrib.NetCore.HttpHandler { internal sealed class HttpHeadersInjectAdapter : ITextMap { diff --git a/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticListenerObserver.cs b/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticEventObserver.cs similarity index 60% rename from src/OpenTracing.Contrib.NetCore/Internal/DiagnosticListenerObserver.cs rename to src/OpenTracing.Contrib.NetCore/Internal/DiagnosticEventObserver.cs index 32b5d14..f32cf07 100644 --- a/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticListenerObserver.cs +++ b/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticEventObserver.cs @@ -2,25 +2,27 @@ using System.Collections.Generic; using System.Diagnostics; using Microsoft.Extensions.Logging; +using OpenTracing.Contrib.NetCore.Configuration; namespace OpenTracing.Contrib.NetCore.Internal { - - internal abstract class DiagnosticListenerObserver : DiagnosticObserver, IObserver> + /// + /// Base class that allows handling events from a single . + /// + internal abstract class DiagnosticEventObserver + : DiagnosticObserver, IObserver> { + private readonly DiagnosticOptions _options; private readonly GenericEventProcessor _genericEventProcessor; - /// - /// The name of the that should be instrumented. - /// - protected abstract string GetListenerName(); - - protected DiagnosticListenerObserver(ILoggerFactory loggerFactory, ITracer tracer, GenericEventOptions options) + protected DiagnosticEventObserver(ILoggerFactory loggerFactory, ITracer tracer, DiagnosticOptions options) : base(loggerFactory, tracer) { - if (!options.IsIgnored(GetListenerName())) + _options = options; + + if (options.LogEvents) { - _genericEventProcessor = new GenericEventProcessor(GetListenerName(), Tracer, Logger, options); + _genericEventProcessor = new GenericEventProcessor(GetListenerName(), Tracer, Logger); } } @@ -48,7 +50,7 @@ void IObserver>.OnNext(KeyValuePair { if (IsEnabled(value.Key)) { - OnNext(value.Key, value.Value); + HandleEvent(value.Key, value.Value); } } catch (Exception ex) @@ -57,14 +59,35 @@ void IObserver>.OnNext(KeyValuePair } } - protected virtual bool IsEnabled(string eventName) + /// + /// The name of the that should be instrumented. + /// + protected abstract string GetListenerName(); + + protected virtual bool IsSupportedEvent(string eventName) => true; + + protected abstract IEnumerable HandledEventNames(); + + private bool IsEnabled(string eventName) { + if (!IsSupportedEvent(eventName)) + return false; + + foreach (var handledEventName in HandledEventNames()) + { + if (handledEventName == eventName) + return true; + } + + if (!_options.LogEvents || _options.IgnoredEvents.Contains(eventName)) + return false; + return true; } - protected abstract void OnNext(string eventName, object untypedArg); + protected abstract void HandleEvent(string eventName, object untypedArg); - protected void ProcessUnhandledEvent(string eventName, object untypedArg) + protected void HandleUnknownEvent(string eventName, object untypedArg) { _genericEventProcessor?.ProcessEvent(eventName, untypedArg); } diff --git a/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticManager.cs b/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticManager.cs index a06fe6c..30ebd4f 100644 --- a/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticManager.cs +++ b/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticManager.cs @@ -7,6 +7,9 @@ namespace OpenTracing.Contrib.NetCore.Internal { + /// + /// Subscribes to and forwards events to individual instances. + /// internal sealed class DiagnosticManager : IObserver, IDisposable { private readonly ILogger _logger; @@ -36,7 +39,7 @@ public DiagnosticManager( _logger = loggerFactory.CreateLogger(); - _diagnosticSubscribers = diagnosticSubscribers.Where(x => x.IsSubscriberEnabled()); + _diagnosticSubscribers = diagnosticSubscribers; } public void Start() diff --git a/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticObserver.cs b/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticObserver.cs index 81d546a..735f6e1 100644 --- a/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticObserver.cs +++ b/src/OpenTracing.Contrib.NetCore/Internal/DiagnosticObserver.cs @@ -26,11 +26,6 @@ protected DiagnosticObserver(ILoggerFactory loggerFactory, ITracer tracer) IsLogLevelTraceEnabled = Logger.IsEnabled(LogLevel.Trace); } - public virtual bool IsSubscriberEnabled() - { - return true; - } - public abstract IDisposable SubscribeIfMatch(DiagnosticListener diagnosticListener); } } diff --git a/src/OpenTracing.Contrib.NetCore/Internal/GenericEventOptions.cs b/src/OpenTracing.Contrib.NetCore/Internal/GenericEventOptions.cs deleted file mode 100644 index 49b370e..0000000 --- a/src/OpenTracing.Contrib.NetCore/Internal/GenericEventOptions.cs +++ /dev/null @@ -1,127 +0,0 @@ -using System; -using System.Collections.Generic; - -namespace OpenTracing.Contrib.NetCore.Internal -{ - public class GenericEventOptions - { - private bool _hasFilter; - private bool _ignoreAll; - private Dictionary> _ignoredEvents; - private HashSet _ignoredListeners; - - /// - /// is ignore all events log - /// - public bool IgnoreAll - { - get => _ignoreAll; - set - { - _ignoreAll = value; - CheckHasFilter(); - } - } - - /// - /// listener names which will be ignored for logging - /// - public HashSet IgnoredListenerNames - { - get => _ignoredListeners; - set - { - _ignoredListeners = value; - CheckHasFilter(); - } - } - - /// - /// events which will be ignored for logging. Key is listener name, HashSet item is event name of the listener - /// - public Dictionary> IgnoredEvents - { - get => _ignoredEvents; - set - { - _ignoredEvents = value; - CheckHasFilter(); - } - } - - public void IgnoreListener(string listenerName) - { - if (listenerName == null) - throw new ArgumentNullException(nameof(listenerName)); - - if (IgnoredListenerNames == null) - IgnoredListenerNames = new HashSet(); - - IgnoredListenerNames.Add(listenerName); - _hasFilter = true; - } - - public void IgnoreEvent(string listenerName, string eventName) - { - if (listenerName == null) - throw new ArgumentNullException(nameof(listenerName)); - - if (eventName == null) - throw new ArgumentNullException(nameof(eventName)); - - if (IgnoredListenerNames == null) - IgnoredListenerNames = new HashSet(); - - if (!IgnoredEvents.TryGetValue(listenerName, out var ignoredListenerEvents)) - { - ignoredListenerEvents = new HashSet(); - IgnoredEvents.Add(listenerName, ignoredListenerEvents); - } - - ignoredListenerEvents.Add(eventName); - _hasFilter = true; - } - - /// - /// usually used in DiagnosticObserver - /// - /// - /// - public bool IsIgnored(string listenerName) - { - if (!_hasFilter) - return false; - - if (IgnoreAll) - return true; - - return IgnoredListenerNames.Count > 0 - && IgnoredListenerNames.Contains(listenerName); - } - - public bool IsIgnored(string listenerName, string eventName) - { - if (!_hasFilter) - return false; - - if (IgnoreAll) - return true; - - return IgnoredEvents.TryGetValue(listenerName, out var set) - && set.Contains(eventName); - } - - private void CheckHasFilter() - { - if (IgnoredListenerNames == null) - IgnoredListenerNames = new HashSet(); - - if (IgnoredEvents == null) - IgnoredEvents = new Dictionary>(); - - _hasFilter = IgnoreAll - || IgnoredListenerNames.Count > 0 - || IgnoredEvents.Count > 0; - } - } -} diff --git a/src/OpenTracing.Contrib.NetCore/Internal/GenericEventProcessor.cs b/src/OpenTracing.Contrib.NetCore/Internal/GenericEventProcessor.cs index d274d7b..5438213 100644 --- a/src/OpenTracing.Contrib.NetCore/Internal/GenericEventProcessor.cs +++ b/src/OpenTracing.Contrib.NetCore/Internal/GenericEventProcessor.cs @@ -12,14 +12,12 @@ internal class GenericEventProcessor private readonly ITracer _tracer; private readonly ILogger _logger; private readonly bool _isLogLevelTraceEnabled; - private readonly GenericEventOptions _options; - public GenericEventProcessor(string listenerName, ITracer tracer, ILogger logger, GenericEventOptions options) + public GenericEventProcessor(string listenerName, ITracer tracer, ILogger logger) { _listenerName = listenerName ?? throw new ArgumentNullException(nameof(listenerName)); _tracer = tracer ?? throw new ArgumentNullException(nameof(tracer)); _logger = logger ?? throw new ArgumentNullException(nameof(logger)); - _options = options; _isLogLevelTraceEnabled = _logger.IsEnabled(LogLevel.Trace); } @@ -28,11 +26,6 @@ public void ProcessEvent(string eventName, object untypedArg) { Activity activity = Activity.Current; - if (_options != null && _options.IsIgnored(_listenerName, eventName)) - { - return; - } - if (activity != null && eventName.EndsWith(".Start", StringComparison.Ordinal)) { HandleActivityStart(eventName, activity, untypedArg); @@ -75,7 +68,7 @@ private void HandleActivityStop(string eventName, Activity activity) private void HandleRegularEvent(string eventName, object untypedArg) { - ISpan span = _tracer.ActiveSpan; + var span = _tracer.ActiveSpan; if (span != null) { diff --git a/src/OpenTracing.Contrib.NetCore/MicrosoftSqlClient/MicrosoftSqlClientDiagnosticOptions.cs b/src/OpenTracing.Contrib.NetCore/MicrosoftSqlClient/MicrosoftSqlClientDiagnosticOptions.cs index f0f24d5..74d34c2 100644 --- a/src/OpenTracing.Contrib.NetCore/MicrosoftSqlClient/MicrosoftSqlClientDiagnosticOptions.cs +++ b/src/OpenTracing.Contrib.NetCore/MicrosoftSqlClient/MicrosoftSqlClientDiagnosticOptions.cs @@ -3,10 +3,37 @@ using System.Linq; using Microsoft.Data.SqlClient; -namespace OpenTracing.Contrib.NetCore.MicrosoftSqlClient +namespace OpenTracing.Contrib.NetCore.Configuration { - public class MicrosoftSqlClientDiagnosticOptions + public class MicrosoftSqlClientDiagnosticOptions : DiagnosticOptions { + public static class EventNames + { + // https://github.com/dotnet/SqlClient/blob/master/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SqlClientDiagnosticListenerExtensions.cs + + private const string SqlClientPrefix = "Microsoft.Data.SqlClient."; + + public const string WriteCommandBefore = SqlClientPrefix + nameof(WriteCommandBefore); + public const string WriteCommandAfter = SqlClientPrefix + nameof(WriteCommandAfter); + public const string WriteCommandError = SqlClientPrefix + nameof(WriteCommandError); + + public const string WriteConnectionOpenBefore = SqlClientPrefix + nameof(WriteConnectionOpenBefore); + public const string WriteConnectionOpenAfter = SqlClientPrefix + nameof(WriteConnectionOpenAfter); + public const string WriteConnectionOpenError = SqlClientPrefix + nameof(WriteConnectionOpenError); + + public const string WriteConnectionCloseBefore = SqlClientPrefix + nameof(WriteConnectionCloseBefore); + public const string WriteConnectionCloseAfter = SqlClientPrefix + nameof(WriteConnectionCloseAfter); + public const string WriteConnectionCloseError = SqlClientPrefix + nameof(WriteConnectionCloseError); + + public const string WriteTransactionCommitBefore = SqlClientPrefix + nameof(WriteTransactionCommitBefore); + public const string WriteTransactionCommitAfter = SqlClientPrefix + nameof(WriteTransactionCommitAfter); + public const string WriteTransactionCommitError = SqlClientPrefix + nameof(WriteTransactionCommitError); + + public const string WriteTransactionRollbackBefore = SqlClientPrefix + nameof(WriteTransactionRollbackBefore); + public const string WriteTransactionRollbackAfter = SqlClientPrefix + nameof(WriteTransactionRollbackAfter); + public const string WriteTransactionRollbackError = SqlClientPrefix + nameof(WriteTransactionRollbackError); + } + public const string DefaultComponent = "SqlClient"; public const string SqlClientPrefix = "sqlClient "; diff --git a/src/OpenTracing.Contrib.NetCore/MicrosoftSqlClient/MicrosoftSqlClientDiagnostics.cs b/src/OpenTracing.Contrib.NetCore/MicrosoftSqlClient/MicrosoftSqlClientDiagnostics.cs index f8fc2a1..e3be713 100644 --- a/src/OpenTracing.Contrib.NetCore/MicrosoftSqlClient/MicrosoftSqlClientDiagnostics.cs +++ b/src/OpenTracing.Contrib.NetCore/MicrosoftSqlClient/MicrosoftSqlClientDiagnostics.cs @@ -1,14 +1,16 @@ using System; using System.Collections.Concurrent; +using System.Collections.Generic; using Microsoft.Data.SqlClient; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; +using OpenTracing.Contrib.NetCore.Configuration; using OpenTracing.Contrib.NetCore.Internal; using OpenTracing.Tag; namespace OpenTracing.Contrib.NetCore.MicrosoftSqlClient { - internal sealed class MicrosoftSqlClientDiagnostics : DiagnosticListenerObserver + internal sealed class MicrosoftSqlClientDiagnostics : DiagnosticEventObserver { public const string DiagnosticListenerName = "SqlClientDiagnosticListener"; @@ -18,9 +20,8 @@ internal sealed class MicrosoftSqlClientDiagnostics : DiagnosticListenerObserver private readonly MicrosoftSqlClientDiagnosticOptions _options; private readonly ConcurrentDictionary _spanStorage; - public MicrosoftSqlClientDiagnostics(ILoggerFactory loggerFactory, ITracer tracer, IOptions options, - IOptions genericEventOptions) - : base(loggerFactory, tracer, genericEventOptions.Value) + public MicrosoftSqlClientDiagnostics(ILoggerFactory loggerFactory, ITracer tracer, IOptions options) + : base(loggerFactory, tracer, options?.Value) { _options = options?.Value ?? throw new ArgumentNullException(nameof(options)); _spanStorage = new ConcurrentDictionary(); @@ -28,28 +29,51 @@ public MicrosoftSqlClientDiagnostics(ILoggerFactory loggerFactory, ITracer trace protected override string GetListenerName() => DiagnosticListenerName; - protected override bool IsEnabled(string eventName) + /// + /// Both diagnostic listeners for System.Data.SqlClient and Microsoft.Data.SqlClient use the same listener name, + /// so we need to make sure this observer gets the correct events. + /// + protected override bool IsSupportedEvent(string eventName) => eventName.StartsWith("Microsoft."); + + protected override IEnumerable HandledEventNames() { - return eventName.StartsWith("Microsoft.Data.SqlClient"); + yield return MicrosoftSqlClientDiagnosticOptions.EventNames.WriteCommandBefore; + yield return MicrosoftSqlClientDiagnosticOptions.EventNames.WriteCommandError; + yield return MicrosoftSqlClientDiagnosticOptions.EventNames.WriteCommandAfter; } - protected override void OnNext(string eventName, object untypedArg) + protected override void HandleEvent(string eventName, object untypedArg) { switch (eventName) { - case "Microsoft.Data.SqlClient.WriteCommandBefore": + case MicrosoftSqlClientDiagnosticOptions.EventNames.WriteCommandBefore: { var cmd = (SqlCommand)_activityCommand_RequestFetcher.Fetch(untypedArg); + var activeSpan = Tracer.ActiveSpan; + + if (activeSpan == null && !_options.StartRootSpans) + { + if (IsLogLevelTraceEnabled) + { + Logger.LogTrace("Ignoring SQL command due to missing parent span"); + } + return; + } + if (IgnoreEvent(cmd)) { - Logger.LogDebug("Ignoring SQL command due to IgnorePatterns"); + if (IsLogLevelTraceEnabled) + { + Logger.LogTrace("Ignoring SQL command due to IgnorePatterns"); + } return; } string operationName = _options.OperationNameResolver(cmd); var span = Tracer.BuildSpan(operationName) + .AsChildOf(activeSpan) .WithTag(Tags.SpanKind, Tags.SpanKindClient) .WithTag(Tags.Component, _options.ComponentName) .WithTag(Tags.DbInstance, cmd.Connection.Database) @@ -60,7 +84,7 @@ protected override void OnNext(string eventName, object untypedArg) } break; - case "Microsoft.Data.SqlClient.WriteCommandError": + case MicrosoftSqlClientDiagnosticOptions.EventNames.WriteCommandError: { var cmd = (SqlCommand)_activityCommand_RequestFetcher.Fetch(untypedArg); var ex = (Exception)_exception_ExceptionFetcher.Fetch(untypedArg); @@ -73,7 +97,7 @@ protected override void OnNext(string eventName, object untypedArg) } break; - case "Microsoft.Data.SqlClient.WriteCommandAfter": + case MicrosoftSqlClientDiagnosticOptions.EventNames.WriteCommandAfter: { var cmd = (SqlCommand)_activityCommand_RequestFetcher.Fetch(untypedArg); @@ -83,6 +107,10 @@ protected override void OnNext(string eventName, object untypedArg) } } break; + + default: + HandleUnknownEvent(eventName, untypedArg); + break; } } diff --git a/src/OpenTracing.Contrib.NetCore/CoreFx/SqlClientDiagnosticOptions.cs b/src/OpenTracing.Contrib.NetCore/SystemSqlClient/SqlClientDiagnosticOptions.cs similarity index 94% rename from src/OpenTracing.Contrib.NetCore/CoreFx/SqlClientDiagnosticOptions.cs rename to src/OpenTracing.Contrib.NetCore/SystemSqlClient/SqlClientDiagnosticOptions.cs index 465554a..5132a33 100644 --- a/src/OpenTracing.Contrib.NetCore/CoreFx/SqlClientDiagnosticOptions.cs +++ b/src/OpenTracing.Contrib.NetCore/SystemSqlClient/SqlClientDiagnosticOptions.cs @@ -3,9 +3,9 @@ using System.Data.SqlClient; using System.Linq; -namespace OpenTracing.Contrib.NetCore.CoreFx +namespace OpenTracing.Contrib.NetCore.Configuration { - public class SqlClientDiagnosticOptions + public class SqlClientDiagnosticOptions : DiagnosticOptions { public const string DefaultComponent = "SqlClient"; public const string SqlClientPrefix = "sqlClient "; diff --git a/src/OpenTracing.Contrib.NetCore/CoreFx/SqlClientDiagnostics.cs b/src/OpenTracing.Contrib.NetCore/SystemSqlClient/SqlClientDiagnostics.cs similarity index 53% rename from src/OpenTracing.Contrib.NetCore/CoreFx/SqlClientDiagnostics.cs rename to src/OpenTracing.Contrib.NetCore/SystemSqlClient/SqlClientDiagnostics.cs index c3829e6..5a72feb 100644 --- a/src/OpenTracing.Contrib.NetCore/CoreFx/SqlClientDiagnostics.cs +++ b/src/OpenTracing.Contrib.NetCore/SystemSqlClient/SqlClientDiagnostics.cs @@ -1,26 +1,29 @@ using System; using System.Collections.Concurrent; +using System.Collections.Generic; using System.Data.SqlClient; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; +using OpenTracing.Contrib.NetCore.Configuration; using OpenTracing.Contrib.NetCore.Internal; using OpenTracing.Tag; -namespace OpenTracing.Contrib.NetCore.CoreFx +namespace OpenTracing.Contrib.NetCore.SystemSqlClient { - internal sealed class SqlClientDiagnostics : DiagnosticListenerObserver + internal sealed class SqlClientDiagnostics : DiagnosticEventObserver { public const string DiagnosticListenerName = "SqlClientDiagnosticListener"; - private static readonly PropertyFetcher _activityCommand_RequestFetcher = new PropertyFetcher("Command"); + private static readonly PropertyFetcher _writeCommandBefore_CommandFetcher = new PropertyFetcher("Command"); + private static readonly PropertyFetcher _writeCommandError_CommandFetcher = new PropertyFetcher("Command"); + private static readonly PropertyFetcher _writeCommandAfter_CommandFetcher = new PropertyFetcher("Command"); private static readonly PropertyFetcher _exception_ExceptionFetcher = new PropertyFetcher("Exception"); private readonly SqlClientDiagnosticOptions _options; private readonly ConcurrentDictionary _spanStorage; - public SqlClientDiagnostics(ILoggerFactory loggerFactory, ITracer tracer, IOptions options, - IOptions genericEventOptions) - : base(loggerFactory, tracer, genericEventOptions.Value) + public SqlClientDiagnostics(ILoggerFactory loggerFactory, ITracer tracer, IOptions options) + : base(loggerFactory, tracer, options?.Value) { _options = options?.Value ?? throw new ArgumentNullException(nameof(options)); _spanStorage = new ConcurrentDictionary(); @@ -28,28 +31,51 @@ public SqlClientDiagnostics(ILoggerFactory loggerFactory, ITracer tracer, IOptio protected override string GetListenerName() => DiagnosticListenerName; - protected override bool IsEnabled(string eventName) + /// + /// Both diagnostic listeners for System.Data.SqlClient and Microsoft.Data.SqlClient use the same listener name, + /// so we need to make sure this observer gets the correct events. + /// + protected override bool IsSupportedEvent(string eventName) => eventName.StartsWith("System."); + + protected override IEnumerable HandledEventNames() { - return eventName.StartsWith("System.Data.SqlClient"); + yield return "System.Data.SqlClient.WriteCommandBefore"; + yield return "System.Data.SqlClient.WriteCommandError"; + yield return "System.Data.SqlClient.WriteCommandAfter"; } - protected override void OnNext(string eventName, object untypedArg) + protected override void HandleEvent(string eventName, object untypedArg) { switch (eventName) { case "System.Data.SqlClient.WriteCommandBefore": { - var cmd = (SqlCommand)_activityCommand_RequestFetcher.Fetch(untypedArg); + var cmd = (SqlCommand)_writeCommandBefore_CommandFetcher.Fetch(untypedArg); + + var activeSpan = Tracer.ActiveSpan; + + if (activeSpan == null && !_options.StartRootSpans) + { + if (IsLogLevelTraceEnabled) + { + Logger.LogTrace("Ignoring SQL command due to missing parent span"); + } + return; + } if (IgnoreEvent(cmd)) { - Logger.LogDebug("Ignoring SQL command due to IgnorePatterns"); + if (IsLogLevelTraceEnabled) + { + Logger.LogTrace("Ignoring SQL command due to IgnorePatterns"); + } return; } string operationName = _options.OperationNameResolver(cmd); var span = Tracer.BuildSpan(operationName) + .AsChildOf(activeSpan) .WithTag(Tags.SpanKind, Tags.SpanKindClient) .WithTag(Tags.Component, _options.ComponentName) .WithTag(Tags.DbInstance, cmd.Connection.Database) @@ -62,7 +88,7 @@ protected override void OnNext(string eventName, object untypedArg) case "System.Data.SqlClient.WriteCommandError": { - var cmd = (SqlCommand)_activityCommand_RequestFetcher.Fetch(untypedArg); + var cmd = (SqlCommand)_writeCommandError_CommandFetcher.Fetch(untypedArg); var ex = (Exception)_exception_ExceptionFetcher.Fetch(untypedArg); if (_spanStorage.TryRemove(cmd, out var span)) @@ -75,7 +101,7 @@ protected override void OnNext(string eventName, object untypedArg) case "System.Data.SqlClient.WriteCommandAfter": { - var cmd = (SqlCommand)_activityCommand_RequestFetcher.Fetch(untypedArg); + var cmd = (SqlCommand)_writeCommandAfter_CommandFetcher.Fetch(untypedArg); if (_spanStorage.TryRemove(cmd, out var span)) { @@ -83,6 +109,10 @@ protected override void OnNext(string eventName, object untypedArg) } } break; + + default: + HandleUnknownEvent(eventName, untypedArg); + break; } } diff --git a/test/OpenTracing.Contrib.NetCore.Tests/AspNetCore/HostingTest1_0.cs b/test/OpenTracing.Contrib.NetCore.Tests/AspNetCore/HostingTest1_0.cs index 959c921..12b3928 100644 --- a/test/OpenTracing.Contrib.NetCore.Tests/AspNetCore/HostingTest1_0.cs +++ b/test/OpenTracing.Contrib.NetCore.Tests/AspNetCore/HostingTest1_0.cs @@ -127,7 +127,7 @@ public async Task Span_has_correct_properties() Assert.Equal(Tags.SpanKindServer, span.Tags[Tags.SpanKind.Key]); Assert.Equal("HttpIn", span.Tags[Tags.Component.Key]); Assert.Equal("GET", span.Tags[Tags.HttpMethod.Key]); - Assert.Equal($"http://{HostingEventProcessor.NoHostSpecified}/foo", span.Tags[Tags.HttpUrl.Key]); + Assert.Equal($"http://{AspNetCoreDiagnostics.NoHostSpecified}/foo", span.Tags[Tags.HttpUrl.Key]); Assert.Equal(200, span.Tags[Tags.HttpStatus.Key]); } } diff --git a/test/OpenTracing.Contrib.NetCore.Tests/CoreFx/HttpHandlerDiagnosticTest.cs b/test/OpenTracing.Contrib.NetCore.Tests/CoreFx/HttpHandlerDiagnosticTest.cs index 69c2b04..b824959 100644 --- a/test/OpenTracing.Contrib.NetCore.Tests/CoreFx/HttpHandlerDiagnosticTest.cs +++ b/test/OpenTracing.Contrib.NetCore.Tests/CoreFx/HttpHandlerDiagnosticTest.cs @@ -7,7 +7,7 @@ using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; -using OpenTracing.Contrib.NetCore.CoreFx; +using OpenTracing.Contrib.NetCore.Configuration; using OpenTracing.Contrib.NetCore.Internal; using OpenTracing.Mock; using OpenTracing.Tag; @@ -58,7 +58,7 @@ public HttpHandlerDiagnosticTest(ITestOutputHelper output) }) .AddOpenTracingCoreServices(builder => { - builder.AddCoreFx(); + builder.AddHttpHandler(); builder.Services.AddSingleton(_tracer); builder.Services.AddSingleton(Options.Create(_options)); })