From owner-freebsd-firewire@FreeBSD.ORG Mon Dec 15 11:06:51 2008 Return-Path: Delivered-To: freebsd-firewire@FreeBSD.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 6F034106564A for ; Mon, 15 Dec 2008 11:06:51 +0000 (UTC) (envelope-from owner-bugmaster@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [IPv6:2001:4f8:fff6::28]) by mx1.freebsd.org (Postfix) with ESMTP id 4833D8FC17 for ; Mon, 15 Dec 2008 11:06:51 +0000 (UTC) (envelope-from owner-bugmaster@FreeBSD.org) Received: from freefall.freebsd.org (localhost [127.0.0.1]) by freefall.freebsd.org (8.14.3/8.14.3) with ESMTP id mBFB6p2V004309 for ; Mon, 15 Dec 2008 11:06:51 GMT (envelope-from owner-bugmaster@FreeBSD.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.14.3/8.14.3/Submit) id mBFB6oEP004305 for freebsd-firewire@FreeBSD.org; Mon, 15 Dec 2008 11:06:50 GMT (envelope-from owner-bugmaster@FreeBSD.org) Date: Mon, 15 Dec 2008 11:06:50 GMT Message-Id: <200812151106.mBFB6oEP004305@freefall.freebsd.org> X-Authentication-Warning: freefall.freebsd.org: gnats set sender to owner-bugmaster@FreeBSD.org using -f From: FreeBSD bugmaster To: freebsd-firewire@FreeBSD.org Cc: Subject: Current problem reports assigned to freebsd-firewire@FreeBSD.org X-BeenThere: freebsd-firewire@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Firewire support in FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 15 Dec 2008 11:06:51 -0000 Note: to view an individual PR, use: http://www.freebsd.org/cgi/query-pr.cgi?pr=(number). The following is a listing of current problems submitted by FreeBSD users. These represent problem reports covering all versions including experimental development code and obsolete releases. S Tracker Resp. Description -------------------------------------------------------------------------------- o kern/113785 firewire [firewire] dropouts when playing DV on firewire o kern/74238 firewire [firewire] fw_rcv: unknown response; firewire ad-hoc w 2 problems total. From owner-freebsd-firewire@FreeBSD.ORG Tue Dec 16 05:10:10 2008 Return-Path: Delivered-To: freebsd-firewire@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id B752610656F1 for ; Tue, 16 Dec 2008 05:10:04 +0000 (UTC) (envelope-from freebsd@sopwith.solgatos.com) Received: from sopwith.solgatos.com (pool-71-182-69-106.ptldor.fios.verizon.net [71.182.69.106]) by mx1.freebsd.org (Postfix) with ESMTP id 9896F8FC14 for ; Tue, 16 Dec 2008 05:10:02 +0000 (UTC) (envelope-from freebsd@sopwith.solgatos.com) Received: by sopwith.solgatos.com (Postfix, from userid 66) id 5C88E3F22; Mon, 15 Dec 2008 20:53:55 -0800 (PST) Received: from localhost by sopwith.solgatos.com (8.8.8/6.24) id DAA27074; Mon, 15 Dec 2008 03:30:04 GMT Message-Id: <200812150330.DAA27074@sopwith.solgatos.com> To: freebsd-firewire@freebsd.org, freebsd-drivers@freebsd.org Date: Sun, 14 Dec 2008 19:30:04 +0000 From: Dieter Cc: bug-followup@FreeBSD.org Subject: Re: kern/118093: firewire bus reset hogs CPU, causing data to be lost X-BeenThere: freebsd-firewire@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Firewire support in FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 16 Dec 2008 05:10:10 -0000 I found the source of this problem. When a firewire bus resets, the firewire driver prints a few lines to the console, using printf(9) and device_printf(9). I suspect that these are running at splfw aka splimp, locking out other i/o. Commenting out the *printf() calls fixes the problem, but that isn't a good solution. Would changing the *printf() calls to log(9) calls be safe? ("safe" meaning other i/o doesn't get locked out) Ah, for the good old days when 19200 baud seemed fast... From owner-freebsd-firewire@FreeBSD.ORG Tue Dec 16 05:14:34 2008 Return-Path: Delivered-To: freebsd-firewire@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 2CBBF106564A for ; Tue, 16 Dec 2008 05:14:34 +0000 (UTC) (envelope-from sbruno@miralink.com) Received: from plato.miralink.com (mail.miralink.com [70.103.185.20]) by mx1.freebsd.org (Postfix) with ESMTP id 03ADC8FC19 for ; Tue, 16 Dec 2008 05:14:33 +0000 (UTC) (envelope-from sbruno@miralink.com) Received: from localhost (localhost.localdomain [127.0.0.1]) by plato.miralink.com (Postfix) with ESMTP id 9B66A1A9115; Mon, 15 Dec 2008 21:14:33 -0800 (PST) X-Virus-Scanned: amavisd-new at X-Spam-Flag: NO X-Spam-Score: -4.399 X-Spam-Level: X-Spam-Status: No, score=-4.399 tagged_above=-10 required=6.6 tests=[ALL_TRUSTED=-1.8, BAYES_00=-2.599] Received: from plato.miralink.com ([127.0.0.1]) by localhost (plato.miralink.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id Arvkv1hJ5-d5; Mon, 15 Dec 2008 21:14:33 -0800 (PST) Received: from [10.47.1.6] (vpn.office.miralink.com [10.0.0.5]) by plato.miralink.com (Postfix) with ESMTP id E187B1A90E6; Mon, 15 Dec 2008 21:14:32 -0800 (PST) Message-ID: <49473938.80906@miralink.com> Date: Mon, 15 Dec 2008 21:14:32 -0800 From: Sean Bruno User-Agent: Thunderbird 2.0.0.18 (X11/20081119) MIME-Version: 1.0 To: Dieter References: <200812150330.DAA27074@sopwith.solgatos.com> In-Reply-To: <200812150330.DAA27074@sopwith.solgatos.com> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Cc: freebsd-firewire@freebsd.org, bug-followup@FreeBSD.org Subject: Re: kern/118093: firewire bus reset hogs CPU, causing data to be lost X-BeenThere: freebsd-firewire@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Firewire support in FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 16 Dec 2008 05:14:34 -0000 Dieter wrote: > I found the source of this problem. When a firewire bus resets, > the firewire driver prints a few lines to the console, > using printf(9) and device_printf(9). I suspect that these are > running at splfw aka splimp, locking out other i/o. > > Commenting out the *printf() calls fixes the problem, but that > isn't a good solution. > > Would changing the *printf() calls to log(9) calls be safe? > ("safe" meaning other i/o doesn't get locked out) > > Ah, for the good old days when 19200 baud seemed fast... > _______________________________________________ > Which one are you looking at Dieter? Sean From owner-freebsd-firewire@FreeBSD.ORG Tue Dec 16 05:35:08 2008 Return-Path: Delivered-To: freebsd-firewire@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 933D91065672; Tue, 16 Dec 2008 05:35:08 +0000 (UTC) (envelope-from ikob@ni.aist.go.jp) Received: from mail.asahi-net.or.jp (mail2.asahi-net.or.jp [202.224.39.198]) by mx1.freebsd.org (Postfix) with ESMTP id 605B18FC0C; Tue, 16 Dec 2008 05:35:08 +0000 (UTC) (envelope-from ikob@ni.aist.go.jp) Received: from dhcpa11093.tky.aist.go.jp (unknown [150.82.175.93]) by mail.asahi-net.or.jp (Postfix) with ESMTP id C75126806D; Tue, 16 Dec 2008 14:17:11 +0900 (JST) Message-Id: <15EB8FB3-CAA8-4834-9979-912508B619D4@ni.aist.go.jp> From: Katsushi Kobayashi To: Dieter In-Reply-To: <200812150330.DAA27074@sopwith.solgatos.com> Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit Mime-Version: 1.0 (Apple Message framework v930.3) Date: Tue, 16 Dec 2008 14:17:10 +0900 References: <200812150330.DAA27074@sopwith.solgatos.com> X-Mailer: Apple Mail (2.930.3) Cc: freebsd-firewire@freebsd.org, freebsd-drivers@freebsd.org, bug-followup@freebsd.org Subject: Re: kern/118093: firewire bus reset hogs CPU, causing data to be lost X-BeenThere: freebsd-firewire@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Firewire support in FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 16 Dec 2008 05:35:08 -0000 Hi, I believe no side effect is anticipated the message. "side effect" includes locking i/o. ---- Katsushi Kobayashi On 2008/12/15, at 4:30, Dieter wrote: > I found the source of this problem. When a firewire bus resets, > the firewire driver prints a few lines to the console, > using printf(9) and device_printf(9). I suspect that these are > running at splfw aka splimp, locking out other i/o. > > Commenting out the *printf() calls fixes the problem, but that > isn't a good solution. > > Would changing the *printf() calls to log(9) calls be safe? > ("safe" meaning other i/o doesn't get locked out) > > Ah, for the good old days when 19200 baud seemed fast... > _______________________________________________ > freebsd-firewire@freebsd.org mailing list > http://lists.freebsd.org/mailman/listinfo/freebsd-firewire > To unsubscribe, send any mail to "freebsd-firewire-unsubscribe@freebsd.org" From owner-freebsd-firewire@FreeBSD.ORG Tue Dec 16 06:03:20 2008 Return-Path: Delivered-To: freebsd-firewire@FreeBSD.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id A2E431065670; Tue, 16 Dec 2008 06:03:20 +0000 (UTC) (envelope-from imp@bsdimp.com) Received: from harmony.bsdimp.com (bsdimp.com [199.45.160.85]) by mx1.freebsd.org (Postfix) with ESMTP id 5E1708FC1F; Tue, 16 Dec 2008 06:03:20 +0000 (UTC) (envelope-from imp@bsdimp.com) Received: from localhost (localhost [127.0.0.1]) by harmony.bsdimp.com (8.14.2/8.14.1) with ESMTP id mBG61UKQ048412; Mon, 15 Dec 2008 23:01:30 -0700 (MST) (envelope-from imp@bsdimp.com) Date: Mon, 15 Dec 2008 23:01:30 -0700 (MST) Message-Id: <20081215.230130.74702477.imp@bsdimp.com> To: freebsd@sopwith.solgatos.com From: Warner Losh In-Reply-To: <200812150330.DAA27074@sopwith.solgatos.com> References: <200812150330.DAA27074@sopwith.solgatos.com> X-Mailer: Mew version 3.3 on Emacs 21.3 / Mule 5.0 (SAKAKI) Mime-Version: 1.0 Content-Type: Text/Plain; charset=us-ascii Content-Transfer-Encoding: 7bit Cc: freebsd-firewire@FreeBSD.org, freebsd-drivers@FreeBSD.org, bug-followup@FreeBSD.org Subject: Re: kern/118093: firewire bus reset hogs CPU, causing data to be lost X-BeenThere: freebsd-firewire@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Firewire support in FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 16 Dec 2008 06:03:20 -0000 > I found the source of this problem. When a firewire bus resets, > the firewire driver prints a few lines to the console, > using printf(9) and device_printf(9). I suspect that these are > running at splfw aka splimp, locking out other i/o. This can't be the case. There's no SPL involved at all. Maybe removing the printfs causes an interrupt to be serviced faster, resulting in what appears to be better performance... > Commenting out the *printf() calls fixes the problem, but that > isn't a good solution. > > Would changing the *printf() calls to log(9) calls be safe? > ("safe" meaning other i/o doesn't get locked out) > > Ah, for the good old days when 19200 baud seemed fast... > _______________________________________________ > freebsd-drivers@freebsd.org mailing list > http://lists.freebsd.org/mailman/listinfo/freebsd-drivers > To unsubscribe, send any mail to "freebsd-drivers-unsubscribe@freebsd.org" > > From owner-freebsd-firewire@FreeBSD.ORG Wed Dec 17 05:10:24 2008 Return-Path: Delivered-To: freebsd-firewire@FreeBSD.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 1AC52106564A; Wed, 17 Dec 2008 05:10:24 +0000 (UTC) (envelope-from freebsd@sopwith.solgatos.com) Received: from sopwith.solgatos.com (pool-71-182-69-106.ptldor.fios.verizon.net [71.182.69.106]) by mx1.freebsd.org (Postfix) with ESMTP id 8C7028FC18; Wed, 17 Dec 2008 05:10:22 +0000 (UTC) (envelope-from freebsd@sopwith.solgatos.com) Received: by sopwith.solgatos.com (Postfix, from userid 66) id 9B0D13F22; Tue, 16 Dec 2008 20:51:06 -0800 (PST) Received: from localhost by sopwith.solgatos.com (8.8.8/6.24) id DAA17848; Wed, 17 Dec 2008 03:29:13 GMT Message-Id: <200812170329.DAA17848@sopwith.solgatos.com> To: freebsd-firewire@FreeBSD.org, freebsd-drivers@FreeBSD.org, bug-followup@FreeBSD.org In-reply-to: Your message of "Tue, 16 Dec 2008 09:51:44 PST." <4947EAB0.3020704@miralink.com> Date: Tue, 16 Dec 2008 19:29:13 +0000 From: Dieter Cc: Subject: Re: kern/118093: firewire bus reset hogs CPU, causing data to be lost X-BeenThere: freebsd-firewire@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Firewire support in FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 17 Dec 2008 05:10:24 -0000 Sean> Which file in dev/firewire are you looking at? fwohci.c and firewire.c examples: printf("non CYCLEMASTER mode\n"); device_printf(fc->dev, "Initiate bus reset\n"); ------------------- Warner> This can't be the case. There's no SPL involved at all. Maybe Warner> removing the printfs causes an interrupt to be serviced faster, Warner> resulting in what appears to be better performance... With the printfs, Ethernet is not getting serviced. This is repeatable and easily reproduced. Without the printfs, it seems ok. If it isn't spl, what is locking out Ethernet? From owner-freebsd-firewire@FreeBSD.ORG Wed Dec 17 07:00:25 2008 Return-Path: Delivered-To: freebsd-firewire@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 196401065674; Wed, 17 Dec 2008 07:00:25 +0000 (UTC) (envelope-from imp@bsdimp.com) Received: from harmony.bsdimp.com (bsdimp.com [199.45.160.85]) by mx1.freebsd.org (Postfix) with ESMTP id C64458FC40; Wed, 17 Dec 2008 07:00:24 +0000 (UTC) (envelope-from imp@bsdimp.com) Received: from localhost (localhost [127.0.0.1]) by harmony.bsdimp.com (8.14.2/8.14.1) with ESMTP id mBH6xbN5070526; Tue, 16 Dec 2008 23:59:37 -0700 (MST) (envelope-from imp@bsdimp.com) Date: Tue, 16 Dec 2008 23:59:41 -0700 (MST) Message-Id: <20081216.235941.1266245051.imp@bsdimp.com> To: freebsd@sopwith.solgatos.com From: "M. Warner Losh" In-Reply-To: <200812170329.DAA17848@sopwith.solgatos.com> References: <4947EAB0.3020704@miralink.com> <200812170329.DAA17848@sopwith.solgatos.com> X-Mailer: Mew version 5.2 on Emacs 21.3 / Mule 5.0 (SAKAKI) Mime-Version: 1.0 Content-Type: Text/Plain; charset=us-ascii Content-Transfer-Encoding: 7bit Cc: freebsd-firewire@freebsd.org, freebsd-drivers@freebsd.org, bug-followup@freebsd.org Subject: Re: kern/118093: firewire bus reset hogs CPU, causing data to be lost X-BeenThere: freebsd-firewire@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Firewire support in FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 17 Dec 2008 07:00:26 -0000 In message: <200812170329.DAA17848@sopwith.solgatos.com> Dieter writes: : Sean> Which file in dev/firewire are you looking at? : : fwohci.c and firewire.c : : examples: : : printf("non CYCLEMASTER mode\n"); : : device_printf(fc->dev, "Initiate bus reset\n"); : : ------------------- : : Warner> This can't be the case. There's no SPL involved at all. Maybe : Warner> removing the printfs causes an interrupt to be serviced faster, : Warner> resulting in what appears to be better performance... : : With the printfs, Ethernet is not getting serviced. This : is repeatable and easily reproduced. Without the printfs, : it seems ok. : : If it isn't spl, what is locking out Ethernet? interrupt storm? In old-spl-locked drivers, often times the interrupt would be masked while certain operations happened. In new mutex-locked freebsd, there's no way to block the interrupts, so sometimes old code gets into an interrupt storm, which starves other things. Not sure why printf would trigger this, however... Warner From owner-freebsd-firewire@FreeBSD.ORG Thu Dec 18 01:10:57 2008 Return-Path: Delivered-To: freebsd-firewire@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 1C72C1065670; Thu, 18 Dec 2008 01:10:57 +0000 (UTC) (envelope-from sbruno@miralink.com) Received: from plato.miralink.com (mail.miralink.com [70.103.185.20]) by mx1.freebsd.org (Postfix) with ESMTP id DB9FD8FC12; Thu, 18 Dec 2008 01:10:56 +0000 (UTC) (envelope-from sbruno@miralink.com) Received: from localhost (localhost.localdomain [127.0.0.1]) by plato.miralink.com (Postfix) with ESMTP id 2F6E71A9110; Wed, 17 Dec 2008 18:10:55 -0800 (PST) X-Virus-Scanned: amavisd-new at X-Spam-Flag: NO X-Spam-Score: -4.399 X-Spam-Level: X-Spam-Status: No, score=-4.399 tagged_above=-10 required=6.6 tests=[ALL_TRUSTED=-1.8, AWL=0.000, BAYES_00=-2.599] Received: from plato.miralink.com ([127.0.0.1]) by localhost (plato.miralink.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id dgOb+L3-EcNp; Wed, 17 Dec 2008 18:10:54 -0800 (PST) Received: from [10.47.1.6] (vpn.office.miralink.com [10.0.0.5]) by plato.miralink.com (Postfix) with ESMTP id 599391A90BE; Wed, 17 Dec 2008 18:10:54 -0800 (PST) Message-ID: <4949A31D.5030507@miralink.com> Date: Wed, 17 Dec 2008 17:10:53 -0800 From: Sean Bruno User-Agent: Thunderbird 2.0.0.18 (X11/20081119) MIME-Version: 1.0 To: "M. Warner Losh" References: <4947EAB0.3020704@miralink.com> <200812170329.DAA17848@sopwith.solgatos.com> <20081216.235941.1266245051.imp@bsdimp.com> In-Reply-To: <20081216.235941.1266245051.imp@bsdimp.com> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Cc: freebsd-firewire@freebsd.org, bug-followup@freebsd.org Subject: Re: kern/118093: firewire bus reset hogs CPU, causing data to be lost X-BeenThere: freebsd-firewire@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Firewire support in FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 18 Dec 2008 01:10:57 -0000 M. Warner Losh wrote: > In message: <200812170329.DAA17848@sopwith.solgatos.com> > Dieter writes: > : Sean> Which file in dev/firewire are you looking at? > : > : fwohci.c and firewire.c > : > : examples: > : > : printf("non CYCLEMASTER mode\n"); > : > : device_printf(fc->dev, "Initiate bus reset\n"); > : > : ------------------- > : > : Warner> This can't be the case. There's no SPL involved at all. Maybe > : Warner> removing the printfs causes an interrupt to be serviced faster, > : Warner> resulting in what appears to be better performance... > : > : With the printfs, Ethernet is not getting serviced. This > : is repeatable and easily reproduced. Without the printfs, > : it seems ok. > : > : If it isn't spl, what is locking out Ethernet? > > interrupt storm? In old-spl-locked drivers, often times the interrupt > would be masked while certain operations happened. In new > mutex-locked freebsd, there's no way to block the interrupts, so > sometimes old code gets into an interrupt storm, which starves other > things. Not sure why printf would trigger this, however... > > Warner > _______________________________________________ > freebsd-drivers@freebsd.org mailing list > http://lists.freebsd.org/mailman/listinfo/freebsd-drivers > To unsubscribe, send any mail to "freebsd-drivers-unsubscribe@freebsd.org" > Let me take a stab at this one this week. There's got to be something more going on than a printf() causing hell. It could be a mutex being held causing nightmares. The firewire code is my current project, I'll look at this issue now. Sean From owner-freebsd-firewire@FreeBSD.ORG Thu Dec 18 08:53:39 2008 Return-Path: Delivered-To: freebsd-firewire@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id C8D1B1065673; Thu, 18 Dec 2008 08:53:39 +0000 (UTC) (envelope-from freebsd@sopwith.solgatos.com) Received: from sopwith.solgatos.com (pool-71-182-69-106.ptldor.fios.verizon.net [71.182.69.106]) by mx1.freebsd.org (Postfix) with ESMTP id A17938FC0C; Thu, 18 Dec 2008 08:53:38 +0000 (UTC) (envelope-from freebsd@sopwith.solgatos.com) Received: by sopwith.solgatos.com (Postfix, from userid 66) id E0D853F22; Thu, 18 Dec 2008 00:30:39 -0800 (PST) Received: from localhost by sopwith.solgatos.com (8.8.8/6.24) id IAA08485; Thu, 18 Dec 2008 08:51:41 GMT Message-Id: <200812180851.IAA08485@sopwith.solgatos.com> To: freebsd-firewire@freebsd.org, bug-followup@freebsd.org In-reply-to: Your message of "Wed, 17 Dec 2008 17:10:53 PST." <4949A31D.5030507@miralink.com> Date: Thu, 18 Dec 2008 00:51:41 +0000 From: Dieter Cc: Subject: Re: kern/118093: firewire bus reset hogs CPU, causing data to be lost X-BeenThere: freebsd-firewire@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Firewire support in FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 18 Dec 2008 08:53:39 -0000 > > : Warner> This can't be the case. There's no SPL involved at all. Maybe > > : Warner> removing the printfs causes an interrupt to be serviced faster, > > : Warner> resulting in what appears to be better performance... > > : > > : With the printfs, Ethernet is not getting serviced. This > > : is repeatable and easily reproduced. Without the printfs, > > : it seems ok. > > : > > : If it isn't spl, what is locking out Ethernet? > > > > interrupt storm? In old-spl-locked drivers, often times the interrupt > > would be masked while certain operations happened. In new > > mutex-locked freebsd, there's no way to block the interrupts, so > > sometimes old code gets into an interrupt storm, which starves other > > things. Not sure why printf would trigger this, however... I tried logging in on the console and "cat /etc/termcap" does not create a problem. Systat -vmstat reports that IRQ 5 (console) interrupts go from 0 to 120. CPU: 0.0%Sys 0.6%Intr 0.0%User 0.0%Nice 99.4%Idle The normal firewire bus reset printfs generate 890 IRQ 5 interrupts with the shell firing off "fwcontrol -u 1 -r" in a loop. CPU goes from idle to 100% busy: 98.1%Sys 1.7%Intr 0.3%User 0.0%Nice 0.0%Idle "fwcontrol -u 0 -r" (the onboard firewire controller) gives the same 890 IRQ 5 interrupts, but CPU usage is different: 79.2%Sys 20.8%Intr 0.0%User 0.0%Nice 0.0%Idle A couple of other IRQs go up to 30-40 range, nothing huge. A single "fwcontrol -u 0 -r" generates 14 interrupts on IRQ 5 and 4 interrupts on 3 other IRQs. A single "fwcontrol -u 1 -r" generates 14 interrupts on IRQ 5 and 3 interrupts on 2 other IRQs. yawn ------ With the bus reset printfs commented out, I get: -u 0 80.0%Sys 4.8%Intr 13.9%User 0.0%Nice 1.2%Idle 3300 interrupts on the onboard firewire controller -u 1 84.8%Sys 1.1%Intr 14.1%User 0.0%Nice 0.0%Idle 3900 interrupts on the PCI card firewire controller After awhile the console says: fwohci1: phy read failed(1). i = 100 retry = 0 fwohci1: phy read failed(1). i = 100 retry = 1 fwohci1: phy read failed(1). i = 100 retry = 2 fwohci1: phy read failed(1). i = 100 retry = 3 ... and the system becomes unresponsive. Reset button required. :-( Observations: Kernel printfs to console appear to take more interrupts and more CPU than userland output to console. Seems odd that the onboard controller uses so much CPU for interrupts in the with-printf case, but there wasn't a large number on interrupts. The without-printf case had a LOT more interrupts from the fw controller. Resetting the firewire bus in an endless loop is not recommended. I'm not an expert on interrupt storms, but none of this looks like an interrupt storm to me. (Assuming systat is trustworthy.) Looks like the kernel printf takes a *lot* of CPU, and somehow locks out Ethernet. From owner-freebsd-firewire@FreeBSD.ORG Sat Dec 20 05:14:24 2008 Return-Path: Delivered-To: freebsd-firewire@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 882711065670; Sat, 20 Dec 2008 05:14:24 +0000 (UTC) (envelope-from freebsd@sopwith.solgatos.com) Received: from sopwith.solgatos.com (pool-71-182-69-106.ptldor.fios.verizon.net [71.182.69.106]) by mx1.freebsd.org (Postfix) with ESMTP id 8EDE28FC17; Sat, 20 Dec 2008 05:14:23 +0000 (UTC) (envelope-from freebsd@sopwith.solgatos.com) Received: by sopwith.solgatos.com (Postfix, from userid 66) id 874FD3F22; Fri, 19 Dec 2008 20:46:38 -0800 (PST) Received: from localhost by sopwith.solgatos.com (8.8.8/6.24) id TAA01939; Fri, 19 Dec 2008 19:02:21 GMT Message-Id: <200812191902.TAA01939@sopwith.solgatos.com> To: freebsd-firewire@freebsd.org, bug-followup@freebsd.org Date: Fri, 19 Dec 2008 11:02:21 +0000 From: Dieter Cc: Subject: Re: kern/118093: firewire bus reset hogs CPU, causing data to be lost X-BeenThere: freebsd-firewire@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Firewire support in FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 20 Dec 2008 05:14:24 -0000 Here are the results of two more experiments: I tried to verify what spl the firewire code is at when calling printf(9) by adding the following block into fwohci.c just before one of the printfs. { #include #include intrmask_t debug_spl; /* __uint32_t */ intrmask_t debug_spl_high; intrmask_t debug_spl_tty; intrmask_t debug_spl_fw; intrmask_t debug_spl_0; intrmask_t debug_spl_net; debug_spl = splhigh(); debug_spl_high = spltty(); debug_spl_tty = splfw(); debug_spl_fw = splnet(); debug_spl_net = splhigh(); spl0(); /* void */ debug_spl_0 = splhigh(); splx(debug_spl); printf("fwohci_intr_core(): spl = 0x%x\n splhigh=0x%x spltty=0x%x splfw=0x%x splnet=0x%x spl0=0x%x\n", debug_spl, debug_spl_high, debug_spl_tty, debug_spl_fw, debug_spl_net, debug_spl_0); } But my results appear bogus: fwohci_intr_core(): spl = 0x0 splhigh=0x0 spltty=0x0 splfw=0x0 splnet=0x0 spl0=0x0 I have examined my code and the spl(9) man page several times but I can't find what is wrong. Any clues? -------------------------------------------------------- To isolate the effects of printf(9) from the firewire bus reset, I picked a trivial system call (chown(2)) and added some printf(9) calls. Calling chown several times and monitoring with systat -vmstat gives: 1098 interrupts on the console IRQ 93.1%Sys 6.7%Intr 0.2%User 0.0%Nice 0.0%Idle This did NOT interfere with Ethernet. So printf(9) interferes with Ethernet when called from the firewire driver, but not when called from a vanilla system call. -------------------------------------------------------- sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 sio0: type 16550A, console sio0: [FILTER] What does [FILTER] mean? I don't see an explanation on the sio man page.