All of lore.kernel.org
 help / color / mirror / Atom feed
From: Lee Revell <rlrevell@joe-job.com>
To: Ingo Molnar <mingo@elte.hu>
Cc: Kevin Hilman <kjh-lkml@hilman.org>,
	linux-kernel <linux-kernel@vger.kernel.org>
Subject: Re: voluntary-preemption: understanding latency trace
Date: Fri, 10 Sep 2004 03:09:04 -0400	[thread overview]
Message-ID: <1094800144.15407.4.camel@krustophenia.net> (raw)
In-Reply-To: <20040910063749.GA25298@elte.hu>

On Fri, 2004-09-10 at 02:37, Ingo Molnar wrote:
> * Lee Revell <rlrevell@joe-job.com> wrote:
> 
> > > I've got a SCHED_FIFO kernel thread at the highest priority
> > > (MAX_USER_RT_PRIO-1) and it's sleeping on a wait queue.  The wake is
> > > called from an ISR.  Since this thread is the highest priority in the
> > > system, I expect it to run before the ISR threads and softIRQ threads
> > > etc. 
> > > 
> > > In the ISR I sample sched_clock() just before the call to wake_up()
> > > and in the thread I sample sched_clock() again just after the call to
> > > sleep.  I'm seeing an almost 4ms latency between the call to wake_up
> > > and the actual wakeup.  However, in /proc/latency_trace, the worst
> > > latency I see during the running of this test is <500us.
> 
> > Ingo, any ideas here?  Looks like maybe the use of sched_clock is the
> > problem.
> 
> sched_clock() is not 100% accurate (it takes a few shortcuts to avoid a
> division) but it should be better than 90% so 4 msec measured means
> there's likely some big delay.
> 
> if the priority setup is indeed as described above then the RT task
> should have run much faster. First i'd suggest to check whether it's not
> console printing (printing of a stacktrace or a latency trace) that 
> slows things down.
> 

Ah, this is probably it, this is pretty close to the latency I get when
/proc/latency_trace is updated, and this is also the one latency that
doesn't show in the traces by design.

rlrevell@mindpipe:~$ ./amlat-rlr/amlat 
599.895 MHz
secondsPerTick=0.000000
ticksPerSecond=599894954.372806
599.895 MHz
Using rtc interval of 1024
u=0
latency = 53 microseconds
latency = 60 microseconds
latency = 60 microseconds
latency = 62 microseconds
latency = 66 microseconds
latency = 76 microseconds
latency = 78 microseconds
latency = 2548 microseconds

The last line is the latency trace being updated.  If I turn off tracing
or set preempt_max_latency to a high value then amlat doesn't show
these.

Lee



  reply	other threads:[~2004-09-10  7:12 UTC|newest]

Thread overview: 6+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2004-09-09 10:41 voluntary-preemption: understanding latency trace Kevin Hilman
2004-09-09 21:02 ` Lee Revell
2004-09-10  6:37   ` Ingo Molnar
2004-09-10  7:09     ` Lee Revell [this message]
2004-09-10  7:51     ` Ingo Molnar
2004-09-10 14:56     ` Kevin Hilman

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=1094800144.15407.4.camel@krustophenia.net \
    --to=rlrevell@joe-job.com \
    --cc=kjh-lkml@hilman.org \
    --cc=linux-kernel@vger.kernel.org \
    --cc=mingo@elte.hu \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.