From owner-freebsd-hackers@FreeBSD.ORG Fri Aug 11 17:58:31 2006 Return-Path: X-Original-To: hackers@freebsd.org Delivered-To: freebsd-hackers@FreeBSD.ORG Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id CAA2F16A4DD for ; Fri, 11 Aug 2006 17:58:31 +0000 (UTC) (envelope-from ulf@alameda.net) Received: from mail.alameda.net (mail.alameda.net [64.81.53.120]) by mx1.FreeBSD.org (Postfix) with ESMTP id 7000443D6B for ; Fri, 11 Aug 2006 17:58:31 +0000 (GMT) (envelope-from ulf@alameda.net) Received: by mail.alameda.net (Postfix, from userid 1000) id 5A71933C62; Fri, 11 Aug 2006 10:58:26 -0700 (PDT) Date: Fri, 11 Aug 2006 10:58:26 -0700 From: Ulf Zimmermann To: Jeremie Le Hen Message-ID: <20060811175825.GI37510@evil.alameda.net> References: <20060718221415.GI45191@evil.alameda.net> <20060811094623.GA39702@obiwan.tataz.chchile.org> Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20060811094623.GA39702@obiwan.tataz.chchile.org> User-Agent: Mutt/1.4.2.1i Organization: Alameda Networks, Inc. X-Operating-System: FreeBSD 5.3-STABLE X-ANI-MailScanner-Information: Please contact the ISP for more information X-ANI-MailScanner: Found to be clean X-ANI-MailScanner-From: ulf@alameda.net Cc: hackers@freebsd.org, Ulf Zimmermann Subject: Re: [fbsd] sshd throwing signal 6 (sigabrt) X-BeenThere: freebsd-hackers@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: ulf@Alameda.net List-Id: Technical Discussions relating to FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 11 Aug 2006 17:58:31 -0000 On Fri, Aug 11, 2006 at 11:46:24AM +0200, Jeremie Le Hen wrote: > Hi Ulf, > > On Tue, Jul 18, 2006 at 03:14:16PM -0700, Ulf Zimmermann wrote: > > I have a FreeBSD server (was 5.4-prerelease, now 6-stable as of noon PDT). > > On this server I got a problem with sshd throwing signal 6: > > > > Jul 18 15:04:03 log01 sshd[66161]: debug2: User child is on pid 66163 > > Jul 18 15:04:03 log01 sshd[66163]: debug3: PAM: opening session > > Jul 18 15:04:03 log01 sshd[66163]: debug1: PAM: reinitializing credentials > > Jul 18 15:04:03 log01 sshd[66163]: debug2: set_newkeys: mode 0 > > Jul 18 15:04:03 log01 sshd[66163]: debug2: set_newkeys: mode 1 > > Jul 18 15:04:03 log01 sshd[66163]: debug1: Entering interactive session for SSH2. > > Jul 18 15:04:03 log01 sshd[66163]: debug2: fd 5 setting O_NONBLOCK > > Jul 18 15:04:03 log01 sshd[66163]: debug2: fd 6 setting O_NONBLOCK > > Jul 18 15:04:03 log01 sshd[66163]: debug1: server_init_dispatch_20 > > Jul 18 15:04:03 log01 sshd[66163]: debug1: server_input_channel_open: ctype session rchan 0 win 131072 max 32768 > > Jul 18 15:04:03 log01 sshd[66163]: debug1: input_session_request > > Jul 18 15:04:03 log01 sshd[66163]: debug1: channel 0: new [server-session] > > Jul 18 15:04:03 log01 sshd[66163]: debug1: session_new: init > > Jul 18 15:04:03 log01 sshd[66163]: debug1: session_new: session 0 > > Jul 18 15:04:03 log01 sshd[66163]: debug1: session_open: channel 0 > > Jul 18 15:04:03 log01 sshd[66163]: debug1: session_open: session 0: link with channel 0 > > Jul 18 15:04:03 log01 sshd[66163]: debug1: server_input_channel_open: confirm session > > Jul 18 15:04:03 log01 sshd[66163]: debug1: server_input_channel_req: channel 0 request exec reply 0 > > Jul 18 15:04:03 log01 sshd[66163]: debug1: session_by_channel: session 0 channel 0 > > Jul 18 15:04:03 log01 sshd[66163]: debug1: session_input_channel_req: session 0 req exec > > Jul 18 15:04:03 log01 sshd[66163]: debug2: fd 8 setting O_NONBLOCK > > Jul 18 15:04:03 log01 sshd[66163]: debug3: fd 8 is O_NONBLOCK > > Jul 18 15:04:03 log01 sshd[66163]: debug2: fd 10 setting O_NONBLOCK > > Jul 18 15:04:03 log01 sshd[66163]: debug2: channel 0: rcvd eof > > Jul 18 15:04:03 log01 sshd[66163]: debug2: channel 0: output open -> drain > > Jul 18 15:04:03 log01 sshd[66163]: debug2: channel 0: obuf empty > > Jul 18 15:04:03 log01 sshd[66163]: debug2: channel 0: close_write > > Jul 18 15:04:03 log01 sshd[66163]: debug2: channel 0: output drain -> closed > > Jul 18 15:04:03 log01 pid 66163 (sshd), uid 10042: exited on signal 6 > > > > About 80 servers have two cronjobs each starting at the full hour. Each > > cronjob has a random sleep of 0 to 900 seconds before it executes ssh/scp/rsync > > to copy one or multiple files to that FreeBSD server. One cronjob copies > > one file ranging in size 30KB to 300KB. The other cronjob copies 10-30 > > RRD files, ranging in size from 200KB to 1MB. > > > > Of these about 160 ssh connections in a time range of 15 minutes, I get > > 1 to 10 errors at the end of the connection. All files get copied as far > > I can tell but when the connection closes I see the above signal 6. > > > > On the source side of the ssh connection I get error messages like > > > > "Connection to xxxx closed by remote host" > > "ssh_exchange_identification: Connection closed by remote host lost connection" > > > > Anyone have an idea what the problem could be that sshd see sigabrt? > > % obiwan:openssh$ grep -rl SIGABRT . | wc -l > % 0 > > This should come from one of the underlying librairies sshd(8) is > linked to. > > Do you run by chance 6-STABLE with ProPolice/SSP patch ? If a > stack-based buffer overflow is detected, SIGABRT (signal 6) will > be sent to the faulty process. > > Regards, > -- > Jeremie Le Hen I was running a 5.3-PRERELEASE and now it is running 6.1-STABLE (Jul 18). Pretty much a plain box, the only thing added are things like Apache, PHP, syslog-ng. There should not be an overflow, as these are regular ssh connections. The upgrade to 6.1-STABLE made things happen less often, but they still happen. Mostly during close of connection, much more rarely during opening of the connection. -- Regards, Ulf. --------------------------------------------------------------------- Ulf Zimmermann, 1525 Pacific Ave., Alameda, CA-94501, #: 510-865-0204 You can find my resume at: http://seven.Alameda.net/~ulf/resume.html