Re: rt20 scheduling latency testcase and failure data

Mike Galbraith
2006-05-14T05:48:19Z

On Sun, 2006-05-14 at 05:47 +0200, Mike Galbraith wrote:
> On Sat, 2006-05-13 at 16:01 -0700, Darren Hart wrote:
> > On Saturday 13 May 2006 11:21, Lee Revell wrote:
> > > On Sat, 2006-05-13 at 11:06 -0700, Darren Hart wrote:
> > > > 1 [softirq-timer/0]
> > >
> > > What happens if you set the softirq-timer threads to 99?
> > >
> >
> > After setting all 4 softirq-timer threads to prio 99 I seemed to get only 2
> > failures in 100 runs.
>
> If you disable printf + fflush in iterations loop, problem goes away?

P.S.

I think it probably will, because...

sched_latency [ea53a0b0]D 00000001 0 8261 7858 8260 (NOTLB)
e29a0e70 e29a0e58 00000008 00000001 df6158e0 00000000 623266f4 0000017d
b23d45c4 efd53870 dfcb8dc0 efd53870 00000000 000011e6 ea53a1e8 ea53a0b0
efdf0d30 b2454560 623e5018 0000017d 00000001 efdf0d30 00000100 00000000
Call Trace:
[<b1038454>] __rt_mutex_adjust_prio+0x1f/0x24 (112)
[<b1038ad8>] task_blocks_on_rt_mutex+0x1b6/0x1c9 (16)
[<b13bfeb1>] schedule+0x34/0x10b (24)
[<b13c0963>] rt_mutex_slowlock+0xc7/0x258 (28)
[<b13c0bb6>] rt_mutex_lock+0x3f/0x43 (100)
[<b1039075>] rt_down+0x12/0x32 (20)
[<b13c14a7>] lock_kernel+0x1d/0x23 (16)
[<b1228246>] tty_write+0x119/0x21b (12)
[<b122b758>] write_chan+0x0/0x338 (24)
[<b10352bd>] hrtimer_wakeup+0x0/0x1c (20)
[<b10671f0>] vfs_write+0xc1/0x19b (24)
[<b1067bfa>] sys_write+0x4b/0x74 (40)
[<b1002eeb>] sysenter_past_esp+0x54/0x75 (40)

...generated via SysRq-T, induces...

PERIOD MISSED!
scheduled delta: 4964 us
actual delta: 4974 us
latency: 10 us
---------------------------------------
previous start: 1750012 us
now: 13122245 us
scheduled start: 1755000 us
next scheduled start is in the past!