And still it fails

[jpff <jp...@codemist.co.uk>]

I tried switching bayes off and it has run for 4 hrs before the
failing starts again

Apr 18 08:16:37 snout spamd[29102]: spamd: copy_config timeout, respawning child process after 1 messages at /usr/bin/spamd line 968. 
Apr 18 08:16:46 snout spamd[29096]: spamd: copy_config timeout, respawning child process after 1 messages at /usr/bin/spamd line 968. 
2007-04-18 08:17:16 1He4JI-0007Z8-MA spam acl condition: error reading from spamd socket: Connection timed out
2007-04-18 08:17:41 1He4JI-0007Z8-MA H=lists9.rootsweb.com [66.43.27.45] F=<en...@rootsweb.com> temporarily rejected after DATA
Apr 18 08:17:54 snout spamd[27089]: prefork: child states: BIBBB 
Apr 18 08:17:54 snout spamd[27089]: prefork: child states: BIBBB 
Apr 18 08:17:54 snout spamd[29101]: spamd: copy_config timeout, respawning child process after 1 messages at /usr/bin/spamd line 968. 
Apr 18 08:17:56 snout spamd[27089]: prefork: child states: BIBBB 
....
Apr 18 08:19:51 snout spamd[27089]: prefork: cannot ping 29102, file handle not defined, child likely to still be processing SIGCHLD handler after killing itself 
Apr 18 08:19:52 snout spamd[27089]: prefork: killing failed child 29102 fd=undefined at /usr/local/share/perl/5.8.4/Mail/SpamAssassin/SpamdForkScaling.pm line 137. 
Apr 18 08:19:52 snout spamd[27089]: prefork: killed child 29102 
Apr 18 08:19:52 snout spamd[27089]: prefork: cannot ping 29101, file handle not defined, child likely to still be processing SIGCHLD handler after killing itself 
Apr 18 08:19:52 snout spamd[27089]: prefork: killing failed child 29101 fd=undefined at /usr/local/share/perl/5.8.4/Mail/SpamAssassin/SpamdForkScaling.pm line 137. 
Apr 18 08:19:52 snout spamd[27089]: prefork: killed child 29101 
Apr 18 08:19:52 snout spamd[27089]: prefork: cannot ping 29096, file handle not defined, child likely to still be processing SIGCHLD handler after killing itself 
Apr 18 08:19:52 snout spamd[27089]: prefork: killing failed child 29096 fd=undefined at /usr/local/share/perl/5.8.4/Mail/SpamAssassin/SpamdForkScaling.pm line 137. 
Apr 18 08:19:52 snout spamd[27089]: prefork: killed child 29096 
Apr 18 08:19:54 snout spamd[27089]: spamd: handled cleanup of child pid 29096 due to SIGCHLD 
Apr 18 08:19:54 snout spamd[27089]: spamd: handled cleanup of child pid 29101 due to SIGCHLD 
Apr 18 08:19:54 snout spamd[27089]: spamd: handled cleanup of child pid 29102 due to SIGCHLD 

Is it really that case that I am the only one with this kind of problem?
==John ffitch

Re: And still it fails

["Daryl C. W. O'Shea" <sp...@dostech.ca>]

jpff wrote:
> I tried switching bayes off and it has run for 4 hrs before the
> failing starts again
> 
> Apr 18 08:16:37 snout spamd[29102]: spamd: copy_config timeout, respawning child process after 1 messages at /usr/bin/spamd line 968. 
> Apr 18 08:16:46 snout spamd[29096]: spamd: copy_config timeout, respawning child process after 1 messages at /usr/bin/spamd line 968. 
> 2007-04-18 08:17:16 1He4JI-0007Z8-MA spam acl condition: error reading from spamd socket: Connection timed out
> 2007-04-18 08:17:41 1He4JI-0007Z8-MA H=lists9.rootsweb.com [66.43.27.45] F=<en...@rootsweb.com> temporarily rejected after DATA
> Apr 18 08:17:54 snout spamd[27089]: prefork: child states: BIBBB 
> Apr 18 08:17:54 snout spamd[27089]: prefork: child states: BIBBB 
> Apr 18 08:17:54 snout spamd[29101]: spamd: copy_config timeout, respawning child process after 1 messages at /usr/bin/spamd line 968. 
> Apr 18 08:17:56 snout spamd[27089]: prefork: child states: BIBBB 
> ....
> Apr 18 08:19:51 snout spamd[27089]: prefork: cannot ping 29102, file handle not defined, child likely to still be processing SIGCHLD handler after killing itself 
> Apr 18 08:19:52 snout spamd[27089]: prefork: killing failed child 29102 fd=undefined at /usr/local/share/perl/5.8.4/Mail/SpamAssassin/SpamdForkScaling.pm line 137. 
> Apr 18 08:19:52 snout spamd[27089]: prefork: killed child 29102 
> Apr 18 08:19:52 snout spamd[27089]: prefork: cannot ping 29101, file handle not defined, child likely to still be processing SIGCHLD handler after killing itself 
> Apr 18 08:19:52 snout spamd[27089]: prefork: killing failed child 29101 fd=undefined at /usr/local/share/perl/5.8.4/Mail/SpamAssassin/SpamdForkScaling.pm line 137. 
> Apr 18 08:19:52 snout spamd[27089]: prefork: killed child 29101 
> Apr 18 08:19:52 snout spamd[27089]: prefork: cannot ping 29096, file handle not defined, child likely to still be processing SIGCHLD handler after killing itself 
> Apr 18 08:19:52 snout spamd[27089]: prefork: killing failed child 29096 fd=undefined at /usr/local/share/perl/5.8.4/Mail/SpamAssassin/SpamdForkScaling.pm line 137. 
> Apr 18 08:19:52 snout spamd[27089]: prefork: killed child 29096 
> Apr 18 08:19:54 snout spamd[27089]: spamd: handled cleanup of child pid 29096 due to SIGCHLD 
> Apr 18 08:19:54 snout spamd[27089]: spamd: handled cleanup of child pid 29101 due to SIGCHLD 
> Apr 18 08:19:54 snout spamd[27089]: spamd: handled cleanup of child pid 29102 due to SIGCHLD 
> 
> Is it really that case that I am the only one with this kind of problem?
> ==John ffitch


FWIW, I've only ever been able to reproduce this by getting a system to 
seriously swap thrash and/or by driving the load average above a few 
hundred.

Note that the copy_config timeout is causing the child to kill itself 
(intentionally) and then the "likely to still be processing SIGCHLD 
handler after killing itself" messages indicate that the child hadn't 
finished killing itself off (and hadn't yet told the parent it was doing 
so) before the parent initiated a child ping.  As the message suggests, 
though, the parent knows how to handle this so it isn't a problem.

So... there's nothing in your log snippet that indicates a fatal error 
or that spamd was doing anything that it wouldn't recover from.  Your 
log does indicate that your system is under some major load though.  2 
minutes and 34 seconds to kill off a child is an insane amount of time.

Deal with the system load and SA will likely oblige to doing things in a 
timely manner.


Daryl