Factor recorders into their own module (event listeners will provide slighly different recorders).

src/supervisor/options.py

@@ -1459,6 +1459,30 @@ class ProcessConfig(Config):
             dir=self.options.childlogdir)
         return logfile
 
+    def make_stderr_recorder(self):
+        from supervisor.recorders import LoggingRecorder
+        if self.stderr_logfile and not self.redirect_stderr:
+            return LoggingRecorder(
+                options = self.options,
+                procname = self.name,
+                channel = 'stderr',
+                logfile = self.stderr_logfile,
+                logfile_backups = self.stderr_logfile_backups,
+                logfile_maxbytes = self.stderr_logfile_maxbytes,
+                capturefile = self.stderr_capturefile)
+
+    def make_stdout_recorder(self):
+        from supervisor.recorders import LoggingRecorder
+        if self.stdout_logfile:
+            return LoggingRecorder(
+                options = self.options,
+                procname = self.name,
+                channel = 'stdout',
+                logfile = self.stdout_logfile,
+                logfile_backups = self.stdout_logfile_backups,
+                logfile_maxbytes = self.stdout_logfile_maxbytes,
+                capturefile = self.stdout_capturefile)
+
 class ProcessGroupConfig(Config):
     def __init__(self, options, name, priority, process_configs):
         self.options = options

src/supervisor/process.py

@@ -17,7 +17,6 @@ import os
 import time
 import errno
 import shlex
-import logging
 import StringIO
 import traceback
 import signal
@@ -26,9 +25,6 @@ from supervisor.options import decode_wait_status
 from supervisor.options import signame
 from supervisor.options import ProcessException
 
-from supervisor.events import ProcessCommunicationEvent
-from supervisor.events import notify
-
 class ProcessStates:
     STOPPED = 0
     STARTING = 10
@@ -76,29 +72,13 @@ class Subprocess:
         self.pipes = {}
         self.rpipes = {}
         self.dispatchers = {}
-        if config.stdout_logfile:
-            self.stdout_recorder = LoggingRecorder(
-                options = config.options,
-                procname = config.name,
-                channel = 'stdout',
-                logfile = config.stdout_logfile,
-                logfile_backups = config.stdout_logfile_backups,
-                logfile_maxbytes = config.stdout_logfile_maxbytes,
-                capturefile = config.stdout_capturefile)
-        if config.stderr_logfile and not config.redirect_stderr:
-            self.stderr_recorder = LoggingRecorder(
-                options = config.options,
-                procname = config.name,
-                channel = 'stderr',
-                logfile = config.stderr_logfile,
-                logfile_backups = config.stderr_logfile_backups,
-                logfile_maxbytes = config.stderr_logfile_maxbytes,
-                capturefile = config.stderr_capturefile)
+        self.stdout_recorder = self.config.make_stdout_recorder()
+        self.stderr_recorder = self.config.make_stderr_recorder()
 
     def removelogs(self):
         for recorder in self.stdout_recorder, self.stderr_recorder:
             if recorder is not None:
-                if hasatrr(recorder, 'removelogs'):
+                if hasattr(recorder, 'removelogs'):
                     recorder.removelogs()
 
     def reopenlogs(self):
@@ -570,130 +550,6 @@ class ProcessGroup:
             dispatchers.update(process.dispatchers)
         return dispatchers
 
-class LoggingRecorder:
-    options = None # reference to options.ServerOptions instance
-    procname = '' # process name which "owns" this logger
-    channel = None # 'stdin' or 'stdout'
-    capturemode = False # are we capturing process event data
-    mainlog = None #  the process' "normal" log file
-    capturelog = None # the log file while we're in capturemode
-    childlog = None # the current logger (event or main)
-    output_buffer = '' # data waiting to be logged
-    
-    def __init__(self, options, procname, channel, logfile, logfile_backups,
-                 logfile_maxbytes, capturefile):
-        self.procname = procname
-        self.channel = channel
-        self.options = options
-        self.mainlog = options.getLogger(
-                logfile, logging.INFO,
-                '%(message)s',
-                rotating=not not logfile_maxbytes,
-                maxbytes=logfile_maxbytes,
-                backups=logfile_backups)
-        self.childlog = self.mainlog
-
-        self.capturefile = capturefile
-        if capturefile:
-            self.capturelog = options.getLogger(
-                capturefile,
-                logging.INFO,
-                '%(message)s',
-                rotating=False)
-
-    def removelogs(self):
-        for log in (self.mainlog, self.capturelog):
-            if log is not None:
-                for handler in log.handlers:
-                    handler.remove()
-                    handler.reopen()
-
-    def reopenlogs(self):
-        for log in (self.mainlog, self.capturelog):
-            if log is not None:
-                for handler in log.handlers:
-                    handler.reopen()
-
-    def record_output(self):
-        if self.capturemode:
-            token = ProcessCommunicationEvent.END_TOKEN
-        else:
-            token = ProcessCommunicationEvent.BEGIN_TOKEN
-
-        data = self.output_buffer
-        self.output_buffer = ''
-
-        if len(data) <= len(token):
-            self.output_buffer = data
-            return # not enough data
-
-        try:
-            before, after = data.split(token, 1)
-        except ValueError:
-            after = None
-            index = find_prefix_at_end(data, token)
-            if index:
-                self.output_buffer = self.output_buffer + data[-index:]
-                data = data[:-index]
-        else:
-            data = before
-            self.toggle_capturemode()
-            self.output_buffer = after
-
-        if self.childlog and data:
-            if self.options.strip_ansi:
-                data = self.options.stripEscapes(data)
-            self.childlog.info(data)
-
-        if data:
-            msg = '%r %s output:\n%s' % (self.procname, self.channel, data)
-            self.options.logger.log(self.options.TRACE, msg)
-
-        if after:
-            self.record_output()
-
-    def toggle_capturemode(self):
-        self.capturemode = not self.capturemode
-
-        if self.capturelog is not None:
-            if self.capturemode:
-                self.childlog = self.capturelog
-            else:
-                capturefile = self.capturefile
-                for handler in self.capturelog.handlers:
-                    handler.flush()
-                data = ''
-                f = self.options.open(capturefile, 'r')
-                while 1:
-                    new = f.read(1<<20) # 1MB
-                    data += new
-                    if not new:
-                        break
-                    if len(data) > (1 << 21): #2MB
-                        data = data[:1<<21]
-                        # DWIM: don't overrun memory
-                        self.options.logger.info(
-                            'Truncated oversized EVENT mode log to 2MB')
-                        break 
-
-                channel = self.channel
-                procname = self.procname
-                notify(ProcessCommunicationEvent(procname, channel, data))
-                                        
-                msg = "%r %s emitted a comm event" % (procname, channel)
-                self.options.logger.log(self.options.TRACE, msg)
-                                        
-                for handler in self.capturelog.handlers:
-                    handler.remove()
-                    handler.reopen()
-                self.childlog = self.mainlog
-        
-def find_prefix_at_end(haystack, needle):
-    l = len(needle) - 1
-    while l and not haystack.endswith(needle[:l]):
-        l -= 1
-    return l
-
 class PDispatcher:
     """ Asyncore dispatcher for mainloop, representing a process channel
     (stdin, stdout, or stderr).  This class is abstract. """

src/supervisor/recorders.py

@@ -0,0 +1,128 @@
+import logging
+from supervisor.events import ProcessCommunicationEvent
+from supervisor.events import notify
+
+class LoggingRecorder:
+    options = None # reference to options.ServerOptions instance
+    procname = '' # process name which "owns" this logger
+    channel = None # 'stdin' or 'stdout'
+    capturemode = False # are we capturing process event data
+    mainlog = None #  the process' "normal" log file
+    capturelog = None # the log file while we're in capturemode
+    childlog = None # the current logger (event or main)
+    output_buffer = '' # data waiting to be logged
+    
+    def __init__(self, options, procname, channel, logfile, logfile_backups,
+                 logfile_maxbytes, capturefile):
+        self.procname = procname
+        self.channel = channel
+        self.options = options
+        self.mainlog = options.getLogger(
+                logfile, logging.INFO,
+                '%(message)s',
+                rotating=not not logfile_maxbytes,
+                maxbytes=logfile_maxbytes,
+                backups=logfile_backups)
+        self.childlog = self.mainlog
+
+        self.capturefile = capturefile
+        if capturefile:
+            self.capturelog = options.getLogger(
+                capturefile,
+                logging.INFO,
+                '%(message)s',
+                rotating=False)
+
+    def removelogs(self):
+        for log in (self.mainlog, self.capturelog):
+            if log is not None:
+                for handler in log.handlers:
+                    handler.remove()
+                    handler.reopen()
+
+    def reopenlogs(self):
+        for log in (self.mainlog, self.capturelog):
+            if log is not None:
+                for handler in log.handlers:
+                    handler.reopen()
+
+    def record_output(self):
+        if self.capturemode:
+            token = ProcessCommunicationEvent.END_TOKEN
+        else:
+            token = ProcessCommunicationEvent.BEGIN_TOKEN
+
+        data = self.output_buffer
+        self.output_buffer = ''
+
+        if len(data) <= len(token):
+            self.output_buffer = data
+            return # not enough data
+
+        try:
+            before, after = data.split(token, 1)
+        except ValueError:
+            after = None
+            index = find_prefix_at_end(data, token)
+            if index:
+                self.output_buffer = self.output_buffer + data[-index:]
+                data = data[:-index]
+        else:
+            data = before
+            self.toggle_capturemode()
+            self.output_buffer = after
+
+        if self.childlog and data:
+            if self.options.strip_ansi:
+                data = self.options.stripEscapes(data)
+            self.childlog.info(data)
+
+        if data:
+            msg = '%r %s output:\n%s' % (self.procname, self.channel, data)
+            self.options.logger.log(self.options.TRACE, msg)
+
+        if after:
+            self.record_output()
+
+    def toggle_capturemode(self):
+        self.capturemode = not self.capturemode
+
+        if self.capturelog is not None:
+            if self.capturemode:
+                self.childlog = self.capturelog
+            else:
+                capturefile = self.capturefile
+                for handler in self.capturelog.handlers:
+                    handler.flush()
+                data = ''
+                f = self.options.open(capturefile, 'r')
+                while 1:
+                    new = f.read(1<<20) # 1MB
+                    data += new
+                    if not new:
+                        break
+                    if len(data) > (1 << 21): #2MB
+                        data = data[:1<<21]
+                        # DWIM: don't overrun memory
+                        self.options.logger.info(
+                            'Truncated oversized EVENT mode log to 2MB')
+                        break 
+
+                channel = self.channel
+                procname = self.procname
+                notify(ProcessCommunicationEvent(procname, channel, data))
+                                        
+                msg = "%r %s emitted a comm event" % (procname, channel)
+                self.options.logger.log(self.options.TRACE, msg)
+                                        
+                for handler in self.capturelog.handlers:
+                    handler.remove()
+                    handler.reopen()
+                self.childlog = self.mainlog
+        
+def find_prefix_at_end(haystack, needle):
+    l = len(needle) - 1
+    while l and not haystack.endswith(needle[:l]):
+        l -= 1
+    return l
+

src/supervisor/tests/base.py

@@ -419,6 +419,12 @@ class DummyPConfig:
     def create_autochildlogs(self):
         self.autochildlogs_created = True
 
+    def make_stdout_recorder(self):
+        return DummyRecorder()
+
+    def make_stderr_recorder(self):
+        return DummyRecorder()
+
 def makeExecutable(file, substitutions=None):
     import os
     import sys
@@ -695,6 +701,13 @@ class PopulatedDummySupervisor(DummySupervisor):
 class DummyRecorder:
     def __init__(self):
         self.output_buffer = ''
+        self.childlog = DummyLogger()
+        self.mainlog = self.childlog
+        self.output_buffer = ''
+        self.output_recorded = ''
+
+    def record_output(self):
+        self.output_recorded += self.output_buffer
 
 class DummyDispatcher:
     write_event_handled = False

src/supervisor/tests/test_options.py

@@ -588,6 +588,69 @@ class TestProcessConfig(unittest.TestCase):
         instance.create_autochildlogs()
         self.assertEqual(instance.stdout_logfile, options.tempfile_name)
         self.assertEqual(instance.stderr_logfile, options.tempfile_name)
+
+    def test_make_stderr_recorder(self):
+        options = DummyOptions()
+        instance = self._makeOne(options)
+        instance.redirect_stderr = False
+        recorder = instance.make_stderr_recorder()
+        from supervisor.recorders import LoggingRecorder
+        self.assertEqual(recorder.__class__, LoggingRecorder)
+        self.assertEqual(recorder.procname, 'name')
+        self.assertEqual(recorder.channel, 'stderr')
+        self.assertEqual(recorder.options, options)
+        self.assertEqual(recorder.mainlog.__class__, DummyLogger)
+        self.assertEqual(recorder.mainlog.args, (
+            ('stderr_logfile', 20, '%(message)s'),
+            {'rotating': True,
+             'backups': 'stderr_logfile_backups',
+             'maxbytes': 'stderr_logfile_maxbytes'}
+            ))
+        self.assertEqual(recorder.childlog, recorder.mainlog)
+        self.assertEqual(recorder.capturelog.__class__, DummyLogger)
+        self.assertEqual(recorder.capturelog.args,
+                         (('stderr_capturefile', 20, '%(message)s'),
+                          {'rotating': False}))
+
+    def test_make_stderr_recorder_nocapture(self):
+        options = DummyOptions()
+        instance = self._makeOne(options)
+        instance.redirect_stderr = False
+        instance.stderr_capturefile = None
+        recorder = instance.make_stderr_recorder()
+        from supervisor.recorders import LoggingRecorder
+        self.assertEqual(recorder.capturelog, None)
+
+    def test_make_stdout_recorder(self):
+        options = DummyOptions()
+        instance = self._makeOne(options)
+        recorder = instance.make_stdout_recorder()
+        from supervisor.recorders import LoggingRecorder
+        self.assertEqual(recorder.__class__, LoggingRecorder)
+        self.assertEqual(recorder.procname, 'name')
+        self.assertEqual(recorder.channel, 'stdout')
+        self.assertEqual(recorder.options, options)
+        self.assertEqual(recorder.mainlog.__class__, DummyLogger)
+        self.assertEqual(recorder.mainlog.args, (
+            ('stdout_logfile', 20, '%(message)s'),
+            {'rotating': True,
+             'backups': 'stdout_logfile_backups',
+             'maxbytes': 'stdout_logfile_maxbytes'}
+            ))
+        self.assertEqual(recorder.childlog, recorder.mainlog)
+        self.assertEqual(recorder.capturelog.__class__, DummyLogger)
+        self.assertEqual(recorder.capturelog.args,
+                         (('stdout_capturefile', 20, '%(message)s'),
+                          {'rotating': False}))
+
+    def test_make_stdout_recorder_nocapture(self):
+        options = DummyOptions()
+        instance = self._makeOne(options)
+        instance.redirect_stderr = False
+        instance.stdout_capturefile = None
+        recorder = instance.make_stdout_recorder()
+        from supervisor.recorders import LoggingRecorder
+        self.assertEqual(recorder.capturelog, None)
             
 class BasicAuthTransportTests(unittest.TestCase):
     def _getTargetClass(self):

src/supervisor/tests/test_process.py

@@ -27,12 +27,6 @@ class SubprocessTests(unittest.TestCase):
         self.assertEqual(instance.config, config)
         self.assertEqual(instance.config.options, options)
         self.assertEqual(instance.laststart, 0)
-        self.assertEqual(instance.stdout_recorder.childlog.args, (
-            ('/tmp/temp123.log', 20, '%(message)s'),
-            {'rotating': False, 'backups': 0, 'maxbytes': 0}))
-        self.assertEqual(instance.stderr_recorder.childlog.args, (
-            ('/tmp/temp456.log', 20, '%(message)s'),
-            {'rotating': False, 'backups': 0, 'maxbytes': 0}))
         self.assertEqual(instance.pid, 0)
         self.assertEqual(instance.laststart, 0)
         self.assertEqual(instance.laststop, 0)
@@ -45,14 +39,12 @@ class SubprocessTests(unittest.TestCase):
         self.assertEqual(instance.stdout_recorder.output_buffer, '')
         self.assertEqual(instance.stderr_recorder.output_buffer, '')
 
-    def test_record_output_no_recorders(self):
+    def test_record_output_no_recorders_doesnt_barf(self):
         options = DummyOptions()
-        config = DummyPConfig(options, 'notthere', '/notthere',
-                              stdout_logfile=None,
-                              stderr_logfile=None)
+        config = DummyPConfig(options, 'notthere', '/notthere')
         instance = self._makeOne(config)
-        self.assertEqual(instance.stdout_recorder, None)
-        self.assertEqual(instance.stderr_recorder, None)
+        instance.stdout_recorder = None
+        instance.stderr_recorder = None
         instance.record_output()
         self.assertEqual(options.logger.data, [])
 
@@ -555,45 +547,6 @@ class SubprocessTests(unittest.TestCase):
         instance.laststart = 1
         self.assertEqual(instance.get_state(), ProcessStates.UNKNOWN)
 
-    def test_strip_ansi(self):
-        executable = '/bin/cat'
-        options = DummyOptions()
-        from supervisor.options import getLogger
-        options.getLogger = getLogger
-        options.strip_ansi = True
-        config = DummyPConfig(options, 'output', executable,
-                              stdout_logfile='/tmp/foo')
-
-        ansi = '\x1b[34mHello world... this is longer than a token!\x1b[0m'
-        noansi = 'Hello world... this is longer than a token!'
-
-        try:
-            instance = self._makeOne(config)
-            instance.stdout_recorder.output_buffer = ansi
-            instance.record_output()
-            [ x.flush() for x in instance.stdout_recorder.childlog.handlers ]
-            self.assertEqual(
-                open(instance.config.stdout_logfile, 'r').read(), noansi)
-        finally:
-            try:
-                os.remove(instance.config.stdout_logfile)
-            except (OSError, IOError):
-                pass
-
-        try:
-            options.strip_ansi = False
-            instance = self._makeOne(config)
-            instance.stdout_recorder.output_buffer = ansi
-            instance.record_output()
-            [ x.flush() for x in instance.stdout_recorder.childlog.handlers ]
-            self.assertEqual(
-                open(instance.config.stdout_logfile, 'r').read(), ansi)
-        finally:
-            try:
-                os.remove(instance.config.stdout_logfile)
-            except (OSError, IOError):
-                pass
-
     def test_drain_output_fd(self):
         options = DummyOptions()
         config = DummyPConfig(options, 'test', '/test')
@@ -854,7 +807,7 @@ class ProcessGroupTests(unittest.TestCase):
 
 class LoggingRecorderTests(unittest.TestCase):
     def _getTargetClass(self):
-        from supervisor.process import LoggingRecorder
+        from supervisor.recorders import LoggingRecorder
         return LoggingRecorder
 
     def _makeOne(self, options, procname, channel, logfile, logfile_backups,
@@ -974,6 +927,26 @@ class LoggingRecorderTests(unittest.TestCase):
             except (OSError, IOError):
                 pass
 
+    def test_strip_ansi(self):
+        options = DummyOptions()
+        options.strip_ansi = True
+        instance = self._makeOne(options, 'whatever', 'stdout',
+                                 '/tmp/log', None, 100, '/tmp/capture')
+        ansi = '\x1b[34mHello world... this is longer than a token!\x1b[0m'
+        noansi = 'Hello world... this is longer than a token!'
+
+        instance.output_buffer = ansi
+        instance.record_output()
+        self.assertEqual(len(instance.childlog.data), 1)
+        self.assertEqual(instance.childlog.data[0], noansi)
+
+        options.strip_ansi = False
+
+        instance.output_buffer = ansi
+        instance.record_output()
+        self.assertEqual(len(instance.childlog.data), 2)
+        self.assertEqual(instance.childlog.data[1], ansi)
+
 class POutputDispatcherTests(unittest.TestCase):
     def _getTargetClass(self):
         from supervisor.process import POutputDispatcher