* firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24]
@ 2021-01-23 11:59 David Runge
2021-01-28 6:28 ` Ahmed S. Darwish
0 siblings, 1 reply; 24+ messages in thread
From: David Runge @ 2021-01-23 11:59 UTC (permalink / raw)
To: linux-rt-users, linux1394-devel
[-- Attachment #1: Type: text/plain, Size: 5563 bytes --]
Hi!
I package linux-rt and linux-rt-lts for Arch Linux.
Due to time constraints over the past months I did not have the time to
test all of my own hardware setups with the recent realtime kernels.
Unfortunately firewire-ohci is unable to initialize my firewire
controller [1] (a PCIe card [2]) both on 5.4.91-rt50 and on 5.10.8-rt24: No
device nodes (i.e. /dev/fw0) are created and therefore no connected devices can
be initialized either.
The controller is initialized properly on our other stock kernels on
Arch Linux though (e.g. linux/ linux-hardened/ linux-lts) and I usually keep
the config files for linux-rt[3] and linux-rt-lts[4] as close as possible to
that of our respective core linux packages linux[5] and linux-lts[6].
Looking at the kernel logs, this is what the initialization usually looks like
on our stock kernels (with `firewire_ohci debug=8` and duplicate lines
truncated for brevity):
```
firewire_ohci 0000:05:00.0: enabling device (0000 -> 0002)
firewire_ohci 0000:05:00.0: IRQ 00020010 AR_req busReset
firewire_ohci 0000:05:00.0: added OHCI v1.10 device as card 0, 8 IR + 8 IT contexts, quirks 0x2
firewire_ohci 0000:05:00.0: IRQ 00030000 selfID busReset
firewire_ohci 0000:05:00.0: IRQ 00020000 busReset
[..]
firewire_ohci 0000:05:00.0: IRQ 00020000 busReset
firewire_core 0000:05:00.0: created device fw0: GUID 7856341278563412, S800
firewire_core 0000:05:00.0: phy config: new root=ffc1, gap_count=5
firewire_ohci 0000:05:00.0: IRQ 00020010 AR_req busReset
firewire_ohci 0000:05:00.0: IRQ 00030000 selfID busReset
firewire_ohci 0000:05:00.0: IRQ 00020000 busReset
[..]
firewire_ohci 0000:05:00.0: IRQ 00020000 busReset
firewire_core 0000:05:00.0: created device fw1: GUID 000a3500ada83262, S400
```
And this is how the initialization looks like on the realtime kernels (with
`firewire_ohci debug=-1`):
```
firewire_ohci 0000:05:00.0: enabling device (0000 -> 0002)
firewire_ohci 0000:05:00.0: added OHCI v1.10 device as card 0, 8 IR + 8 IT contexts, quirks 0x2
firewire_ohci 0000:05:00.0: IRQ 00020010 AR_req busReset
firewire_ohci 0000:05:00.0: AR evt_bus_reset, generation 1
```
I have a laptop using an ExpressCard34 that provides Firewire800 [7], with the
same Texas Instruments chip which initializes properly (i.e. /dev/fw0 is
created, subsequently connected devices are initialized and are usable) on the
realtime kernels:
```
firewire_ohci 0000:06:00.0: added OHCI v1.10 device as card 0, 8 IR + 8 IT contexts, quirks 0x2
firewire_ohci 0000:06:00.0: IRQ 00030010 selfID AR_req busReset
firewire_ohci 0000:06:00.0: IRQ 00020000 busReset
[..]
firewire_ohci 0000:06:00.0: IRQ 00020000 busReset
firewire_core 0000:06:00.0: created device fw0: GUID 000acd12007000ff, S800
firewire_ohci 0000:06:00.0: IRQ 00030010 selfID AR_req busReset
firewire_ohci 0000:06:00.0: IRQ 00020000 busReset
[..]
firewire_ohci 0000:06:00.0: IRQ 00020000 busReset
firewire_ohci 0000:06:00.0: IRQ 00020010 AR_req busReset
firewire_ohci 0000:06:00.0: IRQ 00020000 busReset
firewire_ohci 0000:06:00.0: IRQ 00830000 selfID cycleInconsistent busReset
firewire_ohci 0000:06:00.0: isochronous cycle inconsistent
firewire_ohci 0000:06:00.0: IRQ 00020000 busReset
[..]
firewire_ohci 0000:06:00.0: IRQ 00020000 busReset
firewire_core 0000:06:00.0: created device fw1: GUID 000a3500ada83262, S800
firewire_core 0000:06:00.0: phy config: new root=ffc0, gap_count=5
firewire_ohci 0000:06:00.0: IRQ 00030010 selfID AR_req busReset
firewire_ohci 0000:06:00.0: IRQ 00020000 busReset
[..]
firewire_ohci 0000:06:00.0: IRQ 00020000 busReset
```
At this point in time I'm uncertain whether this is a general problem
with the kernel module on the realtime kernels or a problem with the
kernel module on the realtime kernels with my PCIe controller specifically.
That it works using the ExpressCard34 based controller on my laptop makes it
extra odd (but I guess the underlying driver is handling this
differently due to the PCI bridge?).
Any pointers to solving this issue would be greatly appreciated, as not being
able to use firewire audio interfaces on a realtime kernel in a workstation
context is bad for pro-audio people on Linux in general (and me in particular
;-) ).
Best,
David
[1]
```
$ lspci -kP -s 05:00.0
00:01.2/00.0/00.0/00.0/00.0 FireWire (IEEE 1394): Texas Instruments XIO2213A/B/XIO2221 IEEE-1394b OHCI Controller [Cheetah Express] (rev 01)
Subsystem: Device 3412:7856
Kernel driver in use: firewire_ohci
Kernel modules: firewire_ohci
```
[2] https://www.delock.de/produkte/1114_FireWire/89153/merkmale.html
[3] https://aur.archlinux.org/cgit/aur.git/tree/config?h=linux-rt&id=3aef702717033d63ddc7c078f6d1fc388ea0e420
[4] https://aur.archlinux.org/cgit/aur.git/tree/config?h=linux-rt-lts&id=6c529a838f028fd0c55b97b6f98a9d35108f6696
[5] https://github.com/archlinux/svntogit-packages/blob/a0a47291449ab346e0dd209a2f23c82264c60d79/trunk/config
[6] https://github.com/archlinux/svntogit-packages/blob/1a0e0ed59007a8c0ddd34f847a92174e2838244f/trunk/config
[7]
```
$ lspci -kP -s 05:00.0
00:1c.3/00.0 PCI bridge: Texas Instruments XIO2213A/B/XIO2221 PCI Express to PCI Bridge [Cheetah Express] (rev 01)
$ lspci -kP -s 06:00.0
00:1c.3/00.0/00.0 FireWire (IEEE 1394): Texas Instruments XIO2213A/B/XIO2221 IEEE-1394b OHCI Controller [Cheetah Express] (rev 01)
Subsystem: Device 3412:7856
Kernel driver in use: firewire_ohci
Kernel modules: firewire_ohci
```
--
https://sleepmap.de
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 24+ messages in thread* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-01-23 11:59 firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] David Runge @ 2021-01-28 6:28 ` Ahmed S. Darwish 2021-01-28 21:41 ` David Runge 0 siblings, 1 reply; 24+ messages in thread From: Ahmed S. Darwish @ 2021-01-28 6:28 UTC (permalink / raw) To: David Runge; +Cc: linux-rt-users, linux1394-devel On Sat, Jan 23, 2021 at 12:59:29PM +0100, David Runge wrote: ... > > Unfortunately firewire-ohci is unable to initialize my firewire > controller [1] (a PCIe card [2]) both on 5.4.91-rt50 and on 5.10.8-rt24: No > device nodes (i.e. /dev/fw0) are created and therefore no connected devices can > be initialized either. > ... > At this point in time I'm uncertain whether this is a general problem > with the kernel module on the realtime kernels or a problem with the > kernel module on the realtime kernels with my PCIe controller specifically. > That it works using the ExpressCard34 based controller on my laptop makes it > extra odd (but I guess the underlying driver is handling this > differently due to the PCI bridge?). > Can you please send the full kernel log, with boot parameter "firewire_ohci.debug=-1", for mainline v5.4.91 vs. v5.4.91-rt50? Please also make sure to use the exact same defconfig for both, except with CONFIG_PREEMPT_RT=y for the -rt kenrel of course. This will help in comparing apples to apples, as you were posting the results of different base kernels (vs. the -rt versions), and different defconfigs (vs. -rt) within such kernels. Good luck, P.S. Since this maybe is a timing issue, and ohci bus reset handling occurs at SCHED_OTHER workqueu context, were you by any chance running unreasonably-intensive realtime workloads by the time the driver was loaded? Thanks, -- Ahmed S. Darwish ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-01-28 6:28 ` Ahmed S. Darwish @ 2021-01-28 21:41 ` David Runge 2021-01-29 17:04 ` Sebastian Andrzej Siewior 0 siblings, 1 reply; 24+ messages in thread From: David Runge @ 2021-01-28 21:41 UTC (permalink / raw) To: Ahmed S. Darwish; +Cc: linux-rt-users, linux1394-devel [-- Attachment #1: Type: text/plain, Size: 1817 bytes --] On 2021-01-28 07:28:35 (+0100), Ahmed S. Darwish wrote: > On Sat, Jan 23, 2021 at 12:59:29PM +0100, David Runge wrote: > ... > Can you please send the full kernel log, with boot parameter > "firewire_ohci.debug=-1", for mainline v5.4.91 vs. v5.4.91-rt50? kernel log for mainline: https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.4.91-kernel.log kernel log for rt (no dice :-/): https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.4.91.50.arch1-kernel.log > Please also make sure to use the exact same defconfig for both, except > with CONFIG_PREEMPT_RT=y for the -rt kenrel of course. config diff: https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.4.91-lts_changed_vs_rt-lts.patch > This will help in comparing apples to apples, as you were posting the > results of different base kernels (vs. the -rt versions), and different > defconfigs (vs. -rt) within such kernels. The configuration for the 5.4.91 stock kernel has not been updated since the 5.4.83, which is maybe a bit misleading. Generally I enable anything that I can in the config for the realtime kernel. However, some settings of course get switched off, as they are not compatible. The diff above is for a custom version I just made, just to make sure and clear things out. > Good luck, Thanks, seems it's needed! > P.S. Since this maybe is a timing issue, and ohci bus reset handling > occurs at SCHED_OTHER workqueu context, were you by any chance running > unreasonably-intensive realtime workloads by the time the driver was > loaded? Not that I am aware of. The driver neither initializes the device during boot nor when later reloading. There are no intense services running. The system is fairly multi-purpose, so most things are started on demand. Thanks! David -- https://sleepmap.de [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-01-28 21:41 ` David Runge @ 2021-01-29 17:04 ` Sebastian Andrzej Siewior 2021-01-30 11:46 ` David Runge 0 siblings, 1 reply; 24+ messages in thread From: Sebastian Andrzej Siewior @ 2021-01-29 17:04 UTC (permalink / raw) To: David Runge; +Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel On 2021-01-28 22:41:45 [+0100], David Runge wrote: > kernel log for mainline: > https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.4.91-kernel.log > > kernel log for rt (no dice :-/): > https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.4.91.50.arch1-kernel.log I don't see anything wrong. There is small difference in timing and then the RT version does not do a thing while !RT keeps reseting… Could you try non-RT with the threadirqs option? Sebastian ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-01-29 17:04 ` Sebastian Andrzej Siewior @ 2021-01-30 11:46 ` David Runge 2021-02-01 8:34 ` Sebastian Andrzej Siewior 0 siblings, 1 reply; 24+ messages in thread From: David Runge @ 2021-01-30 11:46 UTC (permalink / raw) To: Sebastian Andrzej Siewior Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel [-- Attachment #1: Type: text/plain, Size: 493 bytes --] On 2021-01-29 18:04:14 (+0100), Sebastian Andrzej Siewior wrote: > I don't see anything wrong. There is small difference in timing and > then the RT version does not do a thing while !RT keeps reseting… > Could you try non-RT with the > threadirqs > > option? Yes, (sorry for not including that earlier D:) that fails the same way as the realtime kernel: https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.4.91-kernel_threadirqs.log Best, David -- https://sleepmap.de [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-01-30 11:46 ` David Runge @ 2021-02-01 8:34 ` Sebastian Andrzej Siewior 2021-02-05 11:26 ` Sebastian Andrzej Siewior 0 siblings, 1 reply; 24+ messages in thread From: Sebastian Andrzej Siewior @ 2021-02-01 8:34 UTC (permalink / raw) To: David Runge Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel, Stefan Richter + firewire maintainer On 2021-01-30 12:46:04 [+0100], David Runge wrote: > On 2021-01-29 18:04:14 (+0100), Sebastian Andrzej Siewior wrote: > > I don't see anything wrong. There is small difference in timing and > > then the RT version does not do a thing while !RT keeps reseting… > > Could you try non-RT with the > > threadirqs > > > > option? > > Yes, (sorry for not including that earlier D:) that fails the same way > as the realtime kernel: > https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.4.91-kernel_threadirqs.log Could be specific to the chip or the ohci driver. Either way, the problem are the threaded interrupts. > Best, > > David Sebastian ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-02-01 8:34 ` Sebastian Andrzej Siewior @ 2021-02-05 11:26 ` Sebastian Andrzej Siewior 2021-02-05 23:22 ` David Runge 0 siblings, 1 reply; 24+ messages in thread From: Sebastian Andrzej Siewior @ 2021-02-05 11:26 UTC (permalink / raw) To: David Runge Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel, Stefan Richter On 2021-02-01 09:34:41 [+0100], To David Runge wrote: > + firewire maintainer > > On 2021-01-30 12:46:04 [+0100], David Runge wrote: > > On 2021-01-29 18:04:14 (+0100), Sebastian Andrzej Siewior wrote: > > > I don't see anything wrong. There is small difference in timing and > > > then the RT version does not do a thing while !RT keeps reseting… > > > Could you try non-RT with the > > > threadirqs > > > > > > option? > > > > Yes, (sorry for not including that earlier D:) that fails the same way > > as the realtime kernel: > > https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.4.91-kernel_threadirqs.log > > Could be specific to the chip or the ohci driver. Either way, the problem > are the threaded interrupts. David, could you please try a v5.10 kernel with threadirqs? I've been just told that it works there on a ppc64 box. > > Best, > > > > David Sebastian ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-02-05 11:26 ` Sebastian Andrzej Siewior @ 2021-02-05 23:22 ` David Runge 2021-02-07 9:58 ` David Runge 0 siblings, 1 reply; 24+ messages in thread From: David Runge @ 2021-02-05 23:22 UTC (permalink / raw) To: Sebastian Andrzej Siewior Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel, Stefan Richter [-- Attachment #1: Type: text/plain, Size: 1519 bytes --] On 2021-02-05 12:26:38 (+0100), Sebastian Andrzej Siewior wrote: > On 2021-02-01 09:34:41 [+0100], To David Runge wrote: > > + firewire maintainer > > > > On 2021-01-30 12:46:04 [+0100], David Runge wrote: > > > On 2021-01-29 18:04:14 (+0100), Sebastian Andrzej Siewior wrote: > > > > I don't see anything wrong. There is small difference in timing and > > > > then the RT version does not do a thing while !RT keeps reseting… > > > > Could you try non-RT with the > > > > threadirqs > > > > > > > > option? > > > > > > Yes, (sorry for not including that earlier D:) that fails the same way > > > as the realtime kernel: > > > https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.4.91-kernel_threadirqs.log > > > > Could be specific to the chip or the ohci driver. Either way, the problem > > are the threaded interrupts. > > David, could you please try a v5.10 kernel with threadirqs? I've been > just told that it works there on a ppc64 box. I have now tried with our vanilla 5.10.13 kernel, as I have issues getting 5.10.12-rt26 to boot at all on my machine (will try to investigate that tomorrow). On 5.10.13 with threadirqs the controller is indeed initialized again (/dev/fw0 appears). However, no connected device is detected (i.e. /dev/fw1 does not appear). Here are the kernel logs with "firewire-ohci debug=-1": https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.10.13.arch1_threadirqs-kernel.log Thanks for the follow-up! Best, David -- https://sleepmap.de [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-02-05 23:22 ` David Runge @ 2021-02-07 9:58 ` David Runge 2021-02-08 9:19 ` Sebastian Andrzej Siewior 0 siblings, 1 reply; 24+ messages in thread From: David Runge @ 2021-02-07 9:58 UTC (permalink / raw) To: Sebastian Andrzej Siewior Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel, Stefan Richter [-- Attachment #1: Type: text/plain, Size: 1458 bytes --] On 2021-02-06 00:22:12 (+0100), David Runge wrote: > On 2021-02-05 12:26:38 (+0100), Sebastian Andrzej Siewior wrote: > > On 2021-02-01 09:34:41 [+0100], To David Runge wrote: > > > + firewire maintainer > > > > > > On 2021-01-30 12:46:04 [+0100], David Runge wrote: > > > > On 2021-01-29 18:04:14 (+0100), Sebastian Andrzej Siewior wrote: > > > > > I don't see anything wrong. There is small difference in timing and > > > > > then the RT version does not do a thing while !RT keeps reseting… > > > > > Could you try non-RT with the > > > > > threadirqs > > > > > > > > > > option? > > > > > > > > Yes, (sorry for not including that earlier D:) that fails the same way > > > > as the realtime kernel: > > > > https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.4.91-kernel_threadirqs.log > > > > > > Could be specific to the chip or the ohci driver. Either way, the problem > > > are the threaded interrupts. > > > > David, could you please try a v5.10 kernel with threadirqs? I've been > > just told that it works there on a ppc64 box. > > I have now tried with our vanilla 5.10.13 kernel, as I have issues > getting 5.10.12-rt26 to boot at all on my machine (will try to > investigate that tomorrow). With 5.10.12-rt26 the controller still does not initialize at all though (/dev/fw0 does not appear): https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.10.12-rt26-kernel.log Best, David -- https://sleepmap.de [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-02-07 9:58 ` David Runge @ 2021-02-08 9:19 ` Sebastian Andrzej Siewior 2021-02-14 19:16 ` David Runge 0 siblings, 1 reply; 24+ messages in thread From: Sebastian Andrzej Siewior @ 2021-02-08 9:19 UTC (permalink / raw) To: David Runge Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel, Stefan Richter On 2021-02-07 10:58:13 [+0100], David Runge wrote: > With 5.10.12-rt26 the controller still does not initialize at all > though (/dev/fw0 does not appear): > https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.10.12-rt26-kernel.log So it is either config or chipset specific. Did you posted a link to your .config? > Best, > David > Sebastian ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-02-08 9:19 ` Sebastian Andrzej Siewior @ 2021-02-14 19:16 ` David Runge 2021-02-18 8:38 ` Sebastian Andrzej Siewior 0 siblings, 1 reply; 24+ messages in thread From: David Runge @ 2021-02-14 19:16 UTC (permalink / raw) To: Sebastian Andrzej Siewior Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel, Stefan Richter [-- Attachment #1: Type: text/plain, Size: 923 bytes --] On 2021-02-08 10:19:40 (+0100), Sebastian Andrzej Siewior wrote: > On 2021-02-07 10:58:13 [+0100], David Runge wrote: > > With 5.10.12-rt26 the controller still does not initialize at all > > though (/dev/fw0 does not appear): > > https://pkgbuild.com/~dvzrv/bugs/2021/01/linux-5.10.12-rt26-kernel.log > > So it is either config or chipset specific. Did you posted a link to > your .config? The current config can be found on the AUR [1]. The equivalent mainline kernel config (note, that it states it is for 5.10.13, but is actually used for 5.10.14 as well) where initialization of the controller works (but the initialization of a connected device does not, when using threadirqs) is here [2]. [1] https://aur.archlinux.org/cgit/aur.git/tree/config?h=linux-rt [2] https://github.com/archlinux/svntogit-packages/blob/37abf96cac628b7f516c266a8c0288671ed96a2a/trunk/config -- https://sleepmap.de [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-02-14 19:16 ` David Runge @ 2021-02-18 8:38 ` Sebastian Andrzej Siewior 2021-02-18 9:27 ` Sebastian Andrzej Siewior 0 siblings, 1 reply; 24+ messages in thread From: Sebastian Andrzej Siewior @ 2021-02-18 8:38 UTC (permalink / raw) To: David Runge Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel, Stefan Richter On 2021-02-14 20:16:02 [+0100], David Runge wrote: > The current config can be found on the AUR [1]. So this did make a difference. John concluded that it might be related to the RESET quirk your hardware is having and his does not. Could you try the patch below? Everything related to canceling tasklets is broken so it is nothing logterm. It is just to figure out if your hardware initializes further than it does right now. ------->8------- Subject: [PATCH] firewire: threaded interrupts Canceling tasklets is broken. Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de> --- drivers/firewire/ohci.c | 103 ++++++++++++++++++++++++++++------------ 1 file changed, 73 insertions(+), 30 deletions(-) diff --git a/drivers/firewire/ohci.c b/drivers/firewire/ohci.c index 17c9d825188bb..f309c7f69b076 100644 --- a/drivers/firewire/ohci.c +++ b/drivers/firewire/ohci.c @@ -2000,7 +2000,6 @@ static void bus_reset_work(struct work_struct *work) spin_lock_irq(&ohci->lock); ohci->generation = generation; - reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_busReset); if (ohci->quirks & QUIRK_RESET_PACKET) ohci->request_generation = generation; @@ -2041,6 +2040,9 @@ static void bus_reset_work(struct work_struct *work) reg_write(ohci, OHCI1394_PhyReqFilterLoSet, ~0); } + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_busReset); + if (param_debug & OHCI_PARAM_DEBUG_BUSRESETS) + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_busReset); spin_unlock_irq(&ohci->lock); if (free_rom) @@ -2055,66 +2057,81 @@ static void bus_reset_work(struct work_struct *work) ohci->csr_state_setclear_abdicate = false; } -static irqreturn_t irq_handler(int irq, void *data) +static irqreturn_t irq_th_handler(int irq, void *data) { struct fw_ohci *ohci = data; u32 event, iso_event; int i; - event = reg_read(ohci, OHCI1394_IntEventClear); + event = reg_read(ohci, OHCI1394_IntEventSet); if (!event || !~event) return IRQ_NONE; - /* - * busReset and postedWriteErr must not be cleared yet - * (OHCI 1.1 clauses 7.2.3.2 and 13.2.8.1) - */ - reg_write(ohci, OHCI1394_IntEventClear, - event & ~(OHCI1394_busReset | OHCI1394_postedWriteErr)); log_irqs(ohci, event); - if (event & OHCI1394_selfIDComplete) - queue_work(selfid_workqueue, &ohci->bus_reset_work); + if (event & OHCI1394_selfIDComplete) { + bus_reset_work(&ohci->bus_reset_work); + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_selfIDComplete); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_selfIDComplete); + } - if (event & OHCI1394_RQPkt) - tasklet_schedule(&ohci->ar_request_ctx.tasklet); + if (event & OHCI1394_RQPkt) { + ar_context_tasklet((unsigned long)&ohci->ar_request_ctx); + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_RQPkt); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_RQPkt); + } - if (event & OHCI1394_RSPkt) - tasklet_schedule(&ohci->ar_response_ctx.tasklet); + if (event & OHCI1394_RSPkt) { + ar_context_tasklet((unsigned long)&ohci->ar_response_ctx); + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_RSPkt); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_RSPkt); + } - if (event & OHCI1394_reqTxComplete) - tasklet_schedule(&ohci->at_request_ctx.tasklet); - if (event & OHCI1394_respTxComplete) - tasklet_schedule(&ohci->at_response_ctx.tasklet); + if (event & OHCI1394_reqTxComplete) { + context_tasklet((unsigned long)&ohci->at_request_ctx); + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_reqTxComplete); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_reqTxComplete); + } + + if (event & OHCI1394_respTxComplete) { + context_tasklet((unsigned long)&ohci->ar_response_ctx); + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_respTxComplete); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_respTxComplete); + } + if (event & OHCI1394_isochRx) { iso_event = reg_read(ohci, OHCI1394_IsoRecvIntEventClear); - reg_write(ohci, OHCI1394_IsoRecvIntEventClear, iso_event); while (iso_event) { i = ffs(iso_event) - 1; - tasklet_schedule( - &ohci->ir_context_list[i].context.tasklet); + context_tasklet((unsigned long)&ohci->ir_context_list[i].context); iso_event &= ~(1 << i); } + reg_write(ohci, OHCI1394_IsoRecvIntEventClear, iso_event); + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_isochRx); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_isochRx); } if (event & OHCI1394_isochTx) { iso_event = reg_read(ohci, OHCI1394_IsoXmitIntEventClear); - reg_write(ohci, OHCI1394_IsoXmitIntEventClear, iso_event); while (iso_event) { i = ffs(iso_event) - 1; - tasklet_schedule( - &ohci->it_context_list[i].context.tasklet); + context_tasklet((unsigned long)&ohci->it_context_list[i].context.tasklet); iso_event &= ~(1 << i); } + reg_write(ohci, OHCI1394_IsoXmitIntEventClear, iso_event); + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_isochTx); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_isochTx); } if (unlikely(event & OHCI1394_regAccessFail)) ohci_err(ohci, "register access failure\n"); + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_regAccessFail); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_regAccessFail); if (unlikely(event & OHCI1394_postedWriteErr)) { reg_read(ohci, OHCI1394_PostedWriteAddressHi); @@ -2123,6 +2140,7 @@ static irqreturn_t irq_handler(int irq, void *data) OHCI1394_postedWriteErr); if (printk_ratelimit()) ohci_err(ohci, "PCI posted write error\n"); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_postedWriteErr); } if (unlikely(event & OHCI1394_cycleTooLong)) { @@ -2130,6 +2148,8 @@ static irqreturn_t irq_handler(int irq, void *data) ohci_notice(ohci, "isochronous cycle too long\n"); reg_write(ohci, OHCI1394_LinkControlSet, OHCI1394_LinkControl_cycleMaster); + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_cycleTooLong); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_cycleTooLong); } if (unlikely(event & OHCI1394_cycleInconsistent)) { @@ -2141,21 +2161,44 @@ static irqreturn_t irq_handler(int irq, void *data) */ if (printk_ratelimit()) ohci_notice(ohci, "isochronous cycle inconsistent\n"); + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_cycleInconsistent); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_cycleInconsistent); } - if (unlikely(event & OHCI1394_unrecoverableError)) + if (unlikely(event & OHCI1394_unrecoverableError)) { handle_dead_contexts(ohci); + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_unrecoverableError); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_unrecoverableError); + } if (event & OHCI1394_cycle64Seconds) { spin_lock(&ohci->lock); update_bus_time(ohci); spin_unlock(&ohci->lock); - } else + reg_write(ohci, OHCI1394_IntEventClear, OHCI1394_cycle64Seconds); + reg_write(ohci, OHCI1394_IntMaskSet, OHCI1394_cycle64Seconds); + } else { flush_writes(ohci); + } return IRQ_HANDLED; } +static irqreturn_t irq_handler(int irq, void *data) +{ + struct fw_ohci *ohci = data; + u32 event; + + event = reg_read(ohci, OHCI1394_IntEventClear); + + if (!event || !~event) + return IRQ_NONE; + + reg_write(ohci, OHCI1394_IntMaskClear, event); + + return IRQ_WAKE_THREAD; +} + static int software_reset(struct fw_ohci *ohci) { u32 val; @@ -3689,9 +3732,9 @@ static int pci_probe(struct pci_dev *dev, if (!(ohci->quirks & QUIRK_NO_MSI)) pci_enable_msi(dev); - if (request_irq(dev->irq, irq_handler, - pci_dev_msi_enabled(dev) ? 0 : IRQF_SHARED, - ohci_driver_name, ohci)) { + if (request_threaded_irq(dev->irq, irq_handler, irq_th_handler, + pci_dev_msi_enabled(dev) ? 0 : IRQF_SHARED, + ohci_driver_name, ohci)) { ohci_err(ohci, "failed to allocate interrupt %d\n", dev->irq); err = -EIO; goto fail_msi; -- 2.30.0 Sebastian ^ permalink raw reply related [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-02-18 8:38 ` Sebastian Andrzej Siewior @ 2021-02-18 9:27 ` Sebastian Andrzej Siewior 2021-03-08 14:12 ` Sebastian Andrzej Siewior 0 siblings, 1 reply; 24+ messages in thread From: Sebastian Andrzej Siewior @ 2021-02-18 9:27 UTC (permalink / raw) To: David Runge Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel, Stefan Richter On 2021-02-18 09:38:49 [+0100], To David Runge wrote: > On 2021-02-14 20:16:02 [+0100], David Runge wrote: > > The current config can be found on the AUR [1]. > > So this did make a difference. made _no_ difference. Sorry for the confusion. Sebastian ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-02-18 9:27 ` Sebastian Andrzej Siewior @ 2021-03-08 14:12 ` Sebastian Andrzej Siewior 2021-03-10 18:15 ` David Runge 0 siblings, 1 reply; 24+ messages in thread From: Sebastian Andrzej Siewior @ 2021-03-08 14:12 UTC (permalink / raw) To: David Runge Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel, Stefan Richter On 2021-02-18 10:27:51 [+0100], To David Runge wrote: > On 2021-02-18 09:38:49 [+0100], To David Runge wrote: > > On 2021-02-14 20:16:02 [+0100], David Runge wrote: > > > The current config can be found on the AUR [1]. > > > > So this did make a difference. > > made _no_ difference. Sorry for the confusion. David, did you had a chance to test the patch? Sebastian ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-03-08 14:12 ` Sebastian Andrzej Siewior @ 2021-03-10 18:15 ` David Runge 2021-09-07 23:17 ` David Runge 0 siblings, 1 reply; 24+ messages in thread From: David Runge @ 2021-03-10 18:15 UTC (permalink / raw) To: Sebastian Andrzej Siewior Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel, Stefan Richter [-- Attachment #1: Type: text/plain, Size: 2985 bytes --] On 2021-03-08 15:12:10 (+0100), Sebastian Andrzej Siewior wrote: > On 2021-02-18 10:27:51 [+0100], To David Runge wrote: > > On 2021-02-18 09:38:49 [+0100], To David Runge wrote: > > > On 2021-02-14 20:16:02 [+0100], David Runge wrote: > > > > The current config can be found on the AUR [1]. > > > > > > So this did make a difference. > > > > made _no_ difference. Sorry for the confusion. > > David, did you had a chance to test the patch? Hey Sebastian, sorry for the long delay! I got busy with other packaging/ infrastructure things and nearly forgot about this one. I have now tested with 5.11.2-rt9 with and without your proposed patch. Without the patch [1], the behavior is as before, only the parent device node of the controller (/dev/fw0) is created, but the attached audio interface is not recognized. With the patch applied [2], things get a little more exciting, as now both the parent and the child node are created (so both /dev/fw0 and /dev/fw1 show up). However, starting jackd on the interface leads to a zombification of the jackd process and the process never exits: ``` Starting JACK server using fw-fireface800-48000.conf profile... no message buffer overruns no message buffer overruns no message buffer overruns jackdmp 1.9.17 Copyright 2001-2005 Paul Davis and others. Copyright 2004-2016 Grame. Copyright 2016-2021 Filipe Coelho. jackdmp comes with ABSOLUTELY NO WARRANTY This is free software, and you are welcome to redistribute it under certain conditions; see the file COPYING for details JACK server starting in realtime mode with priority 80 self-connect-mode is "Don't restrict self connect requests" 1615399142007837: (ffado.cpp)[ 92] ffado_streaming_init: libffado 2.4.4 built Nov 12 2020 17:24:24 jack@fw-fireface800-48000.service: start operation timed out. Terminating. jack@fw-fireface800-48000.service: State 'stop-sigterm' timed out. Killing. jack@fw-fireface800-48000.service: Killing process 1813 (jackd) with signal SIGKILL. jack@fw-fireface800-48000.service: Killing process 2021 (FW_ARMSTD) with signal SIGKILL. jack@fw-fireface800-48000.service: Processes still around after SIGKILL. Ignoring. jack@fw-fireface800-48000.service: State 'final-sigterm' timed out. Killing. jack@fw-fireface800-48000.service: Killing process 1813 (jackd) with signal SIGKILL. jack@fw-fireface800-48000.service: Processes still around after final SIGKILL. Entering failed mode. jack@fw-fireface800-48000.service: Failed with result 'timeout'. jack@fw-fireface800-48000.service: Unit process 1813 (jackd) remains running after unit stopped. Failed to start JACK server using fw-fireface800-48000.conf profile. ``` If I can provide more info, please let me know! Best, David [1] https://pkgbuild.com/~dvzrv/bugs/2021/03/linux-5.11.2-rt9-kernel.log [2] https://pkgbuild.com/~dvzrv/bugs/2021/03/linux-5.11.2-rt9-kernel_firewire_ohci_patch.log -- https://sleepmap.de [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-03-10 18:15 ` David Runge @ 2021-09-07 23:17 ` David Runge 2021-09-08 2:17 ` Takashi Sakamoto 0 siblings, 1 reply; 24+ messages in thread From: David Runge @ 2021-09-07 23:17 UTC (permalink / raw) To: Sebastian Andrzej Siewior Cc: Ahmed S. Darwish, linux-rt-users, linux1394-devel, Stefan Richter, Kristian Hoegsberg [-- Attachment #1: Type: text/plain, Size: 1792 bytes --] Hi all, As a follow-up to the previous conversation, I have now also tried 5.14.1-rt19 (packaged as 5.14.1.19.realtime1) in the hopes that ALSA driver improvements for my Fireface800 will allow me to use pipewire going forward. Unfortunately, firewire-ohci and/or firewire-core are still freezing upon trying to make use of the connected device which is connected with the card using the chip in question (see title). Upon first boot the /dev/fw0 and /dev/fw1 nodes did not show up initially [1] (log without using -1 debug parameter), which is why I switched the device off and on again. Afterwards the device nodes were created, so I attempted to use aplay -l to check whether the device was detected. The command hung forever (also starting jackd) and I had to reboot eventually. Using alsamixer I was able to select the Fireface800 device from the list of devices though. Upon 2nd boot I used the -1 debug parameter for firewire-ohci [2]. The device nodes were created automatically, but neither aplay -l nor alsamixer showed the audio interface. The attempt to switch the device off and on again and afterwards to remove the firewire-ohci module lead to another freeze and a successive reboot. If I can provide further information, please let me know! I hope I can try the vanilla 5.14.1 kernel tomorrow to see how it behaves in regards to firewire-ohci (judging from the past it will probably work though). Best, David P.S.: I have added Kristian Hoegsberg in CC, who is mentioned as the author of firewire-ohci and firewire-core. [1] https://pkgbuild.com/~dvzrv/bugs/2021/09/linux-5.14.1.19.realtime1-kernel.log [2] https://pkgbuild.com/~dvzrv/bugs/2021/09/linux-5.14.1.19.realtime1-restart_device_kernel.log -- https://sleepmap.de [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-09-07 23:17 ` David Runge @ 2021-09-08 2:17 ` Takashi Sakamoto 2021-09-08 17:30 ` David Runge 2021-09-10 11:55 ` Sebastian Andrzej Siewior 0 siblings, 2 replies; 24+ messages in thread From: Takashi Sakamoto @ 2021-09-08 2:17 UTC (permalink / raw) To: David Runge Cc: Sebastian Andrzej Siewior, Kristian Hoegsberg, linux1394-devel, linux-rt-users, Ahmed S. Darwish Hi, On Wed, Sep 08, 2021 at 01:17:02AM +0200, David Runge wrote: > Upon first boot the /dev/fw0 and /dev/fw1 nodes did not show up > initially [1] (log without using -1 debug parameter), which is why I > switched the device off and on again. > Afterwards the device nodes were created, so I attempted to use aplay -l > to check whether the device was detected. The command hung forever (also > starting jackd) and I had to reboot eventually. Using alsamixer I was > able to select the Fireface800 device from the list of devices though. > > Upon 2nd boot I used the -1 debug parameter for firewire-ohci [2]. > The device nodes were created automatically, but neither aplay -l nor > alsamixer showed the audio interface. The attempt to switch the device > off and on again and afterwards to remove the firewire-ohci module lead > to another freeze and a successive reboot. > > If I can provide further information, please let me know! > > I hope I can try the vanilla 5.14.1 kernel tomorrow to see how it > behaves in regards to firewire-ohci (judging from the past it will > probably work though). > > Best, > David > > P.S.: I have added Kristian Hoegsberg in CC, who is mentioned as the > author of firewire-ohci and firewire-core. > > [1] https://pkgbuild.com/~dvzrv/bugs/2021/09/linux-5.14.1.19.realtime1-kernel.log > [2] https://pkgbuild.com/~dvzrv/bugs/2021/09/linux-5.14.1.19.realtime1-restart_device_kernel.log ``` kernel: INFO: task pipewire-media-:2554 blocked for more than 122 seconds. kernel: Not tainted 5.14.1.19.realtime1-1-rt #1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. kernel: task:pipewire-media- state:D stack: 0 pid: 2554 ppid: 1803 flags:0x00000220 kernel: Call Trace: kernel: __schedule+0x338/0x1580 kernel: ? __mod_zone_page_state+0x81/0xf0 kernel: ? rt_spin_unlock+0x13/0x40 kernel: ? rmqueue_bulk+0x201/0x820 kernel: schedule+0x43/0xf0 kernel: schedule_timeout+0x14d/0x190 kernel: wait_for_completion+0x9e/0x100 kernel: fw_run_transaction+0xd7/0x110 [firewire_core bb04f32445782056ab0dc73199b57a87dc27c06d] ... ``` According to the log, the task of 'pipewire-media-:2554' is blocked during 122 seconds by call of 'wait_for_completion()' in code of 'fw_run_transaction()'. This is odd in two points of transaction service programmed in Linux FireWire subsystem: 1. The process context should be awakened by softIRQ context, which should be scheduled by hwIRQ context for hardware interrupt of OHCI 1394 controller. 2. Even if the softIRQ context is not invoked, the process context should be awakened by wheel timer context, which is scheduled to finish the transaction several jiffies later (originally prepared for the case of split-transaction). In the case, the result of transaction is 'RCODE_CANCELLED'. The call graph is below: 1 in the process context: ``` (drivers/firewire/core-transaction.c) ->fw_run_transaction() ->timer_setup_on_stack() ->fw_send_request() ->timer_setup() ->struct fw_card_driver.send_request() (drivers/firewire/ohci.c) = ohci_send_request() ... ->writel() ->wait_for_completion() (blocked and awakened by softIRQ context later) ->destroy_timer_on_stack() ``` 2 in the hwIRQ context: ``` (drivers/firewire/ohci.c) ->irq_handler() ->tasklet_schedule(&ohci->at_response_ctx.tasklet); ``` 3 in the softIRQ context: ``` (drivers/firewire/core-transaction.c) ->handle_at_packet() ->struct fw_packet.callback() = transmit_complete_callback() ->close_transaction() ->struct fw_transaction.callback() = transaction_callback() ->complete() ``` 4. in the timer wheel context: ``` (drivers/firewire/core-transaction.c) ->split_transaction_timeout_callback() ->struct fw_packet.callback() = transaction_callback() ->complete() ``` I guess we have issue in the softIRQ context or timer wheel context instead of hwIRQ context, if the OHCI 1394 controller you use has no quirk (I suggest you to give information about the controller). I'd like you to check it. The firewire-ohci module has 'debug' parameter. `` $ modinfo firewire-ohci ... parm: debug:Verbose logging (default = 0, AT/AR events = 1, self-IDs = 2, IRQs = 4, busReset events = 8, or a combination, or all = -1) (int) `` When the parameter has value '5' (= 1 | 4), we can see information per transaction, like: ``` kernel: firewire_ohci 0000:0b:00.0: IRQ 00000001 AT_req kernel: firewire_ohci 0000:0b:00.0: AT spd 2 tl 27, ffc1 -> ffc0, ack_pending , QR req, fffff0000400 kernel: firewire_ohci 0000:0b:00.0: IRQ 00000020 AR_resp kernel: firewire_ohci 0000:0b:00.0: AR spd 2 tl 27, ffc0 -> ffc1, ack_complete, QR resp = 04101573 ``` The first line: in hwIRQ context for request subaction The second line: in softIRQ context scheduled by the above. The third line: in hwIRQ context for response subaction The fourth line: in softIRQ context scheduled by the above. If we have any issue in invocation of softIRQ, we would often see missing swIRQ logs (and it might be the most concern to RT Linux developers). If you need instruction to configure module parameters, 'man modprobe.d' may be a good help. Thanks Takashi Sakamoto ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-09-08 2:17 ` Takashi Sakamoto @ 2021-09-08 17:30 ` David Runge 2021-09-09 0:46 ` Takashi Sakamoto 2021-09-10 11:55 ` Sebastian Andrzej Siewior 1 sibling, 1 reply; 24+ messages in thread From: David Runge @ 2021-09-08 17:30 UTC (permalink / raw) To: Sebastian Andrzej Siewior, Kristian Hoegsberg, linux1394-devel, linux-rt-users, Ahmed S. Darwish [-- Attachment #1: Type: text/plain, Size: 1952 bytes --] Hi Takashi, thanks for the prompt and detailed response! Unfortunately I lack the knowledge about the driver and its inner workings to be able to provide a patch for this issue myself. If anyone reading this who is able to suggest a fix, I'd be happy to test it! On 2021-09-08 11:17:18 (+0900), Takashi Sakamoto wrote: > I guess we have issue in the softIRQ context or timer wheel context > instead of hwIRQ context, if the OHCI 1394 controller you use has > no quirk (I suggest you to give information about the controller). > > I'd like you to check it. The firewire-ohci module has 'debug' parameter. > > `` > $ modinfo firewire-ohci > ... > parm: debug:Verbose logging (default = 0, AT/AR events = 1, self-IDs = 2, IRQs = 4, busReset events = 8, or a combination, or all = -1) (int) > `` I am using '-1' (all) in the 2nd link in my previous mail. It appears to not show a different output in the kernel logs from when I set it to '5' though. There seems to be something wrong... I'm adding the options in a .conf file below /etc/modprobe.d/, e.g.: ``` options firewire-ohci debug=5 ``` The only output I get from that is: ``` firewire_ohci 0000:05:00.0: enabling device (0000 -> 0002) firewire_ohci 0000:05:00.0: added OHCI v1.10 device as card 0, 8 IR + 8 IT contexts, quirks 0x2 firewire_core 0000:05:00.0: created device fw0: GUID 7856341278563412, S800 firewire_ohci 0000:05:00.0: isochronous cycle inconsistent firewire_core 0000:05:00.0: created device fw1: GUID 000a3500ada83262, S400 firewire_core 0000:05:00.0: phy config: new root=ffc0, gap_count=5 ``` This is with starting with the audio interface connected and on. I have to switch it off and on again to get recognized, but then the driver crashes (full kernel log [1]) [1] https://pkgbuild.com/~dvzrv/bugs/2021/09/linux-5.14.1.19.realtime1-firewire-ohci-debug-kernel.log Best, David -- https://sleepmap.de [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-09-08 17:30 ` David Runge @ 2021-09-09 0:46 ` Takashi Sakamoto 2021-09-12 18:44 ` David Runge 0 siblings, 1 reply; 24+ messages in thread From: Takashi Sakamoto @ 2021-09-09 0:46 UTC (permalink / raw) To: David Runge Cc: Sebastian Andrzej Siewior, Kristian Hoegsberg, linux1394-devel, linux-rt-users, Ahmed S. Darwish On Wed, Sep 08, 2021 at 07:30:14PM +0200, David Runge wrote: > I am using '-1' (all) in the 2nd link in my previous mail. It appears to > not show a different output in the kernel logs from when I set it to '5' > though. There seems to be something wrong... > I'm adding the options in a .conf file below /etc/modprobe.d/, e.g.: > > ``` > options firewire-ohci debug=5 > ``` > > The only output I get from that is: > > ``` > firewire_ohci 0000:05:00.0: enabling device (0000 -> 0002) > firewire_ohci 0000:05:00.0: added OHCI v1.10 device as card 0, 8 IR + 8 IT contexts, quirks 0x2 > firewire_core 0000:05:00.0: created device fw0: GUID 7856341278563412, S800 > firewire_ohci 0000:05:00.0: isochronous cycle inconsistent > firewire_core 0000:05:00.0: created device fw1: GUID 000a3500ada83262, S400 > firewire_core 0000:05:00.0: phy config: new root=ffc0, gap_count=5 > ``` Before printing 'created device fw1', Linux FireWire subsystem already initiates asynchronous transactions to retrieve content of configuration ROM located in 0x'ffff'f000'0400 of node address space. If you can see no transaction record but see the print, it means to fail configuration of the parameter of firewire-ohci module. I think your system uses initramfs. Any node for storage function in IEEE 1394 bus is available as initial boot disk, thus it's reasonable that the designer of your initramfs puts firewire-ohci/firewire-core modules into it. In the case, we can not configure module by '/etc/modprobe.d/*' since the modules are already loaded before mounting root file system. I think the design of initramfs differs depending on distribution, thus you need to find instruction for the way to configure module parameter by yourself. Instead, I suggest you to configure the module via sysfs after booting, like: ``` # echo 5 > /sys/module/firewire_ohci/parameters/debug ``` Then retry detection of node for your Fireface 800. When turning off the debug print, write 0 to the node of sysfs. Regards Takashi Sakamoto ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-09-09 0:46 ` Takashi Sakamoto @ 2021-09-12 18:44 ` David Runge 0 siblings, 0 replies; 24+ messages in thread From: David Runge @ 2021-09-12 18:44 UTC (permalink / raw) To: Sebastian Andrzej Siewior, Kristian Hoegsberg, linux1394-devel, linux-rt-users, Ahmed S. Darwish [-- Attachment #1: Type: text/plain, Size: 3044 bytes --] On 2021-09-09 09:46:06 (+0900), Takashi Sakamoto wrote: > On Wed, Sep 08, 2021 at 07:30:14PM +0200, David Runge wrote: > > I am using '-1' (all) in the 2nd link in my previous mail. It appears to > > not show a different output in the kernel logs from when I set it to '5' > > though. There seems to be something wrong... > > I'm adding the options in a .conf file below /etc/modprobe.d/, e.g.: > > > > ``` > > options firewire-ohci debug=5 > > ``` > > > > The only output I get from that is: > > > > ``` > > firewire_ohci 0000:05:00.0: enabling device (0000 -> 0002) > > firewire_ohci 0000:05:00.0: added OHCI v1.10 device as card 0, 8 IR + 8 IT contexts, quirks 0x2 > > firewire_core 0000:05:00.0: created device fw0: GUID 7856341278563412, S800 > > firewire_ohci 0000:05:00.0: isochronous cycle inconsistent > > firewire_core 0000:05:00.0: created device fw1: GUID 000a3500ada83262, S400 > > firewire_core 0000:05:00.0: phy config: new root=ffc0, gap_count=5 > > ``` > > Before printing 'created device fw1', Linux FireWire subsystem already > initiates asynchronous transactions to retrieve content of configuration > ROM located in 0x'ffff'f000'0400 of node address space. If you can see > no transaction record but see the print, it means to fail configuration > of the parameter of firewire-ohci module. > > I think your system uses initramfs. Any node for storage function in > IEEE 1394 bus is available as initial boot disk, thus it's reasonable > that the designer of your initramfs puts firewire-ohci/firewire-core > modules into it. In the case, we can not configure module by > '/etc/modprobe.d/*' since the modules are already loaded before mounting > root file system. > > I think the design of initramfs differs depending on distribution, thus > you need to find instruction for the way to configure module parameter > by yourself. > > Instead, I suggest you to configure the module via sysfs after booting, > like: > > ``` > # echo 5 > /sys/module/firewire_ohci/parameters/debug > ``` I have played around with adding the configuration and the module explicitly to the initramfs (we're using mkinitcpio on Arch Linux). However, this did not change anything in the output provided by journalctl [1]. A boot with the vanilla 5.14.2 (no threadirqs) and debug=-1 set for firewire-ohci logs everything successfully [2]. My assumption is that the debug parameter is either not considered or the module hangs far before there's any further output when on linux-rt. Unrelated sidenote: I am currently booted into vanilla 5.14.2 (no threadirqs) and the device works well using pipewire and the ALSA driver snd-fireface. Good job to everyone involved! I'm very happy about the results! \o/ Best, David [1] https://pkgbuild.com/~dvzrv/bugs/2021/09/linux-5.14.1.19.realtime1-firewire-ohci-debug--1-initramfs-kernel.log [2] https://pkgbuild.com/~dvzrv/bugs/2021/09/linux-5.14.2.arch1-firewire-ohci-debug--1-initramfs-kernel.log -- https://sleepmap.de [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-09-08 2:17 ` Takashi Sakamoto 2021-09-08 17:30 ` David Runge @ 2021-09-10 11:55 ` Sebastian Andrzej Siewior 2021-09-11 9:46 ` Takashi Sakamoto 1 sibling, 1 reply; 24+ messages in thread From: Sebastian Andrzej Siewior @ 2021-09-10 11:55 UTC (permalink / raw) To: David Runge, Kristian Hoegsberg, linux1394-devel, linux-rt-users, Ahmed S. Darwish On 2021-09-08 11:17:18 [+0900], Takashi Sakamoto wrote: > Hi, Hi, > According to the log, the task of 'pipewire-media-:2554' is blocked during > 122 seconds by call of 'wait_for_completion()' in code of > 'fw_run_transaction()'. This is odd in two points of transaction service > programmed in Linux FireWire subsystem: > > 1. The process context should be awakened by softIRQ context, which should > be scheduled by hwIRQ context for hardware interrupt of OHCI 1394 > controller. > 2. Even if the softIRQ context is not invoked, the process context > should be awakened by wheel timer context, which is scheduled to finish > the transaction several jiffies later (originally prepared for the case > of split-transaction). In the case, the result of transaction is > 'RCODE_CANCELLED'. Side note: David is using PREEMPT_RT and his problem can be reduced to plain vanilla with `threadirqs' boot option. Back in February I sent him a patch [0] which inlines the tasklet job as I assumed it is not good reset the IRQ-event in the tasklet/workqueue. It seemed to improve the situtation as it recognized the device attached to the bus but ended then in the same timeout behaviour as now. [0] https://https://lkml.kernel.org/r/.kernel.org/all/20210218083849.iitcrhdgv2oajfhv@linutronix.de/ > Thanks > > Takashi Sakamoto Sebastian ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-09-10 11:55 ` Sebastian Andrzej Siewior @ 2021-09-11 9:46 ` Takashi Sakamoto 2021-09-12 18:53 ` David Runge 0 siblings, 1 reply; 24+ messages in thread From: Takashi Sakamoto @ 2021-09-11 9:46 UTC (permalink / raw) To: Sebastian Andrzej Siewior Cc: David Runge, linux1394-devel, linux-rt-users, Ahmed S. Darwish Hi, On Fri, Sep 10, 2021 at 01:55:41PM +0200, Sebastian Andrzej Siewior wrote: > On 2021-09-08 11:17:18 [+0900], Takashi Sakamoto wrote: > > Hi, > Hi, > > > According to the log, the task of 'pipewire-media-:2554' is blocked during > > 122 seconds by call of 'wait_for_completion()' in code of > > 'fw_run_transaction()'. This is odd in two points of transaction service > > programmed in Linux FireWire subsystem: > > > > 1. The process context should be awakened by softIRQ context, which should > > be scheduled by hwIRQ context for hardware interrupt of OHCI 1394 > > controller. > > 2. Even if the softIRQ context is not invoked, the process context > > should be awakened by wheel timer context, which is scheduled to finish > > the transaction several jiffies later (originally prepared for the case > > of split-transaction). In the case, the result of transaction is > > 'RCODE_CANCELLED'. > > > Side note: David is using PREEMPT_RT and his problem can be reduced to > plain vanilla with `threadirqs' boot option. Back in February I sent him > a patch [0] which inlines the tasklet job as I assumed it is not good > reset the IRQ-event in the tasklet/workqueue. It seemed to improve the > situtation as it recognized the device attached to the bus but ended > then in the same timeout behaviour as now. > > [0] https://https://lkml.kernel.org/r/.kernel.org/all/20210218083849.iitcrhdgv2oajfhv@linutronix.de/ Thanks for the side note, and I apologize to follow the thread partially, not entire. Furthermore, I'd like to correct my misunderstanding about the 2nd point since the timer wheel context is scheduled only when the peer of transaction transfer ack_pending for the request subaction. Without the hwIRQ context, the task is blocked ever anyway. Regards Takashi Sakamoto ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-09-11 9:46 ` Takashi Sakamoto @ 2021-09-12 18:53 ` David Runge 2022-01-05 21:01 ` Holger Dehnhardt 0 siblings, 1 reply; 24+ messages in thread From: David Runge @ 2021-09-12 18:53 UTC (permalink / raw) To: Sebastian Andrzej Siewior, linux1394-devel, linux-rt-users, Ahmed S. Darwish [-- Attachment #1: Type: text/plain, Size: 2294 bytes --] On 2021-09-11 18:46:57 (+0900), Takashi Sakamoto wrote: > Hi, > > On Fri, Sep 10, 2021 at 01:55:41PM +0200, Sebastian Andrzej Siewior wrote: > > On 2021-09-08 11:17:18 [+0900], Takashi Sakamoto wrote: > > > Hi, > > Hi, > > > > > According to the log, the task of 'pipewire-media-:2554' is blocked during > > > 122 seconds by call of 'wait_for_completion()' in code of > > > 'fw_run_transaction()'. This is odd in two points of transaction service > > > programmed in Linux FireWire subsystem: > > > > > > 1. The process context should be awakened by softIRQ context, which should > > > be scheduled by hwIRQ context for hardware interrupt of OHCI 1394 > > > controller. > > > 2. Even if the softIRQ context is not invoked, the process context > > > should be awakened by wheel timer context, which is scheduled to finish > > > the transaction several jiffies later (originally prepared for the case > > > of split-transaction). In the case, the result of transaction is > > > 'RCODE_CANCELLED'. > > > > > > Side note: David is using PREEMPT_RT and his problem can be reduced to > > plain vanilla with `threadirqs' boot option. Back in February I sent him > > a patch [0] which inlines the tasklet job as I assumed it is not good > > reset the IRQ-event in the tasklet/workqueue. It seemed to improve the > > situtation as it recognized the device attached to the bus but ended > > then in the same timeout behaviour as now. > > > > [0] https://https://lkml.kernel.org/r/.kernel.org/all/20210218083849.iitcrhdgv2oajfhv@linutronix.de/ > > Thanks for the side note, and I apologize to follow the thread partially, > not entire. > > Furthermore, I'd like to correct my misunderstanding about the 2nd point > since the timer wheel context is scheduled only when the peer of > transaction transfer ack_pending for the request subaction. Without the > hwIRQ context, the task is blocked ever anyway. Thanks at any rate to look into this! It is much appreciated! Is there anything further I can try to debug this using threadirqs? It would be really amazing to be able to use this device on PREEMPT_RT again (especially given that now the ALSA driver has improved so drastically). :) Best, David -- https://sleepmap.de [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] 2021-09-12 18:53 ` David Runge @ 2022-01-05 21:01 ` Holger Dehnhardt 0 siblings, 0 replies; 24+ messages in thread From: Holger Dehnhardt @ 2022-01-05 21:01 UTC (permalink / raw) To: David Runge, Sebastian Andrzej Siewior, linux1394-devel, linux-rt-users, Ahmed S. Darwish On 12.09.21 20:53, David Runge wrote: > > Thanks at any rate to look into this! It is much appreciated! > > Is there anything further I can try to debug this using threadirqs? It > would be really amazing to be able to use this device on PREEMPT_RT > again (especially given that now the ALSA driver has improved so > drastically). :) > > Best, > David > Hi, since a processor and BIOS update I ran into the same problems as David. * former processor alt: AMD Ryzen 2 0600X 6-Core * new processor neu: AMD Ryzen 7 3700X 8-Core Processor * kernel (Ubuntu): 5.4.0-91-lowlatency #102-Ubuntu SMP PREEMPT Fri Nov 5 18:18:39 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux * chipset: AMD B450 * firewire card: 05:00.0 FireWire (IEEE 1394): Texas Instruments XIO2213A/B/XIO2221 IEEE-1394b OHCI Controller [Cheetah Express] (rev 01) (prog-if 10 [OHCI]) Subsystem: Device 3412:7856 Flags: bus master, 66MHz, medium devsel, latency 32, IRQ 36 Memory at fc204000 (32-bit, non-prefetchable) [size=2K] Memory at fc200000 (32-bit, non-prefetchable) [size=16K] Capabilities: [44] Power Management version 3 Kernel modules: firewire_ohci I did not change the kernel version - it worked before upgrading the processor and BIOS with the same kernel! Now jack or alternatively "ffado-test Discover" immediately get zombified when I try to start them. In addition to Davids findings a can add the following: Under some weird circumstances I got the card to work (once immediately after loading BIOS to defaults and three times after an unsuccessful try to downgrade the BIOS). Appended are two dmesg outputs one in which the card is initialized correctly [1], one in which the card did not work [2]. Another finding was, that after the driver was trying some time to read the config ROM, it gave up and, did a bus reset and everything was fine [3]. I just have build the kernel modules with some mor debugging output. So if there's something I should try, just give me intructions ;-) Holger [1] https://cloud.dehnhardt.org/s/Z7jwqT9y3x6JgbE [2] https://cloud.dehnhardt.org/s/GAm2MjSqdbYDcod [3] [Mo Jan 3 18:41:53 2022] firewire_ohci 0000:05:00.0: added OHCI v1.10 device as card 0, 8 IR + 8 IT contexts, quirks 0x2 [Mo Jan 3 18:41:53 2022] firewire_core 0000:05:00.0: created device fw0: GUID 7856341278563412, S800 [Mo Jan 3 18:41:53 2022] firewire_core 0000:05:00.0: phy config: new root=ffc1, gap_count=5 [Mo Jan 3 18:45:59 2022] Workqueue: firewire fw_device_workfn [firewire_core] [Mo Jan 3 18:45:59 2022] fw_run_transaction+0xdc/0x110 [firewire_core] [Mo Jan 3 18:45:59 2022] ? fw_core_handle_bus_reset+0x440/0x440 [firewire_core] [Mo Jan 3 18:45:59 2022] ? close_transaction+0x110/0x110 [firewire_core] [Mo Jan 3 18:45:59 2022] ? transmit_phy_packet_callback+0x20/0x20 [firewire_core] [Mo Jan 3 18:45:59 2022] read_rom+0x5e/0xa0 [firewire_core] [Mo Jan 3 18:45:59 2022] read_config_rom+0x8b/0x3d0 [firewire_core] [Mo Jan 3 18:45:59 2022] fw_device_init+0x35/0x320 [firewire_core] [Mo Jan 3 18:45:59 2022] fw_device_workfn+0x12/0x20 [firewire_core] [snip...] [Mo Jan 3 19:04:25 2022] Workqueue: firewire fw_device_workfn [firewire_core] [Mo Jan 3 19:04:25 2022] fw_run_transaction+0xdc/0x110 [firewire_core] [Mo Jan 3 19:04:25 2022] ? fw_core_handle_bus_reset+0x440/0x440 [firewire_core] [Mo Jan 3 19:04:25 2022] ? close_transaction+0x110/0x110 [firewire_core] [Mo Jan 3 19:04:25 2022] ? transmit_phy_packet_callback+0x20/0x20 [firewire_core] [Mo Jan 3 19:04:25 2022] read_rom+0x5e/0xa0 [firewire_core] [Mo Jan 3 19:04:25 2022] read_config_rom+0x8b/0x3d0 [firewire_core] [Mo Jan 3 19:04:25 2022] fw_device_init+0x35/0x320 [firewire_core] [Mo Jan 3 19:04:25 2022] fw_device_workfn+0x12/0x20 [firewire_core] [Mo Jan 3 21:03:50 2022] firewire_core 0000:05:00.0: giving up on node ffc0: reading config rom failed: bus reset [Mo Jan 3 21:03:51 2022] firewire_core 0000:05:00.0: rediscovered device fw0 [Mo Jan 3 21:03:56 2022] firewire_core 0000:05:00.0: rediscovered device fw0 [Mo Jan 3 21:03:56 2022] firewire_core 0000:05:00.0: phy config: new root=ffc1, gap_count=5 [Mo Jan 3 21:04:01 2022] firewire_core 0000:05:00.0: created device fw1: GUID 000ff20400001d98, S400 ^ permalink raw reply [flat|nested] 24+ messages in thread
end of thread, other threads:[~2022-01-05 21:40 UTC | newest] Thread overview: 24+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2021-01-23 11:59 firewire-ohci fails to initialize Texas Instruments XIO2213A/B/XIO2221 based controller on realtime kernels [5.4.91-rt50, 5.10.8-rt24] David Runge 2021-01-28 6:28 ` Ahmed S. Darwish 2021-01-28 21:41 ` David Runge 2021-01-29 17:04 ` Sebastian Andrzej Siewior 2021-01-30 11:46 ` David Runge 2021-02-01 8:34 ` Sebastian Andrzej Siewior 2021-02-05 11:26 ` Sebastian Andrzej Siewior 2021-02-05 23:22 ` David Runge 2021-02-07 9:58 ` David Runge 2021-02-08 9:19 ` Sebastian Andrzej Siewior 2021-02-14 19:16 ` David Runge 2021-02-18 8:38 ` Sebastian Andrzej Siewior 2021-02-18 9:27 ` Sebastian Andrzej Siewior 2021-03-08 14:12 ` Sebastian Andrzej Siewior 2021-03-10 18:15 ` David Runge 2021-09-07 23:17 ` David Runge 2021-09-08 2:17 ` Takashi Sakamoto 2021-09-08 17:30 ` David Runge 2021-09-09 0:46 ` Takashi Sakamoto 2021-09-12 18:44 ` David Runge 2021-09-10 11:55 ` Sebastian Andrzej Siewior 2021-09-11 9:46 ` Takashi Sakamoto 2021-09-12 18:53 ` David Runge 2022-01-05 21:01 ` Holger Dehnhardt
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.