Skip to content

M
mailinabox
Commit 946cd63e authored by Rinze's avatar Rinze
Browse files
Options

Mail log management script cleanup

parent 9ee2d946
Hide whitespace changes
Inline Side-by-side
Showing with 153 additions and 106 deletions
management/mail_log.py
View file @ 946cd63e
#!/usr/bin/python3 #!/usr/bin/python3
import os.path
import re
from collections import defaultdict from collections import defaultdict
import re, os.path
import dateutil.parser import dateutil.parser
import mailconfig import mailconfig
import utils import utils
def scan_mail_log(logger, env): def scan_mail_log(logger, env):
collector = { """ Scan the system's mail log files and collect interesting data
"other-services": set(),
"imap-logins": { }, This function scans the 2 most recent mail log files in /var/log/.
"postgrey": { },
"rejected-mail": { }, Args:
"activity-by-hour": { "imap-logins": defaultdict(int), "smtp-sends": defaultdict(int) }, logger (ConsoleOutput): Object used for writing messages to the console
} env (dict): Dictionary containing MiaB settings
"""
collector["real_mail_addresses"] = set(mailconfig.get_mail_users(env)) | set(alias[0] for alias in mailconfig.get_mail_aliases(env))
collector = {
for fn in ('/var/log/mail.log.1', '/var/log/mail.log'): "other-services": set(),
if not os.path.exists(fn): continue "imap-logins": {},
with open(fn, 'rb') as log: "postgrey": {},
for line in log: "rejected-mail": {},
line = line.decode("utf8", errors='replace') "activity-by-hour": {
scan_mail_log_line(line.strip(), collector) "imap-logins": defaultdict(int),
"smtp-sends": defaultdict(int),
if collector["imap-logins"]: },
logger.add_heading("Recent IMAP Logins") "real_mail_addresses": (
logger.print_block("The most recent login from each remote IP adddress is show.") set(mailconfig.get_mail_users(env)) | set(alias[0] for alias in mailconfig.get_mail_aliases(env))
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]): }
logger.print_line(k + "\t" + str(date) + "\t" + ip)
for fn in ('/var/log/mail.log.1', '/var/log/mail.log'):
if collector["postgrey"]: if not os.path.exists(fn):
logger.add_heading("Greylisted Mail") continue
logger.print_block("The following mail was greylisted, meaning the emails were temporarily rejected. Legitimate senders will try again within ten minutes.") with open(fn, 'rb') as log:
logger.print_line("recipient" + "\t" + "received" + "\t" + "sender" + "\t" + "delivered") for line in log:
for recipient in utils.sort_email_addresses(collector["postgrey"], env): line = line.decode("utf8", errors='replace')
for (client_address, sender), (first_date, delivered_date) in sorted(collector["postgrey"][recipient].items(), key = lambda kv : kv[1][0]): scan_mail_log_line(line.strip(), collector)
logger.print_line(recipient + "\t" + str(first_date) + "\t" + sender + "\t" + (("delivered " + str(delivered_date)) if delivered_date else "no retry yet"))
if collector["imap-logins"]:
if collector["rejected-mail"]: logger.add_heading("Recent IMAP Logins")
logger.add_heading("Rejected Mail") logger.print_block("The most recent login from each remote IP adddress is shown")
logger.print_block("The following incoming mail was rejected.") for k in utils.sort_email_addresses(collector["imap-logins"], env):
for k in utils.sort_email_addresses(collector["rejected-mail"], env): for ip, date in sorted(collector["imap-logins"][k].items(), key=lambda kv: kv[1]):
for date, sender, message in collector["rejected-mail"][k]: logger.print_line(k + "\t" + str(date) + "\t" + ip)
logger.print_line(k + "\t" + str(date) + "\t" + sender + "\t" + message)
if collector["postgrey"]:
logger.add_heading("Activity by Hour") logger.add_heading("Greylisted Mail")
for h in range(24): logger.print_block("The following mail was greylisted, meaning the emails were temporarily rejected. "
logger.print_line("%d\t%d\t%d" % (h, collector["activity-by-hour"]["imap-logins"][h], collector["activity-by-hour"]["smtp-sends"][h] )) "Legitimate senders will try again within ten minutes.")
logger.print_line("recipient" + "\t" + "received" + 3 * "\t" + "sender" + 6 * "\t" + "delivered")
if len(collector["other-services"]) > 0: for recipient in utils.sort_email_addresses(collector["postgrey"], env):
logger.add_heading("Other") sorted_recipients = sorted(collector["postgrey"][recipient].items(), key=lambda kv: kv[1][0])
logger.print_block("Unrecognized services in the log: " + ", ".join(collector["other-services"])) 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")
logger.print_block("The following incoming mail was rejected.")
for k in utils.sort_email_addresses(collector["rejected-mail"], env):
for date, sender, message in collector["rejected-mail"][k]:
logger.print_line(k + "\t" + str(date) + "\t" + sender + "\t" + message)
logger.add_heading("Activity by Hour")
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]
)
)
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): def scan_mail_log_line(line, collector):
m = re.match(r"(\S+ \d+ \d+:\d+:\d+) (\S+) (\S+?)(\[\d+\])?: (.*)", line) """ Scan a log line and extract interesting data """
if not m: return
m = re.match(r"(\S+ \d+ \d+:\d+:\d+) (\S+) (\S+?)(\[\d+\])?: (.*)", line)
date, system, service, pid, log = m.groups() if not m:
date = dateutil.parser.parse(date) return
if service == "dovecot":
scan_dovecot_line(date, log, collector)
elif service == "postgrey": date, system, service, pid, log = m.groups()
scan_postgrey_line(date, log, collector) date = dateutil.parser.parse(date)
elif service == "postfix/smtpd": if service == "dovecot":
scan_postfix_smtpd_line(date, log, collector) 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/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"):
# nothing to look at
pass
else:
collector["other-services"].add(service)
elif service == "postfix/submission/smtpd":
scan_postfix_submission_line(date, log, collector)
elif service in ("postfix/qmgr", "postfix/pickup", "postfix/cleanup", def scan_dovecot_line(date, line, collector):
"postfix/scache", "spampd", "postfix/anvil", "postfix/master", """ Scan a dovecot log line and extract interesting data """
"opendkim", "postfix/lmtp", "postfix/tlsmgr"):
# nothing to look at
pass
else: m = re.match("imap-login: Login: user=<(.*?)>, method=PLAIN, rip=(.*?),", line)
collector["other-services"].add(service)
if m:
login, ip = m.group(1), m.group(2)
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
def scan_dovecot_line(date, log, collector):
m = re.match("imap-login: Login: user=<(.*?)>, method=PLAIN, rip=(.*?),", log)
if m:
login, ip = m.group(1), m.group(2)
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
def scan_postgrey_line(date, log, collector): 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 """
if m:
action, reason, client_name, client_address, sender, recipient = m.groups() m = re.match("action=(greylist|pass), reason=(.*?), (?:delay=\d+, )?client_name=(.*), client_address=(.*), "
key = (client_address, sender) "sender=(.*), recipient=(.*)",
if action == "greylist" and reason == "new": log)
collector["postgrey"].setdefault(recipient, {})[key] = (date, None)
elif action == "pass" and reason == "triplet found" and key in collector["postgrey"].get(recipient, {}): if m:
collector["postgrey"][recipient][key] = (collector["postgrey"][recipient][key][0], date) action, reason, client_name, client_address, sender, recipient = m.groups()
key = (client_address, sender)
if action == "greylist" and reason == "new":
collector["postgrey"].setdefault(recipient, {})[key] = (date, None)
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): def scan_postfix_smtpd_line(date, log, collector):
m = re.match("NOQUEUE: reject: RCPT from .*?: (.*?); from=<(.*?)> to=<(.*?)>", log) """ Scan a postfix smtpd log line and extract interesting data """
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 m = re.match("NOQUEUE: reject: RCPT from .*?: (.*?); from=<(.*?)> to=<(.*?)>", log)
if "Recipient address rejected: Greylisted" in message:
return
# simplify this one if m:
m = re.search(r"Client host \[(.*?)\] blocked using zen.spamhaus.org; (.*)", message) message, sender, recipient = m.groups()
if m: if recipient in collector["real_mail_addresses"]:
message = "ip blocked: " + m.group(2) # only log mail to real recipients
# simplify this one too # skip this, is reported in the greylisting report
m = re.search(r"Sender address \[.*@(.*)\] blocked using dbl.spamhaus.org; (.*)", message) if "Recipient address rejected: Greylisted" in message:
if m: return
message = "domain blocked: " + m.group(2)
# simplify this one
m = re.search(r"Client host \[(.*?)\] blocked using zen.spamhaus.org; (.*)", message)
if m:
message = "ip blocked: " + m.group(2)
# simplify this one too
m = re.search(r"Sender address \[.*@(.*)\] blocked using dbl.spamhaus.org; (.*)", message)
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_submission_line(date, log, collector): def scan_postfix_submission_line(date, log, collector):
m = re.match("([A-Z0-9]+): client=(\S+), sasl_method=PLAIN, sasl_username=(\S+)", log) """ Scan a postfix submission log line and extract interesting data """
if m:
procid, client, user = m.groups() m = re.match("([A-Z0-9]+): client=(\S+), sasl_method=PLAIN, sasl_username=(\S+)", log)
collector["activity-by-hour"]["smtp-sends"][date.hour] += 1
if m:
# procid, client, user = m.groups()
collector["activity-by-hour"]["smtp-sends"][date.hour] += 1
if __name__ == "__main__": if __name__ == "__main__":
from status_checks import ConsoleOutput 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)
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment

Technounit-GROUP 2023