search

microsoft / reverse-proxy

A toolkit for developing high-performance HTTP reverse proxy applications.
https://microsoft.github.io/reverse-proxy
MIT License
8.52k stars 836 forks source link

Don't log TaskCanceledException with warning level #2631

Open marekott opened 1 week ago

marekott commented 1 week ago

What should we add or change to make your life better?

Hi, after log level for some entries was raised to Warning in v2.2.0 I am experiencing a lot (like 5k for one day on dev, inlcuding also cancelled SignalR connections) of entries where underlying exception is TaskCanceledException, for example:

UpgradeResponseCanceled: Copying the upgraded response body was canceled. ResponseBodyCanceled: Copying the response body was canceled.

In both cases:

System.Threading.Tasks.TaskCanceledException: The operation was canceled.\n ---> System.IO.IOException: Unable to read data from the transport connection: Operation canceled.\n ---> System.Net.Sockets.SocketException (125): Operation canceled

Request being cancelled is a common situation when user is interacting with web application or automated tests based on Selenium are being run. Because of that there is a ton of such log entries.

I would like to recommend to not log TaskCanceledException with Warning level or at least expose some configuration that would enable to exclude it on demand.

Why is this important to you?

Like I wrote above, those cancelled requests are valid cases in my application because users or automated tests often closes browser tabs. In a current state those logs could hide much more critical warnings because of their sheer number. I don't want to exclude those logs since they are produced from Yarp.ReverseProxy.Forwarder.HttpForwarder and I believe there are other valuable logs that could be excluded in the process. BTW what is the benefit of logging it with this log level? Why have you decided it is worth marking it as Warning?

jzlhilo commented 2 days ago

This seems related to https://github.com/microsoft/reverse-proxy/issues/2340, which was solved with https://github.com/microsoft/reverse-proxy/pull/2503. 3 types of ForwarderError (RequestCanceled , RequestBodyCanceled, UpgradeRequestCanceled) were redirected to a debug log. It seems like this one (and possibly others) are missing.

Maybe just adding UpgradeResponseCanceled to the list of errors directed to a debug log (HttpForwarder.cs.ErrorProxying) would do the trick

MihaZupan commented 2 days ago

2503 improved this by moving a couple logs that always indicate client-cancellation to a debug-level event. The intention behind it definitely was to avoid this type of warning spam, looks like we didn't go quite far enough.

UpgradeResponseCanceled and ResponseBodyCanceled don't always mean that the client is at fault, so we can't filter them out outright, but we can review how we attribute errors to these enums when we know that the client did disconnect.