Merge pull request #857 from biermeester/master

Small extension to mail log management script

management/mail_log.py

 #!/usr/bin/python3
 
+import os.path
+import re
 from collections import defaultdict
-import re, os.path
+
 import dateutil.parser
 
 import mailconfig
 import utils
 
+
 def scan_mail_log(logger, env):
+    """ Scan the system's mail log files and collect interesting data
+
+    This function scans the 2 most recent mail log files in /var/log/.
+
+    Args:
+        logger (ConsoleOutput): Object used for writing messages to the console
+        env (dict): Dictionary containing MiaB settings
+    """
+
     collector = {
         "other-services": set(),
-		"imap-logins": { },
-		"postgrey": { },
-		"rejected-mail": { },
-		"activity-by-hour": { "imap-logins": defaultdict(int), "smtp-sends": defaultdict(int) },
+        "imap-logins": {},
+        "pop3-logins": {},
+        "postgrey": {},
+        "rejected-mail": {},
+        "activity-by-hour": {
+            "imap-logins": defaultdict(int),
+            "pop3-logins": defaultdict(int),
+            "smtp-sends": defaultdict(int),
+            "smtp-receives": defaultdict(int),
+        },
+        "real_mail_addresses": (
+            set(mailconfig.get_mail_users(env)) | set(alias[0] for alias in mailconfig.get_mail_aliases(env))
+        )
     }
 
-	collector["real_mail_addresses"] = set(mailconfig.get_mail_users(env)) | set(alias[0] for alias in mailconfig.get_mail_aliases(env))
-
     for fn in ('/var/log/mail.log.1', '/var/log/mail.log'):
-		if not os.path.exists(fn): continue
+        if not os.path.exists(fn):
+            continue
         with open(fn, 'rb') as log:
             for line in log:
                 line = line.decode("utf8", errors='replace')
@@ -27,18 +47,30 @@ def scan_mail_log(logger, env):
 
     if collector["imap-logins"]:
         logger.add_heading("Recent IMAP Logins")
-		logger.print_block("The most recent login from each remote IP adddress is show.")
+        logger.print_block("The most recent login from each remote IP adddress is shown.")
         for k in utils.sort_email_addresses(collector["imap-logins"], env):
-			for ip, date in sorted(collector["imap-logins"][k].items(), key = lambda kv : kv[1]):
+            for ip, date in sorted(collector["imap-logins"][k].items(), key=lambda kv: kv[1]):
+                logger.print_line(k + "\t" + str(date) + "\t" + ip)
+
+    if collector["pop3-logins"]:
+        logger.add_heading("Recent POP3 Logins")
+        logger.print_block("The most recent login from each remote IP adddress is shown.")
+        for k in utils.sort_email_addresses(collector["pop3-logins"], env):
+            for ip, date in sorted(collector["pop3-logins"][k].items(), key=lambda kv: kv[1]):
                 logger.print_line(k + "\t" + str(date) + "\t" + ip)
 
     if collector["postgrey"]:
         logger.add_heading("Greylisted Mail")
-		logger.print_block("The following mail was greylisted, meaning the emails were temporarily rejected. Legitimate senders will try again within ten minutes.")
-		logger.print_line("recipient" + "\t" + "received" + "\t" + "sender" + "\t" + "delivered")
+        logger.print_block("The following mail was greylisted, meaning the emails were temporarily rejected. "
+                           "Legitimate senders will try again within ten minutes.")
+        logger.print_line("recipient" + "\t" + "received" + 3 * "\t" + "sender" + 6 * "\t" + "delivered")
         for recipient in utils.sort_email_addresses(collector["postgrey"], env):
-			for (client_address, sender), (first_date, delivered_date) in sorted(collector["postgrey"][recipient].items(), key = lambda kv : kv[1][0]):
-				logger.print_line(recipient + "\t" + str(first_date) + "\t" + sender + "\t" + (("delivered " + str(delivered_date)) if delivered_date else "no retry yet"))
+            sorted_recipients = sorted(collector["postgrey"][recipient].items(), key=lambda kv: kv[1][0])
+            for (client_address, sender), (first_date, delivered_date) in sorted_recipients:
+                logger.print_line(
+                    recipient + "\t" + str(first_date) + "\t" + sender + "\t" +
+                    (("delivered " + str(delivered_date)) if delivered_date else "no retry yet")
+                )
 
     if collector["rejected-mail"]:
         logger.add_heading("Rejected Mail")
@@ -48,51 +80,73 @@ def scan_mail_log(logger, env):
                 logger.print_line(k + "\t" + str(date) + "\t" + sender + "\t" + message)
 
     logger.add_heading("Activity by Hour")
+    logger.print_block("Dovecot logins and Postfix mail traffic per hour.")
+    logger.print_block("Hour\tIMAP\tPOP3\tSent\tReceived")
     for h in range(24):
-		logger.print_line("%d\t%d\t%d" % (h, collector["activity-by-hour"]["imap-logins"][h], collector["activity-by-hour"]["smtp-sends"][h] ))
+        logger.print_line(
+            "%d\t%d\t\t%d\t\t%d\t\t%d" % (
+                h,
+                collector["activity-by-hour"]["imap-logins"][h],
+                collector["activity-by-hour"]["pop3-logins"][h],
+                collector["activity-by-hour"]["smtp-sends"][h],
+                collector["activity-by-hour"]["smtp-receives"][h],
+            )
+        )
 
     if len(collector["other-services"]) > 0:
         logger.add_heading("Other")
         logger.print_block("Unrecognized services in the log: " + ", ".join(collector["other-services"]))
 
+
 def scan_mail_log_line(line, collector):
+    """ Scan a log line and extract interesting data """
+
     m = re.match(r"(\S+ \d+ \d+:\d+:\d+) (\S+) (\S+?)(\[\d+\])?: (.*)", line)
-	if not m: return
+
+    if not m:
+        return
 
     date, system, service, pid, log = m.groups()
     date = dateutil.parser.parse(date)
 
     if service == "dovecot":
         scan_dovecot_line(date, log, collector)
-
     elif service == "postgrey":
         scan_postgrey_line(date, log, collector)
-
     elif service == "postfix/smtpd":
         scan_postfix_smtpd_line(date, log, collector)
-
+    elif service == "postfix/cleanup":
+        scan_postfix_cleanup_line(date, log, collector)
     elif service == "postfix/submission/smtpd":
         scan_postfix_submission_line(date, log, collector)
-
-	elif service in ("postfix/qmgr", "postfix/pickup", "postfix/cleanup",
-			"postfix/scache", "spampd", "postfix/anvil", "postfix/master",
-			"opendkim", "postfix/lmtp", "postfix/tlsmgr"):
+    elif service in ("postfix/qmgr", "postfix/pickup", "postfix/cleanup", "postfix/scache", "spampd", "postfix/anvil",
+                     "postfix/master", "opendkim", "postfix/lmtp", "postfix/tlsmgr"):
         # nothing to look at
         pass
-
     else:
         collector["other-services"].add(service)
 
-def scan_dovecot_line(date, log, collector):
-	m = re.match("imap-login: Login: user=<(.*?)>, method=PLAIN, rip=(.*?),", log)
+
+def scan_dovecot_line(date, line, collector):
+    """ Scan a dovecot log line and extract interesting data """
+
+    m = re.match("(imap|pop3)-login: Login: user=<(.*?)>, method=PLAIN, rip=(.*?),", line)
+
     if m:
-		login, ip = m.group(1), m.group(2)
+        prot, login, ip = m.group(1), m.group(2), m.group(3)
+        logins_key = "%s-logins" % prot
         if ip != "127.0.0.1":  # local login from webmail/zpush
-			collector["imap-logins"].setdefault(login, {})[ip] = date
-		collector["activity-by-hour"]["imap-logins"][date.hour] += 1
+            collector[logins_key].setdefault(login, {})[ip] = date
+        collector["activity-by-hour"][logins_key][date.hour] += 1
+
 
 def scan_postgrey_line(date, log, collector):
-	m = re.match("action=(greylist|pass), reason=(.*?), (?:delay=\d+, )?client_name=(.*), client_address=(.*), sender=(.*), recipient=(.*)", log)
+    """ Scan a postgrey log line and extract interesting data """
+
+    m = re.match("action=(greylist|pass), reason=(.*?), (?:delay=\d+, )?client_name=(.*), client_address=(.*), "
+                 "sender=(.*), recipient=(.*)",
+                 log)
+
     if m:
         action, reason, client_name, client_address, sender, recipient = m.groups()
         key = (client_address, sender)
@@ -101,14 +155,20 @@ def scan_postgrey_line(date, log, collector):
         elif action == "pass" and reason == "triplet found" and key in collector["postgrey"].get(recipient, {}):
             collector["postgrey"][recipient][key] = (collector["postgrey"][recipient][key][0], date)
 
+
 def scan_postfix_smtpd_line(date, log, collector):
+    """ Scan a postfix smtpd log line and extract interesting data """
+
+    # Check if the incomming mail was rejected
+
     m = re.match("NOQUEUE: reject: RCPT from .*?: (.*?); from=<(.*?)> to=<(.*?)>", log)
+
     if m:
         message, sender, recipient = m.groups()
         if recipient in collector["real_mail_addresses"]:
             # only log mail to real recipients
 
-			# skip this, is reported in the greylisting report
+            # skip this, if reported in the greylisting report
             if "Recipient address rejected: Greylisted" in message:
                 return
 
@@ -122,15 +182,30 @@ def scan_postfix_smtpd_line(date, log, collector):
             if m:
                 message = "domain blocked: " + m.group(2)
 
-			collector["rejected-mail"].setdefault(recipient, []).append( (date, sender, message) )
+            collector["rejected-mail"].setdefault(recipient, []).append((date, sender, message))
+
+
+def scan_postfix_cleanup_line(date, _, collector):
+    """ Scan a postfix cleanup log line and extract interesting data
+
+    It is assumed that every log of postfix/cleanup indicates an email that was successfulfy received by Postfix.
+
+    """
+
+    collector["activity-by-hour"]["smtp-receives"][date.hour] += 1
 
 def scan_postfix_submission_line(date, log, collector):
+    """ Scan a postfix submission log line and extract interesting data """
+
     m = re.match("([A-Z0-9]+): client=(\S+), sasl_method=PLAIN, sasl_username=(\S+)", log)
+
     if m:
-		procid, client, user = m.groups()
+        # procid, client, user = m.groups()
         collector["activity-by-hour"]["smtp-sends"][date.hour] += 1
 
+
 if __name__ == "__main__":
     from status_checks import ConsoleOutput
-	env = utils.load_environment()
-	scan_mail_log(ConsoleOutput(), env)
+
+    env_vars = utils.load_environment()
+    scan_mail_log(ConsoleOutput(), env_vars)