asyncio: sync with Tulip

* Tulip issue #184: Log subprocess events in debug mode

  - Log stdin, stdout and stderr transports and protocols
  - Log process identifier (pid)
  - Log connection of pipes
  - Log process exit
  - Log Process.communicate() tasks: feed stdin, read stdout and stderr
  - Add __repr__() method to many classes related to subprocesses


* Add BaseSubprocessTransport._pid attribute. Store the pid so it is still
  accessible after the process exited. It's more convinient for debug.

* create_connection(): add the socket in the "connected to" debug log

* Clean up some docstrings and comments. Remove unused unimplemented
  _read_from_self().

1 files changed, 26 insertions, 0 deletions

diff --git a/Lib/asyncio/subprocess.py b/Lib/asyncio/subprocess.py
index 2cd6de6..12902f1 100644
--- a/Lib/asyncio/subprocess.py
+++ b/Lib/asyncio/subprocess.py
@@ -9,6 +9,7 @@ from . import protocols
 from . import streams
 from . import tasks
 from .coroutines import coroutine
+from .log import logger
 
 
 PIPE = subprocess.PIPE
@@ -28,6 +29,16 @@ class SubprocessStreamProtocol(streams.FlowControlMixin,
         self._waiters = collections.deque()
         self._transport = None
 
+    def __repr__(self):
+        info = [self.__class__.__name__]
+        if self.stdin is not None:
+            info.append('stdin=%r' % self.stdin)
+        if self.stdout is not None:
+            info.append('stdout=%r' % self.stdout)
+        if self.stderr is not None:
+            info.append('stderr=%r' % self.stderr)
+        return '<%s>' % ' '.join(info)
+
     def connection_made(self, transport):
         self._transport = transport
         if transport.get_pipe_transport(1):
@@ -91,6 +102,9 @@ class Process:
         self.stderr = protocol.stderr
         self.pid = transport.get_pid()
 
+    def __repr__(self):
+        return '<%s %s>' % (self.__class__.__name__, self.pid)
+
     @property
     def returncode(self):
         return self._transport.get_returncode()
@@ -126,7 +140,13 @@ class Process:
     @coroutine
     def _feed_stdin(self, input):
         self.stdin.write(input)
+        if self._loop.get_debug():
+            logger.debug('%r communicate: feed stdin (%s bytes)',
+                        self, len(input))
         yield from self.stdin.drain()
+
+        if self._loop.get_debug():
+            logger.debug('%r communicate: close stdin', self)
         self.stdin.close()
 
     @coroutine
@@ -141,7 +161,13 @@ class Process:
         else:
             assert fd == 1
             stream = self.stdout
+        if self._loop.get_debug():
+            name = 'stdout' if fd == 1 else 'stderr'
+            logger.debug('%r communicate: read %s', self, name)
         output = yield from stream.read()
+        if self._loop.get_debug():
+            name = 'stdout' if fd == 1 else 'stderr'
+            logger.debug('%r communicate: close %s', self, name)
         transport.close()
         return output