--- Begin Message ---
Package: spamassassin
Version: 3.3.0-2
Severity: important
Ever since spamassassin 3.3.0 appeared in testing, I have found that spamd
periodically loses the ability to check ident. Since spamd treats a failed
connect to an ident server as an authentication error, it passes the mail
through unchecked (and I'm waking up most mornings to a couple hundred pill
spams). :-)
Two sets of logs follow, one for a normal spam delivery, and one for an
abnormal delivery. In these logs, $Net::Ident::debug is set, and the "dbg:
ident: FOO" lines are extra debugging lines I added to spamd. I am running
spamd from the command line to be able to capture the Net::Ident debug
output.
As you can see in the abnormal delivery, exim successfully connects to the
local ident server, but for some reason spamassassin doesn't ("connect
failed: 115")--however, oident shows an incoming connection attempt (but no
query).
* This happens with both oidentd and bidentd.
* Exim never becomes unable to connect to ident at any time.
* Restarting spamd always fixes the problem for a while.
* The problem starts again, randomly, after anywhere from a few hours up to
a day.
* The problem doesn't start at any predictable time of the day.
* The problem doesn't start after the update cron job runs.
* There are no rules in iptables that would explain this connect failure,
such as use of the connlimit match extension.
* /etc/spamassassin/* files are unchanged from the package.
* /etc/default/spamassassin is the following:
ENABLED=1
OPTIONS="--create-prefs --max-children 5 --helper-home-dir --allow-tell
--auth-ident -D ident"
PIDFILE="/var/run/spamd.pid"
CRON=1
I'm using --auth-ident and --allow-tell so that my users can use SquirrelMail
with
squirrelmail-spam-buttons to directly train their filters.
===============
Normal delivery
===============
--- exim4/mainlog ---
2010-03-15 09:09:40 1NrAzE-0006hu-3l <= [email protected] H=localhost
(MYDOMAIN.NET) [127.0.0.1] U=troy P=esmtp S=2648
2010-03-15 09:09:45 1NrAzE-0006hu-3l => troy <t...@localhost> R=procmail
T=procmail_pipe
2010-03-15 09:09:45 1NrAzE-0006hu-3l Completed
--- syslog ----
Mar 15 09:09:40 tiferet oidentd[25787]: Connection from localhost
(127.0.0.1):54021
Mar 15 09:09:40 tiferet oidentd[25787]: [localhost] Successful lookup: 48692 ,
25 : troy (troy)
Mar 15 09:09:40 tiferet spamd[23355]: spamd: connection from localhost
[127.0.0.1] at port 39727
Mar 15 09:09:40 tiferet oidentd[25794]: Connection from localhost
(127.0.0.1):60009
Mar 15 09:09:40 tiferet oidentd[25794]: [localhost] Successful lookup: 39727 ,
783 : troy (troy)
Mar 15 09:09:40 tiferet spamd[23355]: ident: FOO username = troy
Mar 15 09:09:40 tiferet spamd[23355]: ident: FOO ident_timeout = 5
Mar 15 09:09:40 tiferet spamd[23355]: ident: FOO ident_username = troy
Mar 15 09:09:40 tiferet spamd[23355]: ident: FOO dn = troy
Mar 15 09:09:40 tiferet spamd[23355]: ident: ident_username = troy,
spamc_username = troy
Mar 15 09:09:40 tiferet spamd[23355]: spamd: setuid to troy succeeded
Mar 15 09:09:40 tiferet spamd[23355]: spamd: processing message
<[email protected]> for troy:1000
Mar 15 09:09:45 tiferet spamd[23355]: spamd: identified spam (25.0/6.0) for
troy:1000 in 5.3 seconds, 2805 bytes.
Mar 15 09:09:45 tiferet spamd[23355]: spamd: result: Y 25 -
BAYES_80,DIGEST_MULTIPLE,HK_NAME_DRUGS,HTML_IMAGE_ONLY_20,HTML_IMAGE_RATIO_02,HTML_MESSAGE,HTML_SHORT_LINK_IMG_3,MIME_HTML_ONLY,MSGID_FROM_MTA_HEADER,PYZOR_CHECK,RAZOR2_CF_RANGE_51_100,RAZOR2_CF_RANGE_E8_51_100,RAZOR2_CHECK,RCVD_IN_BRBL_LASTEXT,RCVD_IN_PBL,RCVD_IN_PSBL,RCVD_IN_XBL,RDNS_DYNAMIC,SPF_FAIL,T_SURBL_MULTI1,URIBL_AB_SURBL,URIBL_JP_SURBL
scantime=5.3,size=2805,user=troy,uid=1000,required_score=6.0,rhost=localhost,raddr=127.0.0.1,rport=39727,mid=<[email protected]>,bayes=0.836190,autolearn=spam
Mar 15 09:09:45 tiferet spamd[22919]: prefork: child states: II
--- spamd output ---
Mar 15 09:09:40.245 [23355] info: spamd: connection from localhost [127.0.0.1]
at port 39727
Net::Ident::lookup fh=IO::Socket::INET6=GLOB(0xa9c1438), timeout=5
Net::Ident::new fh=IO::Socket::INET6=GLOB(0xa9c1438), timeout=5
Net::Ident::newFromInAddr localaddr=127.0.0.1:783, remoteaddr=127.0.0.1:39727,
timeout=5
Net::Ident::username
Net::Ident::ready blocking=true
Net::Ident::query
Net::Ident::ready received: 39727,783:USERID:UNIX:troy
Net::Ident::username returns:
userid = troy
opsys = UNIX
error = <undef>
Mar 15 09:09:40.247 [23355] dbg: ident: FOO username = troy
Mar 15 09:09:40.248 [23355] dbg: ident: FOO ident_timeout = 5
Mar 15 09:09:40.248 [23355] dbg: ident: FOO ident_username = troy
Mar 15 09:09:40.248 [23355] dbg: ident: FOO dn = troy
Mar 15 09:09:40.249 [23355] dbg: ident: ident_username = troy, spamc_username =
troy
Mar 15 09:09:40.249 [23355] info: spamd: setuid to troy succeeded
Mar 15 09:09:40.257 [23355] info: spamd: processing message
<[email protected]> for troy:1000
Mar 15 09:09:45.530 [23355] info: spamd: identified spam (25.0/6.0) for
troy:1000 in 5.3 seconds, 2805 bytes.
Mar 15 09:09:45.531 [23355] info: spamd: result: Y 25 -
BAYES_80,DIGEST_MULTIPLE,HK_NAME_DRUGS,HTML_IMAGE_ONLY_20,HTML_IMAGE_RATIO_02,HTML_MESSAGE,HTML_SHORT_LINK_IMG_3,MIME_HTML_ONLY,MSGID_FROM_MTA_HEADER,PYZOR_CHECK,RAZOR2_CF_RANGE_51_100,RAZOR2_CF_RANGE_E8_51_100,RAZOR2_CHECK,RCVD_IN_BRBL_LASTEXT,RCVD_IN_PBL,RCVD_IN_PSBL,RCVD_IN_XBL,RDNS_DYNAMIC,SPF_FAIL,T_SURBL_MULTI1,URIBL_AB_SURBL,URIBL_JP_SURBL
scantime=5.3,size=2805,user=troy,uid=1000,required_score=6.0,rhost=localhost,raddr=127.0.0.1,rport=39727,mid=<[email protected]>,bayes=0.836190,autolearn=spam
Mar 15 09:09:45.609 [22919] info: prefork: child states: II
=================
Abnormal Delivery
=================
--- exim4/mainlog ---
2010-03-15 13:31:29 1NrF4b-0008Ep-Jm <= [email protected]
H=localhost (MYDOMAIN.NET) [127.0.0.1] U=troy P=esmtp S=6187
id=002a01cac42a$a123d0f0$e36b72...@org
2010-03-15 13:31:29 1NrF4b-0008Ep-Jm => troy <t...@localhost> R=procmail
T=procmail_pipe
2010-03-15 13:31:29 1NrF4b-0008Ep-Jm Completed
--- syslog ---
Mar 15 13:31:29 tiferet oidentd[31672]: Connection from localhost
(127.0.0.1):53475
Mar 15 13:31:29 tiferet oidentd[31672]: [localhost] Successful lookup: 59942 ,
25 : troy (troy)
Mar 15 13:31:29 tiferet spamd[23355]: spamd: connection from localhost
[127.0.0.1] at port 54475
Mar 15 13:31:29 tiferet spamd[23355]: ident: FOO username = troy
Mar 15 13:31:29 tiferet oidentd[31679]: Connection from localhost
(127.0.0.1):37676
Mar 15 13:31:29 tiferet spamd[23355]: ident: FOO ident_timeout = 5
Mar 15 13:31:29 tiferet spamd[23355]: Use of uninitialized value
$ident_username in concatenation (.) or string at /usr/sbin/spamd line 2058,
<GEN733> line 2.
Mar 15 13:31:29 tiferet spamd[23355]: ident: FOO ident_username =
Mar 15 13:31:29 tiferet spamd[23355]: ident: FOO dn = NONE
Mar 15 13:31:29 tiferet spamd[23355]: ident: ident_username = NONE,
spamc_username = troy
Mar 15 13:31:29 tiferet spamd[23355]: spamd: ident username (NONE) does not
match spamc username (troy)
Mar 15 13:31:29 tiferet spamd[22919]: prefork: child states: II
--- spamd output ---
Mar 15 13:31:29.745 [23355] info: spamd: connection from localhost [127.0.0.1]
at port 54475
Net::Ident::lookup fh=IO::Socket::INET6=GLOB(0xa82f498), timeout=5
Net::Ident::new fh=IO::Socket::INET6=GLOB(0xa82f498), timeout=5
Net::Ident::newFromInAddr localaddr=127.0.0.1:783, remoteaddr=127.0.0.1:54475,
timeout=5
Net::Ident::new: connect failed: 115
Net::Ident::username
Net::Ident::ready blocking=true
Net::Ident::query
Mar 15 13:31:29.747 [23355] dbg: ident: FOO username = troy
Mar 15 13:31:29.747 [23355] dbg: ident: FOO ident_timeout = 5
Mar 15 13:31:29.748 [23355] warn: Use of uninitialized value $ident_username in
concatenation (.) or string at /usr/sbin/spamd line 2058, <GEN733> line 2.
Mar 15 13:31:29.748 [23355] dbg: ident: FOO ident_username =
Mar 15 13:31:29.749 [23355] dbg: ident: FOO dn = NONE
Mar 15 13:31:29.750 [23355] dbg: ident: ident_username = NONE, spamc_username =
troy
Mar 15 13:31:29.750 [23355] info: spamd: ident username (NONE) does not match
spamc username (troy)
Mar 15 13:31:29.829 [22919] info: prefork: child states: II
-- System Information:
Debian Release: squeeze/sid
APT prefers testing
APT policy: (500, 'testing')
Architecture: i386 (i686)
Kernel: Linux 2.6.32-trunk-686 (SMP w/2 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Versions of packages spamassassin depends on:
pn libarchive-tar-perl <none> (no description available)
ii libdigest-sha1-perl 2.12-1 NIST SHA-1 message digest algorith
ii libhtml-parser-perl 3.64-1 collection of modules that parse H
ii libnet-dns-perl 0.65-1 Perform DNS queries from a Perl sc
ii libnetaddr-ip-perl 4.024+dfsg-1 IP address manipulation module
ii libsocket6-perl 0.23-1 Perl extensions for IPv6
ii libsys-hostname-long-perl 1.4-2 Figure out the long (fully-qualifi
ii libwww-perl 5.834-1 Perl HTTP/WWW client/server librar
ii perl 5.10.1-11 Larry Wall's Practical Extraction
ii perl-modules [libio-zlib-pe 5.10.1-11 Core Perl modules
Versions of packages spamassassin recommends:
ii gcc 4:4.4.2-3 The GNU C compiler
ii gnupg 1.4.10-2 GNU privacy guard - a free PGP rep
ii libc6-dev 2.10.2-6 Embedded GNU C Library: Developmen
ii libio-socket-inet6-perl 2.54-1.1 Object interface for AF_INET6 doma
ii libmail-spf-perl 2.007-1 Perl implementation of Sender Poli
ii libsys-syslog-perl 0.27-1 Perl interface to the UNIX syslog(
ii make 3.81-7 An utility for Directing compilati
ii perl [libsys-syslog-perl] 5.10.1-11 Larry Wall's Practical Extraction
ii re2c 0.13.5-1 tool for generating fast C-based r
ii spamc 3.3.0-2 Client for SpamAssassin spam filte
Versions of packages spamassassin suggests:
ii libcompress-zlib-perl 2.024-1 Transitional dummy package for Com
ii libdbi-perl 1.609-1 Perl Database Interface (DBI)
ii libio-socket-ssl-perl 1.31-1 Perl module implementing object or
pn libmail-dkim-perl <none> (no description available)
ii libnet-ident-perl 1.20-5 lookup the username on the remote
ii perl [libcompress-zlib-perl] 5.10.1-11 Larry Wall's Practical Extraction
ii pyzor 1:0.5.0-2 spam-catcher using a collaborative
ii razor 1:2.85-3 spam-catcher using a collaborative
-- no debconf information
--- End Message ---
