Messages in this thread |  | | | Date | Mon, 10 Oct 2005 16:49:12 -0700 | | From | Mark Knecht <> | | Subject | Re: Latency data - 2.6.14-rc3-rt13 |
| |
On 10/10/05, Mark Knecht <markknecht@gmail.com> wrote: > On 10/10/05, Daniel Walker <dwalker@mvista.com> wrote: > > > > Yes, already that looks interesting. Do I have something going on with > > > acpi? This is before running Jack. I'm in Gnome.There are a lot of > > > these messages, but they've stopped. I suppose the 3997 is the delay? > > > That would coorespond with the info I sent earlier. > > > > I think this is a false reading . Sometimes when a system goes idle it > > will cause interrupt disable latency that isn't real (due to process > > halting) . You could try turning ACPI off if you can , and turn off > > power management .. > > > > Daniel > > OK. NO immediate difference with most of the power management stuff > turned off. I'll just let it run a few hours and see if I get an xrun. > If I do I'll look at the logs again and report back. > > Thanks for the help. I feel like I've got a chance of spotting something. > > Cheers, > Mark
Well, I'm disappointed again. Some xruns came but no additional data was put into the dmesage file:
( softirq-timer/0-3 |#0): new 3997 us maximum-latency critical section. => started at timestamp 253995015: <acpi_processor_idle+0x20/0x379> => ended at timestamp 253999013: <thread_return+0xb5/0x11a> Call Trace:<ffffffff8014e32c>{check_critical_timing+492} <ffffffff8014e785>{sub_preempt_count_ti+133} <ffffffff803ec76c>{thread_return+70} <ffffffff803ec7db>{thread_return+181} <ffffffff803ec945>{schedule+261} <ffffffff801371ca>{ksoftirqd+138} <ffffffff80137140>{ksoftirqd+0} <ffffffff8014740d>{kthread+205} <ffffffff8010e6e6>{child_rip+8} <ffffffff80147340>{kthread+0} <ffffffff8010e6de>{child_rip+0} --------------------------- | preempt count: 00000001 ] | 1-level deep critical section nesting: ---------------------------------------- .. [<ffffffff803ec238>] .... __schedule+0xb8/0x5a6 .....[<00000000>] .. ( <= 0x0) => dump-end timestamp 253999092
kjournald starting. Commit interval 5 seconds EXT3 FS on sdb1, internal journal EXT3-fs: mounted filesystem with ordered data mode. lightning ~ #
Basically the trace above was there pretty much right after booting. I mounted a 1394 drive, which is shown, and then started running apps. I got 3 xruns:
16:42:59.826 XRUN callback (1). **** alsa_pcm: xrun of at least 0.273 msecs 16:43:03.764 XRUN callback (2). **** alsa_pcm: xrun of at least 2.082 msecs 16:43:41.618 XRUN callback (3). **** alsa_pcm: xrun of at least 2.040 msecs but no additional data in the logs.
So possibly this is an IRQ off latency? Or am I jumping to conclusions? The trace above, if I understand it, indicates a delay of nearly 4mS, and again, since I'm trying to run at sub 3mS, that would seem like a potential problem.
I'm going to completely shut off power management as a test just to see where that leads.
- Mark - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
|  |