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

[Nigel Kukard]

We're busy working on it.

Regards
Nigel

On 10/27/10 09:02, asmodevs wrote:
> After several days of testing v2.0.11RC,
> the results are the same.
>
> I see race conditions when inserting into greylist_tracking and
> greylist_autowhitelist.
>
> I think v2.0.11RC doesn't fix these problems as what I had seen in
>
> My environment：
> MX_1 w/ policyd w/ mysqld
> MX_2 w/ policyd w/ MX_1's mysqld
>
> failed INSERT sum：
>             23      24      25      26       27
> MX_1     1        3       2        1         1
> MX_2     8        9       10      3         5
>
> AWL After Count = 1
> ( Assume AWL After Count = 100. I guess that failed insert will happen
> when 100th and 101th messages arrive at the same time. )
>
> Hope this could be helpful.
>
> Best Regards
> Yi-Yen Chuang
>
>
> On Fri, Oct 22, 2010 at 3:11 PM, asmodevs <asmod...@gmail.com
> <mailto:asmod...@gmail.com>> wrote:
>
>     Thanks for reply.
>
>     I tried v2.0.11RC and it seems to work quite better than v2.0.10.
>
>     There's only "ONE" failed insert after running for several hours.
>     ====
>     [2010/10/22-11:43:44 - 30765] [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'7',
>     %09%09%09%09%09%09%09%09'SenderIP:44.33.22.11/32
>     <http://44.33.22.11/32>',
>     %09%09%09%09%09%09%09%09'1287719024',
>     %09%09%09%09%09%09%09%09'1'
>     %09%09%09%09%09%09%09)
>     %09%09%09%09%09': Duplicate entry '7-SenderIP:44.33.22.11/32
>     <http://44.33.22.11/32>' for key 1
>     ====
>
>     $$$$
>     2010-10-22T11:43:44.502960+08:00 penguin cbpolicyd[30754]:
>     module=Quotas, mode=create, host=203.188.201.207,
>     helo=smtp107.mail.tp2.yahoo.com
>     <http://smtp107.mail.tp2.yahoo.com>,
>     from=cxutfhguqhai...@yahoo.com.sg
>     <mailto:cxutfhguqhai...@yahoo.com.sg>, to=945003...@cc.ncu.edu.tw
>     <mailto:945003...@cc.ncu.edu.tw>, reason=quota_create, policy=8,
>     quota=6, limit=7, track=SenderIP:203.188.201.207/32
>     <http://203.188.201.207/32>, counter=MessageCount, quota=8/2000 (0.4%)
>     2010-10-22T11:43:44.504104+08:00 penguin cbpolicyd[30769]:
>     module=Quotas, mode=update, host=203.188.201.207,
>     helo=smtp107.mail.tp2.yahoo.com
>     <http://smtp107.mail.tp2.yahoo.com>,
>     from=cxutfhguqhai...@yahoo.com.sg
>     <mailto:cxutfhguqhai...@yahoo.com.sg>, to=944408...@cc.ncu.edu.tw
>     <mailto:944408...@cc.ncu.edu.tw>, reason=quota_update, policy=8,
>     quota=6, limit=7, track=SenderIP:203.188.201.207/32
>     <http://203.188.201.207/32>, counter=MessageCount, quota=8/2000 (0.4%)
>     */2010-10-22T11:43:44.507701+08:00 penguin postfix/smtpd[30845]:
>     NOQUEUE: reject: RCPT from smtp107.mail.tp2.yahoo.com
>     <http://smtp107.mail.tp2.yahoo.com>[203.188.201.207]: 450 4.7.1
>     <945002...@cc.ncu.edu.tw <mailto:945002...@cc.ncu.edu.tw>>:
>     Recipient address rejected: Access denied;
>     from=<cxutfhguqhai...@yahoo.com.sg
>     <mailto:cxutfhguqhai...@yahoo.com.sg>> to=<945002...@cc.ncu.edu.tw
>     <mailto:945002...@cc.ncu.edu.tw>> proto=SMTP
>     helo=<smtp107.mail.tp2.yahoo.com
>     <http://smtp107.mail.tp2.yahoo.com>>/*
>     2010-10-22T11:43:44.516563+08:00 penguin cbpolicyd[30874]:
>     module=Quotas, mode=update, host=203.188.201.207,
>     helo=smtp107.mail.tp2.yahoo.com
>     <http://smtp107.mail.tp2.yahoo.com>,
>     from=cxutfhguqhai...@yahoo.com.sg
>     <mailto:cxutfhguqhai...@yahoo.com.sg>, to=944203...@cc.ncu.edu.tw
>     <mailto:944203...@cc.ncu.edu.tw>, reason=quota_update, policy=8,
>     quota=6, limit=7, track=SenderIP:203.188.201.207/32
>     <http://203.188.201.207/32>, counter=MessageCount, quota=8/2000 (0.4%)
>     2010-10-22T11:43:44.527249+08:00 penguin cbpolicyd[30854]:
>     module=Quotas, mode=update, host=203.188.201.207,
>     helo=smtp107.mail.tp2.yahoo.com
>     <http://smtp107.mail.tp2.yahoo.com>,
>     from=cxutfhguqhai...@yahoo.com.sg
>     <mailto:cxutfhguqhai...@yahoo.com.sg>, to=944403...@cc.ncu.edu.tw
>     <mailto:944403...@cc.ncu.edu.tw>, reason=quota_update, policy=8,
>     quota=6, limit=7, track=SenderIP:203.188.201.207/32
>     <http://203.188.201.207/32>, counter=MessageCount, quota=8/2000 (0.4%)
>     2010-10-22T11:43:44.541337+08:00 penguin cbpolicyd[30872]:
>     module=Quotas, mode=update, host=203.188.201.207,
>     helo=smtp107.mail.tp2.yahoo.com
>     <http://smtp107.mail.tp2.yahoo.com>,
>     from=cxutfhguqhai...@yahoo.com.sg
>     <mailto:cxutfhguqhai...@yahoo.com.sg>, to=944403...@cc.ncu.edu.tw
>     <mailto:944403...@cc.ncu.edu.tw>, reason=quota_update, policy=8,
>     quota=6, limit=7, track=SenderIP:203.188.201.207/32
>     <http://203.188.201.207/32>, counter=MessageCount, quota=8/2000 (0.4%)
>     2010-10-22T11:43:44.541832+08:00 penguin cbpolicyd[30878]:
>     module=Quotas, mode=update, host=203.188.201.207,
>     helo=smtp107.mail.tp2.yahoo.com
>     <http://smtp107.mail.tp2.yahoo.com>,
>     from=cxutfhguqhai...@yahoo.com.sg
>     <mailto:cxutfhguqhai...@yahoo.com.sg>, to=944203...@cc.ncu.edu.tw
>     <mailto:944203...@cc.ncu.edu.tw>, reason=quota_update, policy=8,
>     quota=6, limit=7, track=SenderIP:203.188.201.207/32
>     <http://203.188.201.207/32>, counter=MessageCount, quota=8/2000 (0.4%)
>     $$$$
>
>
>     I'm quite sure this 'failed insert' is caused by 2.0.11RC.
>     Because after starting 2.0.11RC, 
>     this error message - "Use of uninitialized value in subtraction
>     (-) at /usr/local/lib/policyd-2.0/cbp/modules/Quotas.pm line 179,
>     <_READ> line 1111. " continues to show up in log.
>
>
>     Best Regards
>     Yi-Yen Chuang
>
>
>     On Thu, Oct 21, 2010 at 11:43 PM, Nigel Kukard <nkuk...@lbsd.net
>     <mailto:nkuk...@lbsd.net>> wrote:
>
>
>
>         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
>>         <mailto:a...@aa.aa.aa>','x...@xx.xx.xx <mailto: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
>>         <mailto:a...@aa.aa.aa>','x...@xx.xx.xx <mailto: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
>>         <mailto:a...@aa.aa.aa>','x...@xx.xx.xx <mailto: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>
>>         <mailto:x...@xx.xx.xx>: Recipient address rejected: Access denied;
>>         from=<a...@aa.aa.aa <mailto:a...@aa.aa.aa> to=<x...@xx.xx.xx>
>>         <mailto: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 <mailto: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 <mailto: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>
>>         <mailto: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>
>>         <mailto: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>
>>         <mailto:x...@xx.xx.xx>: Recipient address rejected: Access
>>         denied;
>>         from=<b...@bb.bb.bb <mailto:b...@bb.bb.bb>> to=<x...@xx.xx.xx>
>>         <mailto: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 <mailto: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 <mailto: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 <mailto: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 <mailto:to...@xx.xx.xx>,
>>         reason=quota_update,
>>         policy=8, quota=8, limit=9, track=Recipient:z...@xx.xx.xx
>>         <mailto: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>
>>         <mailto:z...@xx.xx.xx>: Recipient address rejected: Access
>>         denied; from=<c...@cc.cc.cc <mailto:c...@cc.cc.cc>>
>>         to=<z...@xx.xx.xx> <mailto: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
>
>         _______________________________________________
>         Users mailing list
>         Users@lists.policyd.org <mailto:Users@lists.policyd.org>
>         http://lists.policyd.org/mailman/listinfo/users
>
>
>
>
> _______________________________________________
> Users mailing list
> Users@lists.policyd.org
> http://lists.policyd.org/mailman/listinfo/users
>   


-- 
Regards
Nigel Kukard, PhD CompSc
Linux Based Systems Design (Pty) Ltd

Support: 086 747 7600 (premium 24/7/365)
Fax: 086 601 7884

Quote: The best language to use is the language that was designed for
what you want to use it for.

*** The attachment to my email signature.asc is a digital PGP
signature, if your mail client supports digital signatures it will
allow you to verify I am the sender of this email and that it has not
been tampered with along the way ***

signature.asc
Description: OpenPGP digital signature

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