Description
Description
RequestLoggingMiddleware sets the RequestPath log event property using IHttpRequestFeature.RawTarget.
As a result, the RequestPath property in the log event emitted by RequestLoggingMiddleware can be different to that in a regular log event.
Reproduction
Configuration is standard:
public static int Main(string[] args)
{
Log.Logger = new LoggerConfiguration()
.MinimumLevel.Debug()
.MinimumLevel.Override("Microsoft", LogEventLevel.Information)
.MinimumLevel.Override("Microsoft.AspNetCore", LogEventLevel.Warning)
.Enrich.FromLogContext()
.WriteTo.Console(new JsonFormatter())
.CreateLogger();
try
{
Log.Information("Starting web host");
CreateHostBuilder(args).Build().Run();
return 0;
}
catch (Exception ex)
{
Log.Fatal(ex, "Host terminated unexpectedly");
return 1;
}
finally
{
Log.CloseAndFlush();
}
}
public static IHostBuilder CreateHostBuilder(string[] args) =>
Host.CreateDefaultBuilder(args)
.UseSerilog()
.ConfigureWebHostDefaults(webBuilder =>
{
webBuilder.UseStartup<Startup>();
});
public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
{
if (env.IsDevelopment())
{
app.UseDeveloperExceptionPage();
app.UseSwagger();
app.UseSwaggerUI(c => c.SwaggerEndpoint("/swagger/v1/swagger.json", "SerilogRequestPath v1"));
}
app.UseSerilogRequestLogging();
app.UseHttpsRedirection();
app.UseRouting();
app.UseAuthorization();
app.UseEndpoints(endpoints =>
{
endpoints.MapControllers();
});
}
Logging from the controller:
[ApiController]
[Route("[controller]")]
public class TestController : ControllerBase
{
private readonly ILogger<TestController> _logger;
public TestController(ILogger<TestController> logger)
{
_logger = logger;
}
[HttpGet]
public IActionResult Get([FromQuery] string token)
{
_logger.LogInformation("Hello");
return Ok();
}
}
Expected behavior
I expect the RequestPath property in the event logged by RequestLoggingMiddleware to be equal to the RequestPath property in the event logged by the controller. However, the RequestPath property in the event logged by the controller includes the query string.
{
"Timestamp": "2021-02-09T18:16:28.3418609+11:00",
"Level": "Information",
"MessageTemplate": "Hello",
"Properties": {
"SourceContext": "SerilogRequestPath.Controllers.TestController",
"ActionId": "1b917552-e13e-49ff-8ff1-d949e0b7a24d",
"ActionName": "SerilogRequestPath.Controllers.TestController.Get (SerilogRequestPath)",
"RequestId": "0HM6CPA8DRC2U:00000005",
"RequestPath": "/Test",
"ConnectionId": "0HM6CPA8DRC2U"
}
}
{
"Timestamp": "2021-02-09T18:16:28.3459735+11:00",
"Level": "Information",
"MessageTemplate": "HTTP {RequestMethod} {RequestPath} responded {StatusCode} in {Elapsed:0.0000} ms",
"Properties": {
"RequestMethod": "GET",
"RequestPath": "/Test?token=helloworld",
"StatusCode": 200,
"Elapsed": 50.1784,
"SourceContext": "Serilog.AspNetCore.RequestLoggingMiddleware",
"RequestId": "0HM6CPA8DRC2U:00000005",
"ConnectionId": "0HM6CPA8DRC2U"
},
"Renderings": {
"Elapsed": [
{
"Format": "0.0000",
"Rendering": "50.1784"
}
]
}
}
Relevant package, tooling and runtime versions
Serilog.AspNetCore 3.4.0.
Additional context
This behaviour can't be changed by the user because RequestLoggingMiddleware adds the RequestPath property after the call to EnrichDiagnosticContext.
RequestPath is already set in the request scope. It doesn't seem necessary for RequestLoggingMiddleware to set a value for it.