http://bugzilla.spamassassin.org/show_bug.cgi?id=3506
------- Additional Comments From [EMAIL PROTECTED] 2004-07-26 21:52 ------- on my server here, which is pretty low volumn, i had 1 PSPAMD message at 19:08:08 tonite. [EMAIL PROTECTED] spamd]# grep PSPAMD /var/log/maillog | tail -1 Jul 26 19:08:08 mailgw spamc[19705]: spamd responded with bad string 'PSPAMD/1.1 0 EX_OK' luckily, i had spamd debug turned on, so looking throug the debug log, i see that there was only 1 message that came through from 19:07 to 19:10, and here are the last 10 lines of it, showing it was successfully 'PROCESS'd. [EMAIL PROTECTED] spamd]# cat /var/log/spamd/[EMAIL PROTECTED] | tai64nlocal | grep "26 19:08" | tail -10 2004-07-26 19:08:08.603348500 debug: auto-learn: currently using scoreset 3. recomputing score based on scoreset 1. 2004-07-26 19:08:08.603350500 debug: Score set 1 chosen. 2004-07-26 19:08:08.603351500 debug: auto-learn: original score: -1.375, recomputed score: 1.531 2004-07-26 19:08:08.603378500 debug: Score set 3 chosen. 2004-07-26 19:08:08.603379500 debug: auto-learn? no: inside auto-learn thresholds 2004-07-26 19:08:08.603381500 debug: is spam? score=0.672 required=5 2004-07-26 19:08:08.603382500 debug: tests=AWL,BAYES_00,CLICK_BELOW,FOR_FREE,FREE_TRIAL,LINES_OF_YELLING,LINES_OF_YELLING_2,LINES_OF_YELLING_3,NO_REAL_NAME,SAVE_MONEY,SAVE_UP_TO 2004-07-26 19:08:08.603384500 debug: subtests=__CLICK_BELOW,__CT,__CTYPE_CHARSET_QUOTED,__CT_TEXT_PLAIN,__HAS_MSGID,__HAS_SUBJECT,__MIME_VERSION,__MSGID_OK_HEX,__SANE_MSGID 2004-07-26 19:08:08.632565500 logmsg: clean message (0.7/5.0) for [EMAIL PROTECTED]:0 in 36.9 seconds, 13969 bytes. 2004-07-26 19:08:08.632569500 logmsg: result: . 0 - AWL,BAYES_00,CLICK_BELOW,FOR_FREE,FREE_TRIAL,LINES_OF_YELLING,LINES_OF_YELLING_2,LINES_OF_YELLING_3,NO_REAL_NAME,SAVE_MONEY,SAVE_UP_TO scantime=36.9,size=13969,mid=<[EMAIL PROTECTED]>,bayes=1.64305752825555e-06,autolearn=no the one thing that stands out to me is the time it took to process.... 36.9 seconds. and I call spamc with -t 30. ------------- [EMAIL PROTECTED] spamd]# time spamc -t1 < /etc/passwd real 0m1.088s [EMAIL PROTECTED] root]# tail -1 /var/log/maillog Jul 26 23:09:21 mailgw spamc[26521]: spamd responded with bad string 'PSPAMD/1.1 0 EX_OK' ------------- [EMAIL PROTECTED] spamd]# time spamc -t1 < /etc/passwd real 0m4.744s [EMAIL PROTECTED] root]# tail -1 /var/log/maillog Jul 26 23:07:23 mailgw spamc[26483]: spamd responded with bad string 'PROCSPAMD/1.1 0 EX_OK' ------------- [EMAIL PROTECTED] spamd]# time spamc -t1 < /etc/passwd real 0m17.793s [EMAIL PROTECTED] root]# tail -1 /var/log/maillog Jul 26 23:11:22 mailgw spamc[26607]: spamd responded with bad string 'PROCESS SPAMC/1.3SPAMD/1.1 0 EX_OK' ------------- so there ya go... the spamc buf gets plugged in before the spamd response buffer when the timeout is exceeded, and the longer the scan takes beyond the timeout, the more chars you get... and if you count, the number of characters preceeding the SPAMD response is equal to the number of seconds the scan took. 1, 4, and 17 in the tests above. the problem is in _spamc_read_full_line, as the char pointer *buf that is passed in has the spamd response written over top it... see the following on a time out exceeded message as it overwrites the buf... buf 'PROCESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' spamd buffer is 'PROCESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 0 spamd buffer is 'PROCESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 1 spamd buffer is 'PROCESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 2 spamd buffer is 'PSOCESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 3 spamd buffer is 'PSPCESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 4 spamd buffer is 'PSPAESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 5 spamd buffer is 'PSPAMSS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 6 spamd buffer is 'PSPAMDS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 7 spamd buffer is 'PSPAMD/ SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 8 spamd buffer is 'PSPAMD/1SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 9 spamd buffer is 'PSPAMD/1.PAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 10 spamd buffer is 'PSPAMD/1.1AMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 11 spamd buffer is 'PSPAMD/1.1 MC/1.3^M User: root^M Content-length: 1891^M ^M ' len 12 spamd buffer is 'PSPAMD/1.1 0C/1.3^M User: root^M Content-length: 1891^M ^M ' len 13 spamd buffer is 'PSPAMD/1.1 0 /1.3^M User: root^M Content-length: 1891^M ^M ' len 14 spamd buffer is 'PSPAMD/1.1 0 E1.3^M User: root^M Content-length: 1891^M ^M ' len 15 spamd buffer is 'PSPAMD/1.1 0 EX.3^M User: root^M Content-length: 1891^M ^M ' len 16 spamd buffer is 'PSPAMD/1.1 0 EX_3^M User: root^M Content-length: 1891^M ^M ' len 17 spamd buffer is 'PSPAMD/1.1 0 EX_O^M User: root^M Content-length: 1891^M ^M ' len 18 spamd buffer is 'PSPAMD/1.1 0 EX_OK User: root^M Content-length: 1891^M ^M ' len 19 spamd buffer is 'PSPAMD/1.1 0 EX_OK^MUser: root^M Content-length: 1891^M ^M ' spamd buffer length is '18' spamd buf 'PSPAMD/1.1 0 EX_OK' spamd responded with bad string 'PSPAMD/1.1 0 EX_OK' here is what happens on one that does not time out. buf 'PROCESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' spamd buffer is 'PROCESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 0 spamd buffer is 'PROCESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 1 spamd buffer is 'SROCESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 2 spamd buffer is 'SPOCESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 3 spamd buffer is 'SPACESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 4 spamd buffer is 'SPAMESS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 5 spamd buffer is 'SPAMDSS SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 6 spamd buffer is 'SPAMD/S SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 7 spamd buffer is 'SPAMD/1 SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 8 spamd buffer is 'SPAMD/1.SPAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 9 spamd buffer is 'SPAMD/1.1PAMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 10 spamd buffer is 'SPAMD/1.1 AMC/1.3^M User: root^M Content-length: 1891^M ^M ' len 11 spamd buffer is 'SPAMD/1.1 0MC/1.3^M User: root^M Content-length: 1891^M ^M ' len 12 spamd buffer is 'SPAMD/1.1 0 C/1.3^M User: root^M Content-length: 1891^M ^M ' len 13 spamd buffer is 'SPAMD/1.1 0 E/1.3^M User: root^M Content-length: 1891^M ^M ' len 14 spamd buffer is 'SPAMD/1.1 0 EX1.3^M User: root^M Content-length: 1891^M ^M ' len 15 spamd buffer is 'SPAMD/1.1 0 EX_.3^M User: root^M Content-length: 1891^M ^M ' len 16 spamd buffer is 'SPAMD/1.1 0 EX_O3^M User: root^M Content-length: 1891^M ^M ' len 17 spamd buffer is 'SPAMD/1.1 0 EX_OK^M User: root^M Content-length: 1891^M ^M ' len 18 spamd buffer is 'SPAMD/1.1 0 EX_OK^M User: root^M Content-length: 1891^M ^M ' spamd buffer length is '17' spamd buf 'SPAMD/1.1 0 EX_OK' the fd_timeout_read returns -1 when it gets no response from spamd, but the for loop keeps running, and len is increased, causing buf[0] to retain 'P', and then buf[1] to retain 'R' and so on as it waits for a spamd response. the quick and dirty solution is the decrease len on a failed read. a better solution is probably to use seperate buffers for the spamd response and not have it overwrite the spamc buffer. i'm not sure if this will have any effect elsewhere though, so i left it alone. simple patch attached. tested and working as you can see here.. buf 'PROCESS SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' spamd buffer is 'PROCESS SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' size: 56 len 0 spamd buffer is 'PROCESS SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read timeout - len was 0 fd_timeout_read timeout - len is now -1 fd_timeout_read read -1 bytes len 0 spamd buffer is 'PROCESS SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read timeout - len was 0 fd_timeout_read timeout - len is now -1 fd_timeout_read read -1 bytes len 0 spamd buffer is 'PROCESS SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read timeout - len was 0 fd_timeout_read timeout - len is now -1 fd_timeout_read read -1 bytes len 0 spamd buffer is 'PROCESS SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 1 spamd buffer is 'SROCESS SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 2 spamd buffer is 'SPOCESS SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 3 spamd buffer is 'SPACESS SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 4 spamd buffer is 'SPAMESS SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 5 spamd buffer is 'SPAMDSS SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 6 spamd buffer is 'SPAMD/S SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 7 spamd buffer is 'SPAMD/1 SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 8 spamd buffer is 'SPAMD/1.SPAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 9 spamd buffer is 'SPAMD/1.1PAMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 10 spamd buffer is 'SPAMD/1.1 AMC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 11 spamd buffer is 'SPAMD/1.1 0MC/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 12 spamd buffer is 'SPAMD/1.1 0 C/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 13 spamd buffer is 'SPAMD/1.1 0 E/1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 14 spamd buffer is 'SPAMD/1.1 0 EX1.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 15 spamd buffer is 'SPAMD/1.1 0 EX_.3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 16 spamd buffer is 'SPAMD/1.1 0 EX_O3^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 17 spamd buffer is 'SPAMD/1.1 0 EX_OK^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes len 18 spamd buffer is 'SPAMD/1.1 0 EX_OK^M User: root^M Content-length: 14800^M ^M ' fd_timeout_read read 1 bytes spamd buffer length is '17' whew! :) ------- You are receiving this mail because: ------- You are the assignee for the bug, or are watching the assignee.
