# # Platon::Log::Mail::Postfix.pm # # Developed by Lubomir Host 'rajo' # Copyright (c) 2004 Platon SDG, http://platon.sk/ # Licensed under terms of GNU General Public License. # All rights reserved. # # Changelog: # 2004-10-19 - created # # $Platon: perl-modules/Platon/Log/Mail/Postfix.pm,v 1.11 2005-12-04 21:33:45 rajo Exp $ package Platon::Log::Mail::Postfix; use strict; use vars qw($VERSION $DEBUG); use base qw( Platon::Log::Mail ); use Carp; use Platon::Log::Mail; use Platon::DBI; use Date::Parse; use Date::Format; #use Data::Dumper; $VERSION = sprintf("%d.%02d", q$Revision: 1.12 $ =~ /(\d+)\.(\d+)/); $DEBUG = 0 unless defined $DEBUG; # # this saves postfix error message into MySQL # Note: data may be cached before inserting into MySQL sub savelog($$;) { # {{{ my ($self, $line) = @_; my $xx = { }; my $length = 25; if ($line !~ m/^20/o) { $length = 16; } my $time_str = substr($line, 0, $length); my $time = str2time($time_str); $xx->{created} = time2str('%Y-%m-%dT%X%z', $time); #print 'input = "' , substr($line, 0, $length) , '" output = "' , $xx->{created}, "\"\n"; $line = substr($line, $length); return 0 unless defined($xx->{created}); # first separate hostname ($xx->{host}, $line) = ($line =~ m/^\s+(\S+)\s+(.*)$/o); if ($line =~ m/^\[/) { # log level ($xx->{log_level}, $line) = ($line =~ m/^\[(\S+)\] (.*)$/o); } ($xx->{process_name}, $line) = ($line =~ m/^([^[\s]+)(.*)$/o); # process pid is optional if ($line =~ s/^\[(\d+)\]: (.*)$/$2/o) { $xx->{pid} = $1; } else { $xx->{pid} = 0; } # # Support for amavis # {{{ # # Try to parse default log format (Debian GNU/Linux), see /etc/amavis/amavisd.conf # and README.customize.gz # %V a list of virus names found; contains at least one entry (possibly empty) # if a virus was found, otherwise a null list # %F a list of banned file names # %D a list of recipients with successful delivery status (will get mail) # %s original envelope sender, rfc2821-quoted and enclosed in angle brackets # %o best attempt at determining true sender of the virus - normally same as %s # %R a list of original envelope recipients # %i quarantine id, e.g. name of the quarantine file, or empty ($VIRUSFILE) # (for use in notification body, not headers) # %m 'Message-ID' header field body # %c spam level/hits (mnemonic: sCore) as provided by SpamAssassin # # $log_templ = '[? %#V |[? %#F |[?%#D|Not-Delivered|Passed]|BANNED name/type (%F)]|INFECTED (%V)], # [?%o|(?)|<%o>] -> [<%R>|,][? %i ||, quarantine %i], Message-ID: %m, Hits: %c'; # if ($xx->{process_name} eq 'amavis') { if ($line !~ m/^\(/o) { # startup messages, etc. ... $xx->{rest} = $line; return $self->_savelog($xx); } # $xx->{status} = "Not-Delivered" or "Passed" or "BANNED" or "INFECTED" ($xx->{amavis_id}, $xx->{status}, $line) = ($line =~ m/^\(([\d-]+)\) ([^,\s]+)[\s,]*(.*)$/o); ($xx->{amavis_counter}) = ($xx->{amavis_id} =~ m/(\d+)$/o); if ($xx->{status} eq 'INFECTED') { ($xx->{amavis_virus_name}, $line) = ($line =~ m/^\(([^\)]+)\), (.*)$/o); } elsif ($xx->{status} eq 'BANNED') { ($xx->{amavis_banned_file}, $line) = ($line =~ m/^name\/type \(([^\)]+)\), (.*)$/o); } elsif (($xx->{status} ne 'Passed') and ($xx->{status} ne 'Not-Delivered')) { # some error messages $xx->{rest} = "$xx->{status} $line"; $xx->{status} = undef; return $self->_savelog($xx); } ($xx->{from}, $xx->{recipients}, $line) = ($line =~ m/^(\S+) -> (\S+), (.*)$/o); if ($line =~ m/^quarantine (\S+), /o) { $xx->{amavis_quarantine} = $1; } ($xx->{"message-id"}, $xx->{amavis_SA_score}) = ($line =~ m/Message-ID: (\S+), Hits: (\S+)$/o); $xx->{amavis_SA_score} = undef if ($xx->{amavis_SA_score} eq '-'); $xx->{from} =~ s/[\<>]//go; $xx->{"message-id"} =~ s/[\<>]//go; my $retval; my @rcpts = split /[<,>]+/, $xx->{recipients}; foreach my $to (@rcpts) { next if ($to eq ''); $xx->{to} = $to; $retval += $self->_savelog($xx); } return $retval; } # }}} # # Support for postfix # {{{ $xx->{process_name} =~ s/^postfix\///og; if (( $xx->{postfix_key}, $xx->{rest}) = ($line =~ m/\s*(\S+) (.*)$/o)) { $xx->{postfix_key} =~ s/:$//g; # postfix_key: connect disconnect warning fatal lost timeout refreshing terminating lost reload # process_name: postfix-script smtpd smtp cleanup qmgr pickup local master if ($xx->{process_name} eq 'smtpd') { # {{{ # TODO: # postfix/smtpd[13456]: TLS engine: cannot load RSA cert/key data # postfix/smtpd[10972]: unable to get private key from \'/etc/postfix/client.pem\' # postfix/smtpd[10972]: 10972:error:0B080074:x509 certificate routines:X509_check_private_key:key values mismatch:x509_cmp.c:389: # postfix/smtpd[10972]: TLS engine: cannot load RSA cert/key data # postfix/smtpd[13456]: unable to get certificate from \'/etc/postfix/ca.pem\' # postfix/smtpd[13456]: 13456:error:02001002:system library:fopen:No such file or directory:bss_file.c:276:fopen(\'/etc/postfix/ca.pem\',\'r\'): # postfix/smtpd[13456]: 13456:error:20074002:BIO routines:FILE_CTRL:system lib:bss_file.c:278: # postfix/smtpd[13456]: 13456:error:140DC002:SSL routines:SSL_CTX_use_certificate_chain_file:system lib:ssl_rsa.c:760: # postfix/smtpd[2122]: SSL_accept error from gw.xxx.sk[17.5.3.4]: 0 if ($xx->{postfix_key} eq 'NOQUEUE') { # postfix/smtpd[5502]: NOQUEUE: reject: RCPT from mailgw.xxx.sk[58.95.16.250]: 550 : Recipient address rejected: User unknown in local recipient table; from= to= proto=ESMTP helo= # postfix/smtpd[5583]: NOQUEUE: reject: RCPT from daleth.ip.xxx.sk[58.95.17.170]: 554 : Relay access denied; from= to= proto=ESMTP helo=<[58.95.17.170]> # postfix/smtpd[5291]: NOQUEUE: reject: RCPT from rev-95-1-57-83.xxx.sk[95.1.57.83]: 553 : Sender address rejected: not owned by user rajo@gimmel.xxx.sk; from= to= proto=ESMTP helo=<[10.254.0.111]> # postfix/smtpd[7446]: NOQUEUE: reject: RCPT from unknown[80.65.71.48]: 554 Service unavailable; Client host [80.65.71.48] blocked using dnsbl.sorbs.net; Exploitable Server See: http://www.dnsbl.sorbs.net/lookup.shtml?80.65.71.48; from= to= proto=ESMTP helo= my ($addr, $status, $info) = ($xx->{rest} =~ m/[^:]+: ([^:]+): (.*)[;:] ([^;:]+)$/o); ($xx->{sasl_username}) = ($status =~ m/user (\S+)$/o); ($xx->{client_hostname}, $xx->{client_ip}) = ($addr =~ m/(\S+)\[([\.0-9]+)\]$/o); ($xx->{status}) = ($status =~ m/^(\d+)/o); $xx->{rest} = $status; # $info = 'from=<> to= proto=ESMTP helo=' _parse_by_equal($info, $xx); $xx->{from} =~ s/[\<>]//go; $xx->{to} =~ s/[\<>]//go; $xx->{helo} =~ s/[\<>]//go; } elsif ($xx->{postfix_key} =~ m/^[A-F0-9]{10}$/o) { # valid postfix key # postfix/smtpd[5277]: AAF642B2BB: client=rev-95-1-57-83.xxx.sk[95.1.57.83], sasl_method=PLAIN, sasl_username=rajo@gimmel.xxx.sk _parse_by_equal($xx->{rest}, $xx); ($xx->{client_hostname}, $xx->{client_ip}) = ($xx->{client} =~ m/(\S+)\[([\.0-9]+)\]$/o); $xx->{rest} = undef; } elsif ($xx->{postfix_key} eq 'connect' or $xx->{postfix_key} eq 'disconnect' or $xx->{postfix_key} eq 'lost') { ($xx->{client_hostname}, $xx->{client_ip}) = ($xx->{rest} =~ m/(\S+)\[([\.0-9]+)\]$/o); } elsif ($xx->{rest} =~ m/^smtpd_peer_init:/o) { ($xx->{client_ip}, $xx->{client_hostname}) = ($xx->{rest} =~ m/smtpd_peer_init: (\S+): hostname (\S+)/o); } else { # postfix/smtpd[5277]: AAF642B2BB: client=rev-95-1-57-83.xxx.sk[95.1.57.83], sasl_method=PLAIN, sasl_username=rajo@gimmel.xxx.sk # postfix/smtpd[6185]: warning: hostname.sk[111.11.12.34]: SASL CRAM-MD5 authentication failed ($xx->{client_hostname}, $xx->{client_ip}, $xx->{rest}) = ($xx->{rest} =~ m/(\S+)\[([\.0-9]+)\]:\s*([^:]*)$/o); if (!defined($xx->{client_hostname})) { ($xx->{client_hostname}, $xx->{client_ip}) = ($xx->{rest} =~ m/from (\S+)\[([\.0-9]+)\]/o); } if (!defined($xx->{client_hostname})) { ($xx->{client_hostname}, $xx->{client_ip}) = ($xx->{rest} =~ m/client=(\S+)\[([\.0-9]+)\]$/o); } } return $self->_savelog($xx); } # }}} elsif ($xx->{process_name} eq 'local') { # {{{ # postfix/local[18616]: 1BB0F140064D: to=, relay=local, delay=19, status=sent (delivered to command: procmail -a \"$EXTENSION\") # postfix/local[17562]: 5FAD4140064D: to=, orig_to=, relay=local, delay=25, status=sent (delivered to command: procmail -a "$EXTENSION") my ($info); ($info, $xx->{rest}) = ($xx->{rest} =~ m/^([^(]+)\s*(\(.*\))$/o); _parse_by_equal($info, $xx); $xx->{to} =~ s/[\<>]//go; $xx->{orig_to} =~ s/[\<>]//go; return $self->_savelog($xx); } # }}} elsif ($xx->{process_name} eq 'smtp') { # {{{ # postfix/smtp[16172]: connect to bug.com[21.16.4.27]: Connection timed out (port 25) # postfix/smtp[16172]: 6D49F140B966: to=, relay=none, delay=107781, status=deferred (connect to bug.com[21.16.4.27]: Connection timed out) if ($xx->{postfix_key} eq 'connect') { # TODO: incoming and and outgoing connections goes mixed here! seee 'to ' keyword on next line ($xx->{client_hostname}, $xx->{client_ip}, $xx->{rest}) = ($xx->{rest} =~ m/to (\S+)\[([\.0-9]+)\]:\s*([^:]*)$/o); } # TLS error messages in smtp elsif ($xx->{postfix_key} eq 'Host' or $xx->{postfix_key} eq 'verify' or $xx->{postfix_key} eq 'Unverified' or $xx->{postfix_key} eq 'TLS' or $xx->{postfix_key} eq 'Peer' ) { $xx->{rest} = $xx->{postfix_key} . ' ' . $xx->{rest}; undef $xx->{postfix_key}; } else { # postfix/smtp[5155]: 141D32B2BF: to=, relay=idea.xxx.sk[95.68.3.8], delay=5, status=sent (250 Ok: queued as 749C9140008E) # postfix/smtp[6422]: AA8E72B2BF: host idea.xxx.sk[95.68.3.8] said: 451 : Temporary lookup failure (in reply to RCPT TO command) if ($xx->{rest} =~ /^host /) { my ($addr, $status, $rest) = split(/[;:] /, $xx->{rest}); ($xx->{client_hostname}, $xx->{client_ip}) = ($addr =~ m/(\S+)\[([\.0-9]+)\]/o); ($xx->{status}) = ($status =~ m/^(\d+)/o); ($xx->{mail_to}) = ($status =~ m/<([^<>]+)>/o); $xx->{rest} = $rest; } elsif ($xx->{rest} =~ m/^([^(]+)\s*(\(.*\))$/o) { my ($info); ($info, $xx->{rest}) = ($1, $2); _parse_by_equal($info, $xx); $xx->{from} =~ s/[\<>]//go; $xx->{to} =~ s/[\<>]//go; } } # try to parse status info from amavis: # ... relay=127.0.0.1[127.0.0.1], delay=4, status=sent (250 2.6.0 Ok, id=32286-03, from MTA: 250 Ok: queued as 9A1491400624) if ($xx->{rest} =~ m/(\S+), id=(\S+) .* VIRUS: (.*)\)$/o) { $xx->{status} = $1; $xx->{amavis_id} = $2; $xx->{amavis_virus_name} = $3; } if ($xx->{rest} =~ m/id=(\S+),.*queued as (\S+)\)$/o) { $xx->{amavis_id} = $1; $xx->{new_postfix_key} = $2; } return $self->_savelog($xx); } # }}} elsif ($xx->{process_name} eq 'qmgr') { # {{{ # postfix/qmgr[17831]: 8FF9B140064D: from=, size=2906, nrcpt=1 (queue active) # postfix/qmgr[17831]: 8BCF9140064D: removed my ($info); if ($xx->{rest} =~ m/^([^(]+)\s*(\(.*\))$/o) { ($info, $xx->{rest}) = ($1, $2); } _parse_by_equal($info, $xx); $xx->{from} =~ s/[\<>]//go; return $self->_savelog($xx); } # }}} elsif ($xx->{process_name} eq 'cleanup') { # {{{ # postfix/cleanup[17494]: E21B8140064D: message-id= # postfix/cleanup[7123]: 8ED061400304: resent-message-id= _parse_by_equal($xx->{rest}, $xx); $xx->{"message-id"} =~ s/[\<>]//go; $xx->{"resent-message-id"} =~ s/[\<>]//go; undef $xx->{rest}; return $self->_savelog($xx); } # }}} elsif ($xx->{process_name} eq 'pickup') { # {{{ _parse_by_equal($xx->{rest}, $xx); $xx->{from} =~ s/[\<>]//go; $xx->{client_hostname} = 'localhost'; $xx->{client_ip} = '127.0.0.1'; undef $xx->{rest}; return $self->_savelog($xx); } # }}} elsif ($xx->{postfix_key} !~ /^[0-9A-F]+$/o) { # warning, error, or fatal? # search for IP address/hostname ($xx->{client_hostname}, $xx->{client_ip}) = ($xx->{rest} =~ m/from (\S+)\[([\.0-9]+)\]/o); return $self->_savelog($xx); } # }}} } return 0; } # }}} # make cache empty sub flush() { # {{{ my ($self) = @_; $self->{dbh}->check(); if ($self->{_counter} >= $self->{_cache}) { $self->{_counter} -= $self->{_cache}; my @param = splice @{$self->{_param} }, 0, ($self->{_nr_columns} * $self->{_cache}); $self->{sql_insert_multi}->execute( @param ) or warn $self->{sql_insert_multi}->errstr; } foreach (1..$self->{_counter}) { $self->{_counter}--; my @param = splice @{$self->{_param} }, 0, $self->{_nr_columns}; $self->{sql_insert}->execute( @param ) or warn $self->{sql_insert}->errstr; } } # }}} sub _savelog($$;) { # {{{ my ($self, $data) = @_; # store parameters into cache foreach my $key (@{$self->{_columns}}) { push @{ $self->{_param} }, $data->{$key}; } $self->{_counter}++; # if cache is full, insert data into MySQL database if ($self->{_counter} >= $self->{_cache}) { #carp "Cache full, flushing ..."; $self->flush(); } return 1; } # }}} # this method must be defined in your own Platon::Log::ServiceType::YourService module sub _init($$;) { # {{{ my ($self, $conf) = @_; # DEBUG code: remove all rows from db for testing purposes #$self->prepare_keyword('sql_delete', "DELETE FROM " . $conf->table); #$self->{sql_delete}->execute(); $self->{_cache} = $conf->cache; $self->{_counter} = 0; $self->{_param} = ( ); $self->{_sql_columns} = [ qw' created hostname log_level process_name pid postfix_key new_postfix_key client_hostname client_ip client_uid message_id resent_message_id mail_from mail_to mail_size mail_nrcpt relay delay status proto helo sasl_method sasl_username amavis_id amavis_counter amavis_virus_name amavis_banned_file amavis_quarantine amavis_SA_score message ' ]; $self->{_columns} = [ qw' created host log_level process_name pid postfix_key new_postfix_key client_hostname client_ip uid message-id resent-message-id from to size nrcpt relay delay status proto helo sasl_method sasl_username amavis_id amavis_counter amavis_virus_name amavis_banned_file amavis_quarantine amavis_SA_score rest ' ]; $self->{_nr_columns} = scalar(@{$self->{_columns}}); my $sql = ' (' . join(', ', @{$self->{_sql_columns}}) . ') VALUES '; my $val_sql_columns = '(' . join(', ', map { '?' } @{$self->{_sql_columns}}) . ')'; $self->prepare_keyword('sql_insert', 'INSERT INTO ' . $conf->table . "$sql $val_sql_columns"); $self->prepare_keyword('sql_insert_multi', 'INSERT IGNORE INTO ' . $conf->table . "$sql " . join(', ', map { $val_sql_columns } 1..$self->{_cache})); } # }}} sub _parse_by_equal($$;) { # {{{ my ($str, $hash) = @_; (my @params) = split(/([\s|,|;]+)/o, $str); foreach my $param (@params) { if ($param =~ m/(.*)\=(.*)/) { #my ($par, $val) = ($1, $2); $hash->{$1} = $2; } } } # }}} 1; __END__ =head1 NAME Postfix - <<>> =head1 SYNOPSIS use Postfix; my $xxx = new Postfix; =head1 DESCRIPTION The Postfix module allows you ... <<>> =head2 EXPORT <>> =head1 SEE ALSO =head1 AUTHORS Lubomir Host 'rajo', =cut # vim: ts=4 # vim600: fdm=marker fdl=0 fdc=3