Extending class PostfixLogfileParser

diff --git a/lib/pp_admintools/handler/pflogparse.py b/lib/pp_admintools/handler/pflogparse.py
index 4942b13adf4ee6e206f64ec9ef9f3c50e39b31e4..fa28ee6d7c2aea0b6f71c891965066a7e6132374 100644 (file)
--- a/lib/pp_admintools/handler/pflogparse.py
+++ b/lib/pp_admintools/handler/pflogparse.py
@@ -27,7 +27,7 @@ LOG = logging.getLogger(__name__)
 _ = XLATOR.gettext
 ngettext = XLATOR.ngettext
 
-__version__ = '0.3.2'
+__version__ = '0.4.0'
 
 
 # =============================================================================
@@ -43,8 +43,12 @@ class PostfixLogfileParser(HandlingObject):
     re_postfix_id = re.compile(r'^(?P<id>[0-9a-f]+):\s+', re.IGNORECASE)
     # 'connect\s+from\s+[^\[]+\[[0-9a-f\.:]+\]'
     re_connect = re.compile(
-        r'connect\s+from\s+(?P<client>[^\[]+)\[(?P<addr>[0-9a-f\.:]+)\]', re.IGNORECASE)
+        r'\bconnect\s+from\s+(?P<client>[^\[]+)\[(?P<addr>[0-9a-f\.:]+)\]', re.IGNORECASE)
     re_disconnect = re.compile(r'disconnect\s+from\s+', re.IGNORECASE)
+    re_tls_connect = re.compile(
+        r'\bTLS\s+connection\s+established\s.*: (?P<tls_version>(?:TLS|SSL)\S+)'
+        r'\s+with\s+cipher\s+(?P<tls_cipher>\S.*\S)', re.IGNORECASE)
+    re_client = re.compile(r'^client=\S+\s*$', re.IGNORECASE)
 
     re_dis_ehlo = re.compile(r'\sehlo=(\d+)', re.IGNORECASE)
     re_dis_starttls = re.compile(r'\sstarttls=(\d+)', re.IGNORECASE)
@@ -57,7 +61,9 @@ class PostfixLogfileParser(HandlingObject):
 
     re_message_id = re.compile(r'message-id=(\S+)', re.IGNORECASE)
 
-    re_from_addr = re.compile(r'^\s*from=<([^>]*)>')
+    re_from_addr = re.compile(
+        r'^\s*from=<(?P<from>[^>]*)>,\s+size=(?P<size>\d+),\s+nrcpt=(?P<nrcpt>\d+)',
+        re.IGNORECASE)
 
     # -------------------------------------------------------------------------
     def __init__(
@@ -130,29 +136,17 @@ class PostfixLogfileParser(HandlingObject):
             'pid': pid,
             'message': message,
             'postfix_id': postfix_id,
+            'smtpd_done': False,
         }
         if self.verbose > 3:
             LOG.debug('Found log entry:\n' + pp(entry))
 
         if command == 'postfix/smtpd' and pid:
-            self.eval_smtpd_line(entry)
+            entry['smtpd_done'] = self.eval_smtpd_line(entry)
 
         if postfix_id:
-            if command == 'postfix/smtpd' and pid:
-                if postfix_id not in self.chain and pid in self.active_smtpd_pid \
-                        and self.active_smtpd_pid[pid]:
-                    self.chain[postfix_id] = self.active_smtpd_pid[pid]
-
-            if pid in self.active_smtpd_pid and self.active_smtpd_pid[pid] \
-                    and postfix_id in self.chain:
-                m = self.re_message_id.search(message)
-                if m:
-                    self.chain[postfix_id].message_id = m[1]
-                    return
-
-            m = self.re_from_addr.match(message)
-            if m and postfix_id in self.chain and self.chain[postfix_id]:
-                self.chain[postfix_id].from_address = m[1]
+            self.eval_postfix_entry(**entry)
+            return
 
     # -------------------------------------------------------------------------
     def eval_smtpd_line(self, entry):
@@ -163,6 +157,9 @@ class PostfixLogfileParser(HandlingObject):
         m_conn = self.re_connect.search(message)
 
         if m_conn:
+            if self.verbose > 4:
+                LOG.debug('Evaluating connect entry:\n' + pp(entry))
+
             who = m_conn['client']
             if who.lower() == 'unknown':
                 who = m_conn['addr']
@@ -182,10 +179,12 @@ class PostfixLogfileParser(HandlingObject):
             self.connect[who] += 1
 
             if self.verbose > 3:
+                LOG.debug(f'Creating Postfix log chain entry for smtpd PID {pid}.')
+            if self.verbose > 4:
                 msg = 'Creating Postfix log chain:\n' + pp(chain.as_dict())
                 LOG.debug(msg)
 
-            return
+            return True
 
         m_dis = self.re_disconnect.search(message)
         if m_dis:
@@ -193,12 +192,29 @@ class PostfixLogfileParser(HandlingObject):
                 LOG.debug('Found disconnection for PID {}: '.format(pid) + message)
             if pid in self.active_smtpd_pid:
                 self.evaluate_disconnect(message, timestamp, pid)
-                if self.verbose > 2:
+                if self.verbose > 4:
                     LOG.debug(
                         'Updated PD struct of {}:\n'.format(pid) + pp(self.active_smtpd_pid[pid]))
                 del self.active_smtpd_pid[pid]
 
-            return
+            return True
+
+        m_tls = self.re_tls_connect.search(message)
+        if m_tls:
+            if self.verbose > 3:
+                LOG.debug('Found SSL/TLS connect for PID {}: '.format(pid) + message)
+            if pid in self.active_smtpd_pid:
+                self.active_smtpd_pid[pid].tls_version = m_tls['tls_version']
+                self.active_smtpd_pid[pid].tls_cipher = m_tls['tls_cipher']
+            return True
+
+        if self.re_client.match(message):
+            return True
+
+        if self.verbose > 1:
+            LOG.debug('Evaluating further smtpd entry:\n' + pp(entry))
+
+        return False
 
     # -------------------------------------------------------------------------
     def evaluate_disconnect(self, message, timestamp, pid):
@@ -208,12 +224,20 @@ class PostfixLogfileParser(HandlingObject):
         if not self.active_smtpd_pid[pid]:
             return
         if not self.active_smtpd_pid[pid].postfix_id:
+            if self.verbose > 3:
+                LOG.debug(
+                    f'No Postfix ID found in entry for smtpd PID {pid}:\n' + pp(
+                        self.active_smtpd_pid[pid].as_dict()))
             return
 
         postfix_id = self.active_smtpd_pid[pid].postfix_id
         if not self.chain[postfix_id]:
             return
 
+        if self.verbose > 3:
+            LOG.debug(
+                f'Evaluating disconnect from {pid} for {postfix_id} at {timestamp}: {message}')
+
         self.chain[postfix_id].end = timestamp
 
         m = self.re_dis_ehlo.search(message)
@@ -244,8 +268,50 @@ class PostfixLogfileParser(HandlingObject):
         if m:
             self.chain[postfix_id].mail = m[1]
 
+    # -------------------------------------------------------------------------
+    def eval_postfix_entry(
+            self, postfix_id, timestamp=None, host=None, command=None, pid=None,
+            message=None, smtpd_done=False):
+        """Evaluate a log line with a given Postfix-Id."""
+        # Eval Postfix entry from smtpd ...
+        if command == 'postfix/smtpd' and pid:
+            if pid in self.active_smtpd_pid and self.active_smtpd_pid[pid]:
+                self.active_smtpd_pid[pid].postfix_id = postfix_id
+            if postfix_id not in self.chain and pid in self.active_smtpd_pid \
+                    and self.active_smtpd_pid[pid]:
+                if self.verbose > 3:
+                    LOG.debug(
+                        f'Copying entry for smtpd PID {pid} and Postfix ID {postfix_id} '
+                        'into chain.')
+                self.chain[postfix_id] = self.active_smtpd_pid[pid]
 
-# =============================================================================
+        if postfix_id in self.chain:
+            m = self.re_message_id.search(message)
+            if m:
+                self.chain[postfix_id].message_id = m[1]
+                return
+
+        m = self.re_from_addr.match(message)
+        if m:
+            if postfix_id in self.chain and self.chain[postfix_id]:
+                self.chain[postfix_id].from_address = m['from']
+                self.chain[postfix_id].size = m['size']
+                self.chain[postfix_id].nr_rcpt = m['nrcpt']
+            return
+
+        if message.lower() == 'removed' and postfix_id in self.chain:
+            self.chain[postfix_id].end = timestamp
+            return
+
+        if smtpd_done:
+            return
+
+        if self.verbose > 1:
+            msg = f'Evaluating further entry of {command!r} for Postfix Id {postfix_id!r}: '
+            LOG.debug(msg + message)
+
+
+# =========================================================================
 if __name__ == '__main__':
 
     pass

diff --git a/test/test_20_postfix_chain.py b/test/test_20_postfix_chain.py
index e4c5d23b9cf2bfdf9d05f36ab63a0b125dc4a4b2..d78a069d1e21539aa23802658f289875c9ebf739 100755 (executable)
--- a/test/test_20_postfix_chain.py
+++ b/test/test_20_postfix_chain.py
@@ -104,10 +104,16 @@ class TestPostfixChain(PpAdminToolsTestcase):
             data='3',
             mail=1,
             from_address='frank.brehm@pixelpark.com',
-            to_address='frank@brehm-online.com',
+            origin_to='solution@pixelpark.com',
             smtpd_pid='23456',
             mailhost='prd-mail01.pixelpark.com',
+            tls_version='TLSv1.2',
+            tls_cipher='ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)',
+            size=12345,
+            nr_rcpt=1,
         )
+        chain.add_to_address('frank.brehm@pixelpark.com')
+        chain.add_to_address('thomas.dalichow@pixelpark.com')
         LOG.debug('PostfixLogchainInfo %r: {!r}'.format(chain))
         LOG.debug('PostfixLogchainInfo %s:\n{}'.format(chain))
         LOG.debug('PostfixLogchainInfo as_dict():\n{}'.format(pp(chain.as_dict())))