source: ralphm-patches/stream-manager-logging.patch @ 72:727b4d29c48e

wokkel/subprotocols.py

@@ -142 +142 @@
     @type timeout: C{int}
 
     @ivar _reactor: A provider of L{IReactorTime} to track timeouts.
+
+    @cvar __streamCount: Global stream count for distinguishing streams.
     """
 
     timeout = None
     _reactor = None
+    __streamCount = 0
 
     logTraffic = False
 
@@ -195 +198 @@
         and call each handler's C{makeConnection} method with the L{XmlStream}
         instance.
         """
-        def logDataIn(buf):
-            log.msg("RECV: %r" % buf)
-
-        def logDataOut(buf):
-            log.msg("SEND: %r" % buf)
+        xs.serial = self.__streamCount
+        BaseStreamManager.__streamCount += 1
 
         if self.logTraffic:
-            xs.rawDataInFn = logDataIn
-            xs.rawDataOutFn = logDataOut
+            def logData(direction, data):
+                log.msg(format="%(direction)s (%(streamID)s): %(data)r",
+                        direction=direction, streamID=xs.serial, data=data)
+
+            log.msg(format="Connection %(streamID)s made", streamID=xs.serial)
+            xs.rawDataInFn = lambda data: logData("RECV", data)
+            xs.rawDataOutFn = lambda data: logData("SEND", data)
 
         xs.addObserver(xmlstream.STREAM_AUTHD_EVENT,
                        self.connectionInitialized)
         xs.addObserver(xmlstream.STREAM_END_EVENT,
                        self.connectionLost)
+
         self.xmlstream = xs
 
         for e in list(self):
@@ -222 +228 @@
         Send out cached stanzas and call each handler's
         C{connectionInitialized} method.
         """
+        if self.logTraffic:
+            log.msg(format="Connection %(streamID)s initialized",
+                    streamID=xs.serial)
 
         xs.addObserver('/iq[@type="result"]', self._onIQResponse)
         xs.addObserver('/iq[@type="error"]', self._onIQResponse)
@@ -247 +256 @@
         L{XmlStream} anymore and notifies each handler that the connection
         was lost by calling its C{connectionLost} method.
         """
+        if self.logTraffic:
+            log.msg(format="Connection %(streamID)s lost",
+                    streamID=self.xmlstream.serial)
+
         self.xmlstream = None
         self._initialized = False
 

wokkel/test/test_subprotocols.py

@@ -11 +11 @@
 from twisted.test import proto_helpers
 from twisted.internet import defer, task
 from twisted.internet.error import ConnectionDone
-from twisted.python import failure
+from twisted.python import failure, log
 from twisted.words.xish import domish
 from twisted.words.protocols.jabber import error, ijabber, xmlstream
 
@@ -230 +230 @@
         Test raw data functions unset when logTraffic is set to False.
         """
         sm = self.streamManager
+        sm.logTraffic = False
         handler = DummyXMPPHandler()
         handler.setHandlerParent(sm)
         xs = self.xmlstream
@@ -240 +241 @@
 
     def test_makeConnectionLogTrafficTrue(self):
         """
-        Test raw data functions set when logTraffic is set to True.
+        Test raw data functions when logTraffic is set to True.
         """
         sm = self.streamManager
         sm.logTraffic = True
         handler = DummyXMPPHandler()
         handler.setHandlerParent(sm)
         xs = self.xmlstream
+
+        # Set up log observer
+        logged = []
+        log.addObserver(logged.append)
+
         sm.makeConnection(xs)
         self.assertNotIdentical(None, xs.rawDataInFn)
         self.assertNotIdentical(None, xs.rawDataOutFn)
 
+        xs.rawDataInFn("<presence/>")
+        self.assertEqual(2, len(logged))
+
+        eventDict = logged[-1]
+        self.assertEqual('RECV', eventDict['direction'])
+        self.assertEqual(xs.serial, eventDict['streamID'])
+        self.assertEqual('<presence/>', eventDict['data'])
+
+        xs.rawDataOutFn("<presence/>")
+        eventDict = logged[-1]
+        self.assertEqual('SEND', eventDict['direction'])
+
 
     def test_connectionInitialized(self):
         """
@@ -258 +276 @@
         called when the XML stream is initialized.
         """
         sm = self.streamManager
+        sm.logTraffic = True
         handler = DummyXMPPHandler()
         handler.setHandlerParent(sm)
         xs = self.xmlstream
+        xs.serial = 0
         sm.connectionInitialized(xs)
         self.assertEquals(0, handler.doneMade)
         self.assertEquals(1, handler.doneInitialized)
@@ -272 +292 @@
         Protocol handlers have connectionLost called on stream disconnect.
         """
         sm = self.streamManager
+        sm.logTraffic = True
         handler = DummyXMPPHandler()
         handler.setHandlerParent(sm)
+        sm.xmlstream = xmlstream.XmlStream(xmlstream.Authenticator())
+        sm.xmlstream.serial = 0
         sm.connectionLost(None)
         self.assertEquals(0, handler.doneMade)
         self.assertEquals(0, handler.doneInitialized)