diff --git a/src/Ocelot/Configuration/Creator/HttpHandlerOptionsCreator.cs b/src/Ocelot/Configuration/Creator/HttpHandlerOptionsCreator.cs index 6c66f3c0..332c25b7 100644 --- a/src/Ocelot/Configuration/Creator/HttpHandlerOptionsCreator.cs +++ b/src/Ocelot/Configuration/Creator/HttpHandlerOptionsCreator.cs @@ -1,13 +1,24 @@ -using Ocelot.Configuration.File; +using Butterfly.Client.Tracing; +using Ocelot.Configuration.File; +using Ocelot.Requester; namespace Ocelot.Configuration.Creator { public class HttpHandlerOptionsCreator : IHttpHandlerOptionsCreator { + private IServiceTracer _tracer; + + public HttpHandlerOptionsCreator(IServiceTracer tracer) + { + _tracer = tracer; + } + public HttpHandlerOptions Create(FileReRoute fileReRoute) { + var useTracing = _tracer.GetType() != typeof(FakeServiceTracer) ? fileReRoute.HttpHandlerOptions.UseTracing : false; + return new HttpHandlerOptions(fileReRoute.HttpHandlerOptions.AllowAutoRedirect, - fileReRoute.HttpHandlerOptions.UseCookieContainer, fileReRoute.HttpHandlerOptions.UseTracing); + fileReRoute.HttpHandlerOptions.UseCookieContainer, useTracing); } } } diff --git a/src/Ocelot/Infrastructure/Extensions/StringValuesExtensions.cs b/src/Ocelot/Infrastructure/Extensions/StringValuesExtensions.cs new file mode 100644 index 00000000..1b6d1682 --- /dev/null +++ b/src/Ocelot/Infrastructure/Extensions/StringValuesExtensions.cs @@ -0,0 +1,17 @@ +using Microsoft.Extensions.Primitives; +using System.Linq; + +namespace Ocelot.Infrastructure.Extensions +{ + internal static class StringValueExtensions + { + public static string GetValue(this StringValues stringValues) + { + if (stringValues.Count == 1) + { + return stringValues; + } + return stringValues.ToArray().LastOrDefault(); + } + } +} diff --git a/src/Ocelot/Logging/IOcelotLogger.cs b/src/Ocelot/Logging/IOcelotLogger.cs new file mode 100644 index 00000000..67bac731 --- /dev/null +++ b/src/Ocelot/Logging/IOcelotLogger.cs @@ -0,0 +1,22 @@ +using System; + +namespace Ocelot.Logging +{ + /// + /// Thin wrapper around the DotNet core logging framework, used to allow the scopedDataRepository to be injected giving access to the Ocelot RequestId + /// + public interface IOcelotLogger + { + void LogTrace(string message, params object[] args); + void LogDebug(string message, params object[] args); + void LogInformation(string message, params object[] args); + void LogError(string message, Exception exception); + void LogError(string message, params object[] args); + void LogCritical(string message, Exception exception); + + /// + /// The name of the type the logger has been built for. + /// + string Name { get; } + } +} diff --git a/src/Ocelot/Logging/IOcelotLoggerFactory.cs b/src/Ocelot/Logging/IOcelotLoggerFactory.cs index 3a145595..2407afcd 100644 --- a/src/Ocelot/Logging/IOcelotLoggerFactory.cs +++ b/src/Ocelot/Logging/IOcelotLoggerFactory.cs @@ -1,27 +1,7 @@ -using System; - -namespace Ocelot.Logging +namespace Ocelot.Logging { public interface IOcelotLoggerFactory { IOcelotLogger CreateLogger(); } - - /// - /// Thin wrapper around the DotNet core logging framework, used to allow the scopedDataRepository to be injected giving access to the Ocelot RequestId - /// - public interface IOcelotLogger - { - void LogTrace(string message, params object[] args); - void LogDebug(string message, params object[] args); - void LogInformation(string message, params object[] args); - void LogError(string message, Exception exception); - void LogError(string message, params object[] args); - void LogCritical(string message, Exception exception); - - /// - /// The name of the type the logger has been built for. - /// - string Name { get; } - } } diff --git a/src/Ocelot/Logging/OcelotDiagnosticListener.cs b/src/Ocelot/Logging/OcelotDiagnosticListener.cs index ee0b5b8a..d75cfd2c 100644 --- a/src/Ocelot/Logging/OcelotDiagnosticListener.cs +++ b/src/Ocelot/Logging/OcelotDiagnosticListener.cs @@ -3,18 +3,48 @@ using Microsoft.AspNetCore.Http; using Microsoft.Extensions.DiagnosticAdapter; using Butterfly.Client.AspNetCore; using Butterfly.OpenTracing; +using Ocelot.Middleware; +using Butterfly.Client.Tracing; +using System.Linq; +using System.Collections.Generic; +using Ocelot.Infrastructure.Extensions; +using Microsoft.Extensions.Logging; +using Ocelot.Requester; namespace Ocelot.Logging { public class OcelotDiagnosticListener { + private IServiceTracer _tracer; private IOcelotLogger _logger; - public OcelotDiagnosticListener(IOcelotLoggerFactory factory) + public OcelotDiagnosticListener(IOcelotLoggerFactory factory, IServiceTracer tracer) { + _tracer = tracer; _logger = factory.CreateLogger(); } + [DiagnosticName("Ocelot.MiddlewareException")] + public virtual void OcelotMiddlewareException(Exception exception, DownstreamContext context, string name) + { + _logger.LogTrace($"Ocelot.MiddlewareException: {name}; {exception.Message}"); + Event(context.HttpContext, $"Ocelot.MiddlewareStarted: {name}; {context.HttpContext.Request.Path}"); + } + + [DiagnosticName("Ocelot.MiddlewareStarted")] + public virtual void OcelotMiddlewareStarted(DownstreamContext context, string name) + { + _logger.LogTrace($"Ocelot.MiddlewareStarted: {name}; {context.HttpContext.Request.Path}"); + Event(context.HttpContext, $"Ocelot.MiddlewareStarted: {name}; {context.HttpContext.Request.Path}"); + } + + [DiagnosticName("Ocelot.MiddlewareFinished")] + public virtual void OcelotMiddlewareFinished(DownstreamContext context, string name) + { + _logger.LogTrace($"OcelotMiddlewareFinished: {name}; {context.HttpContext.Request.Path}"); + Event(context.HttpContext, $"OcelotMiddlewareFinished: {name}; {context.HttpContext.Request.Path}"); + } + [DiagnosticName("Microsoft.AspNetCore.MiddlewareAnalysis.MiddlewareStarting")] public virtual void OnMiddlewareStarting(HttpContext httpContext, string name) { @@ -36,8 +66,28 @@ namespace Ocelot.Logging } private void Event(HttpContext httpContext, string @event) - { + { + // Hack - if the user isnt using tracing the code gets here and will blow up on + // _tracer.Tracer.TryExtract. We already use the fake tracer for another scenario + // so sticking it here as well..I guess we need a factory for this but no idea + // how to hook that into the diagnostic framework at the moment. + if(_tracer.GetType() == typeof(FakeServiceTracer)) + { + return; + } + var span = httpContext.GetSpan(); + if(span == null) + { + var spanBuilder = new SpanBuilder($"server {httpContext.Request.Method} {httpContext.Request.Path}"); + if (_tracer.Tracer.TryExtract(out var spanContext, httpContext.Request.Headers, (c, k) => c[k].GetValue(), + c => c.Select(x => new KeyValuePair(x.Key, x.Value.GetValue())).GetEnumerator())) + { + spanBuilder.AsChildOf(spanContext); + }; + span = _tracer.Start(spanBuilder); + httpContext.SetSpan(span); + } span?.Log(LogField.CreateNew().Event(@event)); } } diff --git a/src/Ocelot/Middleware/OcelotMiddlewareExtensions.cs b/src/Ocelot/Middleware/OcelotMiddlewareExtensions.cs index cda82bef..61d13f52 100644 --- a/src/Ocelot/Middleware/OcelotMiddlewareExtensions.cs +++ b/src/Ocelot/Middleware/OcelotMiddlewareExtensions.cs @@ -65,6 +65,8 @@ rest of asp.net.. */ + builder.Properties["analysis.NextMiddlewareName"] = "TransitionToOcelotMiddleware"; + builder.Use(async (context, task) => { var downstreamContext = new DownstreamContext(context); diff --git a/src/Ocelot/Middleware/Pipeline/OcelotPipelineBuilderExtensions.cs b/src/Ocelot/Middleware/Pipeline/OcelotPipelineBuilderExtensions.cs index 5989b1dd..539fa6a1 100644 --- a/src/Ocelot/Middleware/Pipeline/OcelotPipelineBuilderExtensions.cs +++ b/src/Ocelot/Middleware/Pipeline/OcelotPipelineBuilderExtensions.cs @@ -3,6 +3,7 @@ // Removed code and changed RequestDelete to OcelotRequestDelete, HttpContext to DownstreamContext, removed some exception handling messages using System; +using System.Diagnostics; using System.Linq; using System.Linq.Expressions; using System.Reflection; @@ -75,7 +76,28 @@ namespace Ocelot.Middleware.Pipeline var instance = ActivatorUtilities.CreateInstance(app.ApplicationServices, middleware, ctorArgs); if (parameters.Length == 1) { - return (OcelotRequestDelegate)methodinfo.CreateDelegate(typeof(OcelotRequestDelegate), instance); + var ocelotDelegate = (OcelotRequestDelegate)methodinfo.CreateDelegate(typeof(OcelotRequestDelegate), instance); + var diagnosticListener = (DiagnosticListener)app.ApplicationServices.GetService(typeof(DiagnosticListener)); + var middlewareName = ocelotDelegate.Target.GetType().Name; + + OcelotRequestDelegate wrapped = context => { + try + { + Write(diagnosticListener, "Ocelot.MiddlewareStarted", middlewareName, context); + return ocelotDelegate(context); + } + catch(Exception ex) + { + Write(diagnosticListener, "Ocelot.MiddlewareException", middlewareName, context); + throw ex; + } + finally + { + Write(diagnosticListener, "Ocelot.MiddlewareFinished", middlewareName, context); + } + }; + + return wrapped; } var factory = Compile(methodinfo, parameters); @@ -93,6 +115,14 @@ namespace Ocelot.Middleware.Pipeline }); } + private static void Write(DiagnosticListener diagnosticListener, string message, string middlewareName, DownstreamContext context) + { + if(diagnosticListener != null) + { + diagnosticListener.Write(message, new { name = middlewareName, context = context }); + } + } + public static IOcelotPipelineBuilder MapWhen(this IOcelotPipelineBuilder app, Predicate predicate, Action configuration) { if (app == null) diff --git a/src/Ocelot/Requester/DelegatingHandlerHandlerFactory.cs b/src/Ocelot/Requester/DelegatingHandlerHandlerFactory.cs index e0d9da82..02969855 100644 --- a/src/Ocelot/Requester/DelegatingHandlerHandlerFactory.cs +++ b/src/Ocelot/Requester/DelegatingHandlerHandlerFactory.cs @@ -2,6 +2,7 @@ using System; using System.Collections.Generic; using System.Linq; using System.Net.Http; +using Butterfly.Client.Tracing; using Microsoft.Extensions.DependencyInjection; using Ocelot.Configuration; using Ocelot.Logging; diff --git a/src/Ocelot/Requester/FakeServiceTracer.cs b/src/Ocelot/Requester/FakeServiceTracer.cs new file mode 100644 index 00000000..95347ef6 --- /dev/null +++ b/src/Ocelot/Requester/FakeServiceTracer.cs @@ -0,0 +1,17 @@ +using Butterfly.Client.Tracing; +using Butterfly.OpenTracing; + +namespace Ocelot.Requester +{ + public class FakeServiceTracer : IServiceTracer + { + public ITracer Tracer { get; } + public string ServiceName { get; } + public string Environment { get; } + public string Identity { get; } + public ISpan Start(ISpanBuilder spanBuilder) + { + return null; + } + } +} diff --git a/src/Ocelot/Requester/TracingHandlerFactory.cs b/src/Ocelot/Requester/TracingHandlerFactory.cs index b514ca18..f0eb97b1 100644 --- a/src/Ocelot/Requester/TracingHandlerFactory.cs +++ b/src/Ocelot/Requester/TracingHandlerFactory.cs @@ -1,5 +1,4 @@ using Butterfly.Client.Tracing; -using Butterfly.OpenTracing; using Ocelot.Infrastructure.RequestData; namespace Ocelot.Requester @@ -22,16 +21,4 @@ namespace Ocelot.Requester return new OcelotHttpTracingHandler(_tracer, _repo); } } - - public class FakeServiceTracer : IServiceTracer - { - public ITracer Tracer { get; } - public string ServiceName { get; } - public string Environment { get; } - public string Identity { get; } - public ISpan Start(ISpanBuilder spanBuilder) - { - throw new System.NotImplementedException(); - } - } } diff --git a/test/Ocelot.ManualTest/appsettings.json b/test/Ocelot.ManualTest/appsettings.json index e3439bab..c10bfed6 100644 --- a/test/Ocelot.ManualTest/appsettings.json +++ b/test/Ocelot.ManualTest/appsettings.json @@ -2,7 +2,7 @@ "Logging": { "IncludeScopes": false, "LogLevel": { - "Default": "Debug", + "Default": "Error", "System": "Error", "Microsoft": "Error" } diff --git a/test/Ocelot.ManualTest/configuration.json b/test/Ocelot.ManualTest/configuration.json index ba34d4e5..12f7f188 100644 --- a/test/Ocelot.ManualTest/configuration.json +++ b/test/Ocelot.ManualTest/configuration.json @@ -99,7 +99,7 @@ "HttpHandlerOptions": { "AllowAutoRedirect": true, "UseCookieContainer": true, - "UseTracing": false + "UseTracing": true }, "QoSOptions": { "ExceptionsAllowedBeforeBreaking": 3, diff --git a/test/Ocelot.UnitTests/Configuration/HttpHandlerOptionsCreatorTests.cs b/test/Ocelot.UnitTests/Configuration/HttpHandlerOptionsCreatorTests.cs index ca22956c..7316dcb3 100644 --- a/test/Ocelot.UnitTests/Configuration/HttpHandlerOptionsCreatorTests.cs +++ b/test/Ocelot.UnitTests/Configuration/HttpHandlerOptionsCreatorTests.cs @@ -1,6 +1,10 @@ -using Ocelot.Configuration; +using System; +using Butterfly.Client.Tracing; +using Butterfly.OpenTracing; +using Ocelot.Configuration; using Ocelot.Configuration.Creator; using Ocelot.Configuration.File; +using Ocelot.Requester; using Shouldly; using TestStack.BDDfy; using Xunit; @@ -9,13 +13,54 @@ namespace Ocelot.UnitTests.Configuration { public class HttpHandlerOptionsCreatorTests { - private readonly IHttpHandlerOptionsCreator _httpHandlerOptionsCreator; + private IHttpHandlerOptionsCreator _httpHandlerOptionsCreator; private FileReRoute _fileReRoute; private HttpHandlerOptions _httpHandlerOptions; + private IServiceTracer _serviceTracer; public HttpHandlerOptionsCreatorTests() { - _httpHandlerOptionsCreator = new HttpHandlerOptionsCreator(); + _serviceTracer = new FakeServiceTracer(); + _httpHandlerOptionsCreator = new HttpHandlerOptionsCreator(_serviceTracer); + } + + [Fact] + public void should_not_use_tracing_if_fake_tracer_registered() + { + var fileReRoute = new FileReRoute + { + HttpHandlerOptions = new FileHttpHandlerOptions + { + UseTracing = true + } + }; + + var expectedOptions = new HttpHandlerOptions(false, false, false); + + this.Given(x => GivenTheFollowing(fileReRoute)) + .When(x => WhenICreateHttpHandlerOptions()) + .Then(x => ThenTheFollowingOptionsReturned(expectedOptions)) + .BDDfy(); + } + + [Fact] + public void should_use_tracing_if_real_tracer_registered() + { + var fileReRoute = new FileReRoute + { + HttpHandlerOptions = new FileHttpHandlerOptions + { + UseTracing = true + } + }; + + var expectedOptions = new HttpHandlerOptions(false, false, true); + + this.Given(x => GivenTheFollowing(fileReRoute)) + .And(x => GivenARealTracer()) + .When(x => WhenICreateHttpHandlerOptions()) + .Then(x => ThenTheFollowingOptionsReturned(expectedOptions)) + .BDDfy(); } [Fact] @@ -68,5 +113,27 @@ namespace Ocelot.UnitTests.Configuration _httpHandlerOptions.UseCookieContainer.ShouldBe(expected.UseCookieContainer); _httpHandlerOptions.UseTracing.ShouldBe(expected.UseTracing); } + + private void GivenARealTracer() + { + var tracer = new RealTracer(); + _httpHandlerOptionsCreator = new HttpHandlerOptionsCreator(tracer); + } + + class RealTracer : IServiceTracer + { + public ITracer Tracer => throw new NotImplementedException(); + + public string ServiceName => throw new NotImplementedException(); + + public string Environment => throw new NotImplementedException(); + + public string Identity => throw new NotImplementedException(); + + public ISpan Start(ISpanBuilder spanBuilder) + { + throw new NotImplementedException(); + } + } } } diff --git a/test/Ocelot.UnitTests/WebSockets/WebSocketsProxyMiddlewareTests.cs b/test/Ocelot.UnitTests/WebSockets/WebSocketsProxyMiddlewareTests.cs deleted file mode 100644 index c3b087d4..00000000 --- a/test/Ocelot.UnitTests/WebSockets/WebSocketsProxyMiddlewareTests.cs +++ /dev/null @@ -1,239 +0,0 @@ -using System; -using System.Collections.Generic; -using System.IO; -using System.Net.WebSockets; -using System.Text; -using System.Threading; -using System.Threading.Tasks; -using Consul; -using Microsoft.AspNetCore.Builder; -using Microsoft.AspNetCore.Hosting; -using Microsoft.Extensions.Configuration; -using Microsoft.Extensions.DependencyInjection; -using Microsoft.Extensions.Logging; -using Newtonsoft.Json; -using Ocelot.Configuration.File; -using Ocelot.DependencyInjection; -using Ocelot.Middleware; -using Shouldly; -using TestStack.BDDfy; -using Xunit; - -namespace Ocelot.UnitTests.Websockets -{ - public class WebSocketsProxyMiddlewareTests : IDisposable - { - private IWebHost _firstDownstreamHost; - private readonly List _firstRecieved; - private WebHostBuilder _ocelotBuilder; - private IWebHost _ocelotHost; - - public WebSocketsProxyMiddlewareTests() - { - _firstRecieved = new List(); - } - - [Fact] - public async Task should_proxy_websocket_input_to_downstream_service() - { - var downstreamPort = 5001; - var downstreamHost = "localhost"; - - var config = new FileConfiguration - { - ReRoutes = new List - { - new FileReRoute - { - UpstreamPathTemplate = "/", - DownstreamPathTemplate = "/ws", - DownstreamScheme = "ws", - DownstreamHostAndPorts = new List - { - new FileHostAndPort - { - Host = downstreamHost, - Port = downstreamPort - } - } - } - } - }; - - this.Given(_ => GivenThereIsAConfiguration(config)) - .And(_ => StartFakeOcelotWithWebSockets()) - .And(_ => StartFakeDownstreamService($"http://{downstreamHost}:{downstreamPort}", "/ws")) - .When(_ => StartClient("ws://localhost:5000/")) - .Then(_ => _firstRecieved.Count.ShouldBe(10)) - .BDDfy(); - } - - public void Dispose() - { - _firstDownstreamHost?.Dispose(); - } - - public async Task StartFakeOcelotWithWebSockets() - { - _ocelotBuilder = new WebHostBuilder(); - _ocelotBuilder.ConfigureServices(s => - { - s.AddSingleton(_ocelotBuilder); - s.AddOcelot(); - }); - _ocelotBuilder.UseKestrel() - .UseUrls("http://localhost:5000") - .UseContentRoot(Directory.GetCurrentDirectory()) - .ConfigureAppConfiguration((hostingContext, config) => - { - config.SetBasePath(hostingContext.HostingEnvironment.ContentRootPath); - var env = hostingContext.HostingEnvironment; - config.AddJsonFile("appsettings.json", optional: true, reloadOnChange: true) - .AddJsonFile($"appsettings.{env.EnvironmentName}.json", optional: true, reloadOnChange: true); - config.AddJsonFile("configuration.json"); - config.AddEnvironmentVariables(); - }) - .ConfigureLogging((hostingContext, logging) => - { - logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging")); - logging.AddConsole(); - }) - .Configure(app => - { - app.UseWebSockets(); - app.UseOcelot().Wait(); - }) - .UseIISIntegration(); - _ocelotHost = _ocelotBuilder.Build(); - await _ocelotHost.StartAsync(); - } - - public void GivenThereIsAConfiguration(FileConfiguration fileConfiguration) - { - var configurationPath = Path.Combine(AppContext.BaseDirectory, "configuration.json"); - - var jsonConfiguration = JsonConvert.SerializeObject(fileConfiguration); - - if (File.Exists(configurationPath)) - { - File.Delete(configurationPath); - } - - File.WriteAllText(configurationPath, jsonConfiguration); - } - - private async Task StartFakeDownstreamService(string url, string path) - { - _firstDownstreamHost = new WebHostBuilder() - .ConfigureServices(s => { }).UseKestrel() - .UseUrls(url) - .UseContentRoot(Directory.GetCurrentDirectory()) - .ConfigureAppConfiguration((hostingContext, config) => - { - config.SetBasePath(hostingContext.HostingEnvironment.ContentRootPath); - var env = hostingContext.HostingEnvironment; - config.AddJsonFile("appsettings.json", optional: true, reloadOnChange: true) - .AddJsonFile($"appsettings.{env.EnvironmentName}.json", optional: true, reloadOnChange: true); - config.AddEnvironmentVariables(); - }) - .ConfigureLogging((hostingContext, logging) => - { - logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging")); - logging.AddConsole(); - }) - .Configure(app => - { - app.UseWebSockets(); - app.Use(async (context, next) => - { - if (context.Request.Path == path) - { - if (context.WebSockets.IsWebSocketRequest) - { - WebSocket webSocket = await context.WebSockets.AcceptWebSocketAsync(); - await Echo(webSocket); - } - else - { - context.Response.StatusCode = 400; - } - } - else - { - await next(); - } - }); - }) - .UseIISIntegration().Build(); - await _firstDownstreamHost.StartAsync(); - } - - private async Task StartClient(string url) - { - var client = new ClientWebSocket(); - - await client.ConnectAsync(new Uri(url), CancellationToken.None); - - var sending = Task.Run(async () => - { - string line = "test"; - for (int i = 0; i < 10; i++) - { - var bytes = Encoding.UTF8.GetBytes(line); - - await client.SendAsync(new ArraySegment(bytes), WebSocketMessageType.Text, true, - CancellationToken.None); - await Task.Delay(10); - } - - await client.CloseOutputAsync(WebSocketCloseStatus.NormalClosure, "", CancellationToken.None); - }); - - var receiving = Task.Run(async () => - { - var buffer = new byte[1024 * 4]; - - while (true) - { - var result = await client.ReceiveAsync(new ArraySegment(buffer), CancellationToken.None); - - if (result.MessageType == WebSocketMessageType.Text) - { - _firstRecieved.Add(Encoding.UTF8.GetString(buffer, 0, result.Count)); - } - - else if (result.MessageType == WebSocketMessageType.Close) - { - await client.CloseAsync(WebSocketCloseStatus.NormalClosure, "", CancellationToken.None); - break; - } - } - }); - - await Task.WhenAll(sending, receiving); - } - - private async Task Echo(WebSocket webSocket) - { - try - { - var buffer = new byte[1024 * 4]; - - var result = await webSocket.ReceiveAsync(new ArraySegment(buffer), CancellationToken.None); - - while (!result.CloseStatus.HasValue) - { - await webSocket.SendAsync(new ArraySegment(buffer, 0, result.Count), result.MessageType, result.EndOfMessage, CancellationToken.None); - - result = await webSocket.ReceiveAsync(new ArraySegment(buffer), CancellationToken.None); - } - - await webSocket.CloseAsync(result.CloseStatus.Value, result.CloseStatusDescription, CancellationToken.None); - } - catch (Exception e) - { - Console.WriteLine(e); - } - } - } -}