bpo-34849: Don't log wating for selector.select in asyncio loop iteration (GH-9641)

The waiting is pretty normal for any asyncio program, logging its time just adds
a noise to logs without any useful information provided.



https://bugs.python.org/issue34849
This commit is contained in:
Andrew Svetlov 2018-09-30 08:28:40 +03:00 committed by Miss Islington (bot)
parent df8101517a
commit d5bd036138
3 changed files with 4 additions and 47 deletions

View File

@ -1719,28 +1719,7 @@ class BaseEventLoop(events.AbstractEventLoop):
when = self._scheduled[0]._when
timeout = min(max(0, when - self.time()), MAXIMUM_SELECT_TIMEOUT)
if self._debug and timeout != 0:
t0 = self.time()
event_list = self._selector.select(timeout)
dt = self.time() - t0
if dt >= 1.0:
level = logging.INFO
else:
level = logging.DEBUG
nevent = len(event_list)
if timeout is None:
logger.log(level, 'poll took %.3f ms: %s events',
dt * 1e3, nevent)
elif nevent:
logger.log(level,
'poll %.3f ms took %.3f ms: %s events',
timeout * 1e3, dt * 1e3, nevent)
elif dt >= 1.0:
logger.log(level,
'poll %.3f ms took %.3f ms: timeout',
timeout * 1e3, dt * 1e3)
else:
event_list = self._selector.select(timeout)
event_list = self._selector.select(timeout)
self._process_events(event_list)
# Handle 'later' callbacks that are ready.

View File

@ -371,31 +371,6 @@ class BaseEventLoopTests(test_utils.TestCase):
self.loop.set_debug(False)
self.assertFalse(self.loop.get_debug())
@mock.patch('asyncio.base_events.logger')
def test__run_once_logging(self, m_logger):
def slow_select(timeout):
# Sleep a bit longer than a second to avoid timer resolution
# issues.
time.sleep(1.1)
return []
# logging needs debug flag
self.loop.set_debug(True)
# Log to INFO level if timeout > 1.0 sec.
self.loop._selector.select = slow_select
self.loop._process_events = mock.Mock()
self.loop._run_once()
self.assertEqual(logging.INFO, m_logger.log.call_args[0][0])
def fast_select(timeout):
time.sleep(0.001)
return []
self.loop._selector.select = fast_select
self.loop._run_once()
self.assertEqual(logging.DEBUG, m_logger.log.call_args[0][0])
def test__run_once_schedule_handle(self):
handle = None
processed = False

View File

@ -0,0 +1,3 @@
Don't log wating for ``selector.select`` in asyncio loop iteration. The
waiting is pretty normal for any asyncio program, logging its time just adds
a noise to logs without any useful information provided.