Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm1-V0.7.27-3

[Ingo Molnar <mingo@elte.hu>]

ah, it's a missed reschedule:

>     5 80010004 0.000ms (+0.000ms): trace_start_sched_wakeup (try_to_wake_up)
>     5 80010003 0.000ms (+0.000ms): (0) ((98))
>     5 80010003 0.000ms (+0.000ms): (2) ((5))
>     5 80010003 0.000ms (+0.000ms): try_to_wake_up (wake_up_process)
>     5 80010003 0.000ms (+0.000ms): (0) ((1))
>     5 80010002 0.000ms (+0.000ms): preempt_schedule (try_to_wake_up)
>     5 80010002 0.000ms (+0.000ms): wake_up_process (redirect_hardirq)
>     5 80010001 0.000ms (+0.000ms): preempt_schedule (__do_IRQ)
>     5 80010001 0.000ms (+0.000ms): irq_exit (do_IRQ)
>     5 80000002 0.000ms (+0.000ms): do_softirq (irq_exit)
>     5 80000002 0.001ms (+1.054ms): __do_softirq (do_softirq)
>     5 00000000 1.055ms (+0.000ms): preempt_schedule (_mmx_memcpy)
>     5 90000000 1.055ms (+0.000ms): __schedule (preempt_schedule)

note this entry:

>     5 80010003 0.000ms (+0.000ms): (0) ((1))

this was generated by:

                __trace(0, need_resched());

so need_resched() is definite set. The kernel should have rescheduled. 

The other trace entries corroborate this:

>     5 80010003 0.000ms (+0.000ms): (0) ((98))
>     5 80010003 0.000ms (+0.000ms): (2) ((5))

these two entries mean that PID 2 got woken up by PID 5, and that PID 2
has a priority of 0, which is much higher than PID 5's prio 98 [the
kernel-internal priority scale is inverted], so no wonder need_resched() 
is set.

	Ingo