Arg, I got sidetracked with a rule based DNS problem, thought to check "other DNS problems", thought I did but apparently didn't.
Problem: rdns check on connecting host (for syslogging purposes) was timing out after 10 seconds ...which is why the problem only affected spamd and not spamassassin. Thanks! Daryl On 21/03/2009 6:38 PM, Justin Mason wrote: > bizarre. the one thing that leaps to mind would be a DNS lookup > happening "behind the scenes" > to a broken/missing DNS server... > > --j. > > On Sat, Mar 21, 2009 at 22:31, Daryl C. W. O'Shea > <[email protected]> wrote: >> Anybody know why a spamd child would consistently sleep 10 seconds >> before even starting to process a message after being ordered to do so >> by the spamd parent? >> >> /usr/local/scripts/spamd -p 5559 -x -u mail -m 2 -d -A 10.0.0.0/8 -i >> 10.10.10.85 -r /var/run/spamd2.pid -L -D >> --siteconfigpath=/home/techsupport/spamassassin --configpath=/dev/null >> >> The only plugin being loaded is the Check plugin. Everything else is >> disabled. The spamd children have the same 10 second delay when running >> in either prefork or round-robin mode. >> >> load average: 0.15, 0.20, 0.18 >> >> Cpu(s): 4.8% us, 0.6% sy, 0.0% ni, 94.2% id, 0.0% wa, 0.0% hi, 0.3% si >> >> Thanks! >> >> Daryl >> >> >>> Mar 21 17:06:34 sa85 spamd[26187]: prefork: ordered 26188 to accept >>> Mar 21 17:06:34 sa85 spamd[26187]: prefork: sysread(6) not ready, wait max >>> 300 secs >>> Mar 21 17:06:34 sa85 spamd[26187]: prefork: child 26188: entering state 2 >>> Mar 21 17:06:34 sa85 spamd[26187]: prefork: new lowest idle kid: 26189 >>> Mar 21 17:06:44 sa85 spamd[26188]: spamd: connection from 10.10.10.85 >>> [10.10.10.85] at port 33494 >>> Mar 21 17:06:44 sa85 spamd[26188]: info: user has changed >>> Mar 21 17:06:44 sa85 spamd[26188]: bayes: no dbs present, cannot tie DB >>> R/O: /var/spool/mail/.spamassassin/bayes_toks >>> Mar 21 17:06:44 sa85 spamd[26188]: config: score set 0 chosen. >>> Mar 21 17:06:44 sa85 spamd[26188]: spamd: running as uid 8 >>> Mar 21 17:06:44 sa85 spamd[26188]: message: main message type: >>> multipart/mixed >>> Mar 21 17:06:44 sa85 spamd[26188]: spamd: processing message <munged> for >>> root:8 >>> Mar 21 17:06:44 sa85 spamd[26188]: bayes: no dbs present, cannot tie DB >>> R/O: /var/spool/mail/.spamassassin/bayes_toks >>> Mar 21 17:06:44 sa85 spamd[26188]: conf: trusted_networks are not >>> configured; it is recommended that you configure trusted_networks manually >> (snip receive header parsing debug output) >>> Mar 21 17:06:44 sa85 spamd[26188]: message: ---- MIME PARSER START ---- >>> Mar 21 17:06:44 sa85 spamd[26188]: message: parsing multipart, got >>> boundary: =_mixed 00493DD98625742D_= >>> Mar 21 17:06:44 sa85 spamd[26188]: message: found part of type >>> multipart/alternative, boundary: =_alternative 00493DD98625742D_= >>> Mar 21 17:06:44 sa85 spamd[26188]: message: added part, type: >>> multipart/alternative >>> Mar 21 17:06:44 sa85 spamd[26188]: message: found part of type >>> application/octet-stream, boundary: =_mixed 00493DD98625742D_= >>> Mar 21 17:06:44 sa85 spamd[26188]: message: added part, type: >>> application/octet-stream >>> Mar 21 17:06:44 sa85 spamd[26188]: message: parsing multipart, got >>> boundary: =_alternative 00493DD98625742D_= >>> Mar 21 17:06:44 sa85 spamd[26188]: message: found part of type text/plain, >>> boundary: =_alternative 00493DD98625742D_= >>> Mar 21 17:06:44 sa85 spamd[26188]: message: added part, type: text/plain >>> Mar 21 17:06:44 sa85 spamd[26188]: message: found part of type text/html, >>> boundary: =_alternative 00493DD98625742D_= >>> Mar 21 17:06:44 sa85 spamd[26188]: message: added part, type: text/html >>> Mar 21 17:06:44 sa85 spamd[26188]: message: parsing normal part >>> Mar 21 17:06:44 sa85 last message repeated 2 times >>> Mar 21 17:06:44 sa85 spamd[26188]: message: ---- MIME PARSER END ---- >>> Mar 21 17:06:44 sa85 spamd[26188]: message: no encoding detected >>> Mar 21 17:06:44 sa85 spamd[26188]: message: no encoding detected >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: local tests only, ignoring RBL >>> eval >>> Mar 21 17:06:44 sa85 spamd[26188]: check: running tests for priority: 0 >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running head tests; score so far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running body tests; score so far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running uri tests; score so far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running rawbody tests; score so >>> far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running full tests; score so far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running meta tests; score so far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: check: running tests for priority: 500 >>> Mar 21 17:06:44 sa85 spamd[26188]: dns: harvest_dnsbl_queries >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running head tests; score so far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running body tests; score so far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running uri tests; score so far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running rawbody tests; score so >>> far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running full tests; score so far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: rules: running meta tests; score so far=0 >>> Mar 21 17:06:44 sa85 spamd[26188]: check: is spam? score=0 required=5 >>> Mar 21 17:06:44 sa85 spamd[26188]: check: tests= >>> Mar 21 17:06:44 sa85 spamd[26188]: check: subtests= >>> Mar 21 17:06:44 sa85 spamd[26188]: spamd: clean message (0.0/5.0) for >>> root:8 in 10.0 seconds, 81532 bytes. >>> Mar 21 17:06:44 sa85 spamd[26188]: spamd: result: . 0 - >>> scantime=10.0,size=81532,user=root,uid=8,required_score=5.0,rhost=10.10.10.85,raddr=10.10.10.85,rport=33494,mid=<munged>,autolearn=no >>> Mar 21 17:06:44 sa85 spamd[26188]: config: copying current conf from backup >>> Mar 21 17:06:44 sa85 spamd[26188]: prefork: sysread(7) not ready, wait max >>> 300 secs >>> Mar 21 17:06:44 sa85 spamd[26187]: prefork: child 26188: entering state 1 >>> Mar 21 17:06:44 sa85 spamd[26187]: prefork: new lowest idle kid: 26188 >>> Mar 21 17:06:44 sa85 spamd[26187]: prefork: child reports idle >>> Mar 21 17:06:44 sa85 spamd[26187]: prefork: child states: II >> >> >
