Messages in this thread | | | Date | Sat, 29 Nov 2008 04:40:37 +0100 | From | "Frédéric Weisbecker" <> | Subject | Re: [PATCH] tracing/function-graph-tracer: adjustments of the trace informations |
| |
2008/11/28 Ingo Molnar <mingo@elte.hu>: > > 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() { > > ?
I tried to figure out a way to signal a hardirq in a trace, I like this arrow but It breaks the indentation. I would suggest:
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() {
Your idea solves a part of one of the features I wanted to add: why not using a single character column to print the current context: workqueue, syscall, kernel thread, tasklet, hardirq .....
| |