I have a systeem with postfix and spamassassin 3.4.6 via spamd. It's
been generally running well. I noticed mail from one of my other
systems timing out and 471, and that caused me to look at the logs. I
have KAM rules, some RBL adjustments, a bunch of local rules for my
spam, but really nothing I consider unusual.
I realized I had DCC enabled, perhaps not correctly, and I just took
that out, since I've never really been clear on how it works and if I
want to use it.
My logs go back to October 3, but starting 24th I have lots of lines like:
Oct 24 03:23:13 bar spamd[25868]: check: exceeded time limit in
Mail::SpamAssassin::Plugin::Check::_eval_tests_type9_pri1000_set1, skipping
further tests
Looking further, I see
Nov 1 12:02:01 bar postfix/cleanup[18861]: 6E2D74106C3:
message-id=<20211031071804.b221b16...@bar.example.com>
Nov 1 12:07:01 bar postfix/cleanup[18861]: warning:
milter unix:/var/run/spamass.sock: can't read SMFIC_BODYEOB reply packet
header: Connection timed out
Nov 1 12:07:01 bar postfix/cleanup[18861]: 6E2D74106C3: milter-reject:
END-OF-MESSAGE from foo.example.com[10.0.0.2]: 4.7.1 Service unavailable - try
again later ; from=<r...@foo.example.com> to=<f...@example.com> proto=ESMTP
helo=<foo.example.com>
Nov 1 12:07:02 bar spamd[23510]: check: exceeded time limit in
Mail::SpamAssassin::Plugin::Check::_eval_tests_type9_pri1000_set1, skipping
further tests
Nov 1 12:07:02 bar spamd[13194]: spamd: clean message (-1.0/1.0) for
fred:10853 in 300.2 seconds, 2064 bytes.
Nov 1 12:07:02 bar spamd[13194]: spamd: result: . 0 -
ALL_TRUSTED,KAM_DMARC_STATUS,TIME_LIMIT_EXCEEDED
scantime=300.2,size=2064,user=fred,uid=10853,required_score=1.0,rhost=::1,raddr=::1,rport=56983,mid=<20211031071804.b221b16...@foo.example.com>,autolearn=unavailable
so it sort of looks like:
postfix is waiting 300s
SA thinks it can spend 300s processing
postfix gives up 1s before SA is done
something is causing a delay
and thus I have two problems:
need to have postfix delay be more than spamassassin delay plus rounding
need to figure out why there is a timeout
The first is surely manual reading, but I wonder why it isn't default.
On the second, I wonder if anyone else is seeing this, and clues appreciated.
Thanks,
Greg
