WIP: Add key logging for TLS 1.3 and TLS 1.2 (#523)

[WIP] sslkeylogfile continued

add unsafe write for unrecognized platform i.e. windows

Author: nickrabbott

tlslite/session.py

@@ -98,6 +98,8 @@ def __init__(self):
         self.tickets = None
         self.tls_1_0_tickets = None
         self.ec_point_format = 0
+        self.cl_handshake_traffic_secret = None
+        self.sr_handshake_traffic_secret = None
 
     def create(self, masterSecret, sessionID, cipherSuite,
                srpUsername, clientCertChain, serverCertChain,
@@ -106,7 +108,9 @@ def create(self, masterSecret, sessionID, cipherSuite,
                appProto=bytearray(0), cl_app_secret=bytearray(0),
                sr_app_secret=bytearray(0), exporterMasterSecret=bytearray(0),
                resumptionMasterSecret=bytearray(0), tickets=None,
-               tls_1_0_tickets=None, ec_point_format=None):
+               tls_1_0_tickets=None, ec_point_format=None,
+               cl_hs_traffic_secret=bytearray(0),
+               sr_hs_traffic_secret=bytearray(0)):
         self.masterSecret = masterSecret
         self.sessionID = sessionID
         self.cipherSuite = cipherSuite
@@ -124,6 +128,8 @@ def create(self, masterSecret, sessionID, cipherSuite,
         self.sr_app_secret = sr_app_secret
         self.exporterMasterSecret = exporterMasterSecret
         self.resumptionMasterSecret = resumptionMasterSecret
+        self.cl_handshake_traffic_secret = cl_hs_traffic_secret
+        self.sr_handshake_traffic_secret = sr_hs_traffic_secret
         # NOTE we need a reference copy not a copy of object here!
         self.tickets = tickets
         self.tls_1_0_tickets = tls_1_0_tickets

tlslite/sslkeylogging.py

@@ -0,0 +1,63 @@
+import os
+import sys
+import threading
+from .utils.compat import b2a_hex
+
+
+def posix_lock_write(file_path, lines):
+    import fcntl
+    with open(file_path, 'a') as f:
+        fcntl.flock(f, fcntl.LOCK_EX)
+        try:
+            f.writelines(lines)
+            f.flush()
+        finally:
+            fcntl.flock(f, fcntl.LOCK_UN)
+
+
+def unsafe_write(file_path, lines):
+    with open(file_path, 'a') as f:
+        f.writelines(lines)
+        f.flush()
+
+
+class SSLKeyLogger:
+    """
+    Write session secrets to the SSLKEYLOGFILE environment variable. Implemented to be thread-safe at the class
+    level and uses OS level file-locking. The file-locking implementation is a function assigned to self.lock_write
+    and determined by the value of sys.platform. Currently, POSIX is supported.
+
+    :param enabled: sets the logger to enabled
+    :type enabled: bool
+    """
+    _lock = threading.Lock()
+
+    def __init__(self, enabled=False):
+        self.enabled = enabled
+        self.ssl_key_logfile = os.environ.get('SSLKEYLOGFILE')
+        self.platform = sys.platform
+        if self.platform in ['darwin', 'linux']:
+            self.lock_write = posix_lock_write
+        else:
+            # TODO warn user of unsafe?
+            self.lock_write = unsafe_write
+
+    def log_session_keys(self, keys):
+        # no-op if not enabled or if SSLKEYLOGFILE env variable isn't set
+        if self.ssl_key_logfile is None or not self.enabled:
+            return
+
+        if isinstance(keys, tuple):
+            keys = [keys]
+
+        lines = [
+            "{0} {1} {2}\n".format(
+                label,
+                b2a_hex(client_random).upper(),
+                b2a_hex(secret).upper()
+            )
+            for label, client_random, secret in keys
+        ]
+
+        with self._lock:
+            self.lock_write(self.ssl_key_logfile, lines)

tlslite/tlsconnection.py

@@ -40,6 +40,7 @@
 from .utils.cipherfactory import createAESCCM, createAESCCM_8, \
         createAESGCM, createCHACHA20
 from .utils.compression import choose_compression_send_algo
+from .sslkeylogging import SSLKeyLogger
 
 class TLSConnection(TLSRecordLayer):
     """
@@ -76,14 +77,17 @@ class TLSConnection(TLSRecordLayer):
         compression wasn't used then it is set to None.
     """
 
-    def __init__(self, sock):
+    def __init__(self, sock, logging_enabled=False):
         """Create a new TLSConnection instance.
 
         :param sock: The socket data will be transmitted on.  The
             socket should already be connected.  It may be in blocking or
             non-blocking mode.
 
         :type sock: socket.socket
+
+        :param logging_enabled: Enable logging session secrets to the SSLKEYLOGFILE env variable.
+        :type logging_enabled: bool
         """
         TLSRecordLayer.__init__(self, sock)
         self.serverSigAlg = None
@@ -101,6 +105,7 @@ def __init__(self, sock):
         self._pha_supported = False
         self.client_cert_compression_algo = None
         self.server_cert_compression_algo = None
+        self.ssl_key_logger = SSLKeyLogger(logging_enabled)
 
     def keyingMaterialExporter(self, label, length=20):
         """Return keying material as described in RFC 5705
@@ -414,7 +419,6 @@ def _handshakeClientAsync(self, srpParams=(), certParams=(), anonParams=(),
                               session=None, settings=None, checker=None,
                               nextProtos=None, serverName=None, reqTack=True,
                               alpn=None):
-
         handshaker = self._handshakeClientAsyncHelper(srpParams=srpParams,
                 certParams=certParams,
                 anonParams=anonParams,
@@ -427,6 +431,10 @@ def _handshakeClientAsync(self, srpParams=(), certParams=(), anonParams=(),
         for result in self._handshakeWrapperAsync(handshaker, checker):
             yield result
 
+        # Log client random and master secret for version < TLS1.3
+        if self.version < (3, 4):
+            self.ssl_key_logger.log_session_keys(('CLIENT_RANDOM', self._clientRandom, self.session.masterSecret))
+
 
     def _handshakeClientAsyncHelper(self, srpParams, certParams, anonParams,
                                session, settings, serverName, nextProtos,
@@ -1323,6 +1331,14 @@ def _clientTLS13Handshake(self, settings, session, clientHello,
                                                     self._handshake_hash,
                                                     prfName)
 
+        # TLS1.3 log Client and Server traffic secrets for SSLKEYLOGFILE
+        self.ssl_key_logger.log_session_keys([
+            ('CLIENT_HANDSHAKE_TRAFFIC_SECRET',
+             clientHello.random, cl_handshake_traffic_secret),
+            ('SERVER_HANDSHAKE_TRAFFIC_SECRET',
+             clientHello.random, sr_handshake_traffic_secret)
+        ])
+
         # prepare for reading encrypted messages
         self._recordLayer.calcTLS1_3PendingState(
             serverHello.cipher_suite,
@@ -1613,6 +1629,15 @@ def _clientTLS13Handshake(self, settings, session, clientHello,
                                                bytearray(b'exp master'),
                                                self._handshake_hash, prfName)
 
+
+        # Now that we have all the TLS1.3 secrets during the handshake,
+        # log them if necessary
+        self.ssl_key_logger.log_session_keys([
+            ('EXPORTER_SECRET', clientHello.random, exporter_master_secret),
+            ('CLIENT_TRAFFIC_SECRET_0', clientHello.random, cl_app_traffic),
+            ('SERVER_TRAFFIC_SECRET_0', clientHello.random, sr_app_traffic)
+        ])
+
         self._recordLayer.calcTLS1_3PendingState(
             serverHello.cipher_suite,
             cl_app_traffic,
@@ -1708,7 +1733,9 @@ def _clientTLS13Handshake(self, settings, session, clientHello,
                             exporterMasterSecret=exporter_master_secret,
                             resumptionMasterSecret=resumption_master_secret,
                             # NOTE it must be a reference, not a copy!
-                            tickets=self.tickets)
+                            tickets=self.tickets,
+                            cl_hs_traffic_secret=cl_handshake_traffic_secret,
+                            sr_hs_traffic_secret=sr_handshake_traffic_secret)
 
         yield "finished" if not resuming else "resumed_and_finished"
 
@@ -2250,6 +2277,12 @@ def handshakeServerAsync(self, verifierDB=None,
         for result in self._handshakeWrapperAsync(handshaker, checker):
             yield result
 
+        # Log client random and master secret for version < TLS1.3
+        if self.version < (3, 4):
+            self.ssl_key_logger.log_session_keys(('CLIENT_RANDOM',
+                                                  self._clientRandom,
+                                                  self.session.masterSecret))
+
 
     def _handshakeServerAsyncHelper(self, verifierDB,
                                     cert_chain, privateKey, reqCert,
@@ -2956,6 +2989,15 @@ def _serverTLS13Handshake(self, settings, clientHello, cipherSuite,
                                                     bytearray(b'c hs traffic'),
                                                     self._handshake_hash,
                                                     prf_name)
+
+        # TLS1.3 log Client and Server traffic secrets for SSLKEYLOGFILE
+        self.ssl_key_logger.log_session_keys([
+            ('CLIENT_HANDSHAKE_TRAFFIC_SECRET',
+             clientHello.random, cl_handshake_traffic_secret),
+            ('SERVER_HANDSHAKE_TRAFFIC_SECRET',
+             clientHello.random, sr_handshake_traffic_secret)
+        ])
+
         self.version = version
         self._recordLayer.calcTLS1_3PendingState(
             cipherSuite,
@@ -3222,6 +3264,19 @@ def _serverTLS13Handshake(self, settings, clientHello, cipherSuite,
                                                self._handshake_hash,
                                                prf_name)
 
+
+        # Now that we have all the TLS1.3 secrets during the handshake,
+        # log them if necessary
+        self.ssl_key_logger.log_session_keys([
+            ('EXPORTER_SECRET',
+             clientHello.random, exporter_master_secret),
+            ('CLIENT_TRAFFIC_SECRET_0',
+             clientHello.random, cl_app_traffic),
+            ('SERVER_TRAFFIC_SECRET_0',
+             clientHello.random, sr_app_traffic)
+        ])
+
+
         # verify Finished of client
         cl_finished_key = HKDF_expand_label(cl_handshake_traffic_secret,
                                             b"finished", b'',
@@ -3285,7 +3340,9 @@ def _serverTLS13Handshake(self, settings, clientHello, cipherSuite,
                             exporterMasterSecret=exporter_master_secret,
                             resumptionMasterSecret=resumption_master_secret,
                             # NOTE it must be a reference, not a copy
-                            tickets=self.tickets)
+                            tickets=self.tickets,
+                            cl_hs_traffic_secret=cl_handshake_traffic_secret,
+                            sr_hs_traffic_secret=sr_handshake_traffic_secret)
 
         # switch to application_traffic_secret for client packets
         self._changeReadState()
@@ -4934,6 +4991,7 @@ def _calculate_master_secret(self, premaster_secret, cipher_suite,
                               output_length=48)
         return secret
 
+
     @staticmethod
     def _pickServerKeyExchangeSig(settings, clientHello, certList=None,
                                   private_key=None,

unit_tests/test_tlslite_ssl_key_log_file.py

@@ -0,0 +1,105 @@
+try:
+    import unittest2 as unittest
+except ImportError:
+    import unittest
+
+import os
+from threading import Thread
+import tempfile
+import random
+import unittest
+
+from tlslite.sslkeylogging import SSLKeyLogger
+from tlslite.utils.compat import b2a_hex
+
+
+class TestSslKeyLogFile(unittest.TestCase):
+    def __init__(self, *args, **kwargs):
+        super(TestSslKeyLogFile, self).__init__(*args, **kwargs)
+
+    def setUp(self):
+        self.temp_log_file = tempfile.NamedTemporaryFile(delete=False)
+        os.environ['SSLKEYLOGFILE'] = self.temp_log_file.name
+
+    def tearDown(self):
+        os.remove(self.temp_log_file.name)
+        if os.environ.get('SSLKEYLOGFILE'):
+            del os.environ['SSLKEYLOGFILE']
+
+    def test_pre_13(self):
+        logger_count = 3
+
+        loggers = []
+        for i in range(logger_count):
+            loggers.append(SSLKeyLogger())
+
+        threads = []
+        expected_labels = []
+        for i in range(logger_count):
+            client_random = random.randbytes(32)
+            master_secret = random.randbytes(48)
+            label = ("CLIENT_RANDOM", client_random, master_secret)
+            expected_labels.append(label)
+            logger = loggers[i]
+            threads.append(Thread(target=logger.log_session_keys, args=(label,)))
+
+        for thread in threads:
+            thread.start()
+
+        for thread in threads:
+            thread.join(10)
+
+        self.validate_log_file(expected_labels)
+
+    def test_13(self):
+        logger_count = 3
+
+        loggers = []
+        for i in range(logger_count):
+            loggers.append(SSLKeyLogger())
+
+        threads = []
+        expected_labels = []
+        for i in range(logger_count):
+            client_random = random.randbytes(32)
+            labels = [
+                ("SERVER_HANDSHAKE_TRAFFIC_SECRET", client_random, random.randbytes(32)),
+                ("EXPORTER_SECRET", client_random, random.randbytes(32)),
+                ("SERVER_TRAFFIC_SECRET_0", client_random, random.randbytes(32)),
+                ("CLIENT_HANDSHAKE_TRAFFIC_SECRET", client_random, random.randbytes(32)),
+                ("CLIENT_TRAFFIC_SECRET_0", client_random, random.randbytes(32))
+            ]
+            expected_labels.append(labels)
+            logger = loggers[i]
+            threads.append(Thread(target=logger.log_session_keys, args=(labels,)))
+
+        for thread in threads:
+            thread.start()
+
+        for thread in threads:
+            thread.join(10)
+
+        self.validate_log_file(expected_labels)
+
+    def validate_log_file(self, all_labels):
+        """
+        Validates lines in SSLKEYLOGFILE for both TLS 1.2 and TLS 1.3
+        """
+        with open(self.temp_log_file.name, 'r') as log_file:
+            lines = [log_line.strip() for log_line in log_file.readlines()]
+            for labels in all_labels:
+                if isinstance(labels, tuple):
+                    client_random = b2a_hex(labels[1]).upper()
+                    master_secret = b2a_hex(labels[2]).upper()
+                    expected_label = "{0} {1} {2}".format(labels[0], client_random, master_secret)
+                    self.assertTrue(expected_label in lines, "Expected: {0}".format(expected_label))
+                elif isinstance(labels, list):
+                    for label_name, client_random, secret in labels:
+                        expected_label = "{0} {1} {2}".format(
+                            label_name, b2a_hex(client_random).upper(), b2a_hex(secret).upper()
+                        )
+                        self.assertTrue(expected_label in lines, "Didn't find expected: {0}".format(expected_label))
+
+
+if __name__ == "__main__":
+    unittest.main()