Make fields in logs of Microsoft.AspNetCore.Hosting consistent
- Dominant language
- C#
- Stars
- 38.4k
- Forks
- 10.9k
- Avg merge
- 2d 6h
- Merged PRs (30d)
- 290
Description
### Is there an existing issue for this?
- [X] I have searched the existing issues
### Is your feature request related to a problem? Please describe the problem.
We are using structured logging (using NLog to output it to json) and shipping the logs to elastic, which indexes it and makes it possible to search through.
However, when elastic tries to index fields it has problems because of miss-matches of types on the same field.
Example of two logs coming from `Microsoft.AspNetCore.Hosting.Diagnostics`, one at the start of the request and the other at the end.
They have some of the same fields, however with different format of values (string vs. object).
Start of the request:
``` json
{
"time": "2024-09-30 12:05:09.6602",
"universal-time": "2024-09-30 12:05:09.6602",
"host": "our-service-86dc4b9fb-d4qnj",
"application": "Our.Service",
"threadId": "41",
"level": "INFO",
"logger": "Microsoft.AspNetCore.Hosting.Diagnostics",
"message": "Request starting HTTP/1.1 GET http://10.225.45.99:8080/metrics - - -",
"message-template": "Request starting {Protocol} {Method} {Scheme}://{Host}{PathBase}{Path}{QueryString} - {ContentType} {ContentLength}",
"aspnet-TraceIdentifier": "00-7a85866bababb599a104c7c6e5561d82-0f1e9948aa2cf78f-00",
"activity-SpanId": "0f1e9948aa2cf78f",
"activity-TraceId": "7a85866bababb599a104c7c6e5561d82",
"activity-OperationName": "Microsoft.AspNetCore.Hosting.HttpRequestIn",
"Protocol": "HTTP/1.1",
"Method": "GET",
"ContentType": null,
"ContentLength": null,
"Scheme": "http",
"Host": "10.225.45.99:8080",
"PathBase": "",
"Path": "/metrics",
"QueryString": "",
"EventId": 1
}
```
end of the request:
``` json
{
"time": "2024-09-30 12:05:09.6602",
"universal-time": "2024-09-30 12:05:09.6602",
"host": "our-service-86dc4b9fb-d4qnj",
"application": "Our.Service",
"threadId": "41",
"level": "INFO",
"logger": "Microsoft.AspNetCore.Hosting.Diagnostics",
"message": "Request reached the end of the middleware pipeline without being handled by application code. Request path: GET http://10.225.45.99:8080/metrics, Response status code: 404",
"message-template": "Request reached the end of the middleware pipeline without being handled by application code. Request path: {Method} {Scheme}://{Host}{PathBase}{Path}, Response status code: {StatusCode}",
"aspnet-TraceIdentifier": "00-7a85866bababb599a104c7c6e5561d82-0f1e9948aa2cf78f-00",
"activity-SpanId": "0f1e9948aa2cf78f",
"activity-TraceId": "7a85866bababb599a104c7c6e5561d82",
"activity-OperationName": "Microsoft.AspNetCore.Hosting.HttpRequestIn",
"Method": "GET",
"Scheme": "http",
"Host": {
"Value": "10.225.45.99:8080",
"HasValue": true,
"Host": "10.225.45.99",
"Port": 8080
},
"PathBase": {
"Value": "",
"HasValue": false
},
"Path": {
"Value": "/metrics",
"HasValue": true
},
"StatusCode": 404,
"EventId": 16
}
```
Notice the `Host`, `PathBase` and `Path` fields.
I'm unsure how many other cases of this there are - this is just what we found.
Starting request comes from here: https://github.com/dotnet/aspnetcore/blob/30ef19c7d9651d0fa113dd8ed08809e545141d74/src/Hosting/Hosting/src/Internal/HostingRequestStartingLog.cs#L30
Where as request end comes from here: https://github.com/dotnet/aspnetcore/blob/30ef19c7d9651d0fa113dd8ed08809e545141d74/src/Hosting/Hosting/src/Internal/HostingRequestUnhandledLog.cs#L25
### Describe the solution you'd like
I think it should be considered if these fields can be made consistent. I believe the situation I described above isn't particularly unique to us.
It would make some headaches go away while using .NET for structured logging.
**Some things we have considered:**
There are some **_apparent_** workarounds for our case. Specificaly this (on the elastic side): https://www.elastic.co/guide/en/elasticsearch/reference/current/ignore-malformed.html
However it doesn't actually help if the value is an object instead of a simple type, as stated here:
> You also can’t use ignore_malformed to ignore JSON objects submitted to fields of the wrong data type. A JSON object is any data surrounded by curly brackets "{}" and includes data mapped to the nested, object, and range data types.
Another option is that we could ignore those fields via our NLog configuration. While doable and would work, it seems like a game of whack-a-mole. We would need to go and add new problematic fields to `excludeProperties` (a parameter in NLog JsonLayout: https://github.com/NLog/NLog/wiki/JsonLayout#parameters).
Also the fields would now not be visible in the logs at all.
We could also exclude the problematic fields from indexing via elastic index config. Again playing whack-a-mole.
To be honest, perhaps we need a solution to deal with such inconsistencies on the application/infra side anyway. However the framework producing logs with consistent field values would help the situation.
### Additional context
_No response_
Contributor guide
Assessment
This issue has not been assessed yet.