From 4ded5512d7ff0d9c86f82af0341ad015c3263272 Mon Sep 17 00:00:00 2001 From: Vinay Sajip Date: Tue, 2 Oct 2012 15:56:16 +0100 Subject: Issue #15452: Added verify option for logging configuration socket listener. --- Doc/library/logging.config.rst | 20 +++++++++-- Lib/logging/config.py | 44 +++++++++++++----------- Lib/test/test_logging.py | 76 +++++++++++++++++++++++++++++++++++++++--- 3 files changed, 114 insertions(+), 26 deletions(-) diff --git a/Doc/library/logging.config.rst b/Doc/library/logging.config.rst index 1391ed2..d116d0a 100644 --- a/Doc/library/logging.config.rst +++ b/Doc/library/logging.config.rst @@ -95,7 +95,7 @@ in :mod:`logging` itself) and defining handlers which are declared either in logging configuration. -.. function:: listen(port=DEFAULT_LOGGING_CONFIG_PORT) +.. function:: listen(port=DEFAULT_LOGGING_CONFIG_PORT, verify=None) Starts up a socket server on the specified port, and listens for new configurations. If no port is specified, the module's default @@ -105,6 +105,17 @@ in :mod:`logging` itself) and defining handlers which are declared either in server, and which you can :meth:`join` when appropriate. To stop the server, call :func:`stopListening`. + The ``verify`` argument, if specified, should be a callable which should + verify whether bytes received across the socket are valid and should be + processed. This could be done by encrypting and/or signing what is sent + across the socket, such that the ``verify`` callable can perform + signature verification and/or decryption. The ``verify`` callable is called + with a single argument - the bytes received across the socket - and should + return the bytes to be processed, or None to indicate that the bytes should + be discarded. The returned bytes could be the same as the passed in bytes + (e.g. when only verification is done), or they could be completely different + (perhaps if decryption were performed). + To send a configuration to the socket, read in the configuration file and send it to the socket as a string of bytes preceded by a four-byte length string packed in binary using ``struct.pack('>L', n)``. @@ -121,7 +132,12 @@ in :mod:`logging` itself) and defining handlers which are declared either in :func:`listen` socket and sending a configuration which runs whatever code the attacker wants to have executed in the victim's process. This is especially easy to do if the default port is used, but not hard even if a - different port is used). + different port is used). To avoid the risk of this happening, use the + ``verify`` argument to :func:`listen` to prevent unrecognised + configurations from being applied. + + .. versionchanged:: 3.4. + The ``verify`` argument was added. .. function:: stopListening() diff --git a/Lib/logging/config.py b/Lib/logging/config.py index 5ef5c91..7dcef39 100644 --- a/Lib/logging/config.py +++ b/Lib/logging/config.py @@ -773,7 +773,7 @@ def dictConfig(config): dictConfigClass(config).configure() -def listen(port=DEFAULT_LOGGING_CONFIG_PORT): +def listen(port=DEFAULT_LOGGING_CONFIG_PORT, verify=None): """ Start up a socket server on the specified port, and listen for new configurations. @@ -809,22 +809,25 @@ def listen(port=DEFAULT_LOGGING_CONFIG_PORT): chunk = self.connection.recv(slen) while len(chunk) < slen: chunk = chunk + conn.recv(slen - len(chunk)) - chunk = chunk.decode("utf-8") - try: - import json - d =json.loads(chunk) - assert isinstance(d, dict) - dictConfig(d) - except: - #Apply new configuration. - - file = io.StringIO(chunk) + if self.server.verify is not None: + chunk = self.server.verify(chunk) + if chunk is not None: # verified, can process + chunk = chunk.decode("utf-8") try: - fileConfig(file) - except (KeyboardInterrupt, SystemExit): #pragma: no cover - raise + import json + d =json.loads(chunk) + assert isinstance(d, dict) + dictConfig(d) except: - traceback.print_exc() + #Apply new configuration. + + file = io.StringIO(chunk) + try: + fileConfig(file) + except (KeyboardInterrupt, SystemExit): #pragma: no cover + raise + except: + traceback.print_exc() if self.server.ready: self.server.ready.set() except socket.error as e: @@ -843,13 +846,14 @@ def listen(port=DEFAULT_LOGGING_CONFIG_PORT): allow_reuse_address = 1 def __init__(self, host='localhost', port=DEFAULT_LOGGING_CONFIG_PORT, - handler=None, ready=None): + handler=None, ready=None, verify=None): ThreadingTCPServer.__init__(self, (host, port), handler) logging._acquireLock() self.abort = 0 logging._releaseLock() self.timeout = 1 self.ready = ready + self.verify = verify def serve_until_stopped(self): import select @@ -867,16 +871,18 @@ def listen(port=DEFAULT_LOGGING_CONFIG_PORT): class Server(threading.Thread): - def __init__(self, rcvr, hdlr, port): + def __init__(self, rcvr, hdlr, port, verify): super(Server, self).__init__() self.rcvr = rcvr self.hdlr = hdlr self.port = port + self.verify = verify self.ready = threading.Event() def run(self): server = self.rcvr(port=self.port, handler=self.hdlr, - ready=self.ready) + ready=self.ready, + verify=self.verify) if self.port == 0: self.port = server.server_address[1] self.ready.set() @@ -886,7 +892,7 @@ def listen(port=DEFAULT_LOGGING_CONFIG_PORT): logging._releaseLock() server.serve_until_stopped() - return Server(ConfigSocketReceiver, ConfigStreamHandler, port) + return Server(ConfigSocketReceiver, ConfigStreamHandler, port, verify) def stopListening(): """ diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index cb908fb..081ffe9 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -150,14 +150,17 @@ class BaseTest(unittest.TestCase): finally: logging._releaseLock() - def assert_log_lines(self, expected_values, stream=None): + def assert_log_lines(self, expected_values, stream=None, pat=None): """Match the collected log lines against the regular expression self.expected_log_pat, and compare the extracted group values to the expected_values list of tuples.""" stream = stream or self.stream - pat = re.compile(self.expected_log_pat) + pat = re.compile(pat or self.expected_log_pat) try: - stream.reset() + if hasattr(stream, 'reset'): + stream.reset() + elif hasattr(stream, 'seek'): + stream.seek(0) actual_lines = stream.readlines() except AttributeError: # StringIO.StringIO lacks a reset() method. @@ -2601,10 +2604,10 @@ class ConfigDictTest(BaseTest): self.assertRaises(Exception, self.apply_config, self.config13) @unittest.skipUnless(threading, 'listen() needs threading to work') - def setup_via_listener(self, text): + def setup_via_listener(self, text, verify=None): text = text.encode("utf-8") # Ask for a randomly assigned port (by using port 0) - t = logging.config.listen(0) + t = logging.config.listen(0, verify) t.start() t.ready.wait() # Now get the port allocated @@ -2664,6 +2667,69 @@ class ConfigDictTest(BaseTest): # Original logger output is empty. self.assert_log_lines([]) + @unittest.skipUnless(threading, 'Threading required for this test.') + def test_listen_verify(self): + + def verify_fail(stuff): + return None + + def verify_reverse(stuff): + return stuff[::-1] + + logger = logging.getLogger("compiler.parser") + to_send = textwrap.dedent(ConfigFileTest.config1) + # First, specify a verification function that will fail. + # We expect to see no output, since our configuration + # never took effect. + with captured_stdout() as output: + self.setup_via_listener(to_send, verify_fail) + # Both will output a message + logger.info(self.next_message()) + logger.error(self.next_message()) + self.assert_log_lines([], stream=output) + # Original logger output has the stuff we logged. + self.assert_log_lines([ + ('INFO', '1'), + ('ERROR', '2'), + ], pat=r"^[\w.]+ -> ([\w]+): ([\d]+)$") + + # Now, perform no verification. Our configuration + # should take effect. + + with captured_stdout() as output: + self.setup_via_listener(to_send) # no verify callable specified + logger = logging.getLogger("compiler.parser") + # Both will output a message + logger.info(self.next_message()) + logger.error(self.next_message()) + self.assert_log_lines([ + ('INFO', '3'), + ('ERROR', '4'), + ], stream=output) + # Original logger output still has the stuff we logged before. + self.assert_log_lines([ + ('INFO', '1'), + ('ERROR', '2'), + ], pat=r"^[\w.]+ -> ([\w]+): ([\d]+)$") + + # Now, perform verification which transforms the bytes. + + with captured_stdout() as output: + self.setup_via_listener(to_send[::-1], verify_reverse) + logger = logging.getLogger("compiler.parser") + # Both will output a message + logger.info(self.next_message()) + logger.error(self.next_message()) + self.assert_log_lines([ + ('INFO', '5'), + ('ERROR', '6'), + ], stream=output) + # Original logger output still has the stuff we logged before. + self.assert_log_lines([ + ('INFO', '1'), + ('ERROR', '2'), + ], pat=r"^[\w.]+ -> ([\w]+): ([\d]+)$") + def test_baseconfig(self): d = { 'atuple': (1, 2, 3), -- cgit v0.12