Re: [patch] Latency Tracer, voluntary-preempt-2.6.8-rc4-O6

James Courtier-Dutton
2004-08-14T12:20:11Z

This is just for info, now that we have a nice latency testing tool, we
might as well collect some useful traces that we can later work on.

Here is a trace showing a latency of 39034us.
http://www.superbug.demon.co.uk/kernel/

The interesting parts of it are:
0.002ms (+0.000ms): __preempt_spin_lock (schedule)
0.523ms (+0.520ms): do_IRQ (common_interrupt)
...
0.532ms (+0.000ms): end_edge_ioapic_irq (do_IRQ)
0.763ms (+0.230ms): smp_apic_timer_interrupt (apic_timer_interrupt)
...
0.768ms (+0.000ms): preempt_schedule (try_to_wake_up)
1.523ms (+0.754ms): do_IRQ (common_interrupt)
...
1.533ms (+0.000ms): __do_softirq (do_softirq)
1.763ms (+0.229ms): smp_apic_timer_interrupt (apic_timer_interrupt)
...
1.765ms (+0.000ms): __do_softirq (do_softirq)
2.523ms (+0.757ms): do_IRQ (common_interrupt)
...
2.533ms (+0.000ms): do_softirq (do_IRQ)
2.533ms (+0.000ms): __do_softirq (do_softirq)
2.763ms (+0.230ms): smp_apic_timer_interrupt (apic_timer_interrupt)
...

This looks to me to be a bug somewhere. Either in the O7 patch, or in
the kernel. Surely, do_IRQ should happen quickly, and not take 39ms.