diff options
Diffstat (limited to '')
| -rw-r--r-- | auxiliary/collate/README | 11 | ||||
| -rw-r--r-- | auxiliary/collate/README.tlstype | 37 | ||||
| -rwxr-xr-x | auxiliary/collate/collate.pl | 146 | ||||
| -rw-r--r-- | auxiliary/collate/tlstype.pl | 31 |
4 files changed, 225 insertions, 0 deletions
diff --git a/auxiliary/collate/README b/auxiliary/collate/README new file mode 100644 index 0000000..6e7e0ab --- /dev/null +++ b/auxiliary/collate/README @@ -0,0 +1,11 @@ +This script, by Viktor Dukhovni, untangles a Postfix logfile and +groups the records one "session" at a time based on queue ID and +process ID information. + +Records from different sessions are separated by an empty line. +Such text is easy to process with $/="" in perl, or RS="" in awk. + +Usage: + perl collate.pl file... + +It reads standard input when no file is specified. diff --git a/auxiliary/collate/README.tlstype b/auxiliary/collate/README.tlstype new file mode 100644 index 0000000..7e74327 --- /dev/null +++ b/auxiliary/collate/README.tlstype @@ -0,0 +1,37 @@ +On Mon, Apr 06, 2020 at 08:21:32AM +0100, Dominic Raferd wrote: + +> Using setting 'smtp_tls_security_level = may' (postfix 3.3.0) is there +> a reliable way to see from log which outgoing emails were sent in the +> clear i.e. *not* using TLS? + +Yes, provided you don't lose too many log messages[1], and your logging +subsystem does not reorder them[1], set: + + smtp_tls_loglevel = 1 + +and use "collate": + + https://github.com/vdukhovni/postfix/tree/master/postfix/auxiliary/collate + +whose output you'd send to the attached Perl script. On my system for +example: + + # bzcat $(ls -tr /var/log/maillog*) | perl collate.pl | perl tlstype.pl + +-- + Viktor. + +[1] If your system is suffering under the yoke of systemd-journald, you +should strongly consider enabling the built-in logging in recent +versions of Postfix to bypass systemd's broken logging subsystem. + + - It is single-threaded, performs poorly on multi-cpu servers and + may not be able to keep up with all the messages generated on a + busy multi-cpu system. + + - By default has low message rate limits, dropping messages + that exceed the limits. + + - Listens on stream socket rather than a dgram socket, which + breaks message ordering from multi-process systems like + Postfix. diff --git a/auxiliary/collate/collate.pl b/auxiliary/collate/collate.pl new file mode 100755 index 0000000..62d08b9 --- /dev/null +++ b/auxiliary/collate/collate.pl @@ -0,0 +1,146 @@ +#! /usr/bin/perl + +use strict; +use warnings; + +# Postfix delivery agents +my @agents = qw(discard error lmtp local pipe smtp virtual); + +my $instre = qr{(?x) + \A # Absolute line start + (?:\S+ \s+){3} # Timestamp, adjust for other time formats + \S+ \s+ # Hostname + (postfix(?:-[^/\s]+)?) # Capture instance name stopping before first '/' + (?:/\S+)* # Optional non-captured '/'-delimited qualifiers + / # Final '/' before the daemon program name + }; + +my $cmdpidre = qr{(?x) + \G # Continue from previous match + (\S+)\[(\d+)\]:\s+ # command[pid]: +}; + +my %smtpd; +my %smtp; +my %transaction; +my $i = 0; +my %seqno; +my %deleted; + +my %isagent = map { ($_, 1) } @agents; + +while (<>) { + next unless m{$instre}ogc; my $inst = $1; + next unless m{$cmdpidre}ogc; my $command = $1; my $pid = $2; + + if ($command eq "smtpd") { + if (m{\Gconnect from }gc) { + # Start new log + $smtpd{$pid}->{"log"} = $_; next; + undef $smtpd{$pid}->{"qid"}; + } + + $smtpd{$pid}->{"log"} .= $_; + + if (m{\G(\w+): client=}gc) { + # Fresh transaction + my $qid = "$inst/$1"; + $smtpd{$pid}->{"qid"} = $qid; + $transaction{$qid} = $smtpd{$pid}->{"log"}; + $seqno{$qid} = ++$i; + next; + } + + my $qid = $smtpd{$pid}->{"qid"}; + $transaction{$qid} .= $_ + if (defined($qid) && exists $transaction{$qid}); + if (m{\Gdisconnect from}gc) { + if (!defined($qid)) { + print $smtpd{$pid}->{"log"}, "\n"; + } elsif (delete $deleted{$qid}) { + print delete $transaction{$qid}, "\n"; + } + delete $smtpd{$pid}; + } + next; + } + + if ($command eq "pickup") { + if (m{\G(\w+): uid=}gc) { + my $qid = "$inst/$1"; + $transaction{$qid} = $_; + $seqno{$qid} = ++$i; + } + next; + } + + # bounce(8) logs transaction start after cleanup(8) already logged + # the message-id, so the cleanup log entry may be first + # + if ($command eq "cleanup") { + next unless (m{\G(\w+): }gc); + my $qid = "$inst/$1"; + $transaction{$qid} .= $_; + $seqno{$qid} = ++$i if (! exists $seqno{$qid}); + if (m{\G(?:milter(?:-(?:header|body))?-)?(?:reject|discard|hold): }) { + $deleted{$qid} = 1; + } + next; + } + + if ($command eq "qmgr") { + next unless (m{\G(\w+): }gc); + my $qid = "$inst/$1"; + if (defined($transaction{$qid})) { + $transaction{$qid} .= $_; + if (m{\Gremoved$}gc) { + print delete $transaction{$qid}, "\n"; + } + } + next; + } + + # Save pre-delivery messages for smtp(8) and lmtp(8) + # + if ($command eq "smtp" || $command eq "lmtp") { + $smtp{$pid} .= $_; + + if (m{\G(\w+): to=}gc) { + my $qid = "$inst/$1"; + if (defined($transaction{$qid})) { + $transaction{$qid} .= $smtp{$pid}; + } + delete $smtp{$pid}; + } + next; + } + + if ($command eq "bounce") { + if (m{\G(\w+): .*? notification: (\w+)$}gc) { + my $qid = "$inst/$1"; + my $newid = "$inst/$2"; + if (defined($transaction{$qid})) { + $transaction{$qid} .= $_; + } + $transaction{$newid} = + $_ . $transaction{$newid}; + $seqno{$newid} = ++$i if (! exists $seqno{$newid}); + } + next; + } + + if ($isagent{$command}) { + if (m{\G(\w+): to=}gc) { + my $qid = "$inst/$1"; + if (defined($transaction{$qid})) { + $transaction{$qid} .= $_; + } + } + next; + } +} + +# Dump logs of incomplete transactions. +foreach my $qid (sort {$seqno{$a} <=> $seqno{$b}} keys %transaction) { + print $transaction{$qid}, "\n"; +} diff --git a/auxiliary/collate/tlstype.pl b/auxiliary/collate/tlstype.pl new file mode 100644 index 0000000..1e5cf9a --- /dev/null +++ b/auxiliary/collate/tlstype.pl @@ -0,0 +1,31 @@ +#! /usr/bin/env perl + +use strict; +use warnings; + +local $/ = "\n\n"; + +while (<>) { + my $qid; + my %tls; + my $smtp; + foreach my $line (split("\n")) { + if ($line =~ m{ postfix(?:\S*?)/qmgr\[\d+\]: (\w+): from=<.*>, size=\d+, nrcpt=\d+ [(]queue active[)]$}) { + $qid //= $1; + next; + } + if ($line =~ m{ postfix(?:\S*?)/smtp\[(\d+)\]: (\S+) TLS connection established to (\S+): (.*)}) { + $tls{$1}->{lc($3)} = [$2, $4]; + next; + } + if ($line =~ m{.*? postfix(?:\S*?)/smtp\[(\d+)\]: (\w+): (to=.*), relay=(\S+), (delay=\S+, delays=\S+, dsn=2\.\S+, status=sent .*)}) { + next unless $qid eq $2; + if (defined($tls{$1}->{lc($4)}) && ($tls{$1}->{lc($4)}->[2] //= $5) eq $5) { + printf "qid=%s, relay=%s, %s -> %s %s\n", $qid, lc($4), $3, @{$tls{$1}->{lc($4)}}[0..1]; + } else { + delete $tls{$1}; + printf "qid=%s, relay=%s, %s -> cleartext\n", $qid, lc($4), $3; + } + } + } +} |