From cc6db53d03cdf53bd65dce87a93ba5ad8a00073e Mon Sep 17 00:00:00 2001 From: Frank Brehm Date: Tue, 26 Mar 2024 18:29:47 +0100 Subject: [PATCH] Extending class PostfixLogfileParser --- lib/pp_admintools/handler/pflogparse.py | 112 +++++++++++++++++++----- test/test_20_postfix_chain.py | 8 +- 2 files changed, 96 insertions(+), 24 deletions(-) diff --git a/lib/pp_admintools/handler/pflogparse.py b/lib/pp_admintools/handler/pflogparse.py index 4942b13..fa28ee6 100644 --- 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[0-9a-f]+):\s+', re.IGNORECASE) # 'connect\s+from\s+[^\[]+\[[0-9a-f\.:]+\]' re_connect = re.compile( - r'connect\s+from\s+(?P[^\[]+)\[(?P[0-9a-f\.:]+)\]', re.IGNORECASE) + r'\bconnect\s+from\s+(?P[^\[]+)\[(?P[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|SSL)\S+)' + r'\s+with\s+cipher\s+(?P\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[^>]*)>,\s+size=(?P\d+),\s+nrcpt=(?P\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 e4c5d23..d78a069 100755 --- 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()))) -- 2.39.5