dlf generated by postfix convertor: what is an email message when virusscanner and aliases are involved? (was: Re: summarizing postfix logs problem(s))

[Joost van Baal]

Hi Razvan,

On Mon, Oct 14, 2002 at 05:51:51PM +0300, Razvan Cosma wrote:
> 
>  I am looking for a solution to create mail traffic statistics for each
> user of a single system (or domain, actually). So I sent a postfix log
> to the online responder to test and noticed some strange results. My
> setup is: one domain for testing, an antivirus (RAV, could be some
> other, don't know yet), and an user with multiple aliases. Here's how
> the delivery from e.g. the subscription mail goes (hope the word wrap
> won't mess it):
> 
> postfix/smtpd[13014]: connect from logreport.IAE.nl[212.61.24.7]
> postfix/smtpd[13014]: 658D918004: client=logreport.IAE.nl[212.61.24.7]
> postfix/cleanup[13015]: 658D918004: message-id=<20021014141519.F3FF2C027 at hibou.logreport.org>
> postfix/smtpd[13014]: disconnect from logreport.IAE.nl[212.61.24.7]
> postfix/qmgr[4218]: 658D918004: from=<questions-request at logreport.org>, size=4415, nrcpt=1 (queue active)
> ravpostfix[13032]: data received... begin scanning...
> ravmd[13033]: scanning mail from <questions-request at logreport.org> to <my.alias at my.domain>.
> ravmd[13033]: scanning file </var/spool/rav/postfix/->(RAV13032)>.
> ravmd[13033]: file_ok
> ravmd[13033]: scanning file </var/spool/rav/postfix/->(RAV13032)->(part0000:)>.
> ravmd[13033]: file_ok
> ravmd[13033]: end_ok.
> ravpostfix[13032]: scanning returns OK... sending file...
> postfix/smtpd[13020]: connect from localhost[127.0.0.1]
> postfix/smtpd[13020]: B1D5C389CE: client=localhost[127.0.0.1]
> postfix/cleanup[13015]: B1D5C389CE: message-id=<20021014141519.F3FF2C027 at hibou.logreport.org>
> postfix/qmgr[4218]: B1D5C389CE: from=<questions-request at logreport.org>, size=4602, nrcpt=1 (queue active)
> postfix/smtpd[13020]: disconnect from localhost[127.0.0.1]
> postfix/smtp[13031]: 658D918004: to=<my.alias at my.domain>, relay=127.0.0.1[127.0.0.1], delay=0, status=sent (250 Ok)
> postfix/local[13021]: B1D5C389CE: to=<my.username at my.domain>, relay=local, delay=0, status=sent ("|/usr/bin/maildrop")
> 
>  The mail could be counted twice (first when received from the network,
> then when returned by the antivirus), or even three times if
> postfix/smtp and postfix/local are treated the same.

I've manually added timestamps and a hostname, to make your log look
like a syslog logfile.  Then I've run:

 lrrcv at gelfand:~% . ~/logreport/etc/lire/profile_lean
 lrrcv at gelfand:~% . ~/logreport/etc/lire/defaults
 lrrcv at gelfand:~% LR_ID=`date +%s` LR_SERVICE=email \
   ~/logreport/libexec/lire/convertors/postfix2dlf < \
   ~/tmp/razvan-postfix.log > ~/tmp/razvan-postfix.dlf

(I've just updated the postfix2dlf manpage: added some hints on how to
run it from the commandline.) This creates:

 1035548714 gelfand 658D918004 <20021014141519.f3ff2c027 at hibou.logreport.org> \
  questions-request logreport.org logreport.iae.nl 212.61.24.7 4415 0 0 \
  my.alias my.domain 127.0.0.1 127.0.0.1 sent (250_ok)
 1035548714 gelfand B1D5C389CE <20021014141519.f3ff2c027 at hibou.logreport.org> \
  questions-request logreport.org localhost 127.0.0.1 4602 0 0 \
  my.username my.domain localhost 127.0.0.1 sent ("|/usr/bin/maildrop")

(Format is the email dlf format, as documented in email.xml:

 <lire:field name="time"        type="timestamp"    default="0">
 <lire:field name="logrelay"    type="hostname"     default="-">
 <lire:field name="queueid"     type="string"       default="-">
 <lire:field name="msgid"       type="string"       default="-">
 <lire:field name="from_user"   type="string"       default="-">
 <lire:field name="from_domain" type="hostname"     default="-">
 <lire:field name="from_relay_host" type="hostname" default="-">
 <lire:field name="from_relay_ip"   type="ip"       default="-">
 <lire:field name="size"        type="bytes"        default="0">
 <lire:field name="delay"       type="duration"     default="0">
 <lire:field name="xdelay"      type="duration"     default="0">
 <lire:field name="to_user"     type="string"       default="-">
 <lire:field name="to_domain"   type="hostname"     default="-">
 <lire:field name="to_relay_host"   type="hostname" default="-">
 <lire:field name="to_relay_ip"     type="ip"       default="-">
 <lire:field name="stat"        type="string"       default="-">
 <lire:field name="xstat"       type="string"       default="-">

)

> Now I am quite
> confused on how the accounting could be done, does logreport handle
> correctly such situations?

It depends on what one regards as `correct' ;-)

(This, in turn, depends on what one regards as `an email message'.)

Anyway, I feel the generated DLF file represents the events happened
quite correctly.  (It might very well be though, that reports generated
from this are misleading.  Razvan, could you test this?)

> Thank you for any pointers, and for taking the time reading the lengthy
> message.

Thanks for your clear question, it helped me: it made me improve the
manpage :)

Bye,

Joost

-- 
Joost van Baal              . .           http://www.logreport.org/
                           .   .
/^LogReport$/               . .               joostvb at logreport.org

-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 189 bytes
Desc: not available
Url : http://lists.logreport.org/pipermail/questions/attachments/20021025/746d9eac/attachment.bin