Re: policyd-weight: blocked because of previous errors

2009-12-23 Thread Robert Felber
On Tue, Dec 22, 2009 at 01:45:56PM +0100, Helga Mayer wrote:
 Hello list,
 
 I have a problem with rejects due to cache entries.
 We use policyd-weight-0.1.14-beta-17.
 
 This is the message found in the logfile:
 
 Dec 21 16:09:28 smtp2 postfix/smtpd[16364]: connect from 
 mail-telecontrol.customer.solnet.ch[82.220.17.226]
 Dec 21 16:09:29 smtp2 postfix/policyd-weight[30193]: decided action=550 
 temporarily blocked because of previous errors - retrying too fast. 
 penalty: 30 seconds x 0 retries.; client=82.220.17.226 
 helo=smtp.telecontrol.ch from=$sen...@telecontrol.ch 
 to=$recipi...@uni-hohenheim.de; delay: 0s
 Dec 21 16:09:29 smtp2 postfix/smtpd[16364]: NOQUEUE: reject: RCPT from 
 mail-telecontrol.customer.solnet.ch[82.220.17.226]: 550 5.7.1 
 $recipi...@uni-hohenheim.de: Recipient address rejected: temporarily 
 blocked 
 because of previous errors - retrying too fast. penalty: 30 seconds x 0 
 retries.; from=$sen...@telecontrol.ch to=$recipi...@uni-hohenheim.de 
 proto=ESMTP helo=smtp.telecontrol.ch
 
 
 There are no other log entries for 82.220.17.226 during the last 8 days.
 The cache entry is:

[bz]grep 82.220.17.226 /var/log/...log...

results only in this snippet?


 policyd-weight -s|grep 82.220.17.226
 blocked: 82.220.17.226 1 0 1261408171
 1261408171 (UNIX) is the date of the first (and only) reject + 2 seconds :
 1261408171 = Mon, 21 Dec 2009 15:09:31 GMT

+ 2 seconds indeed sounds strange but could be explained if the
log is done in GMT (which would make it then a retry after 59:57 minutes).


Is the policy service used by many machines or _only_ by localhost?


 
 As a workaround we whitelisted the particular IP.
 The headers of a mail received from this server are:
 
 Received: from smtp.telecontrol.ch (mail-telecontrol.customer.solnet.ch
  [82.220.17.226])
  by smtp2.rz.uni-hohenheim.de (Postfix) with ESMTP
  for $recipi...@uni-hohenheim.de; Tue,
  22 Dec 2009 12:23:13 +0100 (CET)
 Received: from PRISM.telecontrol.local ([192.168.30.11]) by
   PRISM.telecontrol.local ([192.168.30.11]) with mapi; Tue, 22 Dec 2009
   12:23:18 +0100

Does lead to a reject, yes.

SENDER
% host telecontrol.ch
telecontrol.ch has address 93.88.240.108
telecontrol.ch mail is handled by 5 mta-gw.infomaniak.ch.

% host mta-gw.infomaniak.ch
mta-gw.infomaniak.ch has address 84.16.68.126
mta-gw.infomaniak.ch has address 84.16.68.125


HELO
% host smtp.telecontrol.ch
smtp.telecontrol.ch is an alias for mail.infomaniak.ch.
mail.infomaniak.ch has address 84.16.68.123
mail.infomaniak.ch has address 84.16.68.124



CLIENT
% host mail-telecontrol.customer.solnet.ch
mail-telecontrol.customer.solnet.ch has address 82.220.17.226


The client is in no relation (naming or subnet-wise) to sender or helo.
Would the sender use a correct HELO, he wouldn't have this problem.



-- 
Robert Felber (PGP: 896CF30B)
Munich, Germany


Policyd-weight Mailinglist - http://www.policyd-weight.org/


Re: policyd-weight: blocked because of previous errors

2009-12-23 Thread Helga Mayer

On Wed, 23 Dec 2009, Robert Felber wrote:


On Tue, Dec 22, 2009 at 01:45:56PM +0100, Helga Mayer wrote:

Hello list,

I have a problem with rejects due to cache entries.
We use policyd-weight-0.1.14-beta-17.

This is the message found in the logfile:

Dec 21 16:09:28 smtp2 postfix/smtpd[16364]: connect from
mail-telecontrol.customer.solnet.ch[82.220.17.226]
Dec 21 16:09:29 smtp2 postfix/policyd-weight[30193]: decided action=550
temporarily blocked because of previous errors - retrying too fast.
penalty: 30 seconds x 0 retries.; client=82.220.17.226
helo=smtp.telecontrol.ch from=$sen...@telecontrol.ch
to=$recipi...@uni-hohenheim.de; delay: 0s
Dec 21 16:09:29 smtp2 postfix/smtpd[16364]: NOQUEUE: reject: RCPT from
mail-telecontrol.customer.solnet.ch[82.220.17.226]: 550 5.7.1
$recipi...@uni-hohenheim.de: Recipient address rejected: temporarily
blocked
because of previous errors - retrying too fast. penalty: 30 seconds x 0
retries.; from=$sen...@telecontrol.ch to=$recipi...@uni-hohenheim.de
proto=ESMTP helo=smtp.telecontrol.ch


There are no other log entries for 82.220.17.226 during the last 8 days.
The cache entry is:


[bz]grep 82.220.17.226 /var/log/...log...

results only in this snippet?

yes

What I expected was something like

weighted check:  NOT_IN_SBL_XBL_SPAMHAUS=-1.5 NOT_IN_SPAMCOP=-1.5 
NOT_IN_BL_NJABL=-1.5 HELO_IP_IN_CL_SUBNET=-1.2 (check from: .hotmail. - 
helo: .some.domain - helo-domain: .domain.) 
FROM/MX_MATCHES_NOT_HELO(DOMAIN)=1 IN_PM_RFCI=3.2 IN_ABUSE_RFCI=3.2; 
client=xxx.xxx.xxx.xxx helo=helo.some.domain 
from=sen...@sender.domain to=recipi...@uni-hohenheim.de; rate: 
1.7


but there's no entry like this for 82.220.17.226




policyd-weight -s|grep 82.220.17.226  blocked: 82.220.17.226 1 0 1261408171
1261408171 (UNIX) is the date of the first (and only) reject + 2 seconds :
1261408171 = Mon, 21 Dec 2009 15:09:31 GMT


+ 2 seconds indeed sounds strange but could be explained if the
log is done in GMT (which would make it then a retry after 59:57 minutes).

I apologize, this was my mistake. I checked the logs on a common loghost.
The loghost is 2 second back.



Is the policy service used by many machines or _only_ by localhost?

by 2 machines with identical setup. 2 smtp servers with the same priority
in the MX Record. Each is running policyd-weight locally.
On the particular host the time of the cache entry is exactly the time
of the first reject. So the problem remaining is:
why is there no reason given in the logs for the reject and for rate:1,
as seen in the cache entry.

Regards
Helga Mayer






As a workaround we whitelisted the particular IP.
The headers of a mail received from this server are:

Received: from smtp.telecontrol.ch (mail-telecontrol.customer.solnet.ch
 [82.220.17.226])
 by smtp2.rz.uni-hohenheim.de (Postfix) with ESMTP
 for $recipi...@uni-hohenheim.de; Tue,
 22 Dec 2009 12:23:13 +0100 (CET)
Received: from PRISM.telecontrol.local ([192.168.30.11]) by
  PRISM.telecontrol.local ([192.168.30.11]) with mapi; Tue, 22 Dec 2009
  12:23:18 +0100


Does lead to a reject, yes.

SENDER
% host telecontrol.ch
telecontrol.ch has address 93.88.240.108
telecontrol.ch mail is handled by 5 mta-gw.infomaniak.ch.

% host mta-gw.infomaniak.ch
mta-gw.infomaniak.ch has address 84.16.68.126
mta-gw.infomaniak.ch has address 84.16.68.125


HELO
% host smtp.telecontrol.ch
smtp.telecontrol.ch is an alias for mail.infomaniak.ch.
mail.infomaniak.ch has address 84.16.68.123
mail.infomaniak.ch has address 84.16.68.124



CLIENT
% host mail-telecontrol.customer.solnet.ch
mail-telecontrol.customer.solnet.ch has address 82.220.17.226


The client is in no relation (naming or subnet-wise) to sender or helo.
Would the sender use a correct HELO, he wouldn't have this problem.






--


Policyd-weight Mailinglist - http://www.policyd-weight.org/


policyd-weight: blocked because of previous errors

2009-12-22 Thread Helga Mayer

Hello list,

I have a problem with rejects due to cache entries.
We use policyd-weight-0.1.14-beta-17.

This is the message found in the logfile:

Dec 21 16:09:28 smtp2 postfix/smtpd[16364]: connect from 
mail-telecontrol.customer.solnet.ch[82.220.17.226]
Dec 21 16:09:29 smtp2 postfix/policyd-weight[30193]: decided action=550 
temporarily blocked because of previous errors - retrying too fast. 
penalty: 30 seconds x 0 retries.; client=82.220.17.226 
helo=smtp.telecontrol.ch from=$sen...@telecontrol.ch 
to=$recipi...@uni-hohenheim.de; delay: 0s
Dec 21 16:09:29 smtp2 postfix/smtpd[16364]: NOQUEUE: reject: RCPT from 
mail-telecontrol.customer.solnet.ch[82.220.17.226]: 550 5.7.1 
$recipi...@uni-hohenheim.de: Recipient address rejected: temporarily 
blocked 
because of previous errors - retrying too fast. penalty: 30 seconds x 0 
retries.; from=$sen...@telecontrol.ch to=$recipi...@uni-hohenheim.de 
proto=ESMTP helo=smtp.telecontrol.ch



There are no other log entries for 82.220.17.226 during the last 8 days.
The cache entry is:
policyd-weight -s|grep 82.220.17.226
blocked: 82.220.17.226 1 0 1261408171
1261408171 (UNIX) is the date of the first (and only) reject + 2 seconds :
1261408171 = Mon, 21 Dec 2009 15:09:31 GMT

which is IMO contradictious: The mail has been rejected due to
cache entries but hasn't been in the cache before.

As a workaround we whitelisted the particular IP.
The headers of a mail received from this server are:

Received: from smtp.telecontrol.ch (mail-telecontrol.customer.solnet.ch
[82.220.17.226])
by smtp2.rz.uni-hohenheim.de (Postfix) with ESMTP
for $recipi...@uni-hohenheim.de; Tue,
22 Dec 2009 12:23:13 +0100 (CET)
Received: from PRISM.telecontrol.local ([192.168.30.11]) by
 PRISM.telecontrol.local ([192.168.30.11]) with mapi; Tue, 22 Dec 2009
 12:23:18 +0100

Regards
Helga Mayer


Policyd-weight Mailinglist - http://www.policyd-weight.org/