kern/118093: firewire bus reset hogs CPU, causing data to be lost

[Sean Bruno]

The following reply was made to PR kern/118093; it has been noted by GNATS.

From: Sean Bruno <sbruno at miralink.com>
To: Dieter <freebsd at sopwith.solgatos.com>
Cc: freebsd-firewire at freebsd.org, bug-followup at freebsd.org
Subject: Re: kern/118093: firewire bus reset hogs CPU,	causing data to be
 lost
Date: Mon, 22 Dec 2008 22:01:55 -0800

 Sean Bruno wrote:
 > Dieter wrote:
 >> In message <494DAEB1.1070909 at miralink.com>, Sean Bruno writes:
 >>
 >>  
 >>> I setup my system to execute a bus reset every 1 second, 
 >>> simultaneously, I started copying a large
 >>> file onto the system see if anything would happen.
 >>>
 >>> I saw no change to copy speed reported by SCP during the entire 
 >>> transaction.  I also see no change
 >>> to the system load while this is occurring.
 >>>     
 >>
 >> Does your system have a RS-232 console or VGA console?
 >> The problem might be specific to RS-232.
 >>
 >>   
 > I have both.  I disabled my serial console to test, no change when using
 > the VGA console only.
 >
 >>> This seems indicative of "something else" going on.
 >>>     
 >>
 >> Any idea what this "something else" might be?
 >>
 >> Does anyone have a clue why my spl calls are returning 0 ?
 >>
 >>   
 > I confirmed that spl's are complete no-ops since rel 5.  So, you want 
 > to ignore
 > them as they are just markers now where locking should be implemented.
 >
 > I went back in your original submission and I can see a significant 
 > drop in I/O
 > when resetting the F/W bus.   If I have the following running:
 > dd if=/dev/zero of=/dev/ad6 bs=64k
 >
 > Then I see about 64MB/S normally.  When I reset any firewire bus, I 
 > see the throughput
 > drop as reported by iostat by a significant amount(2-4 MB/s).
 >
 > I am assuming that the firewire driver is holding a very heavy lock 
 > here that is cascading
 > down to the printf().  At least, that would be my ASSumption.  :)
 >
 > I will continue to poke around.  You are not crazy Dieter.
 >
 > Sean
 >
 >
 Hrm ... Looking over the log messages that are generated during a bus 
 reset, there's
 a mish-mash of printf() and device_printf() calls.  I'm not sure what 
 the impact of that
 is to real behavior, but /var/log/messages has a tendency to get garbled 
 like this:
 
 Dec 22 16:00:18 home-test kernel: fwohci1: Initiate bus reset
 Dec 22 16:00:18 home-test kernel: fwohci1: BUS reset
 Dec 22 16:00:18 home-test kernel: fwohci1: node_id=0xc800ffc0, gen=8, 
 CYCLEMASTER mode
 Dec 22 16:00:18 home-test kernel: firewi
 Dec 22 16:00:18 home-test kernel: re1:
 Dec 22 16:00:18 home-test kernel: 1 n
 Dec 22 16:00:18 home-test kernel: odes
 Dec 22 16:00:18 home-test kernel: , ma
 Dec 22 16:00:18 home-test kernel: xhop
 Dec 22 16:00:18 home-test kernel: <=
 Dec 22 16:00:18 home-test kernel: 0, c
 Dec 22 16:00:18 home-test kernel: able
 Dec 22 16:00:18 home-test kernel: IRM
 Dec 22 16:00:18 home-test kernel: = 0
 Dec 22 16:00:18 home-test kernel: (me
 Dec 22 16:00:18 home-test kernel: )
 Dec 22 16:00:18 home-test kernel: f
 Dec 22 16:00:18 home-test kernel: irew
 Dec 22 16:00:18 home-test kernel: ire1
 Dec 22 16:00:18 home-test kernel: : bu
 Dec 22 16:00:18 home-test kernel: s ma
 Dec 22 16:00:18 home-test kernel: nage
 Dec 22 16:00:18 home-test kernel: r 0
 Dec 22 16:00:18 home-test kernel: (me)
 Dec 22 16:00:18 home-test kernel:
 
 
 Let me try to eliminate this behaviour first.
 
 Sean