Merge 9657-jfhbrook-procmon-logger: Update twisted.runner.procmon to …

…use twisted.logger instead of twisted.python.log Author: jfhbrook Reviewer: hawkieowl Fixes: ticket:9657
oshixingxing · Aug 31, 2019 · 049eb52 · 049eb52
1 parent a2bff7d
commit 049eb52
Show file tree

Hide file tree

Showing 3 changed files with 118 additions and 29 deletions.
diff --git a/src/twisted/runner/newsfragments/9657.doc b/src/twisted/runner/newsfragments/9657.doc
@@ -0,0 +1 @@
+twisted.runner.procmon now logs to a twisted.logger.Logger instance defined on instances of ProcessMonitor instead of to the global legacy twisted.python.log instance.
diff --git a/src/twisted/runner/procmon.py b/src/twisted/runner/procmon.py
@@ -8,10 +8,13 @@
 import attr
 import incremental
 
-from twisted.python import log, deprecate
+from twisted.python import deprecate
 from twisted.internet import error, protocol, reactor as _reactor
 from twisted.application import service
 from twisted.protocols import basic
+from twisted.logger import Logger
+
+
 
 @attr.s(frozen=True)
 class _Process(object):
@@ -62,49 +65,84 @@ def toTuple(self):
         """
         return (self.args, self.uid, self.gid, self.env)
 
+
+
 class DummyTransport:
 
     disconnecting = 0
 
+
+
 transport = DummyTransport()
 
+
+
 class LineLogger(basic.LineReceiver):
 
     tag = None
+    stream = None
     delimiter = b'\n'
+    service = None
 
     def lineReceived(self, line):
         try:
             line = line.decode('utf-8')
         except UnicodeDecodeError:
             line = repr(line)
-        log.msg(u'[%s] %s' % (self.tag, line))
+
+        self.service.log.info(u'[{tag}] {line}',
+                              tag=self.tag,
+                              line=line,
+                              stream=self.stream)
+
 
 
 class LoggingProtocol(protocol.ProcessProtocol):
 
     service = None
     name = None
-    empty = 1
 
     def connectionMade(self):
-        self.output = LineLogger()
-        self.output.tag = self.name
-        self.output.makeConnection(transport)
+        self._output = LineLogger()
+        self._output.tag = self.name
+        self._output.stream = 'stdout'
+        self._output.service = self.service
+        self._outputEmpty = True
 
+        self._error = LineLogger()
+        self._error.tag = self.name
+        self._error.stream = 'stderr'
+        self._error.service = self.service
+        self._errorEmpty = True
 
-    def outReceived(self, data):
-        self.output.dataReceived(data)
-        self.empty = data[-1] == b'\n'
+        self._output.makeConnection(transport)
+        self._error.makeConnection(transport)
 
-    errReceived = outReceived
 
+    def outReceived(self, data):
+        self._output.dataReceived(data)
+        self._outputEmpty = data[-1] == b'\n'
+
+    def errReceived(self, data):
+        self._error.dataReceived(data)
+        self._errorEmpty = data[-1] == b'\n'
 
     def processEnded(self, reason):
-        if not self.empty:
-            self.output.dataReceived(b'\n')
+        if not self._outputEmpty:
+            self._output.dataReceived(b'\n')
+        if not self._errorEmpty:
+            self._error.dataReceived(b'\n')
         self.service.connectionLost(self.name)
 
+    @property
+    def output(self):
+        return self._output
+
+    @property
+    def empty(self):
+        return self._outputEmpty
+
+
 
 class ProcessMonitor(service.Service):
     """
@@ -145,11 +183,16 @@ class ProcessMonitor(service.Service):
     @ivar _reactor: A provider of L{IReactorProcess} and L{IReactorTime}
         which will be used to spawn processes and register delayed calls.
 
+    @type log: L{Logger}
+    @ivar log: The logger used to propagate log messages from spawned
+        processes.
+
     """
     threshold = 1
     killTime = 5
     minRestartDelay = 1
     maxRestartDelay = 3600
+    log = Logger()
 
 
     def __init__(self, reactor=_reactor):

diff --git a/src/twisted/runner/test/test_procmon.py b/src/twisted/runner/test/test_procmon.py
@@ -12,7 +12,7 @@
                                     ProcessExitedAlready)
 from twisted.internet.task import Clock
 from twisted.python.failure import Failure
-from twisted.python import log
+from twisted.logger import globalLogPublisher
 from twisted.test.proto_helpers import MemoryReactor
 
 
@@ -347,11 +347,11 @@ def test_stopProcessAlreadyStopped(self):
 
     def test_outputReceivedCompleteLine(self):
         """
-        Getting a complete output line generates a log message.
+        Getting a complete output line on stdout generates a log message.
         """
         events = []
-        self.addCleanup(log.removeObserver, events.append)
-        log.addObserver(events.append)
+        self.addCleanup(globalLogPublisher.removeObserver, events.append)
+        globalLogPublisher.addObserver(events.append)
         self.pm.addProcess("foo", ["foo"])
         # Schedule the process to start
         self.pm.startService()
@@ -363,17 +363,53 @@ def test_outputReceivedCompleteLine(self):
         # Process greets
         self.pm.protocols["foo"].outReceived(b'hello world!\n')
         self.assertEquals(len(events), 1)
-        message = events[0]['message']
-        self.assertEquals(message, tuple([u'[foo] hello world!']))
+        namespace = events[0]['log_namespace']
+        stream = events[0]['stream']
+        tag = events[0]['tag']
+        line = events[0]['line']
+        self.assertEquals(namespace, 'twisted.runner.procmon.ProcessMonitor')
+        self.assertEquals(stream, 'stdout')
+        self.assertEquals(tag, 'foo')
+        self.assertEquals(line, u'hello world!')
+
+
+    def test_ouputReceivedCompleteErrLine(self):
+        """
+        Getting a complete output line on stderr generates a log message.
+        """
+        events = []
+        self.addCleanup(globalLogPublisher.removeObserver, events.append)
+        globalLogPublisher.addObserver(events.append)
+        self.pm.addProcess("foo", ["foo"])
+        # Schedule the process to start
+        self.pm.startService()
+        # Advance the reactor to start the process
+        self.reactor.advance(0)
+        self.assertIn("foo", self.pm.protocols)
+        # Long time passes
+        self.reactor.advance(self.pm.threshold)
+        # Process greets
+        self.pm.protocols["foo"].errReceived(b'hello world!\n')
+        self.assertEquals(len(events), 1)
+        namespace = events[0]['log_namespace']
+        stream = events[0]['stream']
+        tag = events[0]['tag']
+        line = events[0]['line']
+        self.assertEquals(namespace, 'twisted.runner.procmon.ProcessMonitor')
+        self.assertEquals(stream, 'stderr')
+        self.assertEquals(tag, 'foo')
+        self.assertEquals(line, u'hello world!')
+
+
 
 
     def test_outputReceivedCompleteLineInvalidUTF8(self):
         """
         Getting invalid UTF-8 results in the repr of the raw message
         """
         events = []
-        self.addCleanup(log.removeObserver, events.append)
-        log.addObserver(events.append)
+        self.addCleanup(globalLogPublisher.removeObserver, events.append)
+        globalLogPublisher.addObserver(events.append)
         self.pm.addProcess("foo", ["foo"])
         # Schedule the process to start
         self.pm.startService()
@@ -385,11 +421,14 @@ def test_outputReceivedCompleteLineInvalidUTF8(self):
         # Process greets
         self.pm.protocols["foo"].outReceived(b'\xffhello world!\n')
         self.assertEquals(len(events), 1)
-        messages = events[0]['message']
-        self.assertEquals(len(messages), 1)
-        message = messages[0]
-        tag, output = message.split(' ', 1)
-        self.assertEquals(tag, '[foo]')
+        message = events[0]
+        namespace = message['log_namespace']
+        stream = message['stream']
+        tag = message['tag']
+        output = message['line']
+        self.assertEquals(namespace, 'twisted.runner.procmon.ProcessMonitor')
+        self.assertEquals(stream, 'stdout')
+        self.assertEquals(tag, 'foo')
         self.assertEquals(output, repr(b'\xffhello world!'))
 
 
@@ -398,8 +437,8 @@ def test_outputReceivedPartialLine(self):
         Getting partial line results in no events until process end
         """
         events = []
-        self.addCleanup(log.removeObserver, events.append)
-        log.addObserver(events.append)
+        self.addCleanup(globalLogPublisher.removeObserver, events.append)
+        globalLogPublisher.addObserver(events.append)
         self.pm.addProcess("foo", ["foo"])
         # Schedule the process to start
         self.pm.startService()
@@ -413,8 +452,14 @@ def test_outputReceivedPartialLine(self):
         self.assertEquals(len(events), 0)
         self.pm.protocols["foo"].processEnded(Failure(ProcessDone(0)))
         self.assertEquals(len(events), 1)
-        message = events[0]['message']
-        self.assertEquals(message, tuple([u'[foo] hello world!']))
+        namespace = events[0]['log_namespace']
+        stream = events[0]['stream']
+        tag = events[0]['tag']
+        line = events[0]['line']
+        self.assertEquals(namespace, 'twisted.runner.procmon.ProcessMonitor')
+        self.assertEquals(stream, 'stdout')
+        self.assertEquals(tag, 'foo')
+        self.assertEquals(line, u'hello world!')
 
     def test_connectionLostLongLivedProcess(self):
         """
Original file line number	Diff line number	Diff line change
		@@ -0,0 +1 @@
		twisted.runner.procmon now logs to a twisted.logger.Logger instance defined on instances of ProcessMonitor instead of to the global legacy twisted.python.log instance.