darold / sendmailanalyzer

Sendmail log Analyzer is a tool to monitor sendmail usage and generate HTML and graph reports. It reports all you ever wanted to know about email trafic on your network. You can also use it in ISP environment with per domain and per mailbox report.
http://sendmailanalyzer.darold.net/
GNU General Public License v3.0
76 stars 13 forks source link

No DSN data parsed #24

Closed DocLowy closed 9 years ago

DocLowy commented 10 years ago

No DSN records are parsed on my system.

Debug info from sendmailanalyzer

root:~# /usr/local/sendmailanalyzer/sendmailanalyzer -f -b -d
Running in verbose mode...
    sendmailanalyzer v9.0. (c) 2002-2014 - Gilles Darold <gilles@darold.net>
DEBUG: Detach from terminal with pid: 17041
DEBUG: Entering main loop...
DEBUG: Parsing full /var/log/mail.log
DEBUG: Flushing data to disk...
DEBUG: Writing sender data to disk...
DEBUG:  Wrote 276 sender objects
DEBUG: Writing reject data to disk...
DEBUG:  Wrote 392 reject object.
DEBUG: Writing DSN data to disk...
*DEBUG:     Wrote 0 DSN object.*
DEBUG: Writing recipient data to disk...
DEBUG:  Wrote 263 recipient object.
DEBUG: Writing Spam data to disk...
DEBUG:  Wrote 8 spam object.
DEBUG: Writing Spam detail data to disk...
DEBUG: Writing Spam detail for amavis into [...]/2014/10/05/amavis.dat
DEBUG: Writing Spam detail for dnsbl into [...]/2014/10/05/dnsbl.dat
DEBUG:  Wrote 8 spam detail object.
DEBUG: Writing Postgrey detail data to disk...
DEBUG:  Wrote 8 postgrey object.
DEBUG: Writing Virus data to disk...
DEBUG:  Wrote 0 virus object.
DEBUG: Writing syserr data to disk...
DEBUG:  Wrote 911 syserr object.
DEBUG: Writing warning message data to disk...
DEBUG:  Wrote 6 warning message object.
DEBUG: Writing warning auth data to disk...
DEBUG:  Wrote 7 auth object.
DEBUG: Writing last parsed line...

A "grep" on mail.log shows 532 deliveries

root:~# grep 'status=sent' /var/log/mail.log |wc -l
532

Inbound traffic example

Oct  5 19:30:48 xxxxxx postfix/smtpd[16932]: connect from st11p05mm-asmtp002.mac.com[17.172.108.250]
Oct  5 19:30:49 xxxxxx postfwd2/policy[11195]: [DNSBL] 17.172.108.250 listed on rbl:list.dnswl.org (answer: 127.0.5.2, time: 0.01s, ttl: 43200s, 'mac.com http://dnswl.org/s?s=1776')
Oct  5 19:30:49 xxxxxx postfwd2/policy[11195]: [RULES] rule=0, id=OK_DNSWL, client=st11p05mm-asmtp002.mac.com[17.172.108.250], sender=<aaa@bbb.com>, recipient=<xxx@yyy.de>, helo=<st11p05mm-asmtp002.mac.com>, proto=ESMTP, state=RCPT, delay=0.02s, hits=OK_DNSWL, action=OK
Oct  5 19:30:49 xxxxxx postfix/smtpd[16932]: 0CB3413C018D: client=st11p05mm-asmtp002.mac.com[17.172.108.250]
Oct  5 19:30:49 xxxxxx postfix/cleanup[21999]: 0CB3413C018D: message-id=<D4A7FFF1-29DA-4EAF-B029-BCD8E5389747@me.com>
Oct  5 19:30:49 xxxxxx postfix/qmgr[10619]: 0CB3413C018D: from=<aaa@bbb.com>, size=1337, nrcpt=1 (queue active)
Oct  5 19:30:49 xxxxxx postfix/smtpd[16932]: disconnect from st11p05mm-asmtp002.mac.com[17.172.108.250]
Oct  5 19:30:49 xxxxxx postfix/smtpd[22003]: connect from localhost.localdomain[127.0.0.1]
Oct  5 19:30:49 xxxxxx postfix/smtpd[22003]: 79A3A13C0578: client=localhost.localdomain[127.0.0.1]
Oct  5 19:30:49 xxxxxx postfix/cleanup[21999]: 79A3A13C0578: message-id=<D4A7FFF1-29DA-4EAF-B029-BCD8E5389747@me.com>
Oct  5 19:30:49 xxxxxx postfix/smtpd[22003]: disconnect from localhost.localdomain[127.0.0.1]
Oct  5 19:30:49 xxxxxx postfix/qmgr[10619]: 79A3A13C0578: from=<aaa@bbb.com>, size=1791, nrcpt=1 (queue active)
Oct  5 19:30:49 xxxxxx amavis[19981]: (19981-07) Passed CLEAN {RelayedInbound}, [17.172.108.250]:37214 [88.134.138.69] <aaa@bbb.com> -> <xxx@yyy.de>, Queue-ID: 0CB3413C018D, Message-ID: <D4A7FFF1-29DA-4EAF-B029-BCD8E5389747@me.com>, mail_id: CZzPtLQlvLe1, Hits: -1.9, size: 1337, queued_as: 79A3A13C0578, 352 ms
Oct  5 19:30:49 xxxxxx postfix/smtp[22000]: 0CB3413C018D: to=<xxx@yyy.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.58, delays=0.21/0.01/0/0.35, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 79A3A13C0578)
Oct  5 19:30:49 xxxxxx postfix/qmgr[10619]: 0CB3413C018D: removed
Oct  5 19:30:49 xxxxxx dovecot: lda(xxx@yyy.de): sieve: msgid=<D4A7FFF1-29DA-4EAF-B029-BCD8E5389747@me.com>: stored mail into mailbox 'INBOX'
Oct  5 19:30:49 xxxxxx postfix/pipe[22004]: 79A3A13C0578: to=<xxx@yyy.de>, relay=dovecot, delay=0.25, delays=0.09/0.01/0/0.15, dsn=2.0.0, status=sent (delivered via dovecot service)
Oct  5 19:30:49 xxxxxx postfix/qmgr[10619]: 79A3A13C0578: removed

Outbound traffic example

Oct  5 19:44:09 xxxxxx postfix/smtpd[23496]: connect from unknown[11.22.33.44]
Oct  5 19:44:09 xxxxxx postfix/smtpd[23496]: 9476813C015D: client=unknown[11.22.33.44], sasl_method=PLAIN, sasl_username=xxx@yyy.de
Oct  5 19:44:09 xxxxxx postfix/cleanup[23498]: 9476813C015D: message-id=<54318369.6070507@yyy.de>
Oct  5 19:44:09 xxxxxx postfix/qmgr[10619]: 9476813C015D: from=<xxx@yyy.de>, size=4658, nrcpt=1 (queue active)
Oct  5 19:44:09 xxxxxx postfix/smtpd[23496]: disconnect from unknown[11.22.33.44]
Oct  5 19:44:10 xxxxxx postfix/smtpd[23502]: connect from localhost.localdomain[127.0.0.1]
Oct  5 19:44:10 xxxxxx postfix/smtpd[23502]: 147D813C018D: client=localhost.localdomain[127.0.0.1]
Oct  5 19:44:10 xxxxxx postfix/cleanup[23498]: 147D813C018D: message-id=<54318369.6070507@yyy.de>
Oct  5 19:44:10 xxxxxx postfix/qmgr[10619]: 147D813C018D: from=<xxx@yyy.de>, size=5120, nrcpt=1 (queue active)
Oct  5 19:44:10 xxxxxx postfix/smtpd[23502]: disconnect from localhost.localdomain[127.0.0.1]
Oct  5 19:44:10 xxxxxx amavis[19981]: (19981-14) Passed CLEAN {RelayedOpenRelay}, [11.22.33.44]:62460 [11.22.33.44] <xxx@yyy.de> -> <aaa@bbb@com>, Queue-ID: 9476813C015D, Message-ID: <54318369.6070507@yyy.de>, mail_id: tza8DTSKUjpO, Hits: -2.9, size: 4657, queued_as: 147D813C018D, 404 ms
Oct  5 19:44:10 xxxxxx postfix/smtp[23499]: 9476813C015D: to=<aaa@bbb@com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.57, delays=0.15/0.01/0/0.4, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 147D813C018D)
Oct  5 19:44:10 xxxxxx postfix/qmgr[10619]: 9476813C015D: removed
Oct  5 19:44:15 xxxxxx postfix/smtp[23503]: 147D813C018D: to=<aaa@bbb@com>, relay=mx5.mail.icloud.com[17.172.34.68]:25, delay=4.9, delays=0.05/0.01/2.8/2, dsn=2.5.0, status=sent (250 2.5.0 Ok, envelope id 0NCZ00FDUFXP3XK0@st11p00mm-smtpin016.mac.com)
Oct  5 19:44:15 xxxxxx postfix/qmgr[10619]: 147D813C018D: removed
Oct  5 19:44:18 xxxxxx dovecot: imap-login: Login: user=<xxx@yyy.de>, method=PLAIN, rip=11.22.33.44, lip=99.88.77.66, mpid=23505, TLS, session=<7Rb2g7AEAwBYhopF>
Oct  5 19:44:27 xxxxxx postfix/smtpd[18410]: connect from localhost.localdomain[127.0.0.1]
Oct  5 19:44:27 xxxxxx postfix/smtpd[18410]: disconnect from localhost.localdomain[127.0.0.1]

Any ideas?

KR, Wolfgang

darold commented 10 years ago

Hi Wolfgang,

DSN are only available for sendmail logs. They are clearly identified and retrieved with the following regex:

$str =~ m#^([^:\s]+): ([^:\s]+): (DSN|return to sender|sender notify|postmaster notify): (.*)#

Posfix does not have such log entry, so it is impossible to detect.

DocLowy commented 10 years ago

ok, make sense. :grin: would it make sense to hide this menu entry from from menu on postfix systems, means "do not make a menu entry if no dsn.dat exist"!?

BTW... I sent you a private mail 3 days ago, requesting a parsing for postfwd2 spam system. Maybe it got lost. Should I make a new issue for that on GitHub?

Kind regards, Wolfgang

darold commented 10 years ago

I will see to remove that menu with postfix log unless someone knwo how to identify them on pstfix logs.

Yes I received your log and they have been put in my fifo (feature in feature out) :-) I will work on it as soon as I found enough spare time to work on it. Thanks for your help to build a better project.

Regards

DocLowy commented 10 years ago

maybe this code is helpful to parse dsn on postfix log? https://github.com/etsy/logster/blob/master/logster/parsers/PostfixLogster.py

darold commented 9 years ago

Latest commit 9cd91ee should add this feature.

Thanks again for the report.