# mike reported that comm events that took place within a single

        # output buffer were broken 8/20/2007

src/supervisor/dispatchers.py

@@ -76,7 +76,10 @@ class POutputDispatcher(PDispatcher):
 
         self.childlog = self.mainlog
 
-
+    def _trace(self, msg):
+        TRACE = self.process.config.options.TRACE
+        self.process.config.options.logger.log(TRACE, msg)
+        
     def removelogs(self):
         for log in (self.mainlog, self.capturelog):
             if log is not None:
@@ -90,6 +93,16 @@ class POutputDispatcher(PDispatcher):
                 for handler in log.handlers:
                     handler.reopen()
 
+    def _log(self, data):
+        if data:
+            config = self.process.config
+            if config.options.strip_ansi:
+                data = config.options.stripEscapes(data)
+            if self.childlog:
+                self.childlog.info(data)
+            msg = '%r %s output:\n%s' % (config.name, self.channel, data)
+            self._trace(msg)
+
     def record_output(self):
         if self.capturemode:
             token = self.event_type.END_TOKEN
@@ -111,22 +124,12 @@ class POutputDispatcher(PDispatcher):
             if index:
                 self.output_buffer = self.output_buffer + data[-index:]
                 data = data[:-index]
+            self._log(data)
         else:
-            data = before
+            self._log(before)
             self.toggle_capturemode()
             self.output_buffer = after
 
-        if self.childlog and data:
-            if self.process.config.options.strip_ansi:
-                data = self.process.config.options.stripEscapes(data)
-            self.childlog.info(data)
-
-        if data:
-            procname = self.process.config.name
-            msg = '%r %s output:\n%s' % (procname, self.channel, data)
-            TRACE = self.process.config.options.TRACE
-            self.process.config.options.logger.log(TRACE, msg)
-
         if after:
             self.record_output()
 
@@ -160,8 +163,7 @@ class POutputDispatcher(PDispatcher):
                 notify(event)
                                         
                 msg = "%r %s emitted a comm event" % (procname, channel)
-                TRACE = self.process.config.options.TRACE
-                self.process.config.options.logger.log(TRACE, msg)
+                self._trace(msg)
                                         
                 for handler in self.capturelog.handlers:
                     handler.remove()

src/supervisor/tests/test_dispatchers.py

@@ -8,6 +8,14 @@ from supervisor.tests.base import DummyPConfig
 from supervisor.tests.base import DummyLogger
 
 class POutputDispatcherTests(unittest.TestCase):
+    def setUp(self):
+        from supervisor.events import clear
+        clear()
+
+    def tearDown(self):
+        from supervisor.events import clear
+        clear()
+
     def _getTargetClass(self):
         from supervisor.dispatchers import POutputDispatcher
         return POutputDispatcher
@@ -109,7 +117,56 @@ class POutputDispatcherTests(unittest.TestCase):
         self.assertEqual(options.logger.data[1],
              "'process1' stdout output:\nstdout string longer than a token")
 
-    def test_stdout_capturemode_switch(self):
+    def test_stdout_capturemode_single_buffer(self):
+        # mike reported that comm events that took place within a single
+        # output buffer were broken 8/20/2007
+        from supervisor.events import ProcessCommunicationEvent
+        from supervisor.events import subscribe
+        events = []
+        def doit(event):
+            events.append(event)
+        subscribe(ProcessCommunicationEvent, doit)
+        BEGIN_TOKEN = ProcessCommunicationEvent.BEGIN_TOKEN
+        END_TOKEN = ProcessCommunicationEvent.END_TOKEN
+        data = BEGIN_TOKEN + 'hello' + END_TOKEN
+        options = DummyOptions()
+        from supervisor.options import getLogger
+        options.getLogger = getLogger # actually use real logger
+        logfile = '/tmp/log'
+        capturefile = '/tmp/capture'
+        config = DummyPConfig(options, 'process1', '/bin/process1',
+                              stdout_logfile=logfile,
+                              stdout_capturefile=capturefile)
+        config.stdout_logfile = logfile
+        config.capturefile = capturefile
+        process = DummyProcess(config)
+        dispatcher = self._makeOne(process)
+
+        try:
+            dispatcher.output_buffer = data
+            dispatcher.record_output()
+            self.assertEqual(open(logfile, 'r').read(), '')
+            self.assertEqual(dispatcher.output_buffer, '')
+            self.assertEqual(len(events), 1)
+
+            event = events[0]
+            from supervisor.events import ProcessCommunicationStdoutEvent
+            self.assertEqual(event.__class__, ProcessCommunicationStdoutEvent)
+            self.assertEqual(event.process, process)
+            self.assertEqual(event.channel, 'stdout')
+            self.assertEqual(event.data, 'hello')
+
+        finally:
+            try:
+                os.remove(logfile)
+            except (OSError, IOError):
+                pass
+            try:
+                os.remove(capturefile)
+            except (OSError, IOError):
+                pass
+        
+    def test_stdout_capturemode_multiple_buffers(self):
         from supervisor.events import ProcessCommunicationEvent
         from supervisor.events import subscribe
         events = []
@@ -129,7 +186,6 @@ class POutputDispatcherTests(unittest.TestCase):
         second = broken[1] + ':'
         third = broken[2]
 
-        executable = '/bin/cat'
         options = DummyOptions()
         from supervisor.options import getLogger
         options.getLogger = getLogger # actually use real logger