Skip to content

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

Closed
asvetlov wants to merge 1 commit into
python:masterfrom
asvetlov:mask-timeout-error
Closed

bpo-34148: Dont log exception traceback when TimeoutError is occurred in asyncio transports#11576
asvetlov wants to merge 1 commit into
python:masterfrom
asvetlov:mask-timeout-error

Conversation

@asvetlov

@asvetlov asvetlov commented Jan 16, 2019

Copy link
Copy Markdown
Contributor

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

https://bugs.python.org/issue34148

@vstinner

Copy link
Copy Markdown
Member

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

@asvetlov

Copy link
Copy Markdown
Contributor Author

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

1st1 commented Jan 19, 2019

Copy link
Copy Markdown
Member

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

Copy link
Copy Markdown
Contributor Author

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

yjqiang commented Feb 3, 2019

Copy link
Copy Markdown

@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

yjqiang commented Feb 18, 2019

Copy link
Copy Markdown

@1st1

@asvetlov

Copy link
Copy Markdown
Contributor Author

Superseded by #13548

@asvetlov asvetlov closed this May 27, 2019
@asvetlov
asvetlov deleted the mask-timeout-error branch September 12, 2019 12:43
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

6 participants