> On 3/12/2006 2:21 PM, James Long wrote: > > In my SpamAssassin-3.1.0 (p5-Mail-SpamAssassin-3.1.0_6) local.cf, I > > use: > > > > > > ... > > trusted_networks 127.0.0.0/8 65.75.198.48/28 63.105.30.37/32 > > ... > > whitelist_from_rcvd [EMAIL PROTECTED] ns.umpquanet.com > > ... > > > > > > yet messages that I had hoped would match that whitelist entry > > are not. How can I fix this? > > SA can't parse the first (oldest) received header. Since that header is > a local submission header, I wouldn't worry about it. > > Mail sent via SMTP should have all of it's headers parsed correctly and > your whitelist_from_rcvd should work.
Yet, it doesn't. One of the nightly server log messages has been getting rejected because SA thinks it is spam, and doesn't see the whitelist_from_rcvd entry for it. (sendmail log below) > No, it must be listed, as it is now. Okay, so I feel comfortable that my trusted_networks line is correct. On to troubleshooting the whitelist_from_rcvd. BTW, is there an easy way to troubleshoot this from the command line, with perhaps a sample message in a text file that I can just use as input to SA, so that I don't have to use up bandwidth and also put a large number of test messages into my mailbox? Is it as simple as 'spamassassin -t < textfilename' ? Thanks again, Jim Sendmail log excerpt from ns.museum.rain.com: Mar 12 03:04:26 ns sm-mta[44915]: NOQUEUE: connect from ns.umpquanet.com [63.105.30.37] Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: Milter (spamassassin): init success to negotiate Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: Milter (greylist): init success to negotiate Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: Milter: connect to filters Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: milter=spamassassin, action=connect, continue Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: milter=greylist, action=connect, continue Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 220 ns.museum.rain.com ESMTP Sendmail 8.13.4/8.13.4; Sun, 12 Mar 2006 03:04:26 -0800 (PST) Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: <-- EHLO ns.umpquanet.com Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: milter=spamassassin, action=helo, continue Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 250-ns.museum.rain.com Hello ns.umpquanet.com [63.105.30.37], pleased to meet you Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 250-ENHANCEDSTATUSCODES Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 250-PIPELINING Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 250-8BITMIME Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 250-SIZE Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 250-DSN Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 250-ETRN Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 250-STARTTLS Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 250-DELIVERBY Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 250 HELP Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: <-- STARTTLS Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: --- 220 2.0.0 Ready to start TLS Mar 12 03:04:26 ns sm-mta[44915]: STARTTLS=server, get_verify: 0 get_peer: 0x0 Mar 12 03:04:26 ns sm-mta[44915]: STARTTLS=server, relay=ns.umpquanet.com [63.105.30.37], version=TLSv1/SSLv3, verify=NO, cipher=DHE-DSS-AES256-SHA, bits=256/256 Mar 12 03:04:26 ns sm-mta[44915]: STARTTLS=server, cert-subject=, cert-issuer=, verifymsg=ok Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKW044915: <-- EHLO ns.umpquanet.com Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: milter=spamassassin, action=helo, continue Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 250-ns.museum.rain.com Hello ns.umpquanet.com [63.105.30.37], pleased to meet you Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 250-ENHANCEDSTATUSCODES Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 250-PIPELINING Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 250-8BITMIME Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 250-SIZE Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 250-DSN Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 250-ETRN Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 250-DELIVERBY Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 250 HELP Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: <-- MAIL From:<[EMAIL PROTECTED]> SIZE=9162 Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: Milter: senders: <[EMAIL PROTECTED]> Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: milter=spamassassin, action=mail, continue Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: milter=greylist, action=mail, continue Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 250 2.1.0 <[EMAIL PROTECTED]>... Sender ok Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: <-- RCPT To:<[EMAIL PROTECTED]> Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: Milter: rcpts: <[EMAIL PROTECTED]> Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: milter=spamassassin, action=rcpt, continue Mar 12 03:04:26 ns milter-greylist: k2CB4QKX044915: skipping greylist because address 63.105.30.37 is whitelisted, (from=<[EMAIL PROTECTED]>, rcpt=<[EMAIL PROTECTED]>, addr=63.105.30.37) Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: milter=greylist, action=rcpt, continue Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 250 2.1.5 <[EMAIL PROTECTED]>... Recipient ok Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: <-- DATA Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: --- 354 Enter mail, end with "." on a line by itself Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: from=<[EMAIL PROTECTED]>, size=9116, class=0, nrcpts=1, msgid=<[EMAIL PROTECTED]>, proto=ESMTP, daemon=MTA, relay=ns.umpquanet.com [63.105.30.37] Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: milter=spamassassin, action=header, continue Mar 12 03:04:26 ns last message repeated 8 times Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: milter=spamassassin, action=eoh, continue Mar 12 03:04:26 ns sm-mta[44915]: k2CB4QKX044915: milter=spamassassin, action=body, continue Mar 12 03:04:26 ns spamd[27906]: spamd: connection from localhost [127.0.0.1] at port 61344 Mar 12 03:04:26 ns spamd[27906]: spamd: setuid to root succeeded Mar 12 03:04:26 ns spamd[27906]: spamd: still running as root: user not specified with -u, not found, or set to root, falling back to nobody at /usr/local/bin/spamd line 1147, <GEN228> line 4. Mar 12 03:04:27 ns spamd[27906]: spamd: processing message <[EMAIL PROTECTED]> for root:65534 Mar 12 03:04:36 ns spamd[27906]: locker: safe_lock: cannot create tmp lockfile /root/.spamassassin/auto-whitelist.lock.ns.museum.rain.com.27906 for /root/.spamassassin/auto-whitelist.lock: Permission denied Mar 12 03:04:36 ns spamd[27906]: auto-whitelist: open of auto-whitelist file failed: locker: safe_lock: cannot create tmp lockfile /root/.spamassassin/auto-whitelist.lock.ns.museum.rain.com.27906 for /root/.spamassassin/auto-whitelist.lock: Permission denied Mar 12 03:04:36 ns spamd[27906]: Can't call method "finish" on an undefined value at /usr/local/lib/perl5/site_perl/5.8.7/Mail/SpamAssassin/Plugin/AWL.pm line 397. Mar 12 03:04:36 ns spamd[27906]: spamd: identified spam (7.5/5.0) for root:65534 in 9.8 seconds, 9186 bytes. Mar 12 03:04:36 ns spamd[27906]: spamd: result: Y 7 - UNPARSEABLE_RELAY,URIBL_JP_SURBL,URIBL_OB_SURBL,URIBL_WS_SURBL scantime=9.8,size=9186,user=root,uid=65534,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=61344,mid=<[EMAIL PROTECTED]>,autolearn=no Mar 12 03:04:36 ns sm-mta[44915]: k2CB4QKX044915: Milter add: header: X-Spam-Flag: YES Mar 12 03:04:36 ns sm-mta[44915]: k2CB4QKX044915: Milter change: header X-Spam-Status: from No, score=-93.9 required=5.0 tests=ALL_TRUSTED,URIBL_JP_SURBL,\n\tURIBL_OB_SURBL,URIBL_WS_SURBL,USER_IN_WHITELIST autolearn=no \n\tversion=3.1.0 to Yes, score=7.5 required=5.0 tests=UNPARSEABLE_RELAY,\n\tURIBL_JP_SURBL,URIBL_OB_SURBL,URIBL_WS_SURBL autolearn=no \n\tversion=3.1.0 Mar 12 03:04:36 ns sm-mta[44915]: k2CB4QKX044915: milter=spamassassin, reject=550 5.7.1 Message content rejected Mar 12 03:04:36 ns sm-mta[44915]: k2CB4QKX044915: Milter (greylist): abort filter Mar 12 03:04:36 ns sm-mta[44915]: k2CB4QKX044915: Milter: data, reject=550 5.7.1 Message content rejected Mar 12 03:04:36 ns sm-mta[44915]: k2CB4QKX044915: --- 550 5.7.1 Message content rejected (hold) Mar 12 03:04:36 ns sm-mta[44915]: k2CB4QKX044915: to=<[EMAIL PROTECTED]>, delay=00:00:10, pri=39116, stat=Message content rejected Mar 12 03:04:36 ns sm-mta[44915]: k2CB4QKX044915: --- 550 5.7.1 Message content rejected (held) Mar 12 03:04:36 ns sm-mta[44915]: k2CB4QKY044915: <-- RSET Mar 12 03:04:36 ns sm-mta[44915]: k2CB4QKY044915: --- 250 2.0.0 Reset state Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: <-- MAIL From:<> SIZE=10186 Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: Milter: senders: <> Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: milter=spamassassin, action=mail, continue Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: milter=greylist, action=mail, continue Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: --- 250 2.1.0 <>... Sender ok Mar 12 03:04:37 ns spamd[27882]: prefork: child states: II Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: <-- RCPT To:<[EMAIL PROTECTED]> Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: Milter: rcpts: <[EMAIL PROTECTED]> Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: milter=spamassassin, action=rcpt, continue Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: milter=greylist, action=rcpt, continue Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: --- 250 2.1.5 <[EMAIL PROTECTED]>... Recipient ok Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: <-- DATA Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: --- 354 Enter mail, end with "." on a line by itself Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: from=<>, size=10878, class=0, nrcpts=1, msgid=<[EMAIL PROTECTED]>, proto=ESMTP, daemon=MTA, relay=ns.umpquanet.com [63.105.30.37] Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: milter=spamassassin, action=header, continue Mar 12 03:04:37 ns last message repeated 8 times Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: milter=spamassassin, action=eoh, continue Mar 12 03:04:37 ns sm-mta[44915]: k2CB4QKZ044915: milter=spamassassin, action=body, continue Mar 12 03:04:37 ns spamd[27906]: spamd: connection from localhost [127.0.0.1] at port 61249 Mar 12 03:04:37 ns spamd[27906]: spamd: setuid to root succeeded Mar 12 03:04:37 ns spamd[27906]: spamd: still running as root: user not specified with -u, not found, or set to root, falling back to nobody at /usr/local/bin/spamd line 1147, <GEN231> line 4. Mar 12 03:04:37 ns spamd[27906]: spamd: processing message <[EMAIL PROTECTED]> for root:65534 Mar 12 03:04:47 ns spamd[27906]: locker: safe_lock: cannot create tmp lockfile /root/.spamassassin/auto-whitelist.lock.ns.museum.rain.com.27906 for /root/.spamassassin/auto-whitelist.lock: Permission denied Mar 12 03:04:47 ns spamd[27906]: auto-whitelist: open of auto-whitelist file failed: locker: safe_lock: cannot create tmp lockfile /root/.spamassassin/auto-whitelist.lock.ns.museum.rain.com.27906 for /root/.spamassassin/auto-whitelist.lock: Permission denied Mar 12 03:04:47 ns spamd[27906]: Can't call method "finish" on an undefined value at /usr/local/lib/perl5/site_perl/5.8.7/Mail/SpamAssassin/Plugin/AWL.pm line 397. Mar 12 03:04:47 ns spamd[27906]: spamd: identified spam (7.5/5.0) for root:65534 in 10.2 seconds, 11219 bytes. Mar 12 03:04:47 ns spamd[27906]: spamd: result: Y 7 - UNPARSEABLE_RELAY,URIBL_JP_SURBL,URIBL_OB_SURBL,URIBL_WS_SURBL scantime=10.2,size=11219,user=root,uid=65534,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=61249,mid=<[EMAIL PROTECTED]>,autolearn=no Mar 12 03:04:47 ns sm-mta[44915]: k2CB4QKZ044915: Milter add: header: X-Spam-Flag: YES Mar 12 03:04:47 ns sm-mta[44915]: k2CB4QKZ044915: Milter add: header: X-Spam-Status: Yes, score=7.5 required=5.0 tests=UNPARSEABLE_RELAY,\n\tURIBL_JP_SURBL,URIBL_OB_SURBL,URIBL_WS_SURBL autolearn=no \n\tversion=3.1.0 Mar 12 03:04:47 ns sm-mta[44915]: k2CB4QKZ044915: milter=spamassassin, reject=550 5.7.1 Message content rejected Mar 12 03:04:47 ns sm-mta[44915]: k2CB4QKZ044915: Milter (greylist): abort filter Mar 12 03:04:47 ns sm-mta[44915]: k2CB4QKZ044915: Milter: data, reject=550 5.7.1 Message content rejected Mar 12 03:04:47 ns sm-mta[44915]: k2CB4QKZ044915: --- 550 5.7.1 Message content rejected (hold) Mar 12 03:04:47 ns sm-mta[44915]: k2CB4QKZ044915: to=<[EMAIL PROTECTED]>, delay=00:00:10, pri=40878, stat=Message content rejected Mar 12 03:04:47 ns sm-mta[44915]: k2CB4QKZ044915: --- 550 5.7.1 Message content rejected (held) Mar 12 03:04:47 ns sm-mta[44915]: k2CB4QKa044915: <-- RSET Mar 12 03:04:47 ns sm-mta[44915]: k2CB4QKa044915: --- 250 2.0.0 Reset state Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: <-- MAIL From:<> SIZE=11210 Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: Milter: senders: <> Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: milter=spamassassin, action=mail, continue Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: milter=greylist, action=mail, continue Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: --- 250 2.1.0 <>... Sender ok Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: <-- RCPT To:<[EMAIL PROTECTED]> Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: Milter: rcpts: <[EMAIL PROTECTED]> Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: milter=spamassassin, action=rcpt, continue Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: milter=greylist, action=rcpt, continue Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: --- 250 2.1.5 <[EMAIL PROTECTED]>... Recipient ok Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: <-- DATA Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: --- 354 Enter mail, end with "." on a line by itself Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: from=<>, size=12650, class=0, nrcpts=1, msgid=<[EMAIL PROTECTED]>, proto=ESMTP, daemon=MTA, relay=ns.umpquanet.com [63.105.30.37] Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: milter=spamassassin, action=header, continue Mar 12 03:04:48 ns last message repeated 8 times Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: milter=spamassassin, action=eoh, continue Mar 12 03:04:48 ns sm-mta[44915]: k2CB4QKb044915: milter=spamassassin, action=body, continue Mar 12 03:04:48 ns spamd[27906]: spamd: connection from localhost [127.0.0.1] at port 49944 Mar 12 03:04:48 ns spamd[27906]: spamd: setuid to root succeeded Mar 12 03:04:48 ns spamd[27906]: spamd: still running as root: user not specified with -u, not found, or set to root, falling back to nobody at /usr/local/bin/spamd line 1147, <GEN234> line 4. Mar 12 03:04:48 ns spamd[27906]: spamd: processing message <[EMAIL PROTECTED]> for root:65534 Mar 12 03:04:59 ns spamd[27906]: locker: safe_lock: cannot create tmp lockfile /root/.spamassassin/auto-whitelist.lock.ns.museum.rain.com.27906 for /root/.spamassassin/auto-whitelist.lock: Permission denied Mar 12 03:04:59 ns spamd[27906]: auto-whitelist: open of auto-whitelist file failed: locker: safe_lock: cannot create tmp lockfile /root/.spamassassin/auto-whitelist.lock.ns.museum.rain.com.27906 for /root/.spamassassin/auto-whitelist.lock: Permission denied Mar 12 03:04:59 ns spamd[27906]: Can't call method "finish" on an undefined value at /usr/local/lib/perl5/site_perl/5.8.7/Mail/SpamAssassin/Plugin/AWL.pm line 397. Mar 12 03:04:59 ns spamd[27906]: spamd: identified spam (7.5/5.0) for root:65534 in 10.9 seconds, 13046 bytes. Mar 12 03:04:59 ns spamd[27906]: spamd: result: Y 7 - UNPARSEABLE_RELAY,URIBL_JP_SURBL,URIBL_OB_SURBL,URIBL_WS_SURBL scantime=10.9,size=13046,user=root,uid=65534,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=49944,mid=<[EMAIL PROTECTED]>,autolearn=no Mar 12 03:04:59 ns sm-mta[44915]: k2CB4QKb044915: Milter add: header: X-Spam-Flag: YES Mar 12 03:04:59 ns sm-mta[44915]: k2CB4QKb044915: Milter add: header: X-Spam-Status: Yes, score=7.5 required=5.0 tests=UNPARSEABLE_RELAY,\n\tURIBL_JP_SURBL,URIBL_OB_SURBL,URIBL_WS_SURBL autolearn=no \n\tversion=3.1.0 Mar 12 03:04:59 ns sm-mta[44915]: k2CB4QKb044915: milter=spamassassin, reject=550 5.7.1 Message content rejected Mar 12 03:04:59 ns sm-mta[44915]: k2CB4QKb044915: Milter (greylist): abort filter Mar 12 03:04:59 ns sm-mta[44915]: k2CB4QKb044915: Milter: data, reject=550 5.7.1 Message content rejected Mar 12 03:04:59 ns sm-mta[44915]: k2CB4QKb044915: --- 550 5.7.1 Message content rejected (hold) Mar 12 03:04:59 ns sm-mta[44915]: k2CB4QKb044915: to=<[EMAIL PROTECTED]>, delay=00:00:11, pri=42650, stat=Message content rejected Mar 12 03:04:59 ns sm-mta[44915]: k2CB4QKb044915: --- 550 5.7.1 Message content rejected (held) Mar 12 03:04:59 ns sm-mta[44915]: k2CB4QKc044915: <-- QUIT Mar 12 03:04:59 ns sm-mta[44915]: k2CB4QKc044915: --- 221 2.0.0 ns.museum.rain.com closing connection
