Re: [PATCH] tracing/function-graph-tracer: adjustments of thetrace informations

From: Ingo Molnar
Date: Fri Nov 28 2008 - 14:23:17 EST



another detail: it would be nice to annotate IRQ entries some more.

right now if a syscall is interrupted by a hardware interrupt, it looks
like this:

0) | skb_dequeue() {
0) 0.365 us | _spin_lock_irqsave();
0) 0.422 us | _spin_unlock_irqrestore();
0) 1.912 us | }
0) | memcpy_toiovec() {
0) | copy_to_user() {
0) | smp_apic_timer_interrupt() {
0) 0.450 us | native_apic_mem_write();
0) | irq_enter() {
0) 0.410 us | idle_cpu();
0) 1.167 us | }
0) | hrtimer_interrupt() {

the natural nesting is nice, but easy to miss. It would be nice to have
something like:

0) | skb_dequeue() {
0) 0.365 us | _spin_lock_irqsave();
0) 0.422 us | _spin_unlock_irqrestore();
0) 1.912 us | }
0) | memcpy_toiovec() {
0) | copy_to_user() {
0) =====> smp_apic_timer_interrupt() {
0) 0.450 us | native_apic_mem_write();
0) | irq_enter() {
0) 0.410 us | idle_cpu();
0) 1.167 us | }
0) | hrtimer_interrupt() {

and perhaps something like this at the end of the irq frame:

0) 0.408 us | _local_bh_enable();
0) + 13.139 us | }
0) + 13.887 us | }
0) 0.406 us | idle_cpu();
0) + 15.373 us | }
0) + 74.564 us | }
0) | _cond_resched() {
0) | need_resched() {
0) 0.423 us | constant_test_bit();
0) 1.164 us | }
0) 1.915 us <=== } /* IRQ 1 end */
0) + 78.396 us | }
0) + 79.123 us | }
0) 0.387 us | skb_pull();
0) | kfree_skb() {

?

Ingo
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/