Date: Thu, 29 Apr 2010 23:08:49 +0200 From: "Hans F. Nordhaug" <Hans.F.Nordhaug@hiMolde.no> To: freebsd-questions@freebsd.org Subject: Re: amavisd - exited on signal 11 - FreeBSD 8 with Perl 5.10 Message-ID: <20100429210849.GA14524@hiMolde.no> In-Reply-To: <20100429205840.GA14031@hiMolde.no> References: <20100429205840.GA14031@hiMolde.no>
next in thread | previous in thread | raw e-mail | index | archive | help
* Hans F. Nordhaug <Hans.F.Nordhaug@hiMolde.no> [2010-04-29]: > Hi! > > I have been happily running Postfix with amavisd-new (and Clamav > and SpamAssassin) on FreeBSD 7 with Perl 5.8 for a long time. > Recently, I upgraded to FreeBSD 8 and rebuilt all ports (after > updating). Suddenly I saw many > kernel: pid xxxxx (perl), uid 110: exited on signal 11 > lines in /var/log/messages and mailq returns some messages > with comments like: > > (lost connection with 127.0.0.1[127.0.0.1] while sending end > of data -- message may be sent more than once) > > I Googled and found that this could be related to do_ascii/UUlib > and disabled do_ascii in /usr/local/etc/amavisd.conf. That didn't fix > it. Then I read somewhere that this could be caused by problems with > nested regexp and that Perl 5.10 didn't have that problem. I upgraded > to Perl 5.10.1 (and rebuild all ports depending on it) and that also > didn't fix it. Currently all my port are up-to-date. > > I'm trying to log everything - "$sa_debug = 'all';" and > "$log_level = 5;" in amavisd.conf, but I don't really see the problem. > Recent example: > > /var/log/messages > ================== > Apr 29 22:49:21 myserver kernel: pid 74726 (perl), uid 110: exited on signal 11 > > /var/log/debug.log > ================== > Apr 29 22:49:20 myserver amavis[74726]: Net::Server: 2010/04/29-22:49:20 CONNECT TCP Peer: "127.0.0.1:32829" Local: "127.0.0.1:10024" > Apr 29 22:49:20 myserver amavis[74726]: loaded base policy bank > [ ... skipped many debug lines from amavis[74726] ... ] > Apr 29 22:49:20 myserver amavis[74726]: (74726-01) SpamControl: calling spam scanner SpamAssassin > Apr 29 22:49:20 myserver amavis[74726]: (74726-01) timer set to 320 s for SA (was 480 s) > Apr 29 22:49:20 myserver amavis[74726]: (74726-01) calling SA parse, SA version 3.3.1, 3.003001, data as GLOB > Apr 29 22:49:20 myserver amavis[74726]: (74726-01) CALLING SA check > Apr 29 22:49:21 myserver amavis[10435]: Net::Server: Starting "1" children > Apr 29 22:49:21 myserver amavis[75502]: Net::Server: Child Preforked (75502) > Apr 29 22:49:21 myserver amavis[75502]: entered child_init_hook > Apr 29 22:49:21 myserver amavis[75502]: SpamControl: init_child on SpamAssassin done > > So, is anyone else seeing this? Can you give me any hints? I'm happy to give you more > input if it is possible to turn on more debugging. OK, SA seems to log to /var/log/maillog so here we go: [ ... skipped many "SA dbg" lines ...] Apr 29 22:49:20 myserver amavis[74726]: (74726-01) SA dbg: locker: safe_lock: created /var/amavis/.spamassassin/bayes.lock.nordhaug.priv.no.74726 Apr 29 22:49:20 myserver amavis[74726]: (74726-01) SA dbg: locker: safe_lock: trying to get lock on /var/amavis/.spamassassin/bayes with 0 retries Apr 29 22:49:20 myserver amavis[74726]: (74726-01) SA dbg: locker: safe_lock: breaking stale /var/amavis/.spamassassin/bayes.lock: age=1272573511 now=1272574160 Apr 29 22:49:21 myserver amavis[74726]: (74726-01) SA dbg: locker: safe_lock: trying to get lock on /var/amavis/.spamassassin/bayes with 1 retries Apr 29 22:49:21 myserver amavis[74726]: (74726-01) SA dbg: locker: safe_lock: link to /var/amavis/.spamassassin/bayes.lock: link ok Apr 29 22:49:21 myserver amavis[74726]: (74726-01) SA dbg: bayes: tie-ing to DB file R/W /var/amavis/.spamassassin/bayes_toks Apr 29 22:49:21 myserver amavis[74726]: (74726-01) SA dbg: bayes: tie-ing to DB file R/W /var/amavis/.spamassassin/bayes_seen Apr 29 22:49:21 myserver amavis[74726]: (74726-01) SA dbg: bayes: found bayes db version 3 Apr 29 22:49:21 myserver amavis[74726]: (74726-01) SA dbg: locker: refresh_lock: refresh /var/amavis/.spamassassin/bayes.lock Apr 29 22:49:21 myserver postfix/lmtp[75499]: 595818A07C: to=<xyz@myserver>, relay=127.0.0.1[127.0.0.1]:10024, delay=1.1, delays=0.06/0.01/0.01/0.98, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending end of data -- message may be sent more than once) Apr 29 22:49:21 myserver amavis[75502]: TIMING [total 4 ms] - bdb-open: 4 (100%)100, rundown: 0 (0%)100 This didn't make it clearer for me, but maybe for you? Best regards, Hans
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20100429210849.GA14524>