From 770e48d0174726e339074cfffa68fce23768aab5 Mon Sep 17 00:00:00 2001
From: Victor Stinner <victor.stinner@gmail.com>
Date: Fri, 11 Jul 2014 11:58:33 +0200
Subject: asyncio: sync with Tulip

* Tulip issue #182: Improve logs of BaseEventLoop._run_once()

  - Don't log non-blocking poll
  - Only log polling with a timeout if it gets events or if it timed out after
    more than 1 second.

* Fix some pyflakes warnings: remove unused imports
---
 Lib/asyncio/base_events.py                | 21 ++++++++++++++-------
 Lib/asyncio/streams.py                    |  1 -
 Lib/asyncio/tasks.py                      |  1 -
 Lib/test/test_asyncio/test_base_events.py |  2 +-
 Lib/test/test_asyncio/test_events.py      |  2 +-
 Lib/test/test_asyncio/test_tasks.py       |  9 ++++-----
 6 files changed, 20 insertions(+), 16 deletions(-)

diff --git a/Lib/asyncio/base_events.py b/Lib/asyncio/base_events.py
index f6d7a58..3951fb7 100644
--- a/Lib/asyncio/base_events.py
+++ b/Lib/asyncio/base_events.py
@@ -882,19 +882,26 @@ class BaseEventLoop(events.AbstractEventLoop):
             when = self._scheduled[0]._when
             timeout = max(0, when - self.time())
 
-        if self._debug:
+        if self._debug and timeout != 0:
             t0 = self.time()
             event_list = self._selector.select(timeout)
             dt = self.time() - t0
-            if dt >= 1:
+            if dt >= 1.0:
                 level = logging.INFO
             else:
                 level = logging.DEBUG
-            if timeout is not None:
-                logger.log(level, 'poll %.3f took %.3f seconds',
-                           timeout, dt)
-            else:
-                logger.log(level, 'poll took %.3f seconds', dt)
+            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)
         self._process_events(event_list)
diff --git a/Lib/asyncio/streams.py b/Lib/asyncio/streams.py
index 9bde218..9b654cd 100644
--- a/Lib/asyncio/streams.py
+++ b/Lib/asyncio/streams.py
@@ -14,7 +14,6 @@ from . import coroutines
 from . import events
 from . import futures
 from . import protocols
-from . import tasks
 from .coroutines import coroutine
 
 
diff --git a/Lib/asyncio/tasks.py b/Lib/asyncio/tasks.py
index 3d7e5a4..78b4c4d 100644
--- a/Lib/asyncio/tasks.py
+++ b/Lib/asyncio/tasks.py
@@ -18,7 +18,6 @@ from . import coroutines
 from . import events
 from . import futures
 from .coroutines import coroutine
-from .log import logger
 
 _PY34 = (sys.version_info >= (3, 4))
 
diff --git a/Lib/test/test_asyncio/test_base_events.py b/Lib/test/test_asyncio/test_base_events.py
index f6da7c3..27610f0 100644
--- a/Lib/test/test_asyncio/test_base_events.py
+++ b/Lib/test/test_asyncio/test_base_events.py
@@ -12,7 +12,6 @@ from test.support import IPV6_ENABLED
 
 import asyncio
 from asyncio import base_events
-from asyncio import events
 from asyncio import constants
 from asyncio import test_utils
 
@@ -26,6 +25,7 @@ class BaseEventLoopTests(test_utils.TestCase):
     def setUp(self):
         self.loop = base_events.BaseEventLoop()
         self.loop._selector = mock.Mock()
+        self.loop._selector.select.return_value = ()
         self.set_event_loop(self.loop)
 
     def test_not_implemented(self):
diff --git a/Lib/test/test_asyncio/test_events.py b/Lib/test/test_asyncio/test_events.py
index e04c287..06552f8 100644
--- a/Lib/test/test_asyncio/test_events.py
+++ b/Lib/test/test_asyncio/test_events.py
@@ -715,7 +715,7 @@ class EventLoopTestsMixin:
             with self.assertRaisesRegex(ValueError,
                                         'path and sock can not be specified '
                                         'at the same time'):
-                server = self.loop.run_until_complete(f)
+                self.loop.run_until_complete(f)
 
     def _create_ssl_context(self, certfile, keyfile=None):
         sslcontext = ssl.SSLContext(ssl.PROTOCOL_SSLv23)
diff --git a/Lib/test/test_asyncio/test_tasks.py b/Lib/test/test_asyncio/test_tasks.py
index 85648dc..ca770f9 100644
--- a/Lib/test/test_asyncio/test_tasks.py
+++ b/Lib/test/test_asyncio/test_tasks.py
@@ -1,6 +1,5 @@
 """Tests for tasks.py."""
 
-import os.path
 import re
 import sys
 import types
@@ -1640,9 +1639,9 @@ class TaskTests(test_utils.TestCase):
             asyncio.coroutines._DEBUG = debug
 
         tb_filename = __file__
-        tb_lineno = sys._getframe().f_lineno + 1
-        coro = coro_noop()
-        coro = None
+        tb_lineno = sys._getframe().f_lineno + 2
+        # create a coroutine object but don't use it
+        coro_noop()
         support.gc_collect()
 
         self.assertTrue(m_log.error.called)
@@ -1652,7 +1651,7 @@ class TaskTests(test_utils.TestCase):
                  r'Coroutine object created at \(most recent call last\):\n'
                  r'.*\n'
                  r'  File "%s", line %s, in test_coroutine_never_yielded\n'
-                 r'    coro = coro_noop\(\)$'
+                 r'    coro_noop\(\)$'
                  % (re.escape(coro_noop.__qualname__),
                     re.escape(func_filename), func_lineno,
                     re.escape(tb_filename), tb_lineno))
-- 
cgit v0.12