lkml.org 
[lkml]   [2005]   [Oct]   [10]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    From
    SubjectRe: 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/

    \
     
     \ /
      Last update: 2005-10-11 01:52    [W:0.044 / U:60.912 seconds]
    ©2003-2016 Jasper Spaans. hosted at Digital OceanAdvertise on this site