Some more info-

Spamc is returning an I/O error (communicates on the loopback interface) for
around 60% of the times it runs. Also a script I made, which attempts to
re-run spamc until it succeeds is failing too (ends up with over 50+ tries
until I kill it); sometimes it works, and will only on the 1st try. We're
now running 3.2.1, and are still having the same problem.


eventhorizon5 wrote:
>
> 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#a11530617
Sent from the SpamAssassin - Users mailing list archive at Nabble.com.