log commands sent to the server

add tests, too

Author: whilp

redis/client.py

@@ -336,6 +336,7 @@ def _execute_command(self, command_name, command, **options):
         if self.subscribed and not subscription_command:
             raise RedisError("Cannot issue commands other than SUBSCRIBE and "
                 "UNSUBSCRIBE while channels are open")
+        log.debug(repr_command(command))
         command = self._encode_command(command)
         try:
             self.connection.send(command, self)
@@ -1435,6 +1436,10 @@ def _execute_transaction(self, commands):
             commands,
             (('', ('EXEC',), ''),)
             )])
+        log.debug("MULTI")
+        for command in commands:
+            log.debug("TRANSACTION> "+ repr_command(command[1]))
+        log.debug("EXEC")
         self.connection.send(all_cmds, self)
         # parse off the response for MULTI and all commands prior to EXEC
         for i in range(len(commands)+1):
@@ -1460,6 +1465,8 @@ def _execute_transaction(self, commands):
     def _execute_pipeline(self, commands):
         # build up all commands into a single request to increase network perf
         all_cmds = ''.join([self._encode_command(c) for _1, c, _2 in commands])
+        for command in commands:
+            log.debug("PIPELINE> " + repr_command(command[1]))
         self.connection.send(all_cmds, self)
         data = []
         for command_name, _, options in commands:

tests/__init__.py

@@ -1,5 +1,5 @@
 import unittest
-from server_commands import ServerCommandsTestCase
+from server_commands import ServerCommandsTestCase, LoggingTestCase
 from connection_pool import ConnectionPoolTestCase
 from pipeline import PipelineTestCase
 from lock import LockTestCase
@@ -10,4 +10,5 @@ def all_tests():
     suite.addTest(unittest.makeSuite(ConnectionPoolTestCase))
     suite.addTest(unittest.makeSuite(PipelineTestCase))
     suite.addTest(unittest.makeSuite(LockTestCase))
+    suite.addTest(unittest.makeSuite(LoggingTestCase))
     return suite

tests/server_commands.py

@@ -3,6 +3,8 @@
 import datetime
 import threading
 import time
+import logging
+import logging.handlers
 from distutils.version import StrictVersion
 
 class ServerCommandsTestCase(unittest.TestCase):
@@ -1257,3 +1259,55 @@ def test_binary_lists(self):
         # check that it is possible to get list content by key name
         for key in mapping.keys():
             self.assertEqual(self.client.lrange(key, 0, -1), list(mapping[key]))
+
+class BufferingHandler(logging.handlers.BufferingHandler):
+
+    def __init__(self):
+        logging.handlers.BufferingHandler.__init__(self, None)
+
+    def shouldFlush(self, record):
+        return False
+
+class LoggingTestCase(unittest.TestCase):
+
+    def get_client(self):
+        return redis.Redis(host='localhost', port=6379, db=9)
+
+    def setUp(self):
+        self.client = self.get_client()
+        self.client.flushdb()
+
+        self.log = logging.getLogger("redis")
+        self.log.setLevel(logging.DEBUG)
+        self.handler = BufferingHandler()
+        self.log.addHandler(self.handler)
+        self.buffer = self.handler.buffer
+
+    def tearDown(self):
+        self.client.flushdb()
+        for c in self.client.connection_pool.get_all_connections():
+            c.disconnect()
+
+    def test_command_logging(self):
+        self.client.get("foo")
+
+        self.assertEqual(len(self.buffer), 1)
+        self.assertEqual(self.buffer[0].msg, "GET 'foo'")
+
+    def test_command_logging_pipeline(self):
+        pipe = self.client.pipeline(transaction=False)
+        pipe.get("foo")
+        pipe.execute()
+
+        self.assertEqual(len(self.buffer), 1)
+        self.assertEqual(self.buffer[0].msg, "PIPELINE> GET 'foo'")
+
+    def test_command_logging_transaction(self):
+        txn = self.client.pipeline(transaction=True)
+        txn.get("foo")
+        txn.execute()
+
+        self.assertEqual(len(self.buffer), 3)
+        messages = [x.msg for x in self.buffer]
+        self.assertEqual(messages,
+                ["MULTI", "TRANSACTION> GET 'foo'", "EXEC"])