On Fri, 2004-05-28 at 11:01, Fernando Pablo Lopez-Lezcano wrote: > On Thu, 2004-05-27 at 22:58, Arjan van de Ven wrote: > > On Fri, 2004-05-28 at 02:39, Fernando Pablo Lopez-Lezcano wrote: > > > On Thu, 2004-05-27 at 17:25, Fernando Pablo Lopez-Lezcano wrote: > > > > Hi all. I'm trying to track the cause of high scheduling latency peaks > > > > in FC2 that make the system unusable for low latency audio work. > > > > > > > > Test systems: PIV laptop, radeon video chipset, AMD64 desktop, radeon > > > > video chipset. How I test: I run the Jack (Jack Audio Connection Kit) > > > > sound server with 2 or 3 128 frame buffers for low latency operation > > > > through the Qjackctl gui front-end. I then start GUI apps that use Jack > > > > (for example Freqtweak, Hydrogen and Jamin). I see plenty of buffer > > > > xruns of varying durations during the app load process and afterwards. > > > > > > More data I forgot to include: > > > Jack is running with SCHED_FIFO priority. For achieving that I run a > > > custom kernel (currently based on Arjan's 1.391) with preempt enabled > > > and the realcap kernel module (by Jack O'Quin) added. > > > > can you disable preempt? That should improve latencies.... It does not (in my tests), quite the reverse. > I'll try that and report back. Preempt does not make any difference to the problem I'm seeing. First some pretty pictures. This is the result of running latencytest 0.5.3 (patched to compile with the newer kernels): a) 2.6.6-1.391 with preempt on: http://ccrma.stanford.edu/~nando/latencytest/20040601/2.6.6-1.391.1.ll.rhfc2.ccrma/ b) 2.6.6-1.391 with preempt off: http://ccrma.stanford.edu/~nando/latencytest/20040601/2.6.6-1.391.2.ll.rhfc2.ccrma/ c) 2.6.6-1.391 with preempt off and bad radeon latency patch (see comments below): http://ccrma.stanford.edu/~nando/latencytest/20040601/2.6.6-1.391.3.ll.rhfc2.ccrma/ d) 2.6.6-1.391 with preempt on and bad radeon latency patch: http://ccrma.stanford.edu/~nando/latencytest/20040601/2.6.6-1.391.4.ll.rhfc2.ccrma/ Some comments: it would seem to me that preempt does make a difference, the latency spikes tend to be smaller, as I would expect (at least in what latencytest measures). In [c] and [d] I'm applying an additional latency patch to the drm kernel driver that affects radeon, r128 and mga based cards. The patch is old and _illegal_ as it does reschedules with a lock on. So far the computer has not locked up but I guess it is a matter of time :-) Without this patch or an equivalent properly done patch a computer with a radeon (or r128/mga) chipset is useless for low latency audio. Now, you could say that the graphs look pretty good. And I would agree. Regretfully latencytest is not all there is. A real test with the Jack low latency server reveals that something else is creating latency hits. This is an example of what I see if I start jack inside qjackctl (a gui frontend) and after it is running I start freqtweak, BTW I get similar results running any of the aforementioned kernel builds (jack is running SCHED_FIFO, with 4 buffers of 128 frames in this example): ======== 17:24:09.745 Startup script... 17:24:09.745 artsshell -q terminate 17:24:10.015 Startup script terminated with exit status=256. 17:24:10.015 JACK is starting... 17:24:10.016 /usr/bin/jackstart -R -dalsa -dhw:0 -r48000 -p128 -n4 17:24:10.022 JACK was started with PID=3051 (0xbeb). back from read, ret = 1 errno == Success jackd 0.98.0 Copyright 2001-2003 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 loading driver .. apparent rate = 48000 creating alsa driver ... hw:0|hw:0|128|4|48000|0|0|nomon|swmeter|-|32bit control device hw:0 configuring for 48000Hz, period = 128 frames, buffer = 4 periods Couldn't open hw:0 for 32bit samples trying 24bit instead Couldn't open hw:0 for 24bit samples trying 16bit instead Couldn't open hw:0 for 32bit samples trying 24bit instead Couldn't open hw:0 for 24bit samples trying 16bit instead 17:24:12.101 Server configuration saved to "/home/nando/.jackdrc" 17:24:12.102 Statistics reset. 17:24:12.452 Client activated. 17:24:12.454 Audio connection change. subgraph starting at qjackctl-3037 timed out (subgraph_wait_fd=14, status = 0, state = Triggered) subgraph starting at qjackctl-3037 timed out (subgraph_wait_fd=14, status = 0, state = Triggered) **** alsa_pcm: xrun of at least 0.115 msecs 17:24:12.494 Audio connection graph change. **** alsa_pcm: xrun of at least 16.162 msecs subgraph starting at qjackctl-3037 timed out (subgraph_wait_fd=14, status = 0, state = Triggered) 17:24:12.507 XRUN callback. (1) subgraph starting at qjackctl-3037 timed out (subgraph_wait_fd=14, status = 0, state = Triggered) **** alsa_pcm: xrun of at least 0.096 msecs 17:24:12.515 XRUN callback. (2) **** alsa_pcm: xrun of at least 2.575 msecs 17:24:12.524 XRUN callback. (3) 17:24:12.528 XRUN callback. (4) 17:31:48.938 Audio connection graph change. 17:31:49.064 Audio connection change. 17:31:49.454 Audio connection graph change. subgraph starting at qjackctl-3037 timed out (subgraph_wait_fd=17, status = 0, state = Finished) delay of 1291.000 usecs exceeds estimated spare time of 1207.000; restart ... 17:31:49.996 XRUN callback. (5) subgraph starting at qjackctl-3037 timed out (subgraph_wait_fd=17, status = 0, state = Finished) subgraph starting at qjackctl-3037 timed out (subgraph_wait_fd=17, status = 0, state = Triggered) **** alsa_pcm: xrun of at least 2.380 msecs 17:31:50.024 XRUN callback. (6) subgraph starting at qjackctl-3037 timed out (subgraph_wait_fd=17, status = 0, state = Finished) subgraph starting at qjackctl-3037 timed out (subgraph_wait_fd=17, status = 0, state = Finished) delay of 1338.000 usecs exceeds estimated spare time of 1207.000; restart ... 17:31:50.027 XRUN callback. (7) 17:31:50.037 XRUN callback. (8) **** alsa_pcm: xrun of at least 3.733 msecs 17:31:50.047 XRUN callback. (9) **** alsa_pcm: xrun of at least 2.054 msecs subgraph starting at qjackctl-3037 timed out (subgraph_wait_fd=17, status = 0, state = Finished) subgraph starting at qjackctl-3037 timed out (subgraph_wait_fd=17, status = 0, state = Finished) **** alsa_pcm: xrun of at least 0.993 msecs 17:31:52.148 XRUN callback. (10) **** alsa_pcm: xrun of at least 11.116 msecs 17:31:52.164 XRUN callback. (11) ======== .... and so on and so forth. So, latencytest is happy but a real test with real applications is not. Other important data points: - xruns seem to be related to graphics activity - booting FC2 into 2.4.26 with the low latency and preempt patches gives me similar results (latency hits when running jack and jack apps) - booting FC1 into 2.4.26 (same hardware, just replace the hard disk) gives me a rock solid system (no xruns whatsoever, down to 128x2). So, it would seem to me that it is not (only) the kernel.......... Things I could not make work: - testing 2.6.6-1.391.x in FC1. For some reason init does not get executed, probably a library problem somewhere... Other stuff I tried: - getting a better irq for the audio card (on a desktop) - trying to tune pci latencies Any ideas on what could cause this???? Please keep in mind that I can use FC1 with 2.4.26 on the exact same hardware and it works just fine... -- Fernando
