[Checkins] SVN: zc.resumelb/trunk/src/zc/resumelb/ Tweaked and wrote test for logging of worker connections.

[jim]

Log message for revision 125633:
  Tweaked and wrote test for logging of worker connections.
  

Changed:
  U   zc.resumelb/trunk/src/zc/resumelb/tests.py
  U   zc.resumelb/trunk/src/zc/resumelb/worker.py
  U   zc.resumelb/trunk/src/zc/resumelb/worker.test

-=-
Modified: zc.resumelb/trunk/src/zc/resumelb/tests.py
===================================================================
--- zc.resumelb/trunk/src/zc/resumelb/tests.py	2012-05-03 15:28:47 UTC (rev 125632)
+++ zc.resumelb/trunk/src/zc/resumelb/tests.py	2012-05-03 16:56:34 UTC (rev 125633)
@@ -117,7 +117,9 @@
         manuel.testing.TestSuite(
             manuel.doctest.Manuel(
                 checker = zope.testing.renormalizing.OutputChecker([
-                    (re.compile(r'127.0.0.1:\d+'), '127.0.0.1:0'),
+                    (re.compile(r'127.0.0.1:\d+'), '127.0.0.1:P'),
+                    (re.compile(r"'127.0.0.1', \d+"), "'127.0.0.1', P'"),
+                    (re.compile(r"<socket fileno=\d+"), "<socket fileno=F"),
                     ])
                 ) + manuel.capture.Manuel(),
             'lb.test', 'pool.test', 'worker.test', 'bytesizedqueue.test',

Modified: zc.resumelb/trunk/src/zc/resumelb/worker.py
===================================================================
--- zc.resumelb/trunk/src/zc/resumelb/worker.py	2012-05-03 15:28:47 UTC (rev 125632)
+++ zc.resumelb/trunk/src/zc/resumelb/worker.py	2012-05-03 16:56:34 UTC (rev 125633)
@@ -164,9 +164,8 @@
             while [c for c in self.connections if c.id == connid]:
                 connid += 1
             conn.id = connid
-            logger.info("Received connection (%s) from %s", connid, addr)
             self.connections.add(conn)
-            readers = conn.connected(sock, addr)
+            readers = conn.connected(sock, "%s(%s)" % (addr, connid))
             conn.put((0, self.resume))
             while conn.is_connected:
                 try:

Modified: zc.resumelb/trunk/src/zc/resumelb/worker.test
===================================================================
--- zc.resumelb/trunk/src/zc/resumelb/worker.test	2012-05-03 15:28:47 UTC (rev 125632)
+++ zc.resumelb/trunk/src/zc/resumelb/worker.test	2012-05-03 16:56:34 UTC (rev 125633)
@@ -578,6 +578,10 @@
     ...       zc.resumelb.tests.app(), ('127.0.0.1', 0), history=2,
     ...       tracelog='tracelog', threads=1)
 
+    >>> import zope.testing.loggingsupport
+    >>> util_handler = zope.testing.loggingsupport.InstalledHandler(
+    ...     'zc.resumelb.util')
+
     >>> worker_socket = gevent.socket.create_connection(worker.addr)
     >>> pprint(read_message(worker_socket))
     (0, {})
@@ -674,6 +678,34 @@
     >>> worker_socket2.close()
     >>> worker.stop()
 
+Connections and disconnections are logged and reflect the lb ids that
+show up in the trace logs. This allows us to match lb ids and lb
+addresses.
+
+    >>> print util_handler
+    zc.resumelb.util INFO
+      worker connected ('127.0.0.1', 51886)(0)
+    zc.resumelb.util DEBUG
+      write_message disconnected <socket fileno=8 sock=127.0.0.1:58498>
+    zc.resumelb.util INFO
+      worker disconnected ('127.0.0.1', 34147)(0)
+    zc.resumelb.util INFO
+      worker connected ('127.0.0.1', 51887)(1)
+    zc.resumelb.util INFO
+      read_message disconnected <socket fileno=11 sock=127.0.0.1:57540 peer=127.0.0.1:36766>
+    zc.resumelb.util INFO
+      worker disconnected ('127.0.0.1', 36766)(1)
+    zc.resumelb.util INFO
+      read_message disconnected <socket fileno=10 sock=127.0.0.1:60590>
+    zc.resumelb.util INFO
+      worker disconnected ('127.0.0.1', 51887)(1)
+    zc.resumelb.util INFO
+      read_message disconnected <socket fileno=12 sock=127.0.0.1:60590 peer=127.0.0.1:51886>
+    zc.resumelb.util INFO
+      worker disconnected ('127.0.0.1', 51886)(0)
+
+    >>> util_handler.uninstall()
+
 Updating worker settings
 ------------------------