linux-kernel - Re: [PATCH] tracing/function-graph-tracer: adjustments of the trace informations

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <c62985530811281940w4542546t5a1235ad8e5a24bf@mail.gmail.com>
Date:	Sat, 29 Nov 2008 04:40:37 +0100
From:	"Frédéric Weisbecker" <fweisbec@...il.com>
To:	"Ingo Molnar" <mingo@...e.hu>
Cc:	"Steven Rostedt" <rostedt@...dmis.org>,
	"Tim Bird" <tim.bird@...sony.com>,
	"Peter Zijlstra" <a.p.zijlstra@...llo.nl>,
	"Linux Kernel" <linux-kernel@...r.kernel.org>
Subject: Re: [PATCH] tracing/function-graph-tracer: adjustments of the trace informations

2008/11/28 Ingo Molnar <mingo@...e.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 .....
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/