bpo-34148: Dont log exception traceback when TimeoutError is occurred in asyncio transports

[asvetlov]

The exception is normal behavior, ETIMEDOUT can be set by NAT gateways and IP bridge hardware for example.

https://bugs.python.org/issue34148

[vstinner]

Sorry I don't have the bandwidth to review this change. @1st1 maybe?

[asvetlov]

A couple word to the context: we have a list of expected exceptions like ConnectionError etc.
Exceptions from the list are not logged because they pollute log a lot and scare people.
An expected exception is still passed into protocol.connection_lost(exc) and causes transport closing; unexpected exception does the same plus logging.

We've added certificate errors to the expected list during the last core devs sprint, TimeoutError is similar.

Sure, @1st1 is familiar with it; I guess uvloop should be updated as well :)

[1st1]

I'm not sure about this one. Can you better explain why you want to mask logging of all timeout errors in transports? If we mask it, why don't we mask all exceptions then?

Edit: just saw the previous comment (sorry, typing this on my phone, and the GH is harder to use)

That said i'm still not sure we should mask timeouts from logging.

[asvetlov]

The long story is: in aiohttp bug tracker I had reports about TimeoutError from people several times.
Reporters were not asyncio experts most likely, they scared by this logging.
Additional complexity is that the error is very rare and usually happens only high load or unstable network connection like a weak WiFi access point.
I was even not convinced for first reports if people observed TimeoutError or asyncio.TimeoutError exception, is it raised by blocking or non-blocking sockets etc. In other words, I was uncertain is it normal (while rare) network behavior or programming error.

Now I'm sure that it is a network behavior. TCP keepalive (SO_KEEPALIVE) can raise this error on expiration even for non-blocking sockets, TCP_USER_TIMEOUT can be used to control timeout etc.

There is no reason to log timeout errors, user code still receives the exception in connection_lost() callback.

why don't we mask all exceptions then?

This is a very good question actually. As I said exceptions are passed into the user-side callback. Usually, I use logging for reporting about warnings etc., in other words for cases when I cannot raise an exception (function call should proceed successfully) but want to inform a caller about something.
If we do raise an exception (I consider connection_lost() as a kind of control flow for exception handling) there is no reason for duplication it in logs.

We have the logging in asyncio for now. It served an important role: give us usage feedback. But after collecting more experience I'm inclining to drop the logging. If we decide to keep it -- let's don't log ETIMEOUT at least as we do for e.g. ECONNABORTED.

P.S.
Please let me recall the reason for masking certificate error.
People asked: if they handle ssl.CertificateError why they have it logged by asyncio? The logging looks like a report about an unhandled exception for them but it is definitely not true.
The same logic is applicable to TimeoutError.

[yjqiang]

@1st1 I think ETIMEDOUT is the same as _FATAL_ERROR_IGNORE = (BrokenPipeError, ConnectionResetError, ConnectionAbortedError). I'm not sure it is a bug or a feature for python, but I'm sure it should be fixed or hidden(maybe by python or aiohttp, but not by user). I am suffering from this message.

[yjqiang]

@1st1

[asvetlov]

Superseded by #13548