From owner-freebsd-questions@FreeBSD.ORG Thu Apr 29 21:08:51 2010 Return-Path: Delivered-To: freebsd-questions@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id 5E617106566B for ; Thu, 29 Apr 2010 21:08:51 +0000 (UTC) (envelope-from Hans.F.Nordhaug@hiMolde.no) Received: from malle.himolde.no (malle.hiMolde.no [158.38.68.22]) by mx1.freebsd.org (Postfix) with ESMTP id DA3918FC17 for ; Thu, 29 Apr 2010 21:08:50 +0000 (UTC) Received: from harr.himolde.no (harr.hiMolde.no [158.38.68.20]) by malle.himolde.no (8.13.8/8.13.8) with ESMTP id o3TL8nDu011249 for ; Thu, 29 Apr 2010 23:08:49 +0200 Received: from harr.himolde.no (harr.himolde.no [127.0.0.1]) by harr.himolde.no (8.13.1/8.13.1) with ESMTP id o3TL8n3M014707 for ; Thu, 29 Apr 2010 23:08:49 +0200 Received: (from nordhaug@localhost) by harr.himolde.no (8.13.1/8.13.1/Submit) id o3TL8nMR014706 for freebsd-questions@freebsd.org; Thu, 29 Apr 2010 23:08:49 +0200 Date: Thu, 29 Apr 2010 23:08:49 +0200 From: "Hans F. Nordhaug" To: freebsd-questions@freebsd.org Message-ID: <20100429210849.GA14524@hiMolde.no> References: <20100429205840.GA14031@hiMolde.no> Mime-Version: 1.0 Content-Type: text/plain; charset=iso-8859-1 Content-Disposition: inline In-Reply-To: <20100429205840.GA14031@hiMolde.no> User-Agent: Mutt/1.4.1i Subject: Re: amavisd - exited on signal 11 - FreeBSD 8 with Perl 5.10 X-BeenThere: freebsd-questions@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: User questions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 29 Apr 2010 21:08:51 -0000 * Hans F. Nordhaug [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=, 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