Re: preempt-timing-2.6.8-rc1

Nick Piggin
2004-07-13T12:51:29Z

William Lee Irwin III wrote:
> This patch uses the preemption counter increments and decrements to time
> non-preemptible critical sections.
>
> This is an instrumentation patch intended to help determine the causes of
> scheduling latency related to long non-preemptible critical sections.
>
> Changes from 2.6.7-based patch:
> (1) fix unmap_vmas() check correctly this time
> (2) add touch_preempt_timing() to cond_resched_lock()
> (3) depend on preempt until it's worked out wtf goes wrong without it
>
> --- timing-2.6.8-rc1.orig/kernel/printk.c 2004-07-11 10:35:31.000000000 -0700
> +++ timing-2.6.8-rc1/kernel/printk.c 2004-07-13 03:56:37.901603496 -0700
> @@ -650,10 +650,8 @@
> */
> void console_conditional_schedule(void)
> {
> - if (console_may_schedule && need_resched()) {
> - set_current_state(TASK_RUNNING);
> - schedule();
> - }
> + if (console_may_schedule)
> + cond_resched();
> }

You should send that one in

> +void dec_preempt_count(void)
> +{
> + if (preempt_count() == 1 && system_state == SYSTEM_RUNNING &&
> + __get_cpu_var(preempt_entry)) {
> + u64 hold;
> + unsigned long preempt_exit
> + = (unsigned long)__builtin_return_address(0);
> + hold = sched_clock() - __get_cpu_var(preempt_timings) + 999999;
> + do_div(hold, 1000000);
> + if (preempt_thresh && hold > preempt_thresh &&
> + printk_ratelimit()) {

This looks wrong. This means hold times of 1ns to 1000000ns trigger the
exceeded 1ms threshold, 1000001 to 2000000 trigger the 2ms one, etc.

Removing the + 999999 gives the correct result:
1000000 - 1999999ns triggers the 1ms threshold
2000000 - 2999999ns triggers the 2ms threshold
etc

Or have I missed something?