Skip to content

Commit

Permalink
Logging bug in HttpRequesterMiddleware (#1953)
Browse files Browse the repository at this point in the history
* Fix a bug in HttpRequesterMiddleware.cs, 

BadRequest should be logged as debug!

* Clean code: refactor `CreateLogBasedOnResponse`

* Unit tests

* Remove redundant if-checking

---------

Co-authored-by: Raman Maksimchuk <[email protected]>
  • Loading branch information
masoud-bahrami and raman-m authored Feb 27, 2024
1 parent 0404c24 commit 171e3a7
Show file tree
Hide file tree
Showing 2 changed files with 40 additions and 14 deletions.
16 changes: 10 additions & 6 deletions src/Ocelot/Requester/Middleware/HttpRequesterMiddleware.cs
Original file line number Diff line number Diff line change
Expand Up @@ -39,15 +39,19 @@ public async Task Invoke(HttpContext httpContext)

private void CreateLogBasedOnResponse(Response<HttpResponseMessage> response)
{
if (response.Data?.StatusCode <= HttpStatusCode.BadRequest)
var status = response.Data?.StatusCode ?? HttpStatusCode.Processing;
var reason = response.Data?.ReasonPhrase ?? "unknown";
var uri = response.Data?.RequestMessage?.RequestUri?.ToString() ?? string.Empty;

string message() => $"{(int)status} ({reason}) status code of request URI: {uri}.";

if (status < HttpStatusCode.BadRequest)
{
Logger.LogInformation(() =>
$"{(int)response.Data.StatusCode} ({response.Data.ReasonPhrase}) status code, request uri: {response.Data.RequestMessage?.RequestUri}");
Logger.LogInformation(message);
}
else if (response.Data?.StatusCode >= HttpStatusCode.BadRequest)
else
{
Logger.LogWarning(
() => $"{(int)response.Data.StatusCode} ({response.Data.ReasonPhrase}) status code, request uri: {response.Data.RequestMessage?.RequestUri}");
Logger.LogWarning(message);
}
}
}
Expand Down
38 changes: 30 additions & 8 deletions test/Ocelot.UnitTests/Requester/HttpRequesterMiddlewareTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -34,7 +34,7 @@ public HttpRequesterMiddlewareTests()
public void should_call_services_correctly()
{
this.Given(x => x.GivenTheRequestIs())
.And(x => x.GivenTheRequesterReturns(new OkResponse<HttpResponseMessage>(new HttpResponseMessage(System.Net.HttpStatusCode.OK))))
.And(x => x.GivenTheRequesterReturns(new OkResponse<HttpResponseMessage>(new HttpResponseMessage(HttpStatusCode.OK))))
.When(x => x.WhenICallTheMiddleware())
.Then(x => x.ThenTheDownstreamResponseIsSet())
.Then(x => InformationIsLogged())
Expand All @@ -56,12 +56,38 @@ 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))))
new OkResponse<HttpResponseMessage>(new HttpResponseMessage(HttpStatusCode.InternalServerError))))
.When(x => x.WhenICallTheMiddleware())
.Then(x => x.WarningIsLogged())
.BDDfy();
}

[Theory]
[Trait("Bug", "1953")]
[InlineData(HttpStatusCode.OK)]
[InlineData(HttpStatusCode.PermanentRedirect)]
public void Should_LogInformation_when_status_is_less_than_BadRequest(HttpStatusCode status)
{
this.Given(x => x.GivenTheRequestIs())
.And(x => x.GivenTheRequesterReturns(new OkResponse<HttpResponseMessage>(new HttpResponseMessage(status))))
.When(x => x.WhenICallTheMiddleware())
.Then(x => x.InformationIsLogged())
.BDDfy();
}

[Theory]
[Trait("Bug", "1953")]
[InlineData(HttpStatusCode.BadRequest)]
[InlineData(HttpStatusCode.NotFound)]
public void Should_LogWarning_when_status_is_BadRequest_or_greater(HttpStatusCode status)
{
this.Given(x => x.GivenTheRequestIs())
.And(x => x.GivenTheRequesterReturns(new OkResponse<HttpResponseMessage>(new HttpResponseMessage(status))))
.When(x => x.WhenICallTheMiddleware())
.Then(x => x.WarningIsLogged())
.BDDfy();
}

private void ThenTheErrorIsSet()
{
_httpContext.Items.Errors().Count.ShouldBeGreaterThan(0);
Expand Down Expand Up @@ -103,18 +129,14 @@ private void ThenTheDownstreamResponseIsSet()
private void WarningIsLogged()
{
_logger.Verify(
x => x.LogWarning(
It.IsAny<Func<string>>()
),
x => x.LogWarning(It.IsAny<Func<string>>()),
Times.Once);
}

private void InformationIsLogged()
{
_logger.Verify(
x => x.LogInformation(
It.IsAny<Func<string>>()
),
x => x.LogInformation(It.IsAny<Func<string>>()),
Times.Once);
}
}
Expand Down

0 comments on commit 171e3a7

Please sign in to comment.