lkml.org 
[lkml]   [2008]   [Apr]   [22]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
SubjectRe: [git pull] scheduler changes for v2.6.26
From
Date

On Mon, 2008-04-21 at 21:43 +0200, Ingo Molnar wrote:
> * Frans Pop <elendil@planet.nl> wrote:
>
> > > It would be nice if you could try sched-devel/latest because it has
> > > an improved ftrace "sched_switch" tracer where you can generate much
> > > longer traces of this incident. Try the new /debug/trace_entries
> > > runtime tunable.
> >
> > I'll try to get the trace and will reply on the private thread we had.
> > I may need additional instructions though.
>
> you could also reply to this thread if you dont mind, so that others can
> chime in too.
>
> the 700-800 msecs of delays you see are very "brutal" so there must be
> something fundamentally wrong going on here.

I'm seeing latency hits with 26.git, whereas 25 is hit free.

LatencyTOP version 0.3 (C) 2008 Intel Corporation

Cause Maximum Percentage
Scheduler: waiting for cpu 436.0 msec 79.8 %
do_fork sys_vfork ptregscall_common 37.7 msec 1.5 %
blk_execute_rq scsi_execute scsi_execute_req sr_te 30.5 msec 0.2 %
blk_execute_rq scsi_execute scsi_execute_req sd_re 28.7 msec 0.6 %
msleep wakeup_rh uhci_rh_resume hcd_bus_resume gen 23.3 msec 0.3 %
blk_execute_rq scsi_execute scsi_execute_req scsi_ 23.0 msec 0.8 %
down tty_write vfs_write sys_write system_call_aft 21.9 msec 0.1 %
do_get_write_access journal_get_write_access __ext 21.8 msec 0.1 %
blk_execute_rq scsi_execute scsi_execute_req sr_te 16.5 msec 0.3 %
r_block_media_changed check_disk_change cdrom_open sr_block_open do_open




Process amarokapp (4645)
Scheduler: waiting for cpu 436.0 msec 93.8 %
do_select core_sys_select sys_select system_call_a 4.8 msec 4.7 %
do_sys_poll sys_poll system_call_after_swapgs 4.7 msec 1.5 %

>
> Could you first check (under sched-devel/latest) the quality of your
> sched-clock, via running this script:
>
> http://people.redhat.com/mingo/cfs-scheduler/tools/watch-rq-clock.sh
>
> if you run it, it should output ~1000 msecs periods every second:
>
> europe:~> watch-rq-clock.sh
> 1002.115042
> 1005.509851
> 1004.187275
> 1004.409980
> 1004.430264
> 1004.445508
>
> if it's way too 'slow', say it only 100 msecs per second, then the
> scheduler clock is mis-measuring time and what the scheduler thinks to
> be a 40 msecs delay might become a 400 msecs delay.

Erm, should my Q6600 emit such?

2.6.25:
51.743501
124.292008
59.719506
268.016760
64.004011
144.113851
87.900658
116.007257
72.004509

On 26.git, I get numbers like yours, but with occasional dips down to
~700, though the latency hits don't _seem_ to be synchronous with
watch-rq-clock.sh glitchies.

-Mike



\
 
 \ /
  Last update: 2008-04-22 10:55    [from the cache]
©2003-2014 Jasper Spaans. Advertise on this site