Re: [policyd-users] Race condition when auto[white|black]list, [greylisting|quotas]_tracking

[Nigel Kukard]

On 10/21/10 15:22, asmodevs wrote:
> We encountered a problem (race condition) when using policyd v2.0.10.
>
> Database: MySQL 5
> Mail Daemon: Postfix
>
> Take a look at this.
>
> (greylisting_autowhitelist), also happened in greylisting_autoblacking
> ====
> 1) [2010/10/21-18:28:21 - 12202] [GREYLISTING] DEBUG: Updated
> greylisting triplet
> ('SenderIP:11.22.33.0/24
> <http://11.22.33.0/24>','a...@aa.aa.aa','x...@xx.xx.xx') @ 1287656901
> 2) [2010/10/21-18:33:21 - 14348] [GREYLISTING] DEBUG: Updated
> greylisting triplet
> ('SenderIP:11.22.33.0/24
> <http://11.22.33.0/24>','a...@aa.aa.aa','x...@xx.xx.xx') @ 1287657200
> 3) [2010/10/21-18:33:21 - 14165] [GREYLISTING] DEBUG: Updated
> greylisting triplet
> ('SenderIP:11.22.33.0/24
> <http://11.22.33.0/24>','a...@aa.aa.aa','x...@xx.xx.xx') @ 1287657200
> 4) %09%09%09%09%09%09%09%09%09%09%09'SenderIP:11.22.33.0/24
> <http://11.22.33.0/24>',
> 5) %09%09%09%09%09%09%09%09': Duplicate entry 'SenderIP:11.22.33.0/24
> <http://11.22.33.0/24>' for key 2
> ====
>
> When SenderIP:11.22.33.0/24 <http://11.22.33.0/24> is whitelisted {
> the line 1) and the line 3) },
> the update of greylisting triplet is failed { the line 2), 4), 5) }.
>
> Then, this failed insert will cause the postfix to reject this email.
> $$$$
> 2010-10-21T18:33:21.121314+08:00 foo postfix/smtpd[2206]: NOQUEUE:
> reject: RCPT from
> smtp.aa.aa.aa[11.22.33.44]: 450 4.7.1 <x...@xx.xx.xx>: Recipient
> address rejected: Access denied;
> from=<a...@aa.aa.aa to=<x...@xx.xx.xx> proto=ESMTP helo=<smtp.aa.aa.aa>
> $$$$
>
> The error "Recipient address rejected: Access denied" originally
> indicate that the user doesn't
> exist. But, in here, this account does exists.
>
> Another example of race condition.
> (greylisting_tracking)
> ====
> [2010/10/18-14:17:03 - 32478] [GREYLISTING] DEBUG: Updated greylisting
> triplet
> ('SenderIP:12.23.34.45/32 <http://12.23.34.45/32>','b...@bb.bb.bb
> <mailto:b...@bb.bb.bb>','x...@xx.xx.xx') @ 1287382622
> [2010/10/18-14:17:03 - 31713] [GREYLISTING] ERROR: Database insert
> failed: cbp::dblayer::DBDo(125):
> Error executing command '
> %09%09%09INSERT INTO greylisting_tracking
> %09%09%09%09(TrackKey,Sender,Recipient,FirstSeen,LastUpdate,Tries,Count)
> %09%09%09VALUES
> %09%09%09%09(
> %09%09%09%09%09'SenderIP:12.23.34.45/32 <http://12.23.34.45/32>',
> %09%09%09%09%09'b...@bb.bb.bb
> <mailto:09%2509%2509%2509%2509%2...@bb.bb.bb>',
> %09%09%09%09%09'x...@xx.xx.xx',
> %09%09%09%09%09'1287382622',
> %09%09%09%09%09'1287382622',
> %09%09%09%09%091,
> %09%09%09%09%090
> %09%09%09%09)
> %09%09': Duplicate entry
> 'SenderIP:12.23.34.45/32...@bb.bb.bb-xx12@xx.xx.xx
> <http://12.23.34.45/32...@bb.bb.bb-xx12@xx.xx.xx>' for key 1
> ====
>
> Different results.
> $$$$
> 2010-10-18T14:17:03.323086+08:00 foo postfix/smtpd[31119]: NOQUEUE:
> reject: RCPT from
> 12.23.34.45[12.23.34.45]: 451 4.7.1 <x...@xx.xx.xx>: Recipient address
> rejected: Greylisting in
> effect, please come back later; from=<b...@bb.bb.bb
> <mailto:b...@bb.bb.bb>> to=<x...@xx.xx.xx> proto=SMTP
> helo=<12.23.34.45>
> 2010-10-18T14:17:03.324275+08:00 foo postfix/smtpd[5646]: NOQUEUE:
> reject: RCPT from
> 12.23.34.45[12.23.34.45]: 450 4.7.1 <x...@xx.xx.xx>: Recipient address
> rejected: Access denied;
> from=<b...@bb.bb.bb <mailto:b...@bb.bb.bb>> to=<x...@xx.xx.xx> proto=SMTP
> helo=<12.23.34.45>
> $$$$
>
> And, another.
> (quotas_tracking)
> ====
> [2010/10/19-11:48:28 - 14628] [QUOTAS] ERROR: Failed to insert
> quota_tracking item:
> cbp::dblayer::DBDo(125): Error executing command '
> %09%09%09%09%09%09INSERT INTO quotas_tracking
> %09%09%09%09%09%09%09(QuotasLimitsID,TrackKey,LastUpdate,Counter)
> %09%09%09%09%09%09VALUES
> %09%09%09%09%09%09%09(
> %09%09%09%09%09%09%09%09'8',
> %09%09%09%09%09%09%09%09'Sender:c...@cc.cc.cc
> <mailto:09%2509%2509%2509%2509%2509%2509%2509%27sender%3...@cc.cc.cc>',
> %09%09%09%09%09%09%09%09NULL,
> %09%09%09%09%09%09%09%09'1'
> %09%09%09%09%09%09%09)
> %09%09%09%09%09': Duplicate entry '8-Sender:c...@cc.cc.cc
> <mailto:8-sender%3...@cc.cc.cc>' for key 1
> ====
>
> $$$$
> 2010-10-19T11:48:28.134546+08:00 foo cbpolicyd[14602]: module=Quotas,
> mode=update,
> host=33.44.55.66, helo=66.55.44.33-reverse, from...@cc.cc.cc
> <mailto:c...@cc.cc.cc>, to...@xx.xx.xx, reason=quota_update,
> policy=8, quota=6, limit=7, track=SenderIP:33.44.55.0/24
> <http://33.44.55.0/24>, counter=MessageCount, quota=29/900
> (3.3%)
> 2010-10-19T11:48:28.134594+08:00 foo cbpolicyd[14628]: module=Quotas,
> mode=update,
> host=33.44.55.66, helo=66.55.44.33-reverse, from...@cc.cc.cc
> <mailto:c...@cc.cc.cc>, to=z...@xx.xx.xx,
> reason=quota_update, policy=8, quota=6, limit=7,
> track=SenderIP:33.44.55.0/24 <http://33.44.55.0/24>,
> counter=MessageCount, quota=29/900 (3.3%)
> 2010-10-19T11:48:28.135999+08:00 foo cbpolicyd[14602]: module=Quotas,
> mode=create,
> host=33.44.55.66, helo=66.55.44.33-reverse, from...@cc.cc.cc
> <mailto:c...@cc.cc.cc>, to...@xx.xx.xx, reason=quota_create,
> policy=8, quota=7, limit=8, track=Sender:c...@cc.cc.cc
> <mailto:sender%3...@cc.cc.cc>, counter=MessageCount, quota=1/2000 (0.1%)
> 2010-10-19T11:48:28.137715+08:00 foo cbpolicyd[14602]: module=Quotas,
> mode=update,
> host=33.44.55.66, helo=66.55.44.33-reverse, from...@cc.cc.cc
> <mailto:c...@cc.cc.cc>, to...@xx.xx.xx, reason=quota_update,
> policy=8, quota=8, limit=9, track=Recipient:z...@xx.xx.xx,
> counter=MessageCount, quota=2/200 (0.9%)
> 2010-10-19T11:48:28.138388+08:00 foo postfix/smtpd[14879]: NOQUEUE:
> reject: RCPT from
> 66.55.44.33-reverse[33.44.55.66]: 450 4.7.1 <z...@xx.xx.xx>: Recipient
> address rejected: Access
> denied; from=<c...@cc.cc.cc <mailto:c...@cc.cc.cc>> to=<z...@xx.xx.xx>
> proto=SMTP helo=<66.55.44.33-reverse>
> 2010-10-19T11:48:30.758833+08:00 foo postfix/qmgr[7369]: 22F1719F35F:
> from=<c...@cc.cc.cc <mailto:c...@cc.cc.cc>>,
> size=757966, nrcpt=1 (queue active)
> $$$$
>
> There'r two messages from c...@cc.cc.cc <mailto:c...@cc.cc.cc> at the same
> time. One insert succeed, another failed. So, one
> +message is rejected.
>
> Is there anyone encountered the same problem? Thanks.


Could you try v2.0.11RC1?

Regards
Nigel

signature.asc
Description: OpenPGP digital signature

_______________________________________________
Users mailing list
Users@lists.policyd.org
http://lists.policyd.org/mailman/listinfo/users