Ticket #250 (closed bug: worksforme)

Opened 11 years ago

Last modified 8 years ago

Regular xruns

Reported by: pdhales Assigned to: jwoithe
Priority: major Milestone: FFADO 2.1
Component: Version: FFADO SVN (trunk)
Keywords: Cc:
The device the bug applies to: MOTU 828mk2

Description

Using a pcmcia firewire card (via based) with a Motu 828 mk2, I get xruns every 8 or 9 seconds in Ardour. Like clockwork!

Change History

01/06/10 09:14:05 changed by ppalmers

Given the amount of information you provide, I can only guess what your problem is.

Check: * are you running in realtime mode * is your buffersize too low * do you have shared interrupts * are you using a closed source graphics driver

Please check the README file that comes with ffado on how to gather the information required for a proper bug report.

01/06/10 14:33:03 changed by jwoithe

  • owner set to jwoithe.
  • device_name set to MOTU 828mk2.

In addition to the information requested by Pieter, could you also post the command line you use to start jackd and explicitly state what same rate you were using? A lot of this information is also requested by me in #251 and it's possible that the two issues may be related. Let's keep them separate though until we have sufficient information to determine this for certain.

01/06/10 14:45:14 changed by pdhales

You are right - this may be connected to #251 and it could all be because of buffer size.

I am also guessing that if I could run at 44.1 khz, most of these issues wouldn't exist.

01/06/10 15:20:21 changed by jwoithe

The default buffer configuration for the FFADO jack driver is equivalent to "-p 1024 -n 3". This is fairly conservative in terms of buffer sizes and I would expect it to work without major issues. So unless you explicitly overrode these (particularly "-p") with significantly smaller values it's unlikely to be due directly to the buffer size. Then again, if you are specifying very small buffer sizes (that is, less than or equal to 128) then one will get a higher system load which may partly explain the apparent freezing in #251.

Assuming you're not running jackd with realtime priorities at 96 kHz it would be interesting to try and see whether this addresses the regular xruns you're seeing. A suitable jackd command line would be something like this:

  jackd -R -P70 -d firewire -p 1024 -n 4 -r96000

Regular xruns are symptomatic of not running with realtime priorities so it's certainly worth checking this. As mentioned by Pieter the other things to check for me when you have a chance are

  • whether the firewire card is sharing its interrupts with any other active device (check using something like "cat /proc/interrupts" and look for the line containing "ieee1394")
  • whether you are using binary video drivers from Nvidia or ATI (if you're not sure perhaps do an "lsmod" and look to see if such a module is mentioned)

Both of these can give rise to xruns and other issues.

01/06/10 15:51:57 changed by pdhales

I'm not running a binary video driver (it's an intel video chipset) so at this point my best guess is IRQ sharing....and since this is a laptop my options may be limited.

01/06/10 16:09:11 changed by jwoithe

That's good news on the binary video driver front.

IRQ sharing may be an issue but until you have a chance to check the details we won't know for sure. It may be a simple case of jackd not running with realtime priorities (for example). Hopefully this will become clearer later once you get a chance to work through the above requests.

01/06/10 23:01:28 changed by pdhales

As per below - I get an xrun every 9 seconds, like clockwork.

[phales@localhost ~]$ jackd -R -P70 -d firewire -p 1024 -n 4 -r96000 jackdmp 1.9.4 Copyright 2001-2005 Paul Davis and others. Copyright 2004-2009 Grame. 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 no message buffer overruns no message buffer overruns JACK server starting in realtime mode with priority 70 71227424578: (ffado.cpp)[ 92] ffado_streaming_init: libffado 2.999.0-1786 built Jan 6 2010 22:15:57 JackAudioDriver::ProcessAsync?: read error, skip cycle JackAudioDriver::ProcessAsync?: read error, skip cycle JackAudioDriver::ProcessAsync?: read error, skip cycle JackProcessSync::LockedTimedWait? error usec = 213320 err = Connection timed out JackAudioDriver::ProcessAsync?: read error, skip cycle JackAudioDriver::ProcessAsync?: read error, skip cycle JackAudioDriver::ProcessAsync?: read error, skip cycle JackAudioDriver::ProcessAsync?: read error, skip cycle JackAudioDriver::ProcessAsync?: read error, skip cycle JackAudioDriver::ProcessAsync?: read error, skip cycle

01/06/10 23:03:12 changed by pdhales

Well here is IRQ 20:

20: 4380003 IO-APIC-fasteoi tifm_7xx1, yenta, uhci_hcd:usb6, uhci_hcd:usb7, ehci_hcd:usb8, ohci1394

Not a great sign.

01/06/10 23:29:42 changed by jwoithe

Minor point: when quoting log file output could you put three curly braces on a line by themselves at the top, and three closing curly braces on a line by themselves at the end - that way it's readable from the Trac web interface.

Ah, I see from the output that your running jackmp. Could you please retry with plain jack (version 0.118.0 is the latest)? I'm not sure of the current status of FFADO with jackmp and I'd like to eliminate this as a possible source of problems before continuing.

Assuming normal jack is no better, could you try running jackd like this:

  jackd -R -P70 -d firewire -p 1024 -n 4 -r96000 -v 5

The "-v 5" will turn on some ffado debugging info and might give us a clue as to what's going on.

In terms of the interrupt situation, it is rather crowded. uhci and ehci are USB devices, so it might be worth retrying without any plugged in (assuming there are some plugged in to start with). Yenta is the cardbus driver (I think, from memory). If that were giving trouble I would have expected a xrun frequency greater than once every 9 seconds.

The tifm_7xx1 entry is interesting - what's that module driving?

01/06/10 23:37:37 changed by pdhales

There are no USB devices plugged in, and the yenta driver is the cardbus driver.

Just had a look - the tifm_7xx1 driver is for the memory card reader in the laptop.

01/06/10 23:44:07 changed by pdhales

ffado_streaming_wait
============================================
Xruns: 2
============================================
----------------------------------------------------
Dumping StreamProcessorManager information...
Period count:   2311
Data type: float
 Receive processors...
 StreamProcessor 0x89e1c60, Receive:
  Port, Channel    : 0, 0
  Packets, Dropped, Skipped : 206617, 201, 0
  Now                   : 02994661239 (121s 6824c 1911t)
  Xrun?                 : False
  State                 : ePS_Running
  Buffer                : 0x89e1f70
  Framerate             : Nominal: 96000, Sync: 96000.967035, Buffer 96000.967035
  TimestampedBuffer (0x89e1f70): 0368 frames, 0368 events
   Timestamps           : head: 2994551141.735, Tail: 2994645348.786, Next tail: 2994649444.745
    Head - Tail         :     -94207.051 (-367.999917 frames)
   DLL Rate             : 4095.959667 (255.997479)
   DLL Bandwidth        : 4.069011e-09 1/ticks (0.100000 Hz)
 Transmit processors...
 StreamProcessor 0x89e2888, Transmit:
  Port, Channel    : 0, 1
  Packets, Dropped, Skipped : 206752, 0, 180
  Now                   : 02994663057 (121s 6825c 0657t)
  Xrun?                 : False
  State                 : ePS_Running
  Buffer                : 0x89e3938
  Framerate             : Nominal: 96000, Sync: 96000.967035, Buffer 96001.115812
  TimestampedBuffer (0x89e3938): 2464 frames, 2464 events
   Timestamps           : head: 2994997617.573, Tail: 2995628394.241, Next tail: 2995890535.194
    Head - Tail         :    -630776.668 (-2463.998561 frames)
   DLL Rate             : 262141.106205 (255.997174)
   DLL Bandwidth        : 4.069011e-09 1/ticks (0.100000 Hz)
----------------------------------------------------

00926002669: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 20 exceeded maximum 20
00926002698: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 21 exceeded maximum 20
00926514721: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 20 exceeded maximum 20
00926706736: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 20 exceeded maximum 20
00926717403: Warning (MotuReceiveStreamProcessor.cpp)[ 481] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel control index 20 exceeded maximum 20
00926760092: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 21 exceeded maximum 20
00926760127: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 22 exceeded maximum 20
00926760134: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 23 exceeded maximum 20
00926760141: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 24 exceeded maximum 20
00926760147: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 25 exceeded maximum 20
00926770740: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 26 exceeded maximum 20
00926770767: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 27 exceeded maximum 20
00926770774: Warning (MotuReceiveStreamProcessor.cpp)[ 471] decodeMotuCtrlEvents: MOTU cuemix value parser error: channel pan index 28 exceeded maximum 20

ffado_streaming_wait

01/07/10 02:27:55 changed by jwoithe

Hmm, there's nothing obvious in the log file which suggests that ffado is having difficulty. I also note that this is with realtime scheduling, so the problem's not necessarily that.

I wonder if yenta is creating a problem. The trouble with this is that it's not easy to check since you need yenta in order to use your PCMCIA firewire card. I vaguely recall that it's possible to instruct yenta to use polling mode rather than interrupts; if this could be easily done it might be worth testing this.

Oh, those decodeMotuCtrlEvents warnings can be ignored too.

Could you please post the output of "uname -a" on this machine and the previously mentionly mentioned "lspci -v" output for the firewire card (for completeness)? Also, with jackd running could you do "ps auxw | grep jackd" and report the result? I'm interested to see what the reported loading is on your machine.

01/07/10 21:57:02 changed by jwoithe

A quick note: I'll be travelling over the next week or so for Linux.conf.au. I'll keep an eye on this ticket but might not be able to respond as quickly over that time. I'll check in as I can; hopefully with the additional information as requested we can get a handle on what's going on here and in r251.

01/17/10 14:07:08 changed by jwoithe

I'm online at the conference now and can probably respond in a more timely fashion. Could you please advise where we are at with this ticket so we can make progress?

01/17/10 18:10:25 changed by pdhales

I have had to return the motu 828 to the owner, so I probably won't have it for another month or so.

The laptop I was using for testing has also been upgraded from Fedora 10 to Ubuntu 9.10, so the issue may be resolved.

I think the xrun issue may have been caused by a memory stick reader driver (tifm_7xx1) that shared an IRQ with the pcmcia driver.

At this point I think it best to close the tickets, and I can re-open or start new tickets if and when I have access to the motu.

01/17/10 20:59:45 changed by jwoithe

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

I think it's entirely likely that the issues were at least related to the card reader driver. I will close this ticket (and the associated #251) for now as you suggested. I would encourage you to re-test when you gain access to the MOTU again and to report back, either to the mailing list or by re-opening the applicable ticket. It shouldn't be too hard to test without the tifm_7xx1 driver: an "rmmod tifm_7xx1" should do the trick, at least temporarily. If that doesn't prove to be the cause we can resume fault-finding at that point.

01/23/10 02:00:12 changed by stefanr

Please report this to the tifm_7xx1 maintainer, with Cc to the relevant mailing lists:

Alex Dubov <oakad@yahoo.com>
linux-mmc@vger.kernel.org
linux-kernel@vger.kernel.org

Kernel developers should check whether the driver is switching interrupts off for long periods, and if so whether this can be improved.

03/30/12 04:40:36 changed by jwoithe

Please report this to the tifm_7xx1 maintainer ...

Finally done. Yes, it took me two years to get around to doing it. :-( This may well mean that there's little remaining value in the report, but at least the maintainer has been made aware of it.

05/07/12 16:58:00 changed by jwoithe

For the benefit of future readers, I received the following reply from the tifm_7xx1 maintainer (Alex Dubov):

Unfortunately, I don't have access to that hardware either.

However, there are really only few operations in that driver between "irqsave" and "irqrestore", unless PIO mode is used (which may, ostensibly, cause this sort of interrupt delays). On the other hand, PIO mode there is purely intended for troubleshooting purposes and can only be enabled through special module parameter by an adventurous user.

The mailing list thread was "Possible issue with tifm_7xx1 and interrupt latency" lkml and linux-mmc.

Unless the problem recurs and we can carry out indepth debugging this issue will probably have to be left at that.