Postscreen Logfile Analysis

Geschrieben von Marko Kleen am Friday December 21, 2018

Short description

My Postscreen logfile analyzer is intended to be a companion to "pflogsumm" - a very usable and versatile Postfix log report tool with a shortcoming:

You can't see any details on Postscreen activities. With only a few small steps this gap easily can be closed.

Quick instructions

  1. Download the export tool
  2. Download the report generator
  3. Decompress both (gunzip)
  4. Edit both files and adjust paths, etc.
  5. Run both scripts. That's it.

Long description

This guide assumes you're on a GNU/Linux platform like Debian 9.6 Stretch (was "stable" at the time of writing this entry) using the Postfix mail server. If you're using something else, my scripts are not for you as Postscreen is part of Postfix.

While there are quite a few tools for Postfix logfile analysis on their website, a closer look will reveal a lot of the links are dead, and the others don't do much more than to create some bar graphs representing how many activities there were in a time period. However, none of the tools I checked gave the details I was looking for:

  • Which email adresses appear in block events?
  • What are the sender addresses of the blocked events?
  • What are the sender hosts / networks of these events?

If you don't know these details from Postscreen, you're likely not to see important communication coming in to your mail servers, cutting your users off of information they actually want to receive. At the same time you likely don't see attackers hammering your machine trying to find a way to use your server as a relay.

The export tool

The export tool has a very simple task: Read the Mail Log from /var/log/mail.log (respectively plus /var/log/mail.log.1 if log-rotated), filter for the desired day and save to an export file. You could use Cron to schedule exports like once per hour.

Parameters

  1. report date ‐ e.g. "yesterday", "today", "last week"
    If omitted, the parameter defaults to "yesterday".

Example

./myPSLogExport "2 days ago"

Accessing the log files

If you set the export file location to e.g. a destination within your web server's root you could actually keep a history of your postscreen logs with individual folders per year and month for easy and quick access. The export file location must be reachable for the report generator as well.

The report generator

The report generator tries to imitate the "pflogsumm" output. It expects to find the export tool's files and generates a report from that.

Parameters

  1. report date ‐ e.g. "yesterday", "today", "last week"
    If omitted, the parameter defaults to "yesterday".
  2. export - If omitted, defaults to "no".

Example

./myPSLogReport "today" "export"

When called this way, a report will be generated from today's export (run the export tool first!) and the resulting report should be stored in the (same) export directory. If you omit the 2nd parameter the report will be sent to "stdout" - most likely your screen.

Accessing the reports

If your export files go to a folder within your web root, your reports will also appear in the same folder, making them accessible in a very easy way. Personally I scheduled a Cron job to mail me yesterday's report every morning. In addition to that Cron periodically sends a report to my web server, so that I can always see what's going on with minimal effort.

A word of warning!

Please consider adding password protection to your web server location, should you decide to export to such a location! Log files and reports can contain personal information which mustn't be accessible to the whole world.

Sample report output
(shortened and redacted for privacy)

Postscreen log summaries for Dec 21

Grand Totals
------------
log statistics

     1507     lines in log file        
      394     clients connected        
      152     clients passed to smtpd  
    -----     ---------------------------
      242     clients disconnected     
      155       client listed in DNSBL 
       86       client ip in blacklist 
    -----     ---------------------------
      61%     client connections blocked

passed to smtpd

      114     known clients who passed tests
       36     new clients who passed tests
        2     whitelisted by admin rule
    -----     ---------------------------
      152     clients passed to smtpd  

blocked clients

      155     clients blocked by DNSBL 
       86     clients blocked by blacklist
    -----     ---------------------------
       85     ix.dnsbl.manitu.net      
       12     zen.spamhaus.org         
       28     local blacklist          
        4     communication protocol error
      113     unknown (clients bailed) 
    -----     ---------------------------
      242     total clients blocked    

blocked clients by recipent

       32     emailA@example.com        
       13     emailB@example.com       
       29     emailC@example.com       
       46     emailD@example.com       
        0     emailE@example.com       
        3     emailF@example.com       
        6     other email              
    -----     ---------------------------
      129     sender + recipient known 
      113     only client ip known     
    -----     ---------------------------
      242     total clients blocked    

miscellaneous

        0     system cache update      
        2     system cache full cleanup
        0     transp. endpoint not conn.
        4     550 5.5.1 (protocol error)
       28     550 5.3.2 (local blacklist)
       97     550 5.7.1 (dnsbl blacklist)

quantities by status (tech)

      394     CONNECT                  
       86     BLACKLISTED              
        2     WHITELISTED              
       36     PASS NEW                 
      114     PASS OLD                 
      155     DNSBL                    
      129     NOQUEUE                  
      148     PREGREET                 
      199     HANGUP                   
      242     DISCONNECT               
        0     NON-SMTP COMMAND         


nondelivery details (for analysis)
----------------------------------


emailA@example.com

Dec 21 xx:xx:xx host postfix/postscreen[24237]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.5.1 Protocol error; from=<x@x.x>, to=<emailA@example.com>, proto=SMTP, helo=<helo.hostname>
Dec 21 xx:xx:xx host postfix/postscreen[24434]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.7.1 Service unavailable; client [off.end.ing.ip] blocked using ix.dnsbl.manitu.net; from=<x@x.x>, to=<emailA@example.com>, proto=SMTP, helo=<helo.hostname>
Dec 21 xx:xx:xx host postfix/postscreen[26097]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.7.1 Service unavailable; client [off.end.ing.ip] blocked using ix.dnsbl.manitu.net; from=<x@x.x>, to=<emailA@example.com>, proto=ESMTP, helo=<helo.hostname>


emailB@example.com

Dec 21 xx:xx:xx host postfix/postscreen[23783]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.3.2 Service currently unavailable; from=<x@x.x>, to=<emailB@example.com>, proto=ESMTP, helo=<helo.hostname>
Dec 21 xx:xx:xx host postfix/postscreen[24667]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.3.2 Service currently unavailable; from=<x@x.x>, to=<emailB@example.com>, proto=ESMTP, helo=<helo.hostname>
Dec 21 xx:xx:xx host postfix/postscreen[30987]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.3.2 Service currently unavailable; from=<x@x.x>, to=<emailB@example.com>, proto=ESMTP, helo=<helo.hostname>


emailC@example.com

Dec 21 xx:xx:xx host postfix/postscreen[21110]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.7.1 Service unavailable; client [off.end.ing.ip] blocked using ix.dnsbl.manitu.net; from=<x@x.x>, to=<emailC@example.com>, proto=ESMTP, helo=<helo.hostname>
Dec 21 xx:xx:xx host postfix/postscreen[22631]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.3.2 Service currently unavailable; from=<x@x.x>, to=<emailC@example.com>, proto=ESMTP, helo=<helo.hostname>
Dec 21 xx:xx:xx host postfix/postscreen[23141]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.7.1 Service unavailable; client [off.end.ing.ip] blocked using ix.dnsbl.manitu.net; from=<x@x.x>, to=<emailC@example.com>, proto=ESMTP, helo=<helo.hostname>


emailD@example.com

Dec 21 xx:xx:xx host postfix/postscreen[20977]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.7.1 Service unavailable; client [off.end.ing.ip] blocked using ix.dnsbl.manitu.net; from=<x@x.x>, to=<emailD@example.com>, proto=SMTP, helo=<helo.hostname>
Dec 21 xx:xx:xx host postfix/postscreen[24213]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.7.1 Service unavailable; client [off.end.ing.ip] blocked using ix.dnsbl.manitu.net; from=<x@x.x>, to=<emailD@example.com>, proto=ESMTP, helo=<helo.hostname>


emailE@example.com



emailF@example.com

Dec 21 xx:xx:xx host postfix/postscreen[21883]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.7.1 Service unavailable; client [off.end.ing.ip] blocked using zen.spamhaus.org; from=<x@x.x>, to=<emailF@example.com>, proto=ESMTP, helo=<helo.hostname>
Dec 21 xx:xx:xx host postfix/postscreen[27117]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.7.1 Service unavailable; client [off.end.ing.ip] blocked using zen.spamhaus.org; from=<x@x.x>, to=<emailF@example.com>, proto=ESMTP, helo=<helo.hostname>


other recipients

Dec 21 xx:xx:xx host postfix/postscreen[30536]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.7.1 Service unavailable; client [off.end.ing.ip] blocked using ix.dnsbl.manitu.net; from=<x@x.x>, to=<other recipients>, proto=ESMTP, helo=<helo.hostname>
Dec 21 xx:xx:xx host postfix/postscreen[13447]: NOQUEUE: reject: RCPT from [offending_ip]:port: 550 5.7.1 Service unavailable; client [off.end.ing.ip] blocked using ix.dnsbl.manitu.net; from=<x@x.x>, to=<other recipients>, proto=ESMTP, helo=<helo.hostname>