From 8a8bca92acf6cb7b8e031f6a387e05295e5f22ed Mon Sep 17 00:00:00 2001
From: mtu <maxence.tury@ssi.gouv.fr>
Date: Mon, 28 Aug 2017 14:17:47 +0200
Subject: [PATCH] Proper TLS log formats

---
 scapy/layers/tls/automaton.py         |  2 +-
 scapy/layers/tls/handshake.py         | 12 ++++++------
 scapy/layers/tls/handshake_sslv2.py   |  6 +++---
 scapy/layers/tls/keyexchange_tls13.py |  8 ++++----
 scapy/layers/tls/record.py            |  6 +++---
 scapy/layers/tls/record_sslv2.py      |  2 +-
 scapy/layers/tls/record_tls13.py      |  2 +-
 scapy/layers/tls/session.py           | 23 ++++++++++++-----------
 8 files changed, 31 insertions(+), 30 deletions(-)

diff --git a/scapy/layers/tls/automaton.py b/scapy/layers/tls/automaton.py
index 8bea2111..db18bd2d 100644
--- a/scapy/layers/tls/automaton.py
+++ b/scapy/layers/tls/automaton.py
@@ -219,5 +219,5 @@ class _TLSAutomaton(Automaton):
 
     def vprint(self, s=""):
         if self.verbose:
-            log_interactive.info("> %s" % s)
+            log_interactive.info("> %s", s)
 
diff --git a/scapy/layers/tls/handshake.py b/scapy/layers/tls/handshake.py
index fb2a8adf..f49734fc 100644
--- a/scapy/layers/tls/handshake.py
+++ b/scapy/layers/tls/handshake.py
@@ -715,7 +715,7 @@ class TLSServerKeyExchange(_TLSHandshake):
         """
         s = self.tls_session
         if s.prcs and s.prcs.key_exchange.no_ske:
-            log_runtime.info("USELESS SERVER KEY EXCHANGE")
+            log_runtime.info("TLS: useless ServerKeyExchange")
         if (s.prcs and
             not s.prcs.key_exchange.anonymous and
             s.client_random and s.server_random and
@@ -723,7 +723,7 @@ class TLSServerKeyExchange(_TLSHandshake):
             m = s.client_random + s.server_random + str(self.params)
             sig_test = self.sig._verify_sig(m, s.server_certs[0])
             if not sig_test:
-                log_runtime.info("INVALID SERVER KEY EXCHANGE SIGNATURE")
+                log_runtime.info("TLS: invalid ServerKeyExchange signature")
 
 
 ###############################################################################
@@ -855,13 +855,13 @@ class TLSCertificateVerify(_TLSHandshake):
             if s.client_certs and len(s.client_certs) > 0:
                 sig_test = self.sig._verify_sig(m, s.client_certs[0])
                 if not sig_test:
-                    log_runtime.info("INVALID CERTIFICATE VERIFY SIGNATURE")
+                    log_runtime.info("TLS: invalid CertificateVerify signature")
         elif s.connection_end == "client":
             # should be TLS 1.3 only
             if s.server_certs and len(s.server_certs) > 0:
                 sig_test = self.sig._verify_sig(m, s.server_certs[0])
                 if not sig_test:
-                    log_runtime.info("INVALID CERTIFICATE VERIFY SIGNATURE")
+                    log_runtime.info("TLS: invalid CertificateVerify signature")
 
 
 ###############################################################################
@@ -964,12 +964,12 @@ class TLSFinished(_TLSHandshake):
                 verify_data = s.rcs.prf.compute_verify_data(con_end, "read",
                                                             handshake_msg, ms)
                 if self.vdata != verify_data:
-                    log_runtime.info("INVALID TLS FINISHED RECEIVED")
+                    log_runtime.info("TLS: invalid Finished received")
             elif s.tls_version >= 0x0304:
                 con_end = s.connection_end
                 verify_data = s.compute_tls13_verify_data(con_end, "read")
                 if self.vdata != verify_data:
-                    log_runtime.info("INVALID TLS FINISHED RECEIVED")
+                    log_runtime.info("TLS: invalid Finished received")
 
     def post_build_tls_session_update(self, msg_str):
         self.tls_session_update(msg_str)
diff --git a/scapy/layers/tls/handshake_sslv2.py b/scapy/layers/tls/handshake_sslv2.py
index e9cb1354..d647a61a 100644
--- a/scapy/layers/tls/handshake_sslv2.py
+++ b/scapy/layers/tls/handshake_sslv2.py
@@ -400,7 +400,7 @@ class SSLv2ServerVerify(_SSLv2Handshake):
         s = self.tls_session
         if s.sslv2_challenge is not None:
             if self.challenge != s.sslv2_challenge:
-                log_runtime.info("INVALID TLS SERVER VERIFY RECEIVED")
+                log_runtime.info("TLS: invalid ServerVerify received")
 
 
 ###############################################################################
@@ -476,7 +476,7 @@ class SSLv2ClientCertificate(_SSLv2Handshake):
                  s.server_certs[0].der)
             sig_test = self.responsedata._verify_sig(m, s.client_certs[0])
             if not sig_test:
-                log_runtime.info("INVALID CLIENT CERTIFICATE VERIFY SIGNATURE")
+                log_runtime.info("TLS: invalid client CertificateVerify signature")
 
     def tls_session_update(self, msg_str):
         super(SSLv2ClientCertificate, self).tls_session_update(msg_str)
@@ -507,7 +507,7 @@ class SSLv2ClientFinished(_SSLv2Handshake):
         s = self.tls_session
         if s.sslv2_connection_id is not None:
             if self.connection_id != s.sslv2_connection_id:
-                log_runtime.info("INVALID TLS CLIENT FINISHED RECEIVED")
+                log_runtime.info("TLS: invalid client Finished received")
 
 
 class SSLv2ServerFinished(_SSLv2Handshake):
diff --git a/scapy/layers/tls/keyexchange_tls13.py b/scapy/layers/tls/keyexchange_tls13.py
index 7b5c13a7..cef3b75a 100644
--- a/scapy/layers/tls/keyexchange_tls13.py
+++ b/scapy/layers/tls/keyexchange_tls13.py
@@ -140,7 +140,7 @@ class TLS_Ext_KeyShare_CH(TLS_Ext_Unknown):
             for kse in self.client_shares:
                 if kse.privkey:
                     if _tls_named_curves[kse.group] in privshares:
-                        log_runtime.info("Group %s used twice in the same ClientHello!" % kse.group)
+                        log_runtime.info("TLS: group %s used twice in the same ClientHello", kse.group)
                         break
                     privshares[_tls_named_groups[kse.group]] = kse.privkey
         return super(TLS_Ext_KeyShare_CH, self).post_build(pkt, pay)
@@ -151,7 +151,7 @@ class TLS_Ext_KeyShare_CH(TLS_Ext_Unknown):
                 if kse.pubkey:
                     pubshares = self.tls_session.tls13_client_pubshares
                     if _tls_named_curves[kse.group] in pubshares:
-                        log_runtime.info("Group %s used twice in the same ClientHello!" % kse.group)
+                        log_runtime.info("TLS: group %s used twice in the same ClientHello", kse.group)
                         break
                     pubshares[_tls_named_curves[kse.group]] = kse.pubkey
         return super(TLS_Ext_KeyShare_CH, self).post_dissection(r)
@@ -175,7 +175,7 @@ class TLS_Ext_KeyShare_SH(TLS_Ext_Unknown):
             # if there is a privkey, we assume the crypto library is ok
             privshare = self.tls_session.tls13_server_privshare
             if len(privshare) > 0:
-                log_runtime.info("Server key share was already stored...?")
+                log_runtime.info("TLS: overwriting previous server key share")
             group_name = _tls_named_groups[self.server_share.group]
             privshare[group_name] = self.server_share.privkey
 
@@ -197,7 +197,7 @@ class TLS_Ext_KeyShare_SH(TLS_Ext_Unknown):
             # if there is a pubkey, we assume the crypto library is ok
             pubshare = self.tls_session.tls13_server_pubshare
             if len(pubshare) > 0:
-                log_runtime.info("Server key share was already stored...?")
+                log_runtime.info("TLS: overwriting previous server key share")
             group_name = _tls_named_groups[self.server_share.group]
             pubshare[group_name] = self.server_share.pubkey
 
diff --git a/scapy/layers/tls/record.py b/scapy/layers/tls/record.py
index caec4764..066a040d 100644
--- a/scapy/layers/tls/record.py
+++ b/scapy/layers/tls/record.py
@@ -303,7 +303,7 @@ class TLS(_GenericTLSSessionInheritance):
         except CipherError as e:
             return e.args
         except AEADTagError as e:
-            log_runtime.info("INTEGRITY CHECK FAILED")
+            log_runtime.info("TLS: record integrity check failed")
             return e.args
 
     def _tls_decrypt(self, s):
@@ -424,7 +424,7 @@ class TLS(_GenericTLSSessionInheritance):
                 chdr = hdr[:3] + struct.pack('!H', len(cfrag))
                 is_mac_ok = self._tls_hmac_verify(chdr, cfrag, mac)
                 if not is_mac_ok:
-                    log_runtime.info("INTEGRITY CHECK FAILED")
+                    log_runtime.info("TLS: record integrity check failed")
 
         elif cipher_type == 'stream':
             # Decrypt
@@ -448,7 +448,7 @@ class TLS(_GenericTLSSessionInheritance):
                 chdr = hdr[:3] + struct.pack('!H', len(cfrag))
                 is_mac_ok = self._tls_hmac_verify(chdr, cfrag, mac)
                 if not is_mac_ok:
-                    log_runtime.info("INTEGRITY CHECK FAILED")
+                    log_runtime.info("TLS: record integrity check failed")
 
         elif cipher_type == 'aead':
             # Authenticated encryption
diff --git a/scapy/layers/tls/record_sslv2.py b/scapy/layers/tls/record_sslv2.py
index 4ad4d19f..b79abd9a 100644
--- a/scapy/layers/tls/record_sslv2.py
+++ b/scapy/layers/tls/record_sslv2.py
@@ -140,7 +140,7 @@ class SSLv2(TLS):
         # Verify integrity
         is_mac_ok = self._sslv2_mac_verify(cfrag + pad, mac)
         if not is_mac_ok:
-            log_runtime.info("INTEGRITY CHECK FAILED")
+            log_runtime.info("TLS: record integrity check failed")
 
         reconstructed_body = mac + cfrag + pad
         return hdr + reconstructed_body + r
diff --git a/scapy/layers/tls/record_tls13.py b/scapy/layers/tls/record_tls13.py
index 783e2a83..1e79c9bb 100644
--- a/scapy/layers/tls/record_tls13.py
+++ b/scapy/layers/tls/record_tls13.py
@@ -117,7 +117,7 @@ class TLS13(_GenericTLSSessionInheritance):
         except CipherError as e:
             return e.args
         except AEADTagError as e:
-            log_runtime.info("INTEGRITY CHECK FAILED")
+            log_runtime.info("TLS: record integrity check failed")
             return e.args
 
     def pre_dissect(self, s):
diff --git a/scapy/layers/tls/session.py b/scapy/layers/tls/session.py
index 11563741..cf3a5b73 100644
--- a/scapy/layers/tls/session.py
+++ b/scapy/layers/tls/session.py
@@ -108,10 +108,11 @@ class connState(object):
 
     def debug_repr(self, name, secret):
         if conf.debug_tls and secret:
-            log_runtime.debug("%s %s %s: %s" % (self.connection_end,
-                                    self.row,
-                                    name,
-                                    repr_hex(secret)))
+            log_runtime.debug("TLS: %s %s %s: %s",
+                              self.connection_end,
+                              self.row,
+                              name,
+                              repr_hex(secret))
 
     def derive_keys(self,
                     client_random="",
@@ -525,7 +526,7 @@ class tlsSession(object):
                                                  self.server_random)
         self.master_secret = ms
         if conf.debug_tls:
-            log_runtime.debug("master secret: %s" % repr_hex(ms))
+            log_runtime.debug("TLS: master secret: %s", repr_hex(ms))
 
     def compute_ms_and_derive_keys(self):
         self.compute_master_secret()
@@ -553,8 +554,8 @@ class tlsSession(object):
                                             2*self.pwcs.cipher.key_len)
         self.sslv2_key_material = km
         if conf.debug_tls:
-            log_runtime.debug("master secret: %s" % repr_hex(self.master_secret))
-            log_runtime.debug("key material: %s" % repr_hex(km))
+            log_runtime.debug("TLS: master secret: %s", repr_hex(self.master_secret))
+            log_runtime.debug("TLS: key material: %s", repr_hex(km))
 
     def compute_sslv2_km_and_derive_keys(self):
         self.compute_sslv2_key_material()
@@ -930,7 +931,7 @@ class _tls_sessions(object):
     def add(self, session):
         s = self.find(session)
         if s:
-            log_runtime.info("TLS session already exists. Not adding...")
+            log_runtime.info("TLS: previous session shall not be overwritten")
             return
 
         h = session.hash()
@@ -942,7 +943,7 @@ class _tls_sessions(object):
     def rem(self, session):
         s = self.find(session)
         if s:
-            log_runtime.info("TLS session does not exist. Not removing...")
+            log_runtime.info("TLS: previous session shall not be overwritten")
             return
 
         h = session.hash()
@@ -954,10 +955,10 @@ class _tls_sessions(object):
             for k in self.sessions[h]:
                 if k.eq(session):
                     if conf.tls_verbose:
-                        log_runtime.info("Found Matching session %s" % k)
+                        log_runtime.info("TLS: found session matching %s", k)
                     return k
         if conf.tls_verbose:
-            log_runtime.info("Did not find matching session %s" % session)
+            log_runtime.info("TLS: did not find session matching %s", session)
         return None
 
     def __repr__(self):
-- 
GitLab