Message marked with SpamAssassin timeout when it should't

[Ugo Bellavance]

>-----Message d'origine-----
>De : Mariano Absatz [mailto:mailscanner at LISTS.COM.AR]
>Envoyé : 12 avril, 2004 10:46
>À : MAILSCANNER at JISCMAIL.AC.UK
>Objet : Message marked with SpamAssassin timeout when it should't
>
>
>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...

Maybe spamassassin got time to process text-based tests but timed out on RBL checks and that SA has the default behavior of setting a message wher SA timed out as non-spam?

>
>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.
>