We're running SA 3.1.7 (Debian Etch version) here on a fairly active mail
server, and have recently been experiencing a lot of random spamc crashes
(postfix pipes the message to spamc, which crashes, and then reverts to just
delivering the message). Here's our postfix setup:

(excerpt from master.cf; also shows the old command that was used):
----------
spamassassin unix - n n - - pipe
#user=spamd argv=/usr/bin/spamc -e /usr/sbin/sendmail -oi -f
${sender} ${recipient}
flags=Rq user=spamd argv=/usr/local/bin/filter.sh -f ${sender} --
${recipient}
----------

and filter.sh:
----------
#!/bin/sh
/usr/bin/spamc -u spamd | /usr/sbin/sendmail -i "$@"
----------

The logfile shows this when one fails:

Jul 9 14:47:27 mail spamd[22607]: spamd: clean message (0.2/5.4) for
spamd:7138 in 0.8 seconds, 4316 bytes.
Jul 9 14:47:27 mail spamd[22607]: spamd: result: . 0 - AWL,BAYES_20
scantime=0.8,size=4316,user=spamd,uid=7138,require d_score=5.4,rhost=mail.onshore.net,raddr=127.0.0.1 ,rport=52375,mid=<200707091947.l69JlQlk026302@wallace.careenhance.co m>,bayes=0.158707429227846,autolearn=no
Jul 9 14:47:27 mail spamd[22607]: config: copying current conf from backup
Jul 9 14:47:28 mail spamd[22607]: prefork: sysread(9) not ready, wait max
300 secs
Jul 9 14:47:28 mail spamd[32346]: prefork: child 22607: entering state 1
Jul 9 14:47:28 mail spamd[32346]: prefork: new lowest idle kid: 22607
Jul 9 14:47:28 mail spamd[32346]: prefork: child reports idle
Jul 9 14:47:28 mail spamd[32346]: prefork: child states: II
Jul 9 14:47:32 mail spamd[32346]: prefork: ordered 22607 to accept
Jul 9 14:47:32 mail spamd[22607]: spamd: connection from mail.onshore.net
[127.0.0.1] at port 52379
Jul 9 14:47:32 mail spamd[32346]: prefork: child 22607: entering state 2
Jul 9 14:47:32 mail spamd[32346]: prefork: new lowest idle kid: 22633
Jul 9 14:47:32 mail spamd[32346]: prefork: new lowest idle kid: 22633
Jul 9 14:47:32 mail spamd[32346]: spamd: handled cleanup of child pid 22607
due to SIGCHLD
Jul 9 14:47:32 mail spamd[32346]: prefork: child closed connection
Jul 9 14:47:32 mail spamd[32346]: prefork: child states: I
Jul 9 14:47:32 mail spamd[32346]: spamd: server successfully spawned child
process, pid 22657
Jul 9 14:47:32 mail spamd[22657]: prefork: sysread(9) not ready, wait max
300 secs


and here's an strace dump of one of the failed spamc processes:

---------------------------
17:54:38 execve("/usr/bin/spamc", ["/usr/bin/spamc", "-x", "-u", "spamd"],
[/* 6 vars */]) = 0
17:54:38 uname({sys="Linux", node="mail", ...}) = 0
17:54:38 brk(0) = 0x8050000
17:54:38 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
17:54:38 mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS,
-1, 0) = 0xb7f34000
17:54:38 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or
directory)
17:54:38 open("/etc/ld.so.cache", O_RDONLY) = 3
17:54:38 fstat64(3, {st_mode=S_IFREG|0644, st_size=20915, ...}) = 0
17:54:38 mmap2(NULL, 20915, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7f2e000
17:54:38 close(3) = 0
17:54:38 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
17:54:38 open("/usr/lib/i686/cmov/libssl.so.0.9.8", O_RDONLY) = 3
17:54:38 read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0P\2 55\0"..., 512) = 512
17:54:38 fstat64(3, {st_mode=S_IFREG|0644, st_size=252640, ...}) = 0
17:54:38 mmap2(NULL, 255604, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE,
3, 0) = 0xb7eef000
17:54:38 mmap2(0xb7f2a000, 16384, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3a) = 0xb7f2a000
17:54:38 close(3) = 0
17:54:38 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
17:54:38 open("/usr/lib/i686/cmov/libcrypto.so.0.9.8", O_RDONLY) = 3
17:54:38 read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\30 0Y\3"..., 512) = 512
17:54:38 fstat64(3, {st_mode=S_IFREG|0644, st_size=1270520, ...}) = 0
17:54:38 mmap2(NULL, 1282904, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7db5000
17:54:38 mmap2(0xb7ed7000, 81920, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x122) = 0xb7ed7000
17:54:38 mmap2(0xb7eeb000, 13144, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7eeb000
17:54:38 close(3) = 0
17:54:38 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS,
-1, 0) = 0xb7db4000
17:54:38 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
17:54:38 open("/lib/tls/i686/cmov/libdl.so.2", O_RDONLY) = 3
17:54:38 read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\20 \f\0"..., 512) = 512
17:54:38 fstat64(3, {st_mode=S_IFREG|0644, st_size=9592, ...}) = 0
17:54:38 mmap2(NULL, 12404, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE,
3, 0) = 0xb7db0000
17:54:38 mmap2(0xb7db2000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1) = 0xb7db2000
17:54:38 close(3) = 0
17:54:38 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
17:54:38 open("/lib/tls/i686/cmov/libc.so.6", O_RDONLY) = 3
17:54:38 read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\24 0O\1"..., 512) = 512
17:54:38 fstat64(3, {st_mode=S_IFREG|0644, st_size=1241392, ...}) = 0
17:54:38 mmap2(NULL, 1247388, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7c7f000
17:54:38 mmap2(0xb7da6000, 28672, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x127) = 0xb7da6000
17:54:38 mmap2(0xb7dad000, 10396, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7dad000
17:54:38 close(3) = 0
17:54:38 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
17:54:38 open("/usr/lib/libz.so.1", O_RDONLY) = 3
17:54:38 read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\34 0\26"..., 512) = 512
17:54:38 fstat64(3, {st_mode=S_IFREG|0644, st_size=78500, ...}) = 0
17:54:38 mmap2(NULL, 81456, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE,
3, 0) = 0xb7c6b000
17:54:38 mmap2(0xb7c7e000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x12) = 0xb7c7e000
17:54:38 close(3) = 0
17:54:38 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS,
-1, 0) = 0xb7c6a000
17:54:38 mprotect(0xb7da6000, 20480, PROT_READ) = 0
17:54:38 set_thread_area({entry_number:-1 -> 6, base_addr:0xb7c6a6c0,
limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1,
seg_not_present:0, useable:1}) = 0
17:54:38 munmap(0xb7f2e000, 20915) = 0
17:54:38 rt_sigaction(SIGPIPE, {SIG_IGN}, {SIG_IGN}, 8) = 0
17:54:38 brk(0) = 0x8050000
17:54:38 brk(0x8071000) = 0x8071000
17:54:38 open("/etc/spamassassin/spamc.conf", O_RDONLY) = -1 ENOENT (No such
file or directory)
17:54:38 mmap2(NULL, 258048, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7c2b000
17:54:38 rt_sigaction(SIGALRM, {0x804cc70, [], 0}, {SIG_DFL}, 8) = 0
17:54:38 read(0, "Return-Path: 17:54:38 rt_sigaction(SIGALRM, {SIG_DFL}, {0x804cc70, [], 0}, 8) = 0
17:54:38 rt_sigaction(SIGALRM, {0x804cc70, [], 0}, {SIG_DFL}, 8) = 0
17:54:38 read(0, "", 251735) = 0
17:54:38 rt_sigaction(SIGALRM, {SIG_DFL}, {0x804cc70, [], 0}, 8) = 0
17:54:38 mmap2(NULL, 274432, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7be8000
17:54:38 socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
17:54:38 rt_sigaction(SIGALRM, {0x804cc70, [], 0}, {SIG_DFL}, 8) = 0
17:54:38 alarm(600) = 0
17:54:38 connect(3, {sa_family=AF_INET, sin_port=htons(783),
sin_addr=inet_addr("127.0.0.1")}, 16) = 0
17:54:38 alarm(0) = 600
17:54:38 rt_sigaction(SIGALRM, {SIG_DFL}, {0x804cc70, [], 0}, 8) = 0
17:54:38 send(3, "PROCESS SPAMC/1.3\r\nUser: spamd\r\n"..., 56, 0) = 56
17:54:38 send(3, "Return-Path: 17:54:38 shutdown(3, 1 /* send */) = 0
17:54:38 rt_sigaction(SIGALRM, {0x804cc70, [], 0}, {SIG_DFL}, 8) = 0
17:54:38 alarm(600) = 0
17:54:38 recv(3, 0xbf8cd178, 1, 0) = -1 ECONNRESET (Connection reset by
peer)
17:54:38 alarm(0) = 600
17:54:38 rt_sigaction(SIGALRM, {SIG_DFL}, {0x804cc70, [], 0}, 8) = 0
17:54:38 munmap(0xb7be8000, 274432) = 0
17:54:38 close(3) = 0
17:54:38 write(1, "Return-Path: 17:54:38 rt_sigaction(SIGALRM, {0x804cc70, [], 0}, {SIG_DFL}, 8) = 0
17:54:38 read(0, "", 8192) = 0
17:54:38 rt_sigaction(SIGALRM, {SIG_DFL}, {0x804cc70, [], 0}, 8) = 0
17:54:38 munmap(0xb7c2b000, 258048) = 0
17:54:38 exit_group(74) = ?
Process 18350 detached
-----------------------------------

--
Ryan Thoryk
System Administrator
onShore Networks, LLC
1407 West Chicago Avenue
Chicago, Illinois 60622
www.onshore.com

--
View this message in context: http://www.nabble.com/Random-spamc-c...html#a11512698
Sent from the SpamAssassin - Users mailing list archive at Nabble.com.