Ticket #210 (closed bug: invalid)

Opened 11 years ago

Last modified 11 years ago

[Focusrite Saffire Pro 40] Jack stops and/or crashes after a while (without anything connected)

Reported by: orl Assigned to:
Priority: major Milestone:
Component: Version: FFADO SVN (trunk)
Keywords: Cc:
The device the bug applies to: Focusrite Saffire Pro 40

Description (Last modified by ppalmers)

Jack stops and/or sometimes crashes when using FFADO SVN TRUNK version with Focusrite Saffire Pro 40 without anything plugged in, nothing connected in jack, and nothing running execpt jack and qjackctl. It works something like 1'30", and then stops. Leds (Fw Active, Locked) are lighted after 5 seconds. Logs, and sessions durations are given in the attached files.

Jack version is the Debian Squeeze one (uptodate) 0.116.1-4. Kernel is 2.6.26-8-rt16 (realtime kernel, homemade with Ingo's real-time-patch).

IRQ of ohci1394 is shared with others, though it works with Edirol FA101 and Freebob. By the way, all other optimizations (including those from IRQ Threading and Priority hints) have been done, rtirq is installed,...

Attachments

128_3_44100 (2.8 kB) - added by orl on 04/08/09 02:50:46.
Test informations for 128 frames 3 buffers 44100 Hz samplerate / jack logs…
128_3_48000 (2.7 kB) - added by orl on 04/08/09 02:51:17.
Test informations for 128 frames 3 buffers 48000 Hz samplerate / jack logs…
256_2_44100 (2.8 kB) - added by orl on 04/08/09 02:51:42.
Test informations for 256 frames 2 buffers 44100 Hz samplerate / jack logs…
64_3_44100 (1.0 kB) - added by orl on 04/08/09 02:51:57.
Test information for 64 frames 3 buffers 44100 Hz samplerate / jack logs…
firewire.lspci (384 bytes) - added by orl on 04/08/09 02:52:28.
out of lspci -v ieee1394 section
jack_setup.png (76.7 kB) - added by orl on 04/08/09 02:53:06.
jack setup screenshot (actually, priority is set to 60)
ffado_jack_64_3_48000.log.tar.gz (14.1 kB) - added by orl on 04/09/09 12:55:27.
logs for 64 frames, 3 bufferd, 48000 Hz and r1531
ffado-jack_p64_n3.log.tar.gz (130.7 kB) - added by orl on 04/13/09 08:14:05.
new test log with p64 n3
ffado_dbus_jack_p64_r1538.log.tar.gz (131.3 kB) - added by orl on 04/14/09 05:22:47.
ffaddo-dbus-server and jack/firewire logs for p=64 n=3 (r1538)
ffado_dbus_jack_p128_r1538.log.tar.gz (56.5 kB) - added by orl on 04/14/09 05:23:20.
ffaddo-dbus-server and jack/firewire logs for p=128 n=3 (r1538)
ffado-dbus-server_p1024_n2_r1511.log (40.9 kB) - added by orl on 04/16/09 07:57:26.
ffado-dbus-server logs with p1024 n2 and r1511
ffado-jack_p1024_n2_r1511.log (299.8 kB) - added by orl on 04/16/09 07:57:49.
jackd/firewire logs with p1024 n2 and r1511
ffado-dbus-server_p1024_n4_r1511.log.tar.gz (1.1 kB) - added by orl on 04/16/09 09:15:26.
new logs with new firmware (uptodate)
ffado-jack_p1024_n4_r1511.log.tar.gz (52.0 kB) - added by orl on 04/16/09 09:15:52.
new logs with new firmware (uptodate)
ffado-jack_p1024_n4_r1538_adimode.log.tar.gz (41.2 kB) - added by orl on 04/16/09 12:01:13.
jack logs with r1538, firmawre uptodate, kernel 2.6.29.1-rt7, and adi mod

Change History

04/08/09 02:50:46 changed by orl

  • attachment 128_3_44100 added.

Test informations for 128 frames 3 buffers 44100 Hz samplerate / jack logs...

04/08/09 02:51:17 changed by orl

  • attachment 128_3_48000 added.

Test informations for 128 frames 3 buffers 48000 Hz samplerate / jack logs...

04/08/09 02:51:42 changed by orl

  • attachment 256_2_44100 added.

Test informations for 256 frames 2 buffers 44100 Hz samplerate / jack logs...

04/08/09 02:51:57 changed by orl

  • attachment 64_3_44100 added.

Test information for 64 frames 3 buffers 44100 Hz samplerate / jack logs...

04/08/09 02:52:28 changed by orl

  • attachment firewire.lspci added.

out of lspci -v ieee1394 section

04/08/09 02:53:06 changed by orl

  • attachment jack_setup.png added.

jack setup screenshot (actually, priority is set to 60)

04/08/09 02:55:37 changed by orl

  • milestone deleted.

04/08/09 03:03:18 changed by adi

We're talking about trunk, right?

I have seen similar problems on Alesis io14 yesterday, but I wasn't sure if they were just coincidencial. They went away after the third retry, and I'm sure I haven't encountered this behaviour before r1531.

Can you compile r1530 and re-check if things are different? Is this your first-time ffado run or has it been working before? In any case, -v3 logs (or even higher) would be useful...

TIA

PS: This is pure guessing, I don't know for sure if it's related to r1531 at all.

04/08/09 03:29:44 changed by orl

We're talking about trunk, you're right. By the way, I compiled FFADO last week, so I don't know if we're talking about the very same one! I've been searching a bit, and it looks like I'm using the 1523:

$ cat /usr/src/ffado/ffado-svn/.svn/all-wcprops K 25 svn:wc:ra_dav:version-url V 26 /ffado/!svn/ver/1523/trunk END

I will try compiling 1530 this evening, though, it may perhaps change something. As you may see, it doesn't go away after retry, I can do it as much as I want, it always stops around 1'30".

Concerning your question, it's my first time using FFADO, I used freebob and alsa before (FA101 and HDSP9652). You want -v3 as an option for jackd or for compilation?

04/08/09 03:39:20 changed by orl

I forgot to give this out:

$ ffado-dbus-server


FFADO Control DBUS service Part of the FFADO project -- www.ffado.org Version: 2.999.0-1524 (C) 2008, Pieter Palmers This program comes with ABSOLUTELY NO WARRANTY.


04351212063: (ffado-dbus-server.cpp)[ 270] main: Discovering devices... 04351217087: Debug (devicemanager.cpp)[ 351] discover: Starting discovery... 04352307004: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 16 04353370257: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 16 04354433157: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 16 04355496668: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 16 04356560776: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 16 04357627708: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 1 04358746672: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 16 04359810787: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 16 04360872760: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 16 04361939921: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 16 04363003615: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 16 04364072526: Debug (ieee1394service.cpp)[ 537] readNoLock: raw1394_read failed: node 0xFFC0, addr = 0x0000FFFFF0000480, length = 1 04364094751: Debug (devicemanager.cpp)[ 613] discover: driver found for device 0 04364123556: Debug (devicemanager.cpp)[ 650] discover: discovery of node 0 on port 0 done... 04364123574: Debug (devicemanager.cpp)[ 658] discover: Discovery finished... 04364123686: Debug (devicemanager.cpp)[1149] showDeviceInfo: ===== Device Manager =====

04/08/09 03:40:05 changed by orl

04364123695: Debug (Element.cpp)[ 121] show: Element DeviceManager? 04364123699: Debug (devicemanager.cpp)[1157] showDeviceInfo: --- IEEE1394 Service 0 --- Iso handler info: Dumping IsoHandlerManager? Stream handler information...

State: 2

04364123722: Debug (devicemanager.cpp)[1167] showDeviceInfo: --- Device 0 --- 04364123731: Debug (dice_avdevice.cpp)[ 549] showDevice: Device is a DICE device 04364123737: Debug (ffadodevice.cpp)[ 228] showDevice: Attached to port.......: 0 (ohci1394) 04364123743: Debug (ffadodevice.cpp)[ 229] showDevice: Node...................: 0 04364123746: Debug (ffadodevice.cpp)[ 231] showDevice: Vendor name............: Focusrite 04364123751: Debug (ffadodevice.cpp)[ 233] showDevice: Model name.............: SAFFIRE_PRO_40 04364123756: Debug (ffadodevice.cpp)[ 235] showDevice: GUID...................: 00130e0401400918 04364123763: Debug (ffadodevice.cpp)[ 240] showDevice: Assigned ID....: dev0 04364131274: Debug (dice_avdevice.cpp)[ 570] showDevice: Nick name : Pro40-000918 04364133201: Debug (dice_avdevice.cpp)[ 574] showDevice: Clock Select : 0x01 0x0C 04364135021: Debug (dice_avdevice.cpp)[ 578] showDevice: Enable : false 04364137968: Debug (dice_avdevice.cpp)[ 582] showDevice: Clock Status : locked 0x01 04364141345: Debug (dice_avdevice.cpp)[ 588] showDevice: Samplerate : 0x0000AC44 (44100) 04364143156: Debug (dice_avdevice.cpp)[ 597] showDevice: Version : 0x01000400 (1.0.4.0) 04364203167: Debug (devicemanager.cpp)[1170] showDeviceInfo: Clock sync sources: 04364211184: Debug (devicemanager.cpp)[1179] showDeviceInfo: Type: AES , Id: 4, Valid: 1, Active: 0, Locked 0, Slipping: 0, Description: SPDIF 04364211195: Debug (devicemanager.cpp)[1179] showDeviceInfo: Type: ADAT , Id: 5, Valid: 1, Active: 0, Locked 0, Slipping: 0, Description: ADAT 04364211204: Debug (devicemanager.cpp)[1179] showDeviceInfo: Type: Compound Syt Match, Id: 8, Valid: 1, Active: 0, Locked 0, Slipping: 0, Description: Unused 04364211209: Debug (devicemanager.cpp)[1179] showDeviceInfo: Type: Compound Syt Match, Id: 9, Valid: 1, Active: 0, Locked 0, Slipping: 0, Description: Unused 04364211217: Debug (devicemanager.cpp)[1179] showDeviceInfo: Type: Internal , Id: 12, Valid: 1, Active: 1, Locked 1, Slipping: 0, Description: Internal 04364215161: (ffado-dbus-server.cpp)[ 328] main: DBUS test service running 04364215181: (ffado-dbus-server.cpp)[ 329] main: press ctrl-c to stop it & exit 04364215184: Debug (ffado-dbus-server.cpp)[ 332] main: dispatching...

04/08/09 03:41:25 changed by orl

And then, after a while, I get this:

Error (CycleTimerHelper?.cpp)[ 517] Execute: negative step: -370780256.430600! (correcting to nominal)

over and over.

04/08/09 03:43:52 changed by adi

You can get the subversion revision by running "svn info", but let's assume it's 1523. So my guess about r1531 is probably counterproductive. You may want to checkout current trunk (run svn up).

The -v3 is a jackd argument. See http://subversion.ffado.org/browser/trunk/libffado/README, especially section "Writing a bug report". (compile with ENABLE_DEBUG)

Also make sure to repower your device between jackd runs (see http://subversion.ffado.org/wiki/Troubleshooting)

HTH

04/09/09 12:14:48 changed by orl

$ svn info Chemin : . URL : http://subversion.ffado.org/ffado/trunk Racine du dépôt : http://subversion.ffado.org/ffado UUID du dépôt : 2be59082-3212-0410-8809-b0798e1608f0 Révision : 1524 Type de nœud : répertoire Tâche programmée : normale Auteur de la dernière modification : jwoithe Révision de la dernière modification : 1523 Date de la dernière modification: 2009-03-23 00:37:36 +0100 (lun 23 mar 2009)

So it was the 1523. I am going to upgrade, and I come back here.

04/09/09 12:54:46 changed by orl

OK, update done, I've ran the 1531, it looks like it works a bit longer, but fails at last though. There also are much more Xruns than before. Logs are following.

04/09/09 12:55:27 changed by orl

  • attachment ffado_jack_64_3_48000.log.tar.gz added.

logs for 64 frames, 3 bufferd, 48000 Hz and r1531

04/11/09 01:56:51 changed by ppalmers

  • description changed.

It seems that you have tried to start jack after it crashed. Currently for the saffire pro40 you have to power-cycle it if jack crashes.

04/13/09 08:13:31 changed by orl

Oh, it's weird, I usually always power up and down Pro40 before any test. By the way, it's also weird that it looks like jack was already crashed, but as it's linked.

Here are logs with computer just started, Focusrite just started, and jackd started for first time in this session..

By the way, as it works with you (regarding FFADO blog), I would be interested in reading (maybe on FFADO-users list) your configuration (distribution, kernel, and so on), in order to see what differs from mine.

04/13/09 08:14:05 changed by orl

  • attachment ffado-jack_p64_n3.log.tar.gz added.

new test log with p64 n3

04/14/09 05:20:55 changed by orl

Here come new files with r1538, p=128 and p=64 (for n=3), I've added ffado-dbus-server logs too.

04/14/09 05:22:47 changed by orl

  • attachment ffado_dbus_jack_p64_r1538.log.tar.gz added.

ffaddo-dbus-server and jack/firewire logs for p=64 n=3 (r1538)

04/14/09 05:23:20 changed by orl

  • attachment ffado_dbus_jack_p128_r1538.log.tar.gz added.

ffaddo-dbus-server and jack/firewire logs for p=128 n=3 (r1538)

04/16/09 07:57:26 changed by orl

  • attachment ffado-dbus-server_p1024_n2_r1511.log added.

ffado-dbus-server logs with p1024 n2 and r1511

04/16/09 07:57:49 changed by orl

  • attachment ffado-jack_p1024_n2_r1511.log added.

jackd/firewire logs with p1024 n2 and r1511

04/16/09 09:15:26 changed by orl

  • attachment ffado-dbus-server_p1024_n4_r1511.log.tar.gz added.

new logs with new firmware (uptodate)

04/16/09 09:15:52 changed by orl

  • attachment ffado-jack_p1024_n4_r1511.log.tar.gz added.

new logs with new firmware (uptodate)

04/16/09 12:01:13 changed by orl

  • attachment ffado-jack_p1024_n4_r1538_adimode.log.tar.gz added.

jack logs with r1538, firmawre uptodate, kernel 2.6.29.1-rt7, and adi mod

04/17/09 03:03:12 changed by orl

I've made a sum up of this ticket, quite cleaner and with reflexions that adi and I had about this on irc. I will close this one (as soon I will have found where I close a ticket!)

04/17/09 03:03:51 changed by orl

  • status changed from new to closed.
  • resolution set to invalid.

new ticket is ticket #215