lkml.org 
[lkml]   [2008]   [Nov]   [28]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [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 .....


\
 
 \ /
  Last update: 2008-11-29 04:43    [W:0.621 / U:0.132 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site