#492 log 500 with error log level, acceptance test, unit test

src/Ocelot/Requester/Middleware/HttpRequesterMiddleware.cs

@@ -22,6 +22,11 @@ namespace Ocelot.Requester.Middleware
         {
             var response = await _requester.GetResponse(context);
 
+            if (response.Data != null && response.Data.StatusCode == System.Net.HttpStatusCode.InternalServerError)
+            {
+                Logger.LogError("500 (Internal Server Error) status code, request uri: " + response.Data.RequestMessage?.RequestUri, null);
+            }
+
             if (response.IsError)
             {
                 Logger.LogDebug("IHttpRequester returned an error, setting pipeline error");

test/Ocelot.AcceptanceTests/Ocelot.AcceptanceTests.csproj

@@ -40,6 +40,7 @@
     <PackageReference Include="Microsoft.AspNetCore.App" />
     <PackageReference Include="Microsoft.AspNetCore.TestHost" Version="2.2.0" />
     <PackageReference Include="Microsoft.NET.Test.Sdk" Version="16.1.0" />
+    <PackageReference Include="Moq" Version="4.13.1" />
     <PackageReference Include="StyleCop.Analyzers" Version="1.1.118">
       <PrivateAssets>all</PrivateAssets>
     </PackageReference>

test/Ocelot.AcceptanceTests/ReturnsErrorTests.cs

@@ -21,6 +21,7 @@
         [Fact]
         public void should_return_internal_server_error_if_downstream_service_returns_internal_server_error()
         {
+
             var configuration = new FileConfiguration
             {
                 ReRoutes = new List<FileReRoute>
@@ -51,6 +52,39 @@
                 .BDDfy();
         }
 
+        [Fact]
+        public void should_log_error_if_downstream_service_returns_internal_server_error()
+        {
+            var configuration = new FileConfiguration
+            {
+                ReRoutes = new List<FileReRoute>
+                    {
+                        new FileReRoute
+                        {
+                            DownstreamPathTemplate = "/",
+                            UpstreamPathTemplate = "/",
+                            UpstreamHttpMethod = new List<string> { "Get" },
+                            DownstreamHostAndPorts = new List<FileHostAndPort>
+                            {
+                                new FileHostAndPort
+                                {
+                                    Host = "localhost",
+                                    Port = 53876,
+                                },
+                            },
+                            DownstreamScheme = "http",
+                        },
+                    },
+            };
+
+            this.Given(x => x.GivenThereIsAServiceRunningOn("http://localhost:53876"))
+                .And(x => _steps.GivenThereIsAConfiguration(configuration))
+                .And(x => _steps.GivenOcelotIsRunningWithLogger())
+                .When(x => _steps.WhenIGetUrlOnTheApiGateway("/"))
+                .Then(x => _steps.ThenErrorShouldBeLogged())
+                .BDDfy();
+        }
+
         private void GivenThereIsAServiceRunningOn(string url)
         {
             _serviceHandler.GivenThereIsAServiceRunningOn(url, context => throw new Exception("BLAMMMM"));

test/Ocelot.AcceptanceTests/Steps.cs

@@ -10,12 +10,14 @@
     using Microsoft.Extensions.Configuration;
     using Microsoft.Extensions.DependencyInjection;
     using Microsoft.Extensions.Logging;
+    using Moq;
     using Newtonsoft.Json;
     using Ocelot.Cache.CacheManager;
     using Ocelot.Configuration.Creator;
     using Ocelot.Configuration.File;
     using Ocelot.DependencyInjection;
     using Ocelot.Infrastructure;
+    using Ocelot.Logging;
     using Ocelot.Middleware;
     using Ocelot.Middleware.Multiplexer;
     using Ocelot.Provider.Consul;
@@ -1120,5 +1122,60 @@
 
             _ocelotClient = _ocelotServer.CreateClient();
         }
+
+        public void GivenOcelotIsRunningWithLogger()
+        {
+            _webHostBuilder = new WebHostBuilder();
+
+            _webHostBuilder
+                .ConfigureAppConfiguration((hostingContext, config) =>
+                {
+                    config.SetBasePath(hostingContext.HostingEnvironment.ContentRootPath);
+                    var env = hostingContext.HostingEnvironment;
+                    config.AddJsonFile("appsettings.json", optional: true, reloadOnChange: false)
+                        .AddJsonFile($"appsettings.{env.EnvironmentName}.json", optional: true, reloadOnChange: false);
+                    config.AddJsonFile("ocelot.json", false, false);
+                    config.AddEnvironmentVariables();
+                })
+                .ConfigureServices(s =>
+                {
+                    s.AddOcelot();
+                    s.AddSingleton<IOcelotLoggerFactory, MockLoggerFactory>();
+                })
+                .Configure(app =>
+                {
+                    app.UseOcelot().Wait();
+                });
+
+            _ocelotServer = new TestServer(_webHostBuilder);
+
+            _ocelotClient = _ocelotServer.CreateClient();
+        }
+
+        public void ThenErrorShouldBeLogged()
+        {
+            MockLoggerFactory loggerFactory = (MockLoggerFactory)_ocelotServer.Host.Services.GetService<IOcelotLoggerFactory>();
+            loggerFactory.Verify();
+        }
+
+        internal class MockLoggerFactory : IOcelotLoggerFactory
+        {
+            private Mock<IOcelotLogger> _logger;
+
+            public IOcelotLogger CreateLogger<T>()
+            {
+                if (_logger == null)
+                {
+                    _logger = new Mock<IOcelotLogger>();
+                    _logger.Setup(x => x.LogError(It.IsAny<string>(), It.IsAny<Exception>())).Verifiable();
+                }
+                return _logger.Object;
+            }
+
+            public void Verify()
+            {
+                _logger.Verify(x => x.LogError(It.IsAny<string>(), It.IsAny<Exception>()), Times.Once);
+            }
+        }
     }
 }

test/Ocelot.UnitTests/Requester/HttpRequesterMiddlewareTests.cs

@@ -1,6 +1,7 @@
 namespace Ocelot.UnitTests.Requester
 {
     using Microsoft.AspNetCore.Http;
+    using Microsoft.Extensions.Logging;
     using Moq;
     using Ocelot.Configuration.Builder;
     using Ocelot.Logging;
@@ -57,6 +58,17 @@ namespace Ocelot.UnitTests.Requester
                 .BDDfy();
         }
 
+        [Fact]
+        public void should_log_downstream_internal_server_error()
+        {
+            this.Given(x => x.GivenTheRequestIs())
+                    .And(x => x.GivenTheRequesterReturns(
+                        new OkResponse<HttpResponseMessage>(new HttpResponseMessage(System.Net.HttpStatusCode.InternalServerError))))
+                .When(x => x.WhenICallTheMiddleware())
+                .Then(x => x.ErrorIsLogged())
+                .BDDfy();
+        }
+
         private void ThenTheErrorIsSet()
         {
             _downstreamContext.IsError.ShouldBeTrue();
@@ -98,5 +110,14 @@ namespace Ocelot.UnitTests.Requester
             _downstreamContext.DownstreamResponse.Content.ShouldBe(_response.Data.Content);
             _downstreamContext.DownstreamResponse.StatusCode.ShouldBe(_response.Data.StatusCode);
         }
+
+        private void ErrorIsLogged()
+        {
+            _logger.Verify(
+                x => x.LogError(                 
+                    It.IsAny<string>(),
+                    It.IsAny<Exception>()
+                   ));
+        }
     }
 }