Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Create subcategories for better filtering Kestrel logs #30301

Closed
halter73 opened this issue Feb 19, 2021 · 3 comments · Fixed by #31596
Closed

Create subcategories for better filtering Kestrel logs #30301

halter73 opened this issue Feb 19, 2021 · 3 comments · Fixed by #31596
Labels
area-networking Includes servers, yarp, json patch, bedrock, websockets, http client factory, and http abstractions breaking-change This issue / pr will introduce a breaking change, when resolved / merged. feature-kestrel help wanted Up for grabs. We would accept a PR to help resolve this issue
Milestone

Comments

@halter73
Copy link
Member

Kestrel logs bad request details using the "Microsoft.AspNetCore.Server.Kestrel" category at the debug level. The reason for the low severity is to reduce the log noise misbehaving clients can create. Here's an example log:

dbug: Microsoft.AspNetCore.Server.Kestrel[17]
      Connection id "0HM6L1I0L7H4A" bad request data: "Invalid request header: 'X-Http-Method : PATCH\x0D\x0A'"
      Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Invalid request header: 'X-Http-Method : PATCH\x0D\x0A'
         at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpParser`1.ParseHeaders(TRequestHandler handler, SequenceReader`1& reader)
         at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TakeMessageHeaders(SequenceReader`1& reader, Boolean trailers)
         at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.ParseRequest(SequenceReader`1& reader)
         at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TryParseRequest(ReadResult result, Boolean& endConnection)
         at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
         at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)

This can be a problem when the misbehaving clients are legitimate clients of a production service, and developers want to see more detail about why request are being rejected without enabling all "Microsoft.AspNetCore.Server.Kestrel" debug logs in production which could be overwhelming.

One workaround might be to filter logs by EventID (e.g. don't log debug-level "Microsoft.AspNetCore.Server.Kestrel" logs unless it has EventId(17, "ConnectionBadRequest")). The problem with that is that AddFilter doesn't support this. As of today, you are stuck writing your own ILoggerProvider to get this functionality which is quite complicated.

To make it easier to see details around bad requests without increasing the log severity, I'm proposing a new category for bad request logs. Maybe "Microsoft.AspNetCore.Server.Kestrel.BadRequests". These logs would still be debug-level, but it would be much easier to filter.

If we do this, we'll have to decide whether we duplicate logs to avoid breaking logic depending on bad request logs log being in the "Microsoft.AspNetCore.Server.Kestrel" category. I think duplicate logs are annoying enough we shouldn't do that, but we do need to consider this is technically a breaking change.

@halter73
Copy link
Member Author

halter73 commented Feb 19, 2021

This is a good opportunity to split Kestrel logs into multiple subcategories. It doesn't have to just be bad requests and everything else. Here are some potential categories:

  1. Microsoft.AspNetCore.Server.Kestrel (current category): ApplicationError, ApplicationNeverCompleted, RequestBodyStart, RequestBodyDrainTimeout, ...
  2. Microsoft.AspNetCore.Server.Kestrel.BadRequests: ConnectionBadRequest, RequestBodyMinimumDataRateNotSatisfied, ...
  3. Microsoft.AspNetCore.Server.Kestrel.Connections: ConnectionAccepted, ConnectionStart, ConnectionDisconnect, NotAllConnectionsAborted, ...
  4. Microsoft.AspNetCore.Server.Kestrel.Http2: Http2FrameReceived, Http2ConnectionError, Http2StreamError, HPackDecodingError, Http2StreamResetAbort, Http2ConnectionClosed, ...
  5. Microsoft.AspNetCore.Server.Kestrel.Http3: Http3FrameReceived, Http3ConnectionError, Http3StreamAbort, ...

@davidfowl

@halter73 halter73 changed the title Create unique category for Kestrel bad request logs Create subcategories for better filtering Kestrel logs Feb 19, 2021
@BrennanConroy BrennanConroy added breaking-change This issue / pr will introduce a breaking change, when resolved / merged. help wanted Up for grabs. We would accept a PR to help resolve this issue labels Mar 30, 2021
@ghost
Copy link

ghost commented Mar 31, 2021

Thanks for contacting us.
We're moving this issue to the Next sprint planning milestone for future evaluation / consideration. Because it's not immediately obvious that this is a bug in our framework, we would like to keep this around to collect more feedback, which can later help us determine the impact of it. We will re-evaluate this issue, during our next planning meeting(s).
If we later determine, that the issue has no community involvement, or it's very rare and low-impact issue, we will close it - so that the team can focus on more important and high impact issues.
To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

@BrennanConroy
Copy link
Member

Done via #31596

@dotnet dotnet locked as resolved and limited conversation to collaborators Jun 11, 2021
@amcasey amcasey added area-networking Includes servers, yarp, json patch, bedrock, websockets, http client factory, and http abstractions and removed area-runtime labels Jun 2, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-networking Includes servers, yarp, json patch, bedrock, websockets, http client factory, and http abstractions breaking-change This issue / pr will introduce a breaking change, when resolved / merged. feature-kestrel help wanted Up for grabs. We would accept a PR to help resolve this issue
Projects
Continuous Improvement
Awaiting triage
Development

Successfully merging a pull request may close this issue.

3 participants