cpython: 26c3d170fd56 (original) (raw)

Mercurial > cpython

changeset 79407:26c3d170fd56

Issue #15452: Added verify option for logging configuration socket listener. [#15452]

Vinay Sajip <vinay_sajip@yahoo.co.uk>
date	Tue, 02 Oct 2012 15:56:16 +0100
parents	76435de68379
children	6df80e09ad5e
files	Doc/library/logging.config.rst Lib/logging/config.py Lib/test/test_logging.py
diffstat	3 files changed, 115 insertions(+), 27 deletions(-)[+] [-] Doc/library/logging.config.rst 20 Lib/logging/config.py 46 Lib/test/test_logging.py 76

line wrap: on

line diff

--- a/Doc/library/logging.config.rst +++ b/Doc/library/logging.config.rst @@ -95,7 +95,7 @@ in :mod:logging itself) and defining h 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 h 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 h :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).[](#l1.34)
```

 different port is used). To avoid the risk of this happening, use the[](#l1.35)

 ``verify`` argument to :func:`listen` to prevent unrecognised[](#l1.36)

 configurations from being applied.[](#l1.37)

.. versionchanged:: 3.4.

 The ``verify`` argument was added.[](#l1.40)

.. function:: stopListening()

--- 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_P chunk = self.connection.recv(slen) while len(chunk) < slen: chunk = chunk + conn.recv(slen - len(chunk))

               chunk = chunk.decode("utf-8")[](#l2.16)

```
               try:[](#l2.17)
```

                   import json[](#l2.18)

                   d =json.loads(chunk)[](#l2.19)

                   assert isinstance(d, dict)[](#l2.20)

                   dictConfig(d)[](#l2.21)

```
               except:[](#l2.22)
```

                   #Apply new configuration.[](#l2.23)

               if self.server.verify is not None:[](#l2.24)

                   chunk = self.server.verify(chunk)[](#l2.25)

               if chunk is not None:   # verified, can process[](#l2.26)

                   chunk = chunk.decode("utf-8")[](#l2.27)

```
                   try:[](#l2.28)
```

                       import json[](#l2.29)

                       d =json.loads(chunk)[](#l2.30)

                       assert isinstance(d, dict)[](#l2.31)

                       dictConfig(d)[](#l2.32)

```
                   except:[](#l2.33)
```

                       #Apply new configuration.[](#l2.34)

                   file = io.StringIO(chunk)[](#l2.36)

```
                   try:[](#l2.37)
```

                       fileConfig(file)[](#l2.38)

                   except (KeyboardInterrupt, SystemExit): #pragma: no cover[](#l2.39)

```
                       raise[](#l2.40)
```
```
                   except:[](#l2.41)
```

                       traceback.print_exc()[](#l2.42)

                       file = io.StringIO(chunk)[](#l2.43)

```
                       try:[](#l2.44)
```

                           fileConfig(file)[](#l2.45)

                       except (KeyboardInterrupt, SystemExit): #pragma: no cover[](#l2.46)

                           raise[](#l2.47)

                       except:[](#l2.48)

                           traceback.print_exc()[](#l2.49)
               if self.server.ready:[](#l2.50)
                   self.server.ready.set()[](#l2.51)
       except socket.error as e:[](#l2.52)

@@ -843,13 +846,14 @@ def listen(port=DEFAULT_LOGGING_CONFIG_P allow_reuse_address = 1 def init(self, host='localhost', port=DEFAULT_LOGGING_CONFIG_PORT,

                handler=None, ready=None):[](#l2.57)

                handler=None, ready=None, verify=None):[](#l2.58)
       ThreadingTCPServer.__init__(self, (host, port), handler)[](#l2.59)
       logging._acquireLock()[](#l2.60)
       self.abort = 0[](#l2.61)
       logging._releaseLock()[](#l2.62)
       self.timeout = 1[](#l2.63)
       self.ready = ready[](#l2.64)

```
       self.verify = verify[](#l2.65)
```

def serve_until_stopped(self): import select @@ -867,16 +871,18 @@ def listen(port=DEFAULT_LOGGING_CONFIG_P class Server(threading.Thread):

   def __init__(self, rcvr, hdlr, port):[](#l2.73)

   def __init__(self, rcvr, hdlr, port, verify):[](#l2.74)
       super(Server, self).__init__()[](#l2.75)
       self.rcvr = rcvr[](#l2.76)
       self.hdlr = hdlr[](#l2.77)
       self.port = port[](#l2.78)

       self.verify = verify[](#l2.79)
       self.ready = threading.Event()[](#l2.80)

def run(self): server = self.rcvr(port=self.port, handler=self.hdlr,

                          ready=self.ready)[](#l2.84)

                          ready=self.ready,[](#l2.85)

                          verify=self.verify)[](#l2.86)
       if self.port == 0:[](#l2.87)
           self.port = server.server_address[1][](#l2.88)
       self.ready.set()[](#l2.89)

@@ -886,7 +892,7 @@ def listen(port=DEFAULT_LOGGING_CONFIG_P logging._releaseLock() server.serve_until_stopped()

return Server(ConfigSocketReceiver, ConfigStreamHandler, port)

return Server(ConfigSocketReceiver, ConfigStreamHandler, port, verify)

def stopListening(): """

--- 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)[](#l3.13)

   pat = re.compile(pat or self.expected_log_pat)[](#l3.14)
   try:[](#l3.15)

```
       stream.reset()[](#l3.16)
```

       if hasattr(stream, 'reset'):[](#l3.17)

```
           stream.reset()[](#l3.18)
```

       elif hasattr(stream, 'seek'):[](#l3.19)

           stream.seek(0)[](#l3.20)
       actual_lines = stream.readlines()[](#l3.21)
   except AttributeError:[](#l3.22)
       # StringIO.StringIO lacks a reset() method.[](#l3.23)

@@ -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)[](#l3.32)

   t = logging.config.listen(0, verify)[](#l3.33)
   t.start()[](#l3.34)
   t.ready.wait()[](#l3.35)
   # Now get the port allocated[](#l3.36)

@@ -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):[](#l3.44)
```
```
       return None[](#l3.45)
```

```
   def verify_reverse(stuff):[](#l3.47)
```
```
       return stuff[::-1][](#l3.48)
```

   logger = logging.getLogger("compiler.parser")[](#l3.50)

   to_send = textwrap.dedent(ConfigFileTest.config1)[](#l3.51)

   # First, specify a verification function that will fail.[](#l3.52)

   # We expect to see no output, since our configuration[](#l3.53)

```
   # never took effect.[](#l3.54)
```

   with captured_stdout() as output:[](#l3.55)

       self.setup_via_listener(to_send, verify_fail)[](#l3.56)

       # Both will output a message[](#l3.57)

       logger.info(self.next_message())[](#l3.58)

       logger.error(self.next_message())[](#l3.59)

   self.assert_log_lines([], stream=output)[](#l3.60)

   # Original logger output has the stuff we logged.[](#l3.61)

```
   self.assert_log_lines([[](#l3.62)
```
```
       ('INFO', '1'),[](#l3.63)
```
```
       ('ERROR', '2'),[](#l3.64)
```

   ], pat=r"^[\w.]+ -> ([\w]+): ([\d]+)$")[](#l3.65)

   # Now, perform no verification. Our configuration[](#l3.67)

```
   # should take effect.[](#l3.68)
```

   with captured_stdout() as output:[](#l3.70)

       self.setup_via_listener(to_send)    # no verify callable specified[](#l3.71)

       logger = logging.getLogger("compiler.parser")[](#l3.72)

       # Both will output a message[](#l3.73)

       logger.info(self.next_message())[](#l3.74)

       logger.error(self.next_message())[](#l3.75)

```
   self.assert_log_lines([[](#l3.76)
```
```
       ('INFO', '3'),[](#l3.77)
```
```
       ('ERROR', '4'),[](#l3.78)
```
```
   ], stream=output)[](#l3.79)
```

   # Original logger output still has the stuff we logged before.[](#l3.80)

```
   self.assert_log_lines([[](#l3.81)
```
```
       ('INFO', '1'),[](#l3.82)
```
```
       ('ERROR', '2'),[](#l3.83)
```

   ], pat=r"^[\w.]+ -> ([\w]+): ([\d]+)$")[](#l3.84)

   # Now, perform verification which transforms the bytes.[](#l3.86)

   with captured_stdout() as output:[](#l3.88)

       self.setup_via_listener(to_send[::-1], verify_reverse)[](#l3.89)

       logger = logging.getLogger("compiler.parser")[](#l3.90)

       # Both will output a message[](#l3.91)

       logger.info(self.next_message())[](#l3.92)

       logger.error(self.next_message())[](#l3.93)

```
   self.assert_log_lines([[](#l3.94)
```
```
       ('INFO', '5'),[](#l3.95)
```
```
       ('ERROR', '6'),[](#l3.96)
```
```
   ], stream=output)[](#l3.97)
```

   # Original logger output still has the stuff we logged before.[](#l3.98)

```
   self.assert_log_lines([[](#l3.99)
```
```
       ('INFO', '1'),[](#l3.100)
```
```
       ('ERROR', '2'),[](#l3.101)
```

   ], pat=r"^[\w.]+ -> ([\w]+): ([\d]+)$")[](#l3.102)

+ def test_baseconfig(self): d = { 'atuple': (1, 2, 3),