You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@spamassassin.apache.org by Levente Birta <bl...@gmail.com> on 2016/10/13 12:39:50 UTC

TxRep very slow

Hi

I have postfix with amavisd as content_filter and spamassassin 3.4.2
When I enable the TxRep plugin the mail stay very long in the SA check:


Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is 384
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: created 
/var/spool/amavisd/.spamassassin/tx-reputation.lock.wsrv.benvenutionline.ro.24727
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: link to /var/spool/amavisd/.spamassassin/tx-reputation.lock: 
link ok
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
tie-ing to DB file of type DB_File R/W in 
/var/spool/amavisd/.spamassassin/tx-reputation
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
db-based 55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated|ip=none 
scores 0/0
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_MSG_ID is now ready, value: 0.0
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_MSG_ID_COUNT is now ready, value: 0.0
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_MSG_ID_PRESCORE is now ready, value: -1.7
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: TxRep: 
reputation: none, count: 0, weight: 1.0, delta: 0.000, MSG_ID: 
55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: TxRep: active, 
55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated pre-score: -1.72, 
autolearn score: -1.719, IP: 81.196.63.17, address: xxxxxxxx@gmail.com 
signed by gmail.com
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is 384
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: created 
/var/spool/amavisd/.spamassassin/tx-reputation.lock.wsrv.benvenutionline.ro.24727
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
Oct 13 15:28:41 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 1 retries
Oct 13 15:28:42 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 2 retries
Oct 13 15:28:43 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 3 retries
Oct 13 15:28:44 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 4 retries
Oct 13 15:28:45 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 5 retries
Oct 13 15:28:46 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 6 retries
Oct 13 15:28:47 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 7 retries
Oct 13 15:28:48 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 8 retries
Oct 13 15:28:50 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 9 retries
Oct 13 15:28:51 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 10 retries
Oct 13 15:28:52 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 11 retries
Oct 13 15:28:53 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 12 retries
Oct 13 15:28:54 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 13 retries
Oct 13 15:28:55 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 14 retries
Oct 13 15:28:56 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 15 retries
Oct 13 15:28:57 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 16 retries
Oct 13 15:28:58 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 17 retries
Oct 13 15:28:59 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 18 retries
Oct 13 15:29:00 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 19 retries
Oct 13 15:29:00 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 20 retries
Oct 13 15:29:01 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 21 retries
Oct 13 15:29:02 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 22 retries
Oct 13 15:29:03 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 23 retries
Oct 13 15:29:04 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 24 retries
Oct 13 15:29:05 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 25 retries
Oct 13 15:29:05 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 26 retries
Oct 13 15:29:07 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 27 retries
Oct 13 15:29:08 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 28 retries
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 29 retries
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
tie-ing to DB file of type DB_File R/O in 
/var/spool/amavisd/.spamassassin/tx-reputation
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
db-based xxxxxxxx@gmail.com|ip=none scores 0/0
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_EMAIL_IP is now ready, value: 0.0
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_EMAIL_IP_COUNT is now ready, value: 0.0
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_EMAIL_IP_PRESCORE is now ready, value: -1.7
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: TxRep: 
reputation: none, count: 0, weight: 10.0, delta: 0.000, EMAIL_IP: 
xxxxxxxx@gmail.com
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
add_score: new count: 1, new totscore: -1.719
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is 384
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: created 
/var/spool/amavisd/.spamassassin/tx-reputation.lock.wsrv.benvenutionline.ro.24727
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
Oct 13 15:29:10 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 1 retries
Oct 13 15:29:12 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 2 retries

This is repeated a few times ... after that the mail is arrive.
What can be wrong?
Thanks


-- 
            Levi

Fwd: TxRep very slow

Posted by Levente Birta <bl...@gmail.com>.
I repost this ... someone can help me out?

In the mean time TxRep worked well with sql backend but I prefer the file

Thanks
Levi


-------- Forwarded Message --------
Subject: TxRep very slow
Date: Thu, 13 Oct 2016 15:39:50 +0300
From: Levente Birta <bl...@gmail.com>
To: users@spamassassin.apache.org

Hi

I have postfix with amavisd as content_filter and spamassassin 3.4.2
When I enable the TxRep plugin the mail stay very long in the SA check:


Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is 384
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: created 
/var/spool/amavisd/.spamassassin/tx-reputation.lock.wsrv.benvenutionline.ro.24727
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: link to /var/spool/amavisd/.spamassassin/tx-reputation.lock: 
link ok
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
tie-ing to DB file of type DB_File R/W in 
/var/spool/amavisd/.spamassassin/tx-reputation
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
db-based 55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated|ip=none 
scores 0/0
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_MSG_ID is now ready, value: 0.0
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_MSG_ID_COUNT is now ready, value: 0.0
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_MSG_ID_PRESCORE is now ready, value: -1.7
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: TxRep: 
reputation: none, count: 0, weight: 1.0, delta: 0.000, MSG_ID: 
55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: TxRep: active, 
55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated pre-score: -1.72, 
autolearn score: -1.719, IP: 81.196.63.17, address: xxxxxxxx@gmail.com 
signed by gmail.com
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is 384
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: created 
/var/spool/amavisd/.spamassassin/tx-reputation.lock.wsrv.benvenutionline.ro.24727
Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
Oct 13 15:28:41 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 1 retries
Oct 13 15:28:42 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 2 retries
Oct 13 15:28:43 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 3 retries
Oct 13 15:28:44 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 4 retries
Oct 13 15:28:45 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 5 retries
Oct 13 15:28:46 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 6 retries
Oct 13 15:28:47 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 7 retries
Oct 13 15:28:48 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 8 retries
Oct 13 15:28:50 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 9 retries
Oct 13 15:28:51 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 10 retries
Oct 13 15:28:52 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 11 retries
Oct 13 15:28:53 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 12 retries
Oct 13 15:28:54 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 13 retries
Oct 13 15:28:55 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 14 retries
Oct 13 15:28:56 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 15 retries
Oct 13 15:28:57 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 16 retries
Oct 13 15:28:58 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 17 retries
Oct 13 15:28:59 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 18 retries
Oct 13 15:29:00 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 19 retries
Oct 13 15:29:00 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 20 retries
Oct 13 15:29:01 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 21 retries
Oct 13 15:29:02 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 22 retries
Oct 13 15:29:03 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 23 retries
Oct 13 15:29:04 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 24 retries
Oct 13 15:29:05 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 25 retries
Oct 13 15:29:05 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 26 retries
Oct 13 15:29:07 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 27 retries
Oct 13 15:29:08 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 28 retries
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 29 retries
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
tie-ing to DB file of type DB_File R/O in 
/var/spool/amavisd/.spamassassin/tx-reputation
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
db-based xxxxxxxx@gmail.com|ip=none scores 0/0
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_EMAIL_IP is now ready, value: 0.0
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_EMAIL_IP_COUNT is now ready, value: 0.0
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
tag TXREP_EMAIL_IP_PRESCORE is now ready, value: -1.7
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: TxRep: 
reputation: none, count: 0, weight: 10.0, delta: 0.000, EMAIL_IP: 
xxxxxxxx@gmail.com
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
add_score: new count: 1, new totscore: -1.719
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is 384
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: created 
/var/spool/amavisd/.spamassassin/tx-reputation.lock.wsrv.benvenutionline.ro.24727
Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
Oct 13 15:29:10 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 1 retries
Oct 13 15:29:12 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
safe_lock: trying to get lock on 
/var/spool/amavisd/.spamassassin/tx-reputation with 2 retries

This is repeated a few times ... after that the mail is arrive.
What can be wrong?
Thanks


-- 
            Levi

Re: TxRep very slow

Posted by Sean Greenslade <se...@seangreenslade.com>.
On November 3, 2016 11:41:07 AM PDT, Birta Levente <bl...@gmail.com> wrote:
>I do not use spamassissin daemon. It's called by amavisd 2.10
>

You're probably better off asking on an amavis list in that case. I have no experience with amavis.

However, given that it seems to be a lock contention issue, you might see if there's any setting in amavis to prevent parallel tests.

--Sean



Re: TxRep very slow

Posted by Birta Levente <bl...@gmail.com>.
I do not use spamassissin daemon. It's called by amavisd 2.10

On Thu, Nov 3, 2016, 20:23 Sean Greenslade <se...@seangreenslade.com> wrote:

> On October 13, 2016 5:39:50 AM PDT, Levente Birta <bl...@gmail.com>
> wrote:
> >Hi
> >
> >I have postfix with amavisd as content_filter and spamassassin 3.4.2
> >When I enable the TxRep plugin the mail stay very long in the SA check:
> >
> >
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is
> >384
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: created
> >/var/spool/amavisd/.spamassassin/tx-reputation.
> lock.wsrv.benvenutionline.ro.24727
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: link to /var/spool/amavisd/.spamassassin/tx-reputation.lock:
> >
> >link ok
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist:
> >tie-ing to DB file of type DB_File R/W in
> >/var/spool/amavisd/.spamassassin/tx-reputation
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist:
> >db-based 55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated|ip=none
> >scores 0/0
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun -
> >tag TXREP_MSG_ID is now ready, value: 0.0
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun -
> >tag TXREP_MSG_ID_COUNT is now ready, value: 0.0
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun -
> >tag TXREP_MSG_ID_PRESCORE is now ready, value: -1.7
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: TxRep:
> >reputation: none, count: 0, weight: 1.0, delta: 0.000, MSG_ID:
> >55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: TxRep: active,
> >55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated pre-score: -1.72,
> >
> >autolearn score: -1.719, IP: 81.196.63.17, address: xxxxxxxx@gmail.com
> >signed by gmail.com
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is
> >384
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: created
> >/var/spool/amavisd/.spamassassin/tx-reputation.
> lock.wsrv.benvenutionline.ro.24727
> >Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
> >Oct 13 15:28:41 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 1 retries
> >Oct 13 15:28:42 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 2 retries
> >Oct 13 15:28:43 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 3 retries
> >Oct 13 15:28:44 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 4 retries
> >Oct 13 15:28:45 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 5 retries
> >Oct 13 15:28:46 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 6 retries
> >Oct 13 15:28:47 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 7 retries
> >Oct 13 15:28:48 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 8 retries
> >Oct 13 15:28:50 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 9 retries
> >Oct 13 15:28:51 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 10 retries
> >Oct 13 15:28:52 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 11 retries
> >Oct 13 15:28:53 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 12 retries
> >Oct 13 15:28:54 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 13 retries
> >Oct 13 15:28:55 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 14 retries
> >Oct 13 15:28:56 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 15 retries
> >Oct 13 15:28:57 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 16 retries
> >Oct 13 15:28:58 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 17 retries
> >Oct 13 15:28:59 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 18 retries
> >Oct 13 15:29:00 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 19 retries
> >Oct 13 15:29:00 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 20 retries
> >Oct 13 15:29:01 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 21 retries
> >Oct 13 15:29:02 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 22 retries
> >Oct 13 15:29:03 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 23 retries
> >Oct 13 15:29:04 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 24 retries
> >Oct 13 15:29:05 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 25 retries
> >Oct 13 15:29:05 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 26 retries
> >Oct 13 15:29:07 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 27 retries
> >Oct 13 15:29:08 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 28 retries
> >Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 29 retries
> >Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist:
> >tie-ing to DB file of type DB_File R/O in
> >/var/spool/amavisd/.spamassassin/tx-reputation
> >Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist:
> >db-based xxxxxxxx@gmail.com|ip=none scores 0/0
> >Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun -
> >tag TXREP_EMAIL_IP is now ready, value: 0.0
> >Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun -
> >tag TXREP_EMAIL_IP_COUNT is now ready, value: 0.0
> >Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun -
> >tag TXREP_EMAIL_IP_PRESCORE is now ready, value: -1.7
> >Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: TxRep:
> >reputation: none, count: 0, weight: 10.0, delta: 0.000, EMAIL_IP:
> >xxxxxxxx@gmail.com
> >Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist:
> >add_score: new count: 1, new totscore: -1.719
> >Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is
> >384
> >Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: created
> >/var/spool/amavisd/.spamassassin/tx-reputation.
> lock.wsrv.benvenutionline.ro.24727
> >Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
> >Oct 13 15:29:10 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 1 retries
> >Oct 13 15:29:12 wsrv amavis[24727]: (24727-01) SA dbg: locker:
> >safe_lock: trying to get lock on
> >/var/spool/amavisd/.spamassassin/tx-reputation with 2 retries
> >
> >This is repeated a few times ... after that the mail is arrive.
> >What can be wrong?
> >Thanks
>
> Is your spamassassin daemon set up to spawn multiple children? What
> happens if you reduce the children limit to 1?
>
> --Sean
>
>
>

Re: TxRep very slow

Posted by Sean Greenslade <se...@seangreenslade.com>.
On October 13, 2016 5:39:50 AM PDT, Levente Birta <bl...@gmail.com> wrote:
>Hi
>
>I have postfix with amavisd as content_filter and spamassassin 3.4.2
>When I enable the TxRep plugin the mail stay very long in the SA check:
>
>
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is
>384
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: created 
>/var/spool/amavisd/.spamassassin/tx-reputation.lock.wsrv.benvenutionline.ro.24727
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: link to /var/spool/amavisd/.spamassassin/tx-reputation.lock:
>
>link ok
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
>tie-ing to DB file of type DB_File R/W in 
>/var/spool/amavisd/.spamassassin/tx-reputation
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
>db-based 55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated|ip=none 
>scores 0/0
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
>tag TXREP_MSG_ID is now ready, value: 0.0
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
>tag TXREP_MSG_ID_COUNT is now ready, value: 0.0
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
>tag TXREP_MSG_ID_PRESCORE is now ready, value: -1.7
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: TxRep: 
>reputation: none, count: 0, weight: 1.0, delta: 0.000, MSG_ID: 
>55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: TxRep: active, 
>55ff016ac8b77d76f3c2bd742dd31c10becb6023@sa_generated pre-score: -1.72,
>
>autolearn score: -1.719, IP: 81.196.63.17, address: xxxxxxxx@gmail.com 
>signed by gmail.com
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is
>384
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: created 
>/var/spool/amavisd/.spamassassin/tx-reputation.lock.wsrv.benvenutionline.ro.24727
>Oct 13 15:28:40 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
>Oct 13 15:28:41 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 1 retries
>Oct 13 15:28:42 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 2 retries
>Oct 13 15:28:43 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 3 retries
>Oct 13 15:28:44 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 4 retries
>Oct 13 15:28:45 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 5 retries
>Oct 13 15:28:46 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 6 retries
>Oct 13 15:28:47 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 7 retries
>Oct 13 15:28:48 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 8 retries
>Oct 13 15:28:50 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 9 retries
>Oct 13 15:28:51 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 10 retries
>Oct 13 15:28:52 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 11 retries
>Oct 13 15:28:53 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 12 retries
>Oct 13 15:28:54 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 13 retries
>Oct 13 15:28:55 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 14 retries
>Oct 13 15:28:56 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 15 retries
>Oct 13 15:28:57 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 16 retries
>Oct 13 15:28:58 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 17 retries
>Oct 13 15:28:59 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 18 retries
>Oct 13 15:29:00 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 19 retries
>Oct 13 15:29:00 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 20 retries
>Oct 13 15:29:01 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 21 retries
>Oct 13 15:29:02 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 22 retries
>Oct 13 15:29:03 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 23 retries
>Oct 13 15:29:04 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 24 retries
>Oct 13 15:29:05 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 25 retries
>Oct 13 15:29:05 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 26 retries
>Oct 13 15:29:07 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 27 retries
>Oct 13 15:29:08 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 28 retries
>Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 29 retries
>Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
>tie-ing to DB file of type DB_File R/O in 
>/var/spool/amavisd/.spamassassin/tx-reputation
>Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
>db-based xxxxxxxx@gmail.com|ip=none scores 0/0
>Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
>tag TXREP_EMAIL_IP is now ready, value: 0.0
>Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
>tag TXREP_EMAIL_IP_COUNT is now ready, value: 0.0
>Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: check: tagrun - 
>tag TXREP_EMAIL_IP_PRESCORE is now ready, value: -1.7
>Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: TxRep: 
>reputation: none, count: 0, weight: 10.0, delta: 0.000, EMAIL_IP: 
>xxxxxxxx@gmail.com
>Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: auto-whitelist: 
>add_score: new count: 1, new totscore: -1.719
>Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: mode is
>384
>Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: created 
>/var/spool/amavisd/.spamassassin/tx-reputation.lock.wsrv.benvenutionline.ro.24727
>Oct 13 15:29:09 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 0 retries
>Oct 13 15:29:10 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 1 retries
>Oct 13 15:29:12 wsrv amavis[24727]: (24727-01) SA dbg: locker: 
>safe_lock: trying to get lock on 
>/var/spool/amavisd/.spamassassin/tx-reputation with 2 retries
>
>This is repeated a few times ... after that the mail is arrive.
>What can be wrong?
>Thanks

Is your spamassassin daemon set up to spawn multiple children? What happens if you reduce the children limit to 1?

--Sean