With qmail-scanner 1.16 and SpamAssassin 2.44 both installed from ebuilds, SpamAssassin doesn't seem to be running correctly when spawned from qmail-scanner. I can see that qmail-scanner is processing the message from the Received line that it adds, for example: Received: from nusspli66@aol.com by gateway.the-hansons-az.net by uid 201 with +qmail-scanner-1.16 (f-prot: 3.12. spamassassin: 2.44. Clear:SA:0(0/0):. Processed in 0.066795 secs); 01 May 2003 14:41:33 -0000 However, there are a couple of problems. First, the numbers after SA above are wrong. The numbers inside the paranthesis are supposed to represent: message score/threshold score. My threshold score is not zero. If I run this message manually through spamc it indicated that the message is spam with a score of 9.8 (my threshold is the default: 5.0). Second the processing time is way too low for it to be running SpamAssassin. When I run it manually it takes at least a couple of seconds to process and not 0.06 seconds. There isn't anything unusual in /var/qmailscan/qmail-queue.log. Here is a typical entry: 30/04/2003 23:20:36:13357: fprot: finished scan of dir "/var/spool/qmailscan/gateway.the-hansons-az.net105177003642613357" in 0.032842 secs 30/04/2003 23:20:36:13357: SA: run /usr/bin/spamc -f < /var/spool/qmailscan/working/new/gateway.the-hansons-az.net105177003642613357 30/04/2003 23:20:36:13357: spamassassin: finished scan of dir "/var/spool/qmailscan/gateway.the-hansons-az.net105177003642613357" in 0.021934 secs 30/04/2003 23:20:36:13357: scanloop: finished scan of "/var/spool/qmailscan/gateway.the-hansons-az.net105177003642613357"... 30/04/2003 23:20:36:13357: ini_sc: scanning message took 0.056881 seconds 30/04/2003 23:20:36:13357: q_r: fork off child into /var/qmail/bin/qmail-queue... 30/04/2003 23:20:36:13357: cleanup: /bin/rm -rf /var/spool/qmailscan/gateway.the-hansons-az.net105177003642613357/ /var/spool/qmailscan/working/new/gateway.the-hansons-az.net105177003642613357 30/04/2003 23:20:36:13357: all finished. Total of 0.078322 secs One thing that looks a little off is that fprot and SpamAssassin seem to be scanning two different places. Reproducible: Always Steps to Reproduce: 1. Receive a spam e-mail. Actual Results: SpamAssassin is not correctly identifying spam e-mail when invoked from qmail-scanner. When the same message is run manually through spamc it is identifying the message as spam. qmail-scanner is mangling the return from SpamAssassin in some way. Expected Results: I should have seen SA:1 in the header added by qmail-scanner for this particular message along with the normal headers added by SpamAssassin for its report. jon@gateway qmailscan $ emerge info Portage 2.0.47-r10 (default-x86-1.4, gcc-3.2.2, glibc-2.3.1-r4) ================================================================= System uname: 2.4.20-gentoo-r2 i686 Intel(R) Pentium(R) 4 CPU 3.06GHz GENTOO_MIRRORS="http://gentoo.oregonstate.edu/ http://distro.ibiblio.org/pub/Linux/distributions/gentoo" CONFIG_PROTECT="/etc /var/qmail/control /usr/kde/2/share/config /usr/kde/3/share/config /var/bind /usr/X11R6/lib/X11/xkb /usr/kde/3.1/share/config /usr/share/config" CONFIG_PROTECT_MASK="/etc/gconf /etc/env.d" PORTDIR="/usr/portage" DISTDIR="/usr/portage/distfiles" PKGDIR="/usr/portage/packages" PORTAGE_TMPDIR="/var/tmp" PORTDIR_OVERLAY="" USE="x86 oss 3dnow apm avi crypt cups encode gif jpeg gnome libg++ mikmod mmx mpeg ncurses nls pdflib png quicktime spell truetype xml2 xmms xv zlib gtkhtml gdbm berkdb slang readline arts tetex bonobo svga java guile sdl gpm tcpd pam libwww ssl perl python esd imlib oggvorbis gtk motif opengl X qt kde maildir mozilla tcltk" COMPILER="gcc3" CHOST="i686-pc-linux-gnu" CFLAGS="-march=pentium4 -O3 -pipe -fomit-frame-pointer -mmmx -msse -msse2" CXXFLAGS="-march=pentium4 -O3 -pipe -fomit-frame-pointer -mmmx -msse -msse2" ACCEPT_KEYWORDS="x86" MAKEOPTS="-j3" AUTOCLEAN="yes" SYNC="rsync://rsync.gentoo.org/gentoo-portage" FEATURES="sandbox ccache"
Actually I may have caused this problem. What I was trying to do was get the full SpamAssassin report in the header of the e-mail when something was spam. So I changed the $spamc_options variable in /var/qmail/bin/qmail-scanner.pl so that it did not have the -c option because that tells SpamAssassin to just return the score for the message. I'm checking if I get the results I want with the -c option only. I'd still like to see what SpamAssassin checked when a message isn't spam (like running spamc without the -c option). I'm looking into the Perl script does this.
Jon: any updates on this?
I'm pretty sure that I didn't cause this problem now. I've been looking at /var/qmail/bin/qmail-scanner.pl to debug this problem. Unfortunately I don't have much in the way of Perl skills but being a software engineer I get the jist of what's going on. Here is an update: - I want the long SpamAssassin report in the e-mail so I have removed the -c option from $spamc_options. - Setting the debug level to more than 100 causes the temporary files qmail-scanner operates on to remain on the disk. A file that ends in .spamc looks like it is supposed to contain the output of the spamc command (the processed message with the SpamAssassin added headers). The file without this extension is the original message. All of my .spamc files are identical to their counterparts (SpamAssassin is not adding headers to this message). - I added some printing debug statements around line 1680 of qmail-scanner.pl to see if things would show up in the log. Here is what I added: #X-Spam-Status: No, hits=2.8 required=5.0 if (/^X-Spam-Status: (Yes|No), hits=(.*) required=(.*)/) { &debug("SA (JMH): Found X-Spam-Status header."); $sa_status=1 if ($1 eq "Yes"); $sa_score=$2;$sa_max=$3; &debug("SA (JMH): sa_status: $sa_status, sa_score=$sa_score, sa_max=$sa_max"); In /var/spool/qmailscan/qmail-queue.log I never see any of these debug statements above. I should see both debug statements in all messages whether they are classified as spam or not so it appears that the if test is failing.
Here is an example spam message that I manually put through spamc. The X-Spam-Status field is in the output of spamc. jon@gateway cur $ spamc <1053118070.15984.gateway.the-hansons-az.net\:2\,ST Return-Path: <pw4io04q@yahoo.com> Delivered-To: jon@localhost Received: (qmail 15980 invoked by uid 204); 16 May 2003 20:47:50 -0000 Received: from pw4io04q@yahoo.com by gateway.the-hansons-az.net by uid 201 with qmail-scanner-1.16 (f-prot: 3.12. spamassassin: 2.44. Clear:SA:0(0/0):. Processed in 0.112891 secs); 16 May 2003 20:47:50 -0000 Received: from unknown (HELO localhost) (127.0.0.1) by localhost with SMTP; 16 May 2003 20:47:49 -0000 Delivered-To: jon_hanson@mail-phnx.uswest.net Received: from pop.phnx.uswest.net [63.231.195.31] by localhost with POP3 (fetchmail-6.2.2) for jon@localhost (single-drop); Fri, 16 May 2003 13:47:49 -0700 (MST) Received: (qmail 5878 invoked by uid 0); 16 May 2003 20:47:05 -0000 Received: from unknown (HELO mpls-cmx-06.inet.qwest.net) (63.226.138.6) by mpls-mailin-12.inet.qwest.net with SMTP; 16 May 2003 20:47:05 -0000 Received: (qmail 60821 invoked by uid 0); 16 May 2003 20:47:05 -0000 Received: from unknown (HELO mail.dnsvr.com) (192.197.109.240) by mpls-cmx-06.inet.qwest.net with SMTP; 16 May 2003 20:47:05 -0000 Received: from 192.197.109.240 (unknown [218.80.103.40]) by mail.dnsvr.com (Postfix) with SMTP id D8EA5230C76; Fri, 16 May 2003 16:46:58 -0400 (EDT) Received: from 0db.68jy1.net ([96.62.103.242]) by 192.197.109.240 SMTP id BAbz2qjRcLJaAy; Sat, 17 May 2003 04:40:51 +0400 Date: Sat, 17 May 03 04:40:51 GMT Message-ID: <f60-v9gyl402h5ec6de6kb-9-riu11z@g2r.7v.94y> From: "Terri Barnett" <pw4io04q@yahoo.com> To: hansonj@jon-hanson.net X-Spam: Client host [218.80.103.40] blocked using bl.spamcop.net; Blocked - see http://spamcop.net/bl.shtml?218.80.103.40 X-Spam: Client host [218.80.103.40] blocked using bl.spamcop.net; Blocked - see http://spamcop.net/bl.shtml?218.80.103.40 Subject: nickpl xetachment pxycvuowi bu xgbrjk X-Priority: 3 X-MSMail-Priority: Normal X-Mailer: Microsoft Outlook Express 5.00.2919.6700 MIME-Version: 1.0 Status: U X-UIDL: 1053118025.5884.2323.mpls-mailin-12.inet.qwest.net Content-Type: multipart/alternative; boundary="13_BF_A.D._10B_ADBEFA85" X-Spam-Status: Yes, hits=8.9 required=5.0 tests=AWL,CLICK_BELOW,DATE_IN_FUTURE_03_06,EXCUSE_3, FORGED_YAHOO_RCVD,FROM_HAS_MIXED_NUMS,MISSING_MIMEOLE, RCVD_IN_RFCI,REMOVE_PAGE,SPAM_PHRASE_08_13,USER_AGENT_OE version=2.44 X-Spam-Flag: YES X-Spam-Level: ******** X-Spam-Checker-Version: SpamAssassin 2.44 (1.115.2.24-2003-01-30-exp) X-Spam-Report: Detailed Report SPAM: -------------------- Start SpamAssassin results ---------------------- SPAM: This mail is probably spam. The original message has been altered SPAM: so you can recognise or block similar unwanted mail in future. SPAM: See http://spamassassin.org/tag/ for more details. SPAM: SPAM: Content analysis details: (8.90 hits, 5 required) SPAM: FROM_HAS_MIXED_NUMS (0.3 points) From: contains numbers mixed in with letters SPAM: USER_AGENT_OE (0.2 points) X-Mailer header indicates a non-spam MUA (Outlook Express) SPAM: EXCUSE_3 (0.4 points) BODY: Claims you can be removed from the list SPAM: CLICK_BELOW (0.3 points) BODY: Asks you to click below SPAM: SPAM_PHRASE_08_13 (1.4 points) BODY: Spam phrases score is 08 to 13 (medium) SPAM: [score: 9, hits: click here, from our, removed] SPAM: [from] SPAM: REMOVE_PAGE (0.7 points) URI: URL of page called "remove" SPAM: DATE_IN_FUTURE_03_06 (1.4 points) Date: is 3 to 6 hours after Received: date SPAM: FORGED_YAHOO_RCVD (1.4 points) 'From' yahoo.com does not match 'Received' headers SPAM: RCVD_IN_RFCI (2.3 points) RBL: Received via a relay in ipwhois.rfc-ignorant.org SPAM: [RBL check: found 40.103.80.218.ipwhois.rfc-ignorant.org., type: 127.0.0.6] SPAM: MISSING_MIMEOLE (0.5 points) Message has X-MSMail-Priority, but no X-MimeOLE SPAM: AWL (0.0 points) AWL: Auto-whitelist adjustment SPAM: SPAM: -------------------- End of SpamAssassin results ---------------------
I did some further debugging by printing out each line as it is reaq from SpamAssassin like so (at approximately line 1676 in /var/qmail/bin/qmail-scanner.pl): open(SA,"$spamc_binary $spamc_options < $scandir/$wmaildir/new/$file_id|")||&tempfail("cannot run $spamc_binary < $scandir/$wmaildir/new/$file_id - $!"); open(SOUT,">$scandir/$wmaildir/new/$file_id.spamc")||&tempfail("cannot open for write $scandir/$wmaildir/new/$file_id.spamc - $!"); while (<SA>) { &debug("Read line (JMH): $_"); The lines showing up in the log do not look like SpamAssassin is processing them because there is no added X-Spam headers in the "Read line" lines.
I figured out what the problem was. Turning on the debug loggin of spamd was all it took. The problem was that spamd was trying to create a user preference file in /var/qmail/.spamassassin/user_prefs but it didn't have permission to do that in that directory so it must have died silently. Since I have a site-wide confiuration I want to use anyway, I just told spamd to ignore user preferences (the -x option). It's working fine now.
thanks, closing this
