Milter-greylist

Noticed today some unusual log entries from milter-greylist 1.4 and
sendmail.

It appears that milter-greylist is writing entries to the log file out
of order.  It also appears that the milter is timing out per the entries
that sendmail is logging.  

Example below:

Jul 14 09:05:11 webserver sendmail[17140]: i6ED4vKP017140: Milter
(greylist): timeout before data read
Jul 14 09:05:17 webserver sendmail[17140]: i6ED4vKP017140: Milter
(greylist): to error state
Jul 14 09:05:02 webserver milter-greylist: i6ED4vKP017140: addr
218.165.213.230 from <roughshod0@...> to
<aguirre@...> delayed for 00:02:00
Jul 14 09:05:28 webserver sendmail[17140]: i6ED4vKP017140: lost input
channel from 218-165-213-230.dynamic.hinet.net [218.165.213.230] to MTA
after rcpt
Jul 14 09:05:45 webserver sendmail[17140]: i6ED4vKP017140:
from=<roughshod0@...>, size=0, class=0, nrcpts=1, proto=SMTP,
daemon=MTA, relay=218-165-213-230.dynamic.hinet.net [218.165.213.230]


The order above is as I found the records in the log file.  It looks
like for some reason milter-greylist was delayed in writing an entry to
the maillog file which resulted in sendmail writing the timeout info and
error state messages then when milter-greylist was freed up it wrote the
record that was pending.  

What is interesting is that the milter seems to grey list the message
but I have had a number of messages drop on through without the
milter-greylist headers.  Again this indicates to me that sendmail went
ahead and accepted the connection and subsequently milter-greylist
finished its activity after the fact.

At the time this seemed to occur the load average was at about 3 or so
and it appeared we were receiving a large number of messages during that
time.

The messages that seemed to get through the greylist without delay were
subsequently caught by spamassassin.

Is this something that has been seen before?  Is there additional debug
data that I can access?

Could the fact that I have a 2 minute delay cause this behavior?  Does
this change the update period for the database file which is causing
milter-greylist to exceed a timeout for sendmail?  Been running this way
for several days and we seem to get all the benefits of greylisting.   

Any help would be appreciated.

Other than this anomaly this milter has been working wonders blocking
spam.


-- 
Scot L. Harris
webid@...

There is more to life than increasing its speed.
		-- Mahatma Gandhi

Scot,

     We have the same problem.  Messages somewhat regularly get through 
the edge servers without the greylist headers.

     To be fair, the edge servers run a pretty high load since they do 
sophos and spamassassin filtering.  There are 6 of them load balanced 
(also, using the mx sync feature) and they run a load average between 
3.0 and 8.0 for most of the day.

     I had just attributed it to the machines being overloaded so I've 
been concentrating more on provisioning more machines than on trying to 
debug.

Cheers,

~Ethan B.



Scot L. Harris wrote:

> Noticed today some unusual log entries from milter-greylist 1.4 and
> sendmail.
> 
> It appears that milter-greylist is writing entries to the log file out
> of order.  It also appears that the milter is timing out per the entries
> that sendmail is logging.  
> 
> Example below:
> 
> Jul 14 09:05:11 webserver sendmail[17140]: i6ED4vKP017140: Milter
> (greylist): timeout before data read
> Jul 14 09:05:17 webserver sendmail[17140]: i6ED4vKP017140: Milter
> (greylist): to error state
> Jul 14 09:05:02 webserver milter-greylist: i6ED4vKP017140: addr
> 218.165.213.230 from <roughshod0@...> to
> <aguirre@...> delayed for 00:02:00
> Jul 14 09:05:28 webserver sendmail[17140]: i6ED4vKP017140: lost input
> channel from 218-165-213-230.dynamic.hinet.net [218.165.213.230] to MTA
> after rcpt
> Jul 14 09:05:45 webserver sendmail[17140]: i6ED4vKP017140:
> from=<roughshod0@...>, size=0, class=0, nrcpts=1, proto=SMTP,
> daemon=MTA, relay=218-165-213-230.dynamic.hinet.net [218.165.213.230]
> 
> 
> The order above is as I found the records in the log file.  It looks
> like for some reason milter-greylist was delayed in writing an entry to
> the maillog file which resulted in sendmail writing the timeout info and
> error state messages then when milter-greylist was freed up it wrote the
> record that was pending.  
> 
> What is interesting is that the milter seems to grey list the message
> but I have had a number of messages drop on through without the
> milter-greylist headers.  Again this indicates to me that sendmail went
> ahead and accepted the connection and subsequently milter-greylist
> finished its activity after the fact.
> 
> At the time this seemed to occur the load average was at about 3 or so
> and it appeared we were receiving a large number of messages during that
> time.
> 
> The messages that seemed to get through the greylist without delay were
> subsequently caught by spamassassin.
> 
> Is this something that has been seen before?  Is there additional debug
> data that I can access?
> 
> Could the fact that I have a 2 minute delay cause this behavior?  Does
> this change the update period for the database file which is causing
> milter-greylist to exceed a timeout for sendmail?  Been running this way
> for several days and we seem to get all the benefits of greylisting.   
> 
> Any help would be appreciated.
> 
> Other than this anomaly this milter has been working wonders blocking
> spam.
> 
>

Scot L. Harris <webid@...> wrote:

> Jul 14 09:05:11 webserver sendmail[17140]: i6ED4vKP017140: Milter
> (greylist): timeout before data read
(snip)
> At the time this seemed to occur the load average was at about 3 or so
> and it appeared we were receiving a large number of messages during that
> time.

You can specify a biger timeout for the milter in sendmail.cf

-- 
Emmanuel Dreyfus
Il y a 10 sortes de personnes dans le monde: ceux qui comprennent 
le binaire et ceux qui ne le comprennent pas.
manu@...

On Wed, 2004-07-14 at 14:51, manu@... wrote:

> You can specify a biger timeout for the milter in sendmail.cf

Thanks Ethan for letting me know this my system is not the only one
seeing this.  :)

I looked at the entries setup in sendmail.mc but do not see how to
specify a timeout for the milter.  Emmanuel, can you point me to
documentation or provide some additional hints?  

Thanks.

-- 
Scot L. Harris
webid@...

If we do not change our direction we are likely to end up where we are headed.

On Thu, Jul 15, 2004 at 08:39:51AM -0400, Scot L. Harris wrote:
> I looked at the entries setup in sendmail.mc but do not see how to
> specify a timeout for the milter.  Emmanuel, can you point me to
> documentation or provide some additional hints?  

In sendmail.mc I don't know. In sendmail.cf, you change the Xgreylist
line and add T=R:10s;E:10s for instance

-- 
Emmanuel Dreyfus
manu@...

Hi,

> In sendmail.mc I don't know. In sendmail.cf, you change the Xgreylist
> line and add T=R:10s;E:10s for instance

In sendmail.mc, make the line to add greylist support read something
like

INPUT_MAIL_FILTER(`greylist', 
`S=local:/var/milter-greylist/milter-greylist.sock, T=S:4m;R:4m')

Note that since I enabled spf support, I'm running with quite large
timeouts to allow for dns delays.

Ciao,
Wolfgang
-- 
ws@...				Wolfgang Solfrank, TooLs GmbH

Emmanuel Dreyfus <manu@...> writes:

> In sendmail.mc I don't know. In sendmail.cf, you change the Xgreylist
> line and add T=R:10s;E:10s for instance

Both MILTER_FILTER() & INPUT_MILTER_FILTER() macros accept filter flags
as shown below:

INPUT_MILTER_FILTER(`S=local:/var/greylist/sock, F=T, T=S:1s;R:1s;E:5m')

"Scot L. Harris" <webid@...> writes:

> I looked at the entries setup in sendmail.mc but do not see how to
> specify a timeout for the milter.  Emmanuel, can you point me to
> documentation or provide some additional hints?

Scot,


Parts of op.me should answer your questions:

   5.11.  X -- Mail Filter (Milter) Definitions

           The sendmail Mail Filter API (Milter) is designed
      to allow third-party programs access to mail  messages
      as  they  are being processed in order to filter meta-
      information and content.  They  are  declared  in  the
      configuration file as:

          Xname {, field=value}*

      where  name is the name of the filter (used internally
      only) and the "field=name" pairs define attributes  of
      the filter.  Also see the documentation for the Input-
      MailFilters option for more information.

           Fields are:

          Socket    The socket specification
          Flags     Special flags for this filter
          Timeouts  Timeouts for this filter

      Only the first character of the field name is  checked
      (it's case-sensitive).

           The  socket specification is one of the following
      forms:

          S=inet: port @ host
          S=inet6: port @ host
          S=local: path

      The first two describe an IPv4 or IPv6 socket  listen-
      ing  on  a certain port at a given host or IP address.

      The  final  form  describes  a  named  socket  on  the
      filesystem at the given path.

           The  following  flags  may  be  set in the filter
      description.

      R   Reject connection if filter unavailable.

      T   Temporary fail connection if filter unavailable.

           If neither F=R nor F=T is specified, the  message
      is passed through sendmail in case of filter errors as
      if the failing filters were not present.

           The timeouts can be set  using  the  four  fields
      inside of the T= equate:

      C   Timeout  for connecting to a filter.  If set to 0,
          the system's connect() timeout will be used.

      S   Timeout for sending information from the MTA to  a
          filter.

      R   Timeout for reading reply from the filter.

      E   Overall  timeout between sending end-of-message to
          filter and waiting for the final acknowledgment.

           Note the separator between each timeout field  is
      a   ';'.    The  default  values  (if  not  set)  are:
      T=C:5m;S:10s;R:10s;E:5m where s is seconds  and  m  is
      minutes.

           Examples:

          Xfilter1, S=local:/var/run/f1.sock, F=R
          Xfilter2, S=inet6:999@localhost, F=T, T=S:1s;R:1s;E:5m
          Xfilter3, S=inet:3333@localhost, T=C:2m


and from cf/README:

+-------------------------+
| ADDING NEW MAIL FILTERS |
+-------------------------+

Sendmail supports mail filters to filter incoming SMTP messages according
to the "Sendmail Mail Filter API" documentation.  These filters can be
configured in your mc file using the two commands:

        MAIL_FILTER(`name', `equates')
        INPUT_MAIL_FILTER(`name', `equates')

The first command, MAIL_FILTER(), simply defines a filter with the given
name and equates.  For example:

        MAIL_FILTER(`archive', `S=local:/var/run/archivesock, F=R')

This creates the equivalent sendmail.cf entry:

        Xarchive, S=local:/var/run/archivesock, F=R

The INPUT_MAIL_FILTER() command performs the same actions as MAIL_FILTER
but also populates the m4 variable `confINPUT_MAIL_FILTERS' with the name
of the filter such that the filter will actually be called by sendmail.

For example, the two commands:

        INPUT_MAIL_FILTER(`archive', `S=local:/var/run/archivesock, F=R')
        INPUT_MAIL_FILTER(`spamcheck', `S=inet:2525@localhost, F=T')

are equivalent to the three commands:

        MAIL_FILTER(`archive', `S=local:/var/run/archivesock, F=R')
        MAIL_FILTER(`spamcheck', `S=inet:2525@localhost, F=T')
        define(`confINPUT_MAIL_FILTERS', `archive, spamcheck')

In general, INPUT_MAIL_FILTER() should be used unless you need to define
more filters than you want to use for `confINPUT_MAIL_FILTERS'.

Note that setting `confINPUT_MAIL_FILTERS' after any INPUT_MAIL_FILTER()
commands will clear the list created by the prior INPUT_MAIL_FILTER()
commands.


With the hope it helps.

On Thu, 2004-07-15 at 10:20, Cyril Guibourg wrote:

> Scot,
> 
> 
> Parts of op.me should answer your questions:
> 

Thanks everyone for the quick response and the pointers.

Really do appreciate it.

-- 
Scot L. Harris
webid@...

I don't wanna argue, and I don't wanna fight,
But there will definitely be a party tonight...