Message marked with SpamAssassin timeout when it should't

[Mariano Absatz]

Hi Julian,

I'm doing some testing on a (very overloaded & underpowered) machine, 'cause
it has real mail trafic I'm monitoring...

Due to this, I'm using only 2 MailScanner processes and, even then, I often
get SpamAssassin timeouts... that's expected, OK.

However, as I sent myself a message to verify some SA rules we're fiddling
with I noticed something strange:
1) SA processes the mail AND yelds the result
2) just after that, SA times out 2 times
3) the mailscanner log says it found 1 spam message (luckily enough, it was
my test message)
4) the test message arrives, but it has a 'SpamAssassin (timed out)' in the X-
MailScanner-SpamAssassin: header...

Here's the log corresponding to that batch:

Apr 12 11:26:00 dedos MailScanner[2695]: New Batch: Found 17 messages waiting

Apr 12 11:26:00 dedos MailScanner[2695]: New Batch: Forwarding 1 unscanned
messages, 8711 bytes
Apr 12 11:26:00 dedos MailScanner[2695]: New Batch: Scanning 3 messages, 5699
bytes
Apr 12 11:26:00 dedos MailScanner[2695]: MCP Checks completed at 14410 bytes
per second
Apr 12 11:26:00 dedos MailScanner[2695]: Spam Checks: Starting
Apr 12 11:26:51 dedos MailScanner[2695]: Message 141779 from 205.158.62.67
(el_baby at mail.com) to baby.com.ar is spam, Alerce-SpamAnalista-2.63
(puntaje=10.004, requerido 5, DEJAR_DE_FUMAR_ES 1.00, EXCLAMACION_ES 1.00,
EXCUSE_ES_02 1.00, EXCUSE_ES_06 1.00, MANY_EXCLAMATIONS 0.39, NO_REAL_NAME
0.28, OFERTA_ES 1.00, PERT_OFERTA_ES 2.00, PLING_PLING 1.32, REMOVE_ES_06
1.00)
Apr 12 11:27:51 dedos MailScanner[2695]: SpamAssassin timed out and was
killed, consecutive failure 1 of 20
Apr 12 11:28:52 dedos MailScanner[2695]: SpamAssassin timed out and was
killed, consecutive failure 2 of 20
Apr 12 11:28:53 dedos MailScanner[2695]: Spam Checks: Found 1 spam messages
Apr 12 11:28:53 dedos MailScanner[2695]: Spam Actions: message 141779 actions
are attachment,deliver
Apr 12 11:28:54 dedos MailScanner[2695]: Spam Checks completed at 83 bytes
per second
Apr 12 11:28:54 dedos MailScanner[2695]: ZM: message 141783 renamed into
215984
Apr 12 11:28:54 dedos MailScanner[2695]: Unscanned: Delivered 1 messages
Apr 12 11:28:58 dedos MailScanner[2695]: Virus and Content Scanning: Starting

Apr 12 11:30:32 dedos MailScanner[2695]: Filename Checks: Allowing 141779 msg-
2695-2.txt
Apr 12 11:30:32 dedos MailScanner[2695]: Filename Checks: Allowing 141732 msg-
2695-3.txt
Apr 12 11:30:33 dedos MailScanner[2695]: Filename Checks: Allowing 141782 msg-
2695-4.txt
Apr 12 11:30:33 dedos MailScanner[2695]: Virus Scanning completed at 145
bytes per second
Apr 12 11:30:35 dedos MailScanner[2695]: ZM: message 141779 renamed into
215984
Apr 12 11:30:35 dedos MailScanner[2695]: ZM: message 141732 renamed into
216319
Apr 12 11:30:35 dedos MailScanner[2695]: ZM: message 141782 renamed into
216324
Apr 12 11:30:35 dedos MailScanner[2695]: Uninfected: Delivered 3 messages
Apr 12 11:30:35 dedos MailScanner[2695]: Virus Processing completed at 7205
bytes per second
Apr 12 11:30:35 dedos MailScanner[2695]: Disinfection completed at 14410
bytes per second
Apr 12 11:30:35 dedos MailScanner[2695]: Batch completed at 52 bytes per
second (14410 / 275)
Apr 12 11:30:40 dedos MailScanner[2695]: New Batch: Found 29 messages waiting

Apr 12 11:30:40 dedos MailScanner[2695]: New Batch: Forwarding 26 unscanned
messages, 499377 bytes
Apr 12 11:30:40 dedos MailScanner[2695]: New Batch: Scanning 2 messages,
38091 bytes
Apr 12 11:30:40 dedos MailScanner[2695]: MCP Checks completed at 537468 bytes
per second
Apr 12 11:30:40 dedos MailScanner[2695]: Spam Checks: Starting



The headers of the identified spam message follow:

X-Alerce-Informacion: Contactarse con su proveedor para mas informacion
X-Alerce: Se encontro limpio
X-Alerce-SpamAnalisis: no es spam, Alerce-SpamAnalista-2.63 (timed out)
X-Alerce-From: el_baby at mail.com
Return-Path: <el_baby at mail.com>


I _KNOW_ this is the message (el_baby at mail.com is me) so there's no mistake
in identified the message in question...

What could have happened?

TIA.


--
Mariano Absatz
El Baby
----------------------------------------------------------
This email is ROT26 encrypted, by reading it you are in violation of the
DMCA, and should turn yourself in to the authorities immediately.