[milters] Archive

Lists Index Date Thread Search

Article: 911
From: Taylor, Grant
Date: 2006-05-03 17:45:03 -0400
Subject: Re: Milter-Report v0.8 Strange Behavior...

Removal...........: milters-request@milter.info?subject=remove
More information..: http://www.milter.info/#Support
--------------------------------------------------------

> Note that what milter-report catches varies depending on it execution 
> order. milter-report should probably be the last milter in the chain in 
> order to catch rejections from xxfi_eom (end-of-message) handler. But if 
> its last in the chain then it will not catch (accurately) certain 
> rejections that occur from the xxfi_connect or xxfi_envfrom handlers, in 
> which case you want to have milter-report first in the milter chain.

Sounds confusing.  Or like it might be advantageous to have milter-report interface in a
couple of different ways, both at the beginning and at the end of the milter chain.

> I would suggest trying in your situation placing milter-report last in 
> the milter chain. I would expect it to record rejections based on 
> content filtering then. However, certain pre-DATA filters and rulesets 
> may not be recorded properly.

I *think* I do have milter-report at the end of the chain.  At least from what I know how
to interpret.  Below is a copy of the pertinent section of my MC file with milter-report
at the end.

dnl Milter-Sender is doing something that needs the following M4 directive.
dnl I don't know what it is but it will not work with out it.
define(`confMILTER_MACROS_CONNECT', confMILTER_MACROS_CONNECT`, {client_addr},
{client_name}, {client_port}, {client_resolve}')
INPUT_MAIL_FILTER(`milter-7bit', `S=unix:/var/lib/milter-7bit/socket,
T=C:1m;S:30s;R:2m;E:1m')
INPUT_MAIL_FILTER(`milter-date', `S=unix:/var/lib/milter-date/socket,
T=C:1m;S:30s;R:90s;E:1m')
INPUT_MAIL_FILTER(`milter-spiff', `S=unix:/var/lib/milter-spiff/socket,
T=C:10s;S:10s;R:4m;E:10s')
INPUT_MAIL_FILTER(`milter-sender', `S=unix:/var/lib/milter-sender/socket,
T=C:30s;S:10s;R:10s;E:1m')
INPUT_MAIL_FILTER(`milter-spamc', `S=unix:/var/lib/milter-spamc/socket,
T=C:1m;S:30s;R:6m;E:1m')
INPUT_MAIL_FILTER(`milter-clamc', `S=unix:/var/lib/milter-clamc/socket, T=C:10s;E:5m')
INPUT_MAIL_FILTER(`milter-report', `S=unix:/var/lib/milter-report/socket,
T=C:10s;S:10s;R:60s;E:10s')
define(`confINPUT_MAIL_FILTERS',
`milter-7bit,milter-date,milter-spiff,milter-sender,milter-spamc,milter-clamc,milter-report')

Below is a copy of the pertinent headers from the message that I'm replying to.  Based on
the time stamps and position (newest first(?)) I believe that milter-report is the last
milter to run by correlating confIMPUT_MAIL_FILTERS (above) order.

X-Scanned-By: milter-clamc/0.1.5 (rti02.co-lo.riverviewtech.net [208.47.119.116]); Wed, 03
May 2006 16:15:59 -0500
X-Scanned-By: milter-spamc/0.25.321 (rti02.co-lo.riverviewtech.net [208.47.119.116]); Wed,
03 May 2006 16:15:59 -0500
X-Scanned-By: milter-sender/0.62.837 (rti02.co-lo.riverviewtech.net [208.47.119.116]);
Wed, 03 May 2006 16:15:57 -0500
X-Scanned-By: milter-spiff/0.8.17 (rti02.co-lo.riverviewtech.net [208.47.119.116]); Wed,
03 May 2006 16:15:57 -0500
X-Scanned-By: milter-date/0.17.193 (rti02.co-lo.riverviewtech.net [208.47.119.116]); Wed,
03 May 2006 16:15:57 -0500
X-Scanned-By: milter-7bit/0.11.138 (rti02.co-lo.riverviewtech.net [208.47.119.116]); Wed,
03 May 2006 16:15:57 -0500

Below is a copy of the mail log entries for the message that I'm replying to. 
Interestingly enough I do not see milter-report listed in the log for this email.

May  3 16:15:56 rti02 milter-sender[24982]: 03120 k43LFuxG024978: sender
<milters-bounce@milter.info> (0) cached, skipping
May  3 16:15:56 rti02 milter-spamc[24983]: 22709 k43LFuxG024978:
RCPT='<gtaylor@riverviewtech.net>' rcpt_addr='gtaylor' rcpt_host=''
rcpt_mailer='local'
May  3 16:15:57 rti02 sm-mta[24978]: k43LFuxG024978:
from=<milters-bounce@milter.info>, size=3424, class=-60, nrcpts=1,
msgid=<44591C7B.5070301@snert.com>, proto=ESMTP, daemon=MTA, relay=pop.snert.net
[193.41.72.72]
May  3 16:15:57 rti02 milter-7bit[24979]: 22505 k43LFuxG024978: pass=YES bytes=3496
May  3 16:15:57 rti02 sm-mta[24978]: k43LFuxG024978: Milter add: header: X-Scanned-By:
milter-7bit/0.11.138 (rti02.co-lo.riverviewtech.net [208.47.119.116]); Wed, 03 May 2006
16:15:57 -0500
May  3 16:15:57 rti02 sm-mta[24978]: k43LFuxG024978: Milter add: header:
X-milter-7bit-Pass: YES
May  3 16:15:57 rti02 sm-mta[24978]: k43LFuxG024978: Milter add: header: X-Scanned-By:
milter-date/0.17.193 (rti02.co-lo.riverviewtech.net [208.47.119.116]); Wed, 03 May 2006
16:15:57 -0500
May  3 16:15:57 rti02 sm-mta[24978]: k43LFuxG024978: Milter add: header:
X-milter-date-PASS: YES
May  3 16:15:57 rti02 milter-date[24980]: 22500 k43LFuxG024978: pass=YES
May  3 16:15:57 rti02 sm-mta[24978]: k43LFuxG024978: Milter add: header: X-Scanned-By:
milter-spiff/0.8.17 (rti02.co-lo.riverviewtech.net [208.47.119.116]); Wed, 03 May 2006
16:15:57 -0500
May  3 16:15:57 rti02 sm-mta[24978]: k43LFuxG024978: Milter add: header: Received-SPF:
Pass; receiver=rti02.co-lo.riverviewtech.net; client-ip=193.41.72.72;
envelope-from=<milters-bounce@milter.info>
May  3 16:15:57 rti02 sm-mta[24978]: k43LFuxG024978: Milter add: header: X-Scanned-By:
milter-sender/0.62.837 (rti02.co-lo.riverviewtech.net [208.47.119.116]); Wed, 03 May 2006
16:15:57 -0500
May  3 16:15:59 rti02 milter-spamc[24983]: 22709 k43LFuxG024978: spam=NO score=0.80
required=1.50 client_addr=193.41.72.72 client_name=pop.snert.net subject='[milters] Re:
Milter-Report v0.8 Strange Behavior...' mail=<milters-bounce@milter.info>
rcpts=<gtaylor@riverviewtech.net>
May  3 16:15:59 rti02 sm-mta[24978]: k43LFuxG024978: Milter add: header: X-Scanned-By:
milter-spamc/0.25.321 (rti02.co-lo.riverviewtech.net [208.47.119.116]); Wed, 03 May 2006
16:15:59 -0500
May  3 16:15:59 rti02 milter-clamc[24984]: 22462 k43LFuxG024978: message is clean
May  3 16:15:59 rti02 sm-mta[24978]: k43LFuxG024978: Milter add: header: X-Scanned-By:
milter-clamc/0.1.5 (rti02.co-lo.riverviewtech.net [208.47.119.116]); Wed, 03 May 2006
16:15:59 -0500
May  3 16:15:59 rti02 sm-mta[24978]: k43LFuxG024978: Milter add: header:
X-milter-clamc-Pass: YES


Yet I have milter-report log entries around the time frame that the message that I'm
replying to came in.  Below are the pertinent logs.

May  3 16:10:41 rti02 milter-report[24711]: 13120 k43LAWoe024704: recipient
<xxxxxxx@aaaaaaaaaaaaaaaaa.tld> OK
May  3 16:12:04 rti02 milter-report[24777]: 13123 k43LC3a5024770: recipient
<xxxx@aaaaaaaaaaaaaaaaa.tld> OK
May  3 16:15:34 rti02 milter-report[24963]: 13132 k43LFX3A024954: recipient
<xxxxx@bbbbbbbbbbbbbbbbbb.tld> OK
       16:15:56 <== This where the milter-report log WOULD go but is not.
May  3 16:16:34 rti02 milter-report[25031]: 13136 k43LGXTW025018: recipient
<xxxxx@bbbbbbbbbbbbbbbbbb.tld> OK
May  3 16:16:34 rti02 milter-report[25031]: 13136 k43LGXTW025018: recipient
<xxx@bbbbbbbbbbbbbbbbbb.tld> OK
May  3 16:17:07 rti02 milter-report[25058]: 13138 k43LH5WU025051: recipient
<xxxx@aaaaaaaaaaaaaaaaa.tld> OK

??????????

I'm at a loss.  Most of the time I think milter-report is working but then I'm not sure if
it is or not.



Grant. . . .

Lists Index Date Thread Search