Ubuntu
libfreebob package

jackd crashes using freebob and firewire devices

Bug #231085 reported by prismatic7
This bug report is a duplicate of:  Bug #232490: fw-host0: Iso Xmit 0 Context died. Edit Remove
4
Affects Status Importance Assigned to Milestone
Ubuntu Studio
Invalid
Undecided
Unassigned
jack-audio-connection-kit (Ubuntu)
New
Undecided
Unassigned
libfreebob (Ubuntu)
New
Undecided
Unassigned

Bug Description

Description: Ubuntu 8.04
Release: 8.04
uname: 2.6.24-16-rt #1 SMP PREEMPT RT Thu Apr 10 15:15:40 UTC 2008 i686 GNU/Linux

I have recently purchased a Focusrite Saffire LE firewire audio interface, which is supposedly supported by both freeBoB and FFADO, however I am unable to use the device. jackd either crashes after the timeout period, or jack-aware applications are not able to connect (see log below)

The system is a Dell XPS M1210. sudo lspci -v reports the firewire chipset as:

03:01.0 FireWire (IEEE 1394): Ricoh Co Ltd R5C832 IEEE 1394 Controller (prog-if 10 [OHCI])
 Subsystem: Dell Unknown device 01d7
 Flags: bus master, medium devsel, latency 64, IRQ 18
 Memory at ecbfd800 (32-bit, non-prefetchable) [size=2K]
 Capabilities: [dc] Power Management version 2

This is the output of qjackctl's verbose messages:

17:53:42.703 Patchbay deactivated.
17:53:42.756 Statistics reset.
17:53:42.765 ALSA connection graph change.
17:53:42.963 ALSA connection change.
17:54:12.979 Startup script...
17:54:12.979 artsshell -q terminate
17:54:13.401 Startup script terminated with exit status=256.
17:54:13.401 JACK is starting...
17:54:13.402 /usr/bin/jackd -v -R -P89 -m -dfreebob -dhw:0 -r48000 -p256 -n2 -D
17:54:13.404 JACK was started with PID=12942.
getting driver descriptor from /usr/lib/jack/jack_dummy.so
getting driver descriptor from /usr/lib/jack/jack_oss.so
getting driver descriptor from /usr/lib/jack/jack_freebob.so
getting driver descriptor from /usr/lib/jack/jack_alsa.so
jackd 0.109.2
Copyright 2001-2005 Paul Davis 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
JACK compiled with System V SHM support.
server `default' registered
registered builtin port type 32 bit float mono audio
registered builtin port type 8 bit raw midi
clock source = system clock via clock_gettime
loading driver ..
new client: freebob_pcm, id = 1 type 1 @ 0x8070108 fd = -1
Freebob using Firewire port 0, node -1
new buffer size 256
LibFreeBoB MSG: FreeBoB Streaming Device Init
LibFreeBoB MSG: Using FreeBoB lib version libfreebob 1.0.7
LibFreeBoB MSG: Device information:
LibFreeBoB MSG: Device options:
LibFreeBoB MSG: Port : 0
LibFreeBoB MSG: Device Node Id : -1
LibFreeBoB MSG: Samplerate : 48000
LibFreeBoB MSG: Period Size : 256
LibFreeBoB MSG: Nb Buffers : 2
LibFreeBoB MSG: Directions : 0
showDevice: not implemented
17:54:14.039 ALSA connection graph change.
FreeBoB MSG: Register MIDI IN port dev1c_Midi In
FreeBoB MSG: Register MIDI OUT port dev1p_Midi Out
FreeBoB MSG: Streaming thread running with Realtime scheduling, priority 93
FreeBoB MSG: Registering audio capture port C0_dev1c_Rec 1
FreeBoB MSG: Registering audio capture port C1_dev1c_Rec 2
registered port system:capture_1, offset = 1024
registered port system:capture_2, offset = 2048
FreeBoB MSG: Registering audio capture port C2_dev1c_Rec 3
FreeBoB MSG: Registering audio capture port C3_dev1c_Rec 4
FreeBoB MSG: Registering audio capture port C4_dev1c_Rec 5
FreeBoB MSG: Registering audio capture port C5_dev1c_Rec 6
FreeBoB MSG: Don't register capture port for dev1c_Midi In
FreeBoB MSG: Registering playback audio port P0_dev1p_Play 1
FreeBoB MSG: Registering playback audio port P1_dev1p_Play 2
FreeBoB MSG: Registering playback audio port P2_dev1p_Play 3
FreeBoB MSG: Registering playback audio port P3_dev1p_Play 4
FreeBoB MSG: Registering playback audio port P4_dev1p_Play 5
FreeBoB MSG: Registering playback audio port P5_dev1p_Play 6
FreeBoB MSG: Registering playback audio port P6_dev1p_Play 7
FreeBoB MSG: Registering playback audio port P7_dev1p_Play 8
FreeBoB MSG: Don't register playback port dev1p_Midi Out
registered port system:capture_3, offset = 3072
registered port system:capture_4, offset = 4096
registered port system:capture_5, offset = 5120
registered port system:capture_6, offset = 6144
registered port system:playback_1, offset = 0
registered port system:playback_2, offset = 0
registered port system:playback_3, offset = 0
registered port system:playback_4, offset = 0
registered port system:playback_5, offset = 0
registered port system:playback_6, offset = 0
registered port system:playback_7, offset = 0
registered port system:playback_8, offset = 0
++ jack_rechain_graph():
client freebob_pcm: internal client, execution_order=0.
-- jack_rechain_graph()
FreeBoB MSG: MIDI threads running with Realtime scheduling, priority 92
FreeBoB MSG: MIDI queue thread started
libiec61883 warning: Established connection on channel 0.
You may need to manually set the channel on the receiving node.
libiec61883 warning: Established connection on channel 1.
You may need to manually set the channel on the transmitting node.
12942 waiting for signals
17:54:14.219 ALSA connection change.
17:54:15.434 Server configuration saved to "/home/chris/.jackdrc".
17:54:15.435 Statistics reset.
17:54:15.436 Client activated.
17:54:15.439 JACK connection change.
17:54:15.442 JACK connection graph change.
new client: qjackctl, id = 2 type 2 @ 0xb7ed6000 fd = 17
++ jack_rechain_graph():
client freebob_pcm: internal client, execution_order=0.
client qjackctl: start_fd=7, execution_order=0.
client qjackctl: wait_fd=16, execution_order=1 (last client).
-- jack_rechain_graph()
load = 2.1283 max usecs: 227.000, spare = 5106.000
load = 3.2393 max usecs: 232.000, spare = 5101.000
load = 3.8041 max usecs: 233.000, spare = 5100.000
load = 3.9084 max usecs: 214.000, spare = 5119.000
load = 3.9043 max usecs: 208.000, spare = 5125.000
load = 4.0804 max usecs: 227.000, spare = 5106.000
load = 4.2060 max usecs: 231.000, spare = 5102.000
load = 4.1469 max usecs: 218.000, spare = 5115.000
load = 4.0798 max usecs: 214.000, spare = 5119.000
load = 4.0088 max usecs: 210.000, spare = 5123.000
load = 4.0951 max usecs: 223.000, spare = 5110.000
new client: hydrogen-tmp, id = 3 type 2 @ 0xb7ed5000 fd = 20
removing disconnected client hydrogen-tmp state = Not triggered errors = 0
removing client "hydrogen-tmp"
removing client "hydrogen-tmp" from the processing chain
17:54:27.964 JACK connection graph change.
++ jack_rechain_graph():
client freebob_pcm: internal client, execution_order=0.
client qjackctl: start_fd=7, execution_order=0.
client qjackctl: wait_fd=16, execution_order=1 (last client).
-- jack_rechain_graph()
new client: Hydrogen-1, id = 4 type 2 @ 0xb7ed5000 fd = 20
registered port Hydrogen-1:out_L, offset = 7168
registered port Hydrogen-1:out_R, offset = 8192
++ jack_rechain_graph():
client freebob_pcm: internal client, execution_order=0.
client qjackctl: start_fd=7, execution_order=0.
client Hydrogen-1: in subgraph after qjackctl, execution_order=1.
client qjackctl: wait_fd=19, execution_order=2 (last client).
-- jack_rechain_graph()
unknown destination port in attempted connection [alsa_pcm:playback_1]
++ jack_rechain_graph():
client freebob_pcm: internal client, execution_order=0.
client qjackctl: start_fd=7, execution_order=0.
client qjackctl: wait_fd=16, execution_order=1 (last client).
-- jack_rechain_graph()
removing disconnected client Hydrogen-1 state = Not triggered errors = 0
removing client "Hydrogen-1"
removing client "Hydrogen-1" from the processing chain
++ jack_rechain_graph():
client freebob_pcm: internal client, execution_order=0.
client qjackctl: start_fd=7, execution_order=0.
client qjackctl: wait_fd=16, execution_order=1 (last client).
-- jack_rechain_graph()
17:54:28.018 ALSA connection graph change.
17:54:28.060 ALSA connection change.
load = 3.1445 max usecs: 117.000, spare = 5216.000
load = 3.5505 max usecs: 211.000, spare = 5122.000
load = 3.7160 max usecs: 207.000, spare = 5126.000
load = 3.9019 max usecs: 218.000, spare = 5115.000
load = 4.0792 max usecs: 227.000, spare = 5106.000
load = 3.9522 max usecs: 204.000, spare = 5129.000
load = 4.0106 max usecs: 217.000, spare = 5116.000
load = 4.1242 max usecs: 226.000, spare = 5107.000
load = 4.2091 max usecs: 229.000, spare = 5104.000
load = 4.2797 max usecs: 232.000, spare = 5101.000
load = 4.3337 max usecs: 234.000, spare = 5099.000
load = 4.2482 max usecs: 222.000, spare = 5111.000
load = 4.2055 max usecs: 222.000, spare = 5111.000
load = 4.0622 max usecs: 209.000, spare = 5124.000
load = 4.1688 max usecs: 228.000, spare = 5105.000
load = 4.1095 max usecs: 216.000, spare = 5117.000
17:54:48.050 ALSA connection graph change.
17:54:48.051 Shutdown notification.
17:54:48.055 JACK is stopping...
17:54:48.056 JACK is being forced...
cannot complete execution of the processing graph (Success)
zombified - calling shutdown handler
17:54:48.063 JACK has crashed.
17:54:48.096 ALSA connection change.
17:54:48.257 JACK was stopped successfully.
17:54:48.257 Post-shutdown script...
17:54:48.257 killall jackd
jackd: no process killed
17:54:48.667 Post-shutdown script terminated with exit status=256.
17:54:57.200 ALSA connection graph change.
17:54:57.303 ALSA connection change.

Revision history for this message
prismatic7 (chris-wenn-deactivatedaccount) wrote :

Double-submitted. Sorry. Bug #231085 is a duplicate of this bug.

Revision history for this message
prismatic7 (chris-wenn-deactivatedaccount) wrote :

Please delete this bug. Ricoh chipset is known not to work with audio on all platforms.

I'm still having issues with the Saffire LE, not that anyone has ever paid attention to this bug. Cheers, guys.

Revision history for this message
Vivian Stewart (vivichrist) wrote :

The key here is "cannot complete execution of the processing graph" this has been happening to me since I upgraded to Hardy everything is fine when using alsa but freebob is very unstable and seems to be dependant on CPU processing amount, if you look at the forums this has been happening to quite a few people with FP10's lately, and M-Audio 1010lt's. sometime the connection stays but mostly dies after some time or quite immediately.

Revision history for this message
Vivian Stewart (vivichrist) wrote :
Download full text (15.7 KiB)

load = 5.3048 max usecs: 594.000, spare = 10072.000
17:30:50.424 ALSA connection graph change.
new client: hydrogen-tmp, id = 3 type 2 @ 0x7f36945c7000 fd = 18
17:30:50.479 JACK connection graph change.
removing disconnected client hydrogen-tmp state = Not triggered errors = 0
removing client "hydrogen-tmp"
removing client "hydrogen-tmp" from the processing chain
++ jack_rechain_graph():
client freebob_pcm: internal client, execution_order=0.
client qjackctl: start_fd=5, execution_order=0.
client qjackctl: wait_fd=12, execution_order=1 (last client).
-- jack_rechain_graph()
new client: Hydrogen-1, id = 4 type 2 @ 0x7f36945c7000 fd = 18
registered port Hydrogen-1:out_L, offset = 45056
registered port Hydrogen-1:out_R, offset = 49152
++ jack_rechain_graph():
client freebob_pcm: internal client, execution_order=0.
client qjackctl: start_fd=5, execution_order=0.
client Hydrogen-1: in subgraph after qjackctl, execution_order=1.
client qjackctl: wait_fd=15, execution_order=2 (last client).
-- jack_rechain_graph()
subgraph starting at qjackctl timed out (subgraph_wait_fd=15, status = 0, state = Running)
at 2335567741 waiting on 15 for 10258 usecs, status = 1 sig = 2335557467 awa = 2335557526 fin = 2335557537 dur=70
subgraph starting at qjackctl timed out (subgraph_wait_fd=15, status = 0, state = Running)
at 2335579751 waiting on 15 for 11133 usecs, status = 1 sig = 2335568604 awa = 2335568645 fin = 2335568650 dur=46
subgraph starting at qjackctl timed out (subgraph_wait_fd=15, status = 0, state = Running)
at 2335590689 waiting on 15 for 10419 usecs, status = 1 sig = 2335580250 awa = 2335580302 fin = 2335580310 dur=60
subgraph starting at qjackctl timed out (subgraph_wait_fd=15, status = 0, state = Running)
at 2335601802 waiting on 15 for 10879 usecs, status = 1 sig = 2335590910 awa = 2335590944 fin = 2335590950 dur=40
subgraph starting at qjackctl timed out (subgraph_wait_fd=15, status = 0, state = Running)
at 2335613753 waiting on 15 for 11549 usecs, status = 1 sig = 2335602187 awa = 2335602221 fin = 2335602226 dur=39
17:30:50.633 JACK connection change.
17:30:50.638 ALSA connection change.
17:30:50.640 JACK connection graph change.
17:30:50.642 XRUN callback (1).
subgraph starting at qjackctl timed out (subgraph_wait_fd=15, status = 0, state = Running)
at 2335624845 waiting on 15 for 10768 usecs, status = 1 sig = 2335614052 awa = 2335614094 fin = 2335614101 dur=49
LibFreeBoB ERR: SLAVE XMT : Buffer underrun! 1024 (0 / 704) (0 / 0 )
LibFreeBoB ERR: Xrun on connection 1
subgraph starting at qjackctl timed out (subgraph_wait_fd=15, status = 0, state = Running)
at 2335635703 waiting on 15 for 10396 usecs, status = 1 sig = 2335625275 awa = 2335625341 fin = 2335625350 dur=75
client Hydrogen-1 has died/exited
client failure: client Hydrogen-1 state = Not triggered errors = 1
removing client "Hydrogen-1" from the processing chain
++ jack_rechain_graph():
client freebob_pcm: internal client, execution_order=0.
client qjackctl: start_fd=5, execution_order=0.
client qjackctl: wait_fd=12, execution_order=1 (last client).
-- jack_rechain_graph()
removing disconnected client Hydrogen-1 state = Not triggered errors = 0
removing client "Hydrogen-1"
++ jack_rechai...

Revision history for this message
Andrew Hunter (rexbron) wrote :

This is a bug in the ubuntu package, not ubuntustudio specific.

Changed in ubuntustudio:
status: New → Invalid
Revision history for this message
Vivian Stewart (vivichrist) wrote :

the ubuntu package is the ubuntustudio package, one and same.

Revision history for this message
Vivian Stewart (vivichrist) wrote :
Download full text (13.8 KiB)

kern.log messages

Sep 2 15:37:46 komcrapper kernel: [ 86.311384] ieee1394: The root node is not cycle master capable; selecting a new root node and resetting...
Sep 2 15:37:47 komcrapper kernel: [ 86.775809] ieee1394: Error parsing configrom for node 0-00:1023
Sep 2 15:37:47 komcrapper kernel: [ 86.776007] ieee1394: Node changed: 0-00:1023 -> 0-01:1023
Sep 2 15:37:49 komcrapper kernel: [ 87.629156] doh, someone wants to mess with state set
Sep 2 15:37:49 komcrapper kernel: [ 87.695063] ieee1394: Node added: ID:BUS[0-00:1023] GUID[000a9200c6040746]
Sep 2 15:37:49 komcrapper kernel: [ 87.787207] NOTE: The dv1394 driver is unsupported and may be removed in a future Linux release. Use raw1394 instead.
Sep 2 15:37:49 komcrapper kernel: [ 87.803857] ieee1394: raw1394: /dev/raw1394 device initialized
Sep 2 15:39:12 komcrapper kernel: [ 131.051908] ohci1394: fw-host0: Unrecoverable error!
Sep 2 15:39:12 komcrapper kernel: [ 131.051927] ohci1394: fw-host0: Iso Xmit 0 Context died: ctrl[60649806] cmdptr[f000e2c3]
Sep 2 15:42:34 komcrapper kernel: [ 274.931988] ieee1394: Node changed: 0-01:1023 -> 0-00:1023
Sep 2 15:42:34 komcrapper kernel: [ 274.932000] ieee1394: Node suspended: ID:BUS[0-00:1023] GUID[000a9200c6040746]
Sep 2 15:42:41 komcrapper kernel: [ 282.027725] ieee1394: Error parsing configrom for node 0-00:1023
Sep 2 15:42:41 komcrapper kernel: [ 282.028097] ieee1394: Node changed: 0-00:1023 -> 0-01:1023
Sep 2 15:42:43 komcrapper kernel: [ 283.996463] doh, someone wants to mess with state set
Sep 2 15:42:43 komcrapper kernel: [ 284.129796] ieee1394: Node resumed: ID:BUS[0-00:1023] GUID[000a9200c6040746]
Sep 2 15:53:55 komcrapper kernel: [ 624.366829] ohci1394: fw-host0: Unrecoverable error!
Sep 2 15:53:56 komcrapper kernel: [ 624.366858] ohci1394: fw-host0: Iso Xmit 0 Context died: ctrl[60648806] cmdptr[f000e2c3]
Sep 2 15:54:07 komcrapper kernel: [ 634.682382] ieee1394: Node changed: 0-01:1023 -> 0-00:1023
Sep 2 15:54:07 komcrapper kernel: [ 634.682394] ieee1394: Node suspended: ID:BUS[0-00:1023] GUID[000a9200c6040746]
Sep 2 15:54:12 komcrapper kernel: [ 639.343348] jackd[6361]: segfault at 90 rip 7f56ab43e6a8 rsp 7fffb3f17330 error 4
Sep 2 15:54:13 komcrapper kernel: [ 639.910462] ieee1394: Error parsing configrom for node 0-00:1023
Sep 2 15:54:13 komcrapper kernel: [ 639.910768] ieee1394: Node changed: 0-00:1023 -> 0-01:1023
Sep 2 15:54:14 komcrapper kernel: [ 641.874816] doh, someone wants to mess with state set
Sep 2 15:54:15 komcrapper kernel: [ 642.007500] ieee1394: Node resumed: ID:BUS[0-00:1023] GUID[000a9200c6040746]
Sep 2 15:54:35 komcrapper kernel: [ 658.510745] ohci1394: fw-host0: Unrecoverable error!
Sep 2 15:54:35 komcrapper kernel: [ 658.510759] ohci1394: fw-host0: Iso Xmit 0 Context died: ctrl[60649806] cmdptr[f000e2c3]
Sep 2 15:54:45 komcrapper kernel: [ 667.602205] ieee1394: Node changed: 0-01:1023 -> 0-00:1023
Sep 2 15:54:45 komcrapper kernel: [ 667.602218] ieee1394: Node suspended: ID:BUS[0-00:1023] GUID[000a9200c6040746]
Sep 2 15:54:48 komcrapper kernel: [ 670.285704] ieee1394: The root node is not cycle master capable; selecting a new root node and rese...

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.