From a518a7522ffa3957c90853e832be17124b7f5fcc Mon Sep 17 00:00:00 2001 From: Andrew Svetlov Date: Fri, 24 May 2019 18:09:42 +0300 Subject: [PATCH 1/4] Don't log OSError --- Lib/asyncio/base_events.py | 7 ----- Lib/asyncio/proactor_events.py | 2 +- Lib/asyncio/selector_events.py | 2 +- Lib/asyncio/sslproto.py | 2 +- Lib/asyncio/unix_events.py | 2 +- Lib/test/test_asyncio/test_selector_events.py | 27 +++++++++++++++++-- Lib/test/test_asyncio/test_unix_events.py | 6 +---- 7 files changed, 30 insertions(+), 18 deletions(-) diff --git a/Lib/asyncio/base_events.py b/Lib/asyncio/base_events.py index de9fa4f4f7f3b6..dcbf9cdf83491c 100644 --- a/Lib/asyncio/base_events.py +++ b/Lib/asyncio/base_events.py @@ -59,13 +59,6 @@ # before cleanup of cancelled handles is performed. _MIN_CANCELLED_TIMER_HANDLES_FRACTION = 0.5 -# Exceptions which must not call the exception handler in fatal error -# methods (_fatal_error()) -_FATAL_ERROR_IGNORE = (BrokenPipeError, - ConnectionResetError, ConnectionAbortedError) - -if ssl is not None: - _FATAL_ERROR_IGNORE = _FATAL_ERROR_IGNORE + (ssl.SSLCertVerificationError,) _HAS_IPv6 = hasattr(socket, 'AF_INET6') diff --git a/Lib/asyncio/proactor_events.py b/Lib/asyncio/proactor_events.py index a849be1cc1479b..86f6cc85b869e4 100644 --- a/Lib/asyncio/proactor_events.py +++ b/Lib/asyncio/proactor_events.py @@ -96,7 +96,7 @@ def __del__(self, _warn=warnings.warn): def _fatal_error(self, exc, message='Fatal error on pipe transport'): try: - if isinstance(exc, base_events._FATAL_ERROR_IGNORE): + if isinstance(exc, OSError): if self._loop.get_debug(): logger.debug("%r: %s", self, message, exc_info=True) else: diff --git a/Lib/asyncio/selector_events.py b/Lib/asyncio/selector_events.py index 6461d3077633d0..12abd010fd2c4f 100644 --- a/Lib/asyncio/selector_events.py +++ b/Lib/asyncio/selector_events.py @@ -671,7 +671,7 @@ def __del__(self, _warn=warnings.warn): def _fatal_error(self, exc, message='Fatal error on transport'): # Should be called from exception handler only. - if isinstance(exc, base_events._FATAL_ERROR_IGNORE): + if isinstance(exc, OSError): if self._loop.get_debug(): logger.debug("%r: %s", self, message, exc_info=True) else: diff --git a/Lib/asyncio/sslproto.py b/Lib/asyncio/sslproto.py index 97a6fc66a92735..6e8d65fe050874 100644 --- a/Lib/asyncio/sslproto.py +++ b/Lib/asyncio/sslproto.py @@ -699,7 +699,7 @@ def _process_write_backlog(self): self._fatal_error(exc, 'Fatal error on SSL transport') def _fatal_error(self, exc, message='Fatal error on transport'): - if isinstance(exc, base_events._FATAL_ERROR_IGNORE): + if isinstance(exc, OSError): if self._loop.get_debug(): logger.debug("%r: %s", self, message, exc_info=True) else: diff --git a/Lib/asyncio/unix_events.py b/Lib/asyncio/unix_events.py index 1aa3b396086c59..53c79e2f7ef7bd 100644 --- a/Lib/asyncio/unix_events.py +++ b/Lib/asyncio/unix_events.py @@ -716,7 +716,7 @@ def abort(self): def _fatal_error(self, exc, message='Fatal error on pipe transport'): # should be called by exception handler only - if isinstance(exc, base_events._FATAL_ERROR_IGNORE): + if isinstance(exc, OSError): if self._loop.get_debug(): logger.debug("%r: %s", self, message, exc_info=True) else: diff --git a/Lib/test/test_asyncio/test_selector_events.py b/Lib/test/test_asyncio/test_selector_events.py index bf721b0005b000..2e52e9df5c3b6e 100644 --- a/Lib/test/test_asyncio/test_selector_events.py +++ b/Lib/test/test_asyncio/test_selector_events.py @@ -448,10 +448,23 @@ def test_fatal_error(self, m_exc): tr._force_close = mock.Mock() tr._fatal_error(exc) + m_exc.assert_not_called() + + tr._force_close.assert_called_with(exc) + + @mock.patch('asyncio.log.logger.error') + def test_fatal_error_custom_exception(self, m_exc): + class MyError(Exception): + pass + exc = MyError() + tr = self.create_transport() + tr._force_close = mock.Mock() + tr._fatal_error(exc) + m_exc.assert_called_with( test_utils.MockPattern( 'Fatal error on transport\nprotocol:.*\ntransport:.*'), - exc_info=(OSError, MOCK_ANY, MOCK_ANY)) + exc_info=(MyError, MOCK_ANY, MOCK_ANY)) tr._force_close.assert_called_with(exc) @@ -1338,10 +1351,20 @@ def test_fatal_error_connected(self, m_exc): err = ConnectionRefusedError() transport._fatal_error(err) self.assertFalse(self.protocol.error_received.called) + m_exc.assert_not_called() + + @mock.patch('asyncio.base_events.logger.error') + def test_fatal_error_connected_custom_error(self, m_exc): + class MyException(Exception): + pass + transport = self.datagram_transport(address=('0.0.0.0', 1)) + err = MyException() + transport._fatal_error(err) + self.assertFalse(self.protocol.error_received.called) m_exc.assert_called_with( test_utils.MockPattern( 'Fatal error on transport\nprotocol:.*\ntransport:.*'), - exc_info=(ConnectionRefusedError, MOCK_ANY, MOCK_ANY)) + exc_info=(MyException, MOCK_ANY, MOCK_ANY)) if __name__ == '__main__': diff --git a/Lib/test/test_asyncio/test_unix_events.py b/Lib/test/test_asyncio/test_unix_events.py index 31e710037f76a3..ac84304ec99da6 100644 --- a/Lib/test/test_asyncio/test_unix_events.py +++ b/Lib/test/test_asyncio/test_unix_events.py @@ -977,11 +977,7 @@ def test__write_ready_err(self, m_write, m_logexc): self.assertFalse(self.loop.readers) self.assertEqual(bytearray(), tr._buffer) self.assertTrue(tr.is_closing()) - m_logexc.assert_called_with( - test_utils.MockPattern( - 'Fatal write error on pipe transport' - '\nprotocol:.*\ntransport:.*'), - exc_info=(OSError, MOCK_ANY, MOCK_ANY)) + m_logexc.assert_not_called() self.assertEqual(1, tr._conn_lost) test_utils.run_briefly(self.loop) self.protocol.connection_lost.assert_called_with(err) From 313d0c65fb3363b92c6ed3e0a0603b84ea19c086 Mon Sep 17 00:00:00 2001 From: Andrew Svetlov Date: Fri, 24 May 2019 18:16:19 +0300 Subject: [PATCH 2/4] Add NEWS --- .../next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst | 2 ++ 1 file changed, 2 insertions(+) create mode 100644 Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst diff --git a/Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst b/Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst new file mode 100644 index 00000000000000..4f9f651fb72b05 --- /dev/null +++ b/Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst @@ -0,0 +1,2 @@ +Don't log OSError based exceptions if a fatal error is occured in asyncio +transport From b47306aa6116ef2230310ec7bdc93c91e0d5c9a1 Mon Sep 17 00:00:00 2001 From: Andrew Svetlov Date: Sun, 26 May 2019 05:16:41 +0300 Subject: [PATCH 3/4] Update Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst Co-Authored-By: Matthias Bussonnier --- .../next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst b/Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst index 4f9f651fb72b05..6aa2b0097bda3a 100644 --- a/Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst +++ b/Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst @@ -1,2 +1,2 @@ -Don't log OSError based exceptions if a fatal error is occured in asyncio +Don't log OSError based exceptions if a fatal error has occurred in asyncio transport From 6c1cc11e0ec7f0cc4ed4a0197f4fc4ef07fe82ab Mon Sep 17 00:00:00 2001 From: Andrew Svetlov Date: Mon, 27 May 2019 15:44:53 +0300 Subject: [PATCH 4/4] Trying to explain the change motivation better --- .../next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst b/Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst index 6aa2b0097bda3a..004ec2d1371401 100644 --- a/Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst +++ b/Misc/NEWS.d/next/Library/2019-05-24-18-16-07.bpo-37035.HFbJVT.rst @@ -1,2 +1,5 @@ Don't log OSError based exceptions if a fatal error has occurred in asyncio -transport +transport. Peer can generate almost any OSError, user cannot avoid these exceptions +by fixing own code. +Errors are still propagated to user code, it's just logging them +is pointless and pollute asyncio logs.