Bug#565342: newly released libffado2-based jackd fails with "firewire ERR: Could not start streaming threads: -1"

Sat Jan 16 16:20:03 UTC 2010

On Fri, Jan 15, 2010 at 04:28:16PM +0100, Adrian Knoth wrote:
>On Fri, Jan 15, 2010 at 03:00:57PM +0100, Jonas Smedegaard wrote:

>>> Finding the right value(s) for p (and n) could be a hard job, so 
>>> playing with those might be useful.
>>
>> Are you suggesting to shoot in the dark for magic combinations here, 
>> and that _both_ too low and too high values lead to same error 
>> messages?
>
>Absolutely. Larger unfortunately isn't better here. [details snipped]

Enlightening. Thanks!

>If need be, file a ticket at subversion.ffado.org

I guess it makes sense to first try isolate which part of the Debian 
packaging system cause problem before passing it upstream:

I now tested using a Linux kernel containing both JuJu and oldstyle 
drivers (Ubuntu linux-image-2.6.32-10-generic_2.6.32-10.14_amd64.deb), 
and between each test I unplugged (i.e. powercucled) my Edirol FA-66, 
unloaded all firewire drivers, plugged in, loaded selected drivers, 
verified that only chosen drivers were in fact loaded, and verified that 
recent kernel messages didn't mention e.g. "DMA context still active".

All tests are executed as root, to avoid ACL problems.

Results using *jack* 0.118+svn3796-1, *ffado* 2.0~rc2+svn1569-2 and 
*freebob* 1.0.11-1 (i.e. latest Debian Sid except jackd and least 
possible dependencies rolled back to latest Debian Squeeze):

OK: firewire-ohci + jackd -d firewire -p 512 -n3 -r 44100 -v5

OK: dv1394 + raw1394 + jackd -d firewire -p 512 -n3 -r 44100 -v5

OK: dv1394 + raw1394 + jackd -d freebob -p 512 -n3 -r 44100

Above makes me assume that hardware (MacBook) is ok.

Results using *jack* 0.118+svn3796-2, *ffado* 2.0.0-1 and no *freebob* 
(i.e. latest Debian Sid):

OK: dv1394 + raw1394 + jackd -d firewire -p 512 -n3 -r 44100 -v5

FAIL: firewire-ohci + jackd -d firewire -p 512 -n3 -r 44100 -v5

Below is input/output related to that last failure above:

root at auryn:/lib/modules/2.6.32-10-generic/kernel/drivers# modprobe -r firewire_ohci 
root at auryn:/lib/modules/2.6.32-10-generic/kernel/drivers# lsmod | grep -P '(firewire|1394)'
root at auryn:/lib/modules/2.6.32-10-generic/kernel/drivers# modprobe firewire_ohci 
root at auryn:/lib/modules/2.6.32-10-generic/kernel/drivers# lsmod | grep -P '(firewire|1394)'
firewire_ohci          25343  0 
firewire_core          51370  1 firewire_ohci
crc_itu_t               1715  1 firewire_core
root at auryn:/lib/modules/2.6.32-10-generic/kernel/drivers# dmesg | tail
[ 3634.786560] firewire_core: phy config: card 0, new root=ffc1, gap_count=5
[ 3634.881240] firewire_core: created device fw1: GUID 0040ab0000c348f2, S400, 1 config ROM retries
[ 3659.320070] firewire_ohci: Error: DMA context still active (0x00000400)
[ 3701.601288] firewire_ohci: Removed fw-ohci device.
[ 3751.802544] firewire_ohci: Added fw-ohci device 0000:03:03.0, OHCI version 1.0
[ 3752.300144] firewire_core: created device fw0: GUID 0019e3fffe8484fc, S400
[ 3779.002551] firewire_ohci: failed to set phy reg bits.
[ 3779.005246] firewire_ohci: Removed fw-ohci device.
[ 3786.382032] firewire_ohci: Added fw-ohci device 0000:03:03.0, OHCI version 1.0
[ 3786.880199] firewire_core: created device fw0: GUID 0019e3fffe8484fc, S400
root at auryn:/lib/modules/2.6.32-10-generic/kernel/drivers# dmesg | tail
[ 3659.320070] firewire_ohci: Error: DMA context still active (0x00000400)
[ 3701.601288] firewire_ohci: Removed fw-ohci device.
[ 3751.802544] firewire_ohci: Added fw-ohci device 0000:03:03.0, OHCI version 1.0
[ 3752.300144] firewire_core: created device fw0: GUID 0019e3fffe8484fc, S400
[ 3779.002551] firewire_ohci: failed to set phy reg bits.
[ 3779.005246] firewire_ohci: Removed fw-ohci device.
[ 3786.382032] firewire_ohci: Added fw-ohci device 0000:03:03.0, OHCI version 1.0
[ 3786.880199] firewire_core: created device fw0: GUID 0019e3fffe8484fc, S400
[ 3813.002892] firewire_core: phy config: card 0, new root=ffc1, gap_count=5
[ 3816.492549] firewire_core: phy config: card 0, new root=ffc1, gap_count=5
root at auryn:/lib/modules/2.6.32-10-generic/kernel/drivers# jackd -d firewire -p 512 -n3 -r 44100 -v5
jackd 0.118.0
Copyright 2001-2009 Paul Davis, Stephane Letz, Jack O'Quinn, Torben Hohn and others.
jackd 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

no message buffer overruns
JACK compiled with System V SHM support.
loading driver ..
SSE2 detected
libffado 2.0.0 built Jan  3 2010 16:43:07
03833322720: Warning (ieee1394service.cpp)[ 328] initialize: Could not set SPLIT_TIMEOUT to min requested (1000000)
03833324290: Warning (ieee1394service.cpp)[ 332] initialize: Set SPLIT_TIMEOUT to min requested (1000000) did not succeed
03842391162: Error (StreamProcessor.cpp)[1192] scheduleStartDryRunning: Cannot switch to ePS_DryRunning from ePS_WaitingForStream
03842391205: Error (StreamProcessorManager.cpp)[ 408] startDryRunning: Could not put SP 0x2589a80 into the dry-running state
03842391225: Error (StreamProcessor.cpp)[1192] scheduleStartDryRunning: Cannot switch to ePS_DryRunning from ePS_WaitingForStream
03842391241: Error (StreamProcessorManager.cpp)[ 408] startDryRunning: Could not put SP 0x2589a80 into the dry-running state
03842391258: Error (StreamProcessor.cpp)[1192] scheduleStartDryRunning: Cannot switch to ePS_DryRunning from ePS_WaitingForStream
03842391275: Error (StreamProcessorManager.cpp)[ 408] startDryRunning: Could not put SP 0x2589a80 into the dry-running state
03842391292: Error (StreamProcessor.cpp)[1192] scheduleStartDryRunning: Cannot switch to ePS_DryRunning from ePS_WaitingForStream
03842391307: Error (StreamProcessorManager.cpp)[ 408] startDryRunning: Could not put SP 0x2589a80 into the dry-running state
03842391324: Error (StreamProcessor.cpp)[1192] scheduleStartDryRunning: Cannot switch to ePS_DryRunning from ePS_WaitingForStream
03842391339: Error (StreamProcessorManager.cpp)[ 408] startDryRunning: Could not put SP 0x2589a80 into the dry-running state
03842391356: Error (StreamProcessor.cpp)[1192] scheduleStartDryRunning: Cannot switch to ePS_DryRunning from ePS_WaitingForStream
03842391371: Error (StreamProcessorManager.cpp)[ 408] startDryRunning: Could not put SP 0x2589a80 into the dry-running state
03842391388: Error (StreamProcessor.cpp)[1192] scheduleStartDryRunning: Cannot switch to ePS_DryRunning from ePS_WaitingForStream
03842391403: Error (StreamProcessorManager.cpp)[ 408] startDryRunning: Could not put SP 0x2589a80 into the dry-running state
03842391420: Error (StreamProcessor.cpp)[1192] scheduleStartDryRunning: Cannot switch to ePS_DryRunning from ePS_WaitingForStream
03842391435: Error (StreamProcessorManager.cpp)[ 408] startDryRunning: Could not put SP 0x2589a80 into the dry-running state
03842391452: Error (StreamProcessor.cpp)[1192] scheduleStartDryRunning: Cannot switch to ePS_DryRunning from ePS_WaitingForStream
03842391467: Error (StreamProcessorManager.cpp)[ 408] startDryRunning: Could not put SP 0x2589a80 into the dry-running state
03842391483: Fatal (StreamProcessorManager.cpp)[ 901] start: Could not syncStartAll...
03842391498: Warning (devicemanager.cpp)[ 912] startStreaming: Failed to start SPM!
03842392261: Warning (ieee1394service.cpp)[1284] freeIsoChannel: Could not do CMP disconnect for channel 0!
03842392940: Warning (ieee1394service.cpp)[1284] freeIsoChannel: Could not do CMP disconnect for channel 1!
03842392959: Fatal (ffado.cpp)[ 211] ffado_streaming_start: Could not start the streaming system
firewire ERR: Could not start streaming threads: -1
DRIVER NT: could not start driver
cannot start driver
jackd watchdog: timeout - killing jackd
no message buffer overruns

So, it seems to be that problem is in either jack compilation/linkage or 
in FFADO source.

How to proceed from here?  More tests I can perform?  Should I post 
above to upstream FFADO or Jackd developers (and if so, how?)?

Kind regards,

  - Jonas

-- 
* Jonas Smedegaard - idealist & Internet-arkitekt
* Tlf.: +45 40843136  Website: http://dr.jones.dk/

  [x] quote me freely  [ ] ask before reusing  [ ] keep private
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: Digital signature
URL: <http://lists.alioth.debian.org/pipermail/pkg-multimedia-maintainers/attachments/20100116/2f5cf98b/attachment.pgp>