An error occurred fetching the project authors.
  1. 26 Jul, 2008 1 commit
  2. 18 Jul, 2008 1 commit
    • Steven Rostedt's avatar
      ftrace: only trace preempt off with preempt tracer · 1e01cb0c
      Steven Rostedt authored
      When PREEMPT_TRACER and IRQSOFF_TRACER are both configured and irqsoff
      tracer is running, the preempt_off sections might also be traced.
      
      Thanks to Andrew Morton for pointing out my mistake of spin_lock disabling
      interrupts while he was reviewing ftrace.txt. Seems that my example I used
      actually hit this bug.
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Cc: Linus Torvalds <torvalds@linux-foundation.org>
      Cc: Andrew Morton <akpm@linux-foundation.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      1e01cb0c
  3. 26 May, 2008 1 commit
    • Steven Rostedt's avatar
      ftrace: remove printks from irqsoff trace · da89a7a2
      Steven Rostedt authored
      Printing out new max latencies was fine for the old RT tracer. But for
      mainline it is a bit messy. We also need to test if the run queue
      is locked before we can do the print. This means that we may not be
      printing out latencies if the run queue is locked on another CPU.
      This produces inconsistencies in the output.
      
      This patch simply removes the print altogether.
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Cc: pq@iki.fi
      Cc: proski@gnu.org
      Cc: sandmann@redhat.com
      Cc: a.p.zijlstra@chello.nl
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      da89a7a2
  4. 23 May, 2008 12 commits
    • Steven Rostedt's avatar
      ftrace: irqsoff use raw_smp_processor_id · c5f888ca
      Steven Rostedt authored
      This patch changes the use of __get_cpu_var to explicitly calling
      raw_smp_processor_id and using the per_cpu() macro. On some debug
      configurations, the use of __get_cpu_var may cause ftrace to trigger
      and this can cause problems with the irqsoff tracing.
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      c5f888ca
    • Steven Rostedt's avatar
      ftrace: printk and trace irqsoff and wakeups · 4fe8c304
      Steven Rostedt authored
      printk called from wakeup critical timings and irqs off can
      cause deadlocks since printk might do a wakeup itself. If the
      call to printk happens with the runqueue lock held, it can
      deadlock.
      
      This patch protects the printk from being called in trace irqs off
      with a test to see if the runqueue for the current CPU is locked.
      If it is locked, the printk is skipped.
      
      The wakeup always holds the runqueue lock, so the printk is
      simply removed.
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      4fe8c304
    • Ingo Molnar's avatar
      ftrace: remove notrace · e309b41d
      Ingo Molnar authored
      now that we have a kbuild method for notrace, no need to pollute the
      C code with the annotations.
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      e309b41d
    • Ingo Molnar's avatar
      ftrace: cleanups · 9ff9cdb2
      Ingo Molnar authored
      clean up recent code.
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      9ff9cdb2
    • Steven Rostedt's avatar
      ftrace: add trace_function api for other tracers to use · 6fb44b71
      Steven Rostedt authored
      A new check was added in the ftrace function that wont trace if the CPU
      trace buffer is disabled.  Unfortunately, other tracers used ftrace() to
      write to the buffer after they disabled it. The new disable check makes
      these calls into a nop.
      
      This patch changes the __ftrace that is called without the check into a
      new api for the other tracers to use, called "trace_function". The other
      tracers use this interface instead when the trace CPU buffer is already
      disabled.
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      6fb44b71
    • Ingo Molnar's avatar
      ftrace: timestamp syncing, prepare · 750ed1a4
      Ingo Molnar authored
      rename and uninline now() to ftrace_now().
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      750ed1a4
    • Ingo Molnar's avatar
      ftrace: cleanups · c7aafc54
      Ingo Molnar authored
      factor out code and clean it up.
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      c7aafc54
    • Steven Rostedt's avatar
      ftrace: add self-tests · 60a11774
      Steven Rostedt authored
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      60a11774
    • Steven Rostedt's avatar
      ftrace: fix updates to max trace · 89b2f978
      Steven Rostedt authored
      This patch fixes some bugs to the updating of the max trace that
      was caused by implementing the new buffering.
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      89b2f978
    • Steven Rostedt's avatar
      ftrace: irqs off smp_processor_id() fix · 361943ad
      Steven Rostedt authored
      The irqsoff function tracer did a __get_cpu_var to determine
      if it should trace the function or not. The problem is that
      __get_cpu_var can preempt between getting the CPU and reading
      the cpu variable. This means that the cpu variable that is
      being read is not from the cpu being run on.
      
      At worst, this can give a false positive, where we trace the
      function when we should not.  It will never give a false negative
      since we only want to trace when interrupts are disabled
      and we never preempt when they are.
      
      This fix adds a check after reading the irq flags to only
      trace if the interrupts are actually disabled. It also changes
      the reading of the cpu variable to use a raw_smp_processor_id
      since we now don't care if we preempt. We still catch that fact.
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      361943ad
    • Steven Rostedt's avatar
      ftrace: trace preempt off critical timings · 6cd8a4bb
      Steven Rostedt authored
      Add preempt off timings. A lot of kernel core code is taken from the RT patch
      latency trace that was written by Ingo Molnar.
      
      This adds "preemptoff" and "preemptirqsoff" to /debugfs/tracing/available_tracers
      
      Now instead of just tracing irqs off, preemption off can be selected
      to be recorded.
      
      When this is selected, it shares the same files as irqs off timings.
      One can either trace preemption off, irqs off, or one or the other off.
      
      By echoing "preemptoff" into /debugfs/tracing/current_tracer, recording
      of preempt off only is performed. "irqsoff" will only record the time
      irqs are disabled, but "preemptirqsoff" will take the total time irqs
      or preemption are disabled. Runtime switching of these options is now
      supported by simpling echoing in the appropriate trace name into
      /debugfs/tracing/current_tracer.
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      6cd8a4bb
    • Steven Rostedt's avatar
      ftrace: trace irq disabled critical timings · 81d68a96
      Steven Rostedt authored
      This patch adds latency tracing for critical timings
      (how long interrupts are disabled for).
      
       "irqsoff" is added to /debugfs/tracing/available_tracers
      
      Note:
        tracing_max_latency
          also holds the max latency for irqsoff (in usecs).
         (default to large number so one must start latency tracing)
      
        tracing_thresh
          threshold (in usecs) to always print out if irqs off
          is detected to be longer than stated here.
          If irq_thresh is non-zero, then max_irq_latency
          is ignored.
      
      Here's an example of a trace with ftrace_enabled = 0
      
      =======
      preemption latency trace v1.1.5 on 2.6.24-rc7
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      --------------------------------------------------------------------
       latency: 100 us, #3/3, CPU#1 | (M:rt VP:0, KP:0, SP:0 HP:0 #P:2)
          -----------------
          | task: swapper-0 (uid:0 nice:0 policy:0 rt_prio:0)
          -----------------
       => started at: _spin_lock_irqsave+0x2a/0xb7
       => ended at:   _spin_unlock_irqrestore+0x32/0x5f
      
                       _------=> CPU#
                      / _-----=> irqs-off
                     | / _----=> need-resched
                     || / _---=> hardirq/softirq
                     ||| / _--=> preempt-depth
                     |||| /
                     |||||     delay
         cmd     pid ||||| time  |   caller
            \   /    |||||   \   |   /
       swapper-0     1d.s3    0us+: _spin_lock_irqsave+0x2a/0xb7 (e1000_update_stats+0x47/0x64c [e1000])
       swapper-0     1d.s3  100us : _spin_unlock_irqrestore+0x32/0x5f (e1000_update_stats+0x641/0x64c [e1000])
       swapper-0     1d.s3  100us : trace_hardirqs_on_caller+0x75/0x89 (_spin_unlock_irqrestore+0x32/0x5f)
      
      vim:ft=help
      =======
      
      And this is a trace with ftrace_enabled == 1
      
      =======
      preemption latency trace v1.1.5 on 2.6.24-rc7
      --------------------------------------------------------------------
       latency: 102 us, #12/12, CPU#1 | (M:rt VP:0, KP:0, SP:0 HP:0 #P:2)
          -----------------
          | task: swapper-0 (uid:0 nice:0 policy:0 rt_prio:0)
          -----------------
       => started at: _spin_lock_irqsave+0x2a/0xb7
       => ended at:   _spin_unlock_irqrestore+0x32/0x5f
      
                       _------=> CPU#
                      / _-----=> irqs-off
                     | / _----=> need-resched
                     || / _---=> hardirq/softirq
                     ||| / _--=> preempt-depth
                     |||| /
                     |||||     delay
         cmd     pid ||||| time  |   caller
            \   /    |||||   \   |   /
       swapper-0     1dNs3    0us+: _spin_lock_irqsave+0x2a/0xb7 (e1000_update_stats+0x47/0x64c [e1000])
       swapper-0     1dNs3   46us : e1000_read_phy_reg+0x16/0x225 [e1000] (e1000_update_stats+0x5e2/0x64c [e1000])
       swapper-0     1dNs3   46us : e1000_swfw_sync_acquire+0x10/0x99 [e1000] (e1000_read_phy_reg+0x49/0x225 [e1000])
       swapper-0     1dNs3   46us : e1000_get_hw_eeprom_semaphore+0x12/0xa6 [e1000] (e1000_swfw_sync_acquire+0x36/0x99 [e1000])
       swapper-0     1dNs3   47us : __const_udelay+0x9/0x47 (e1000_read_phy_reg+0x116/0x225 [e1000])
       swapper-0     1dNs3   47us+: __delay+0x9/0x50 (__const_udelay+0x45/0x47)
       swapper-0     1dNs3   97us : preempt_schedule+0xc/0x84 (__delay+0x4e/0x50)
       swapper-0     1dNs3   98us : e1000_swfw_sync_release+0xc/0x55 [e1000] (e1000_read_phy_reg+0x211/0x225 [e1000])
       swapper-0     1dNs3   99us+: e1000_put_hw_eeprom_semaphore+0x9/0x35 [e1000] (e1000_swfw_sync_release+0x50/0x55 [e1000])
       swapper-0     1dNs3  101us : _spin_unlock_irqrestore+0xe/0x5f (e1000_update_stats+0x641/0x64c [e1000])
       swapper-0     1dNs3  102us : _spin_unlock_irqrestore+0x32/0x5f (e1000_update_stats+0x641/0x64c [e1000])
       swapper-0     1dNs3  102us : trace_hardirqs_on_caller+0x75/0x89 (_spin_unlock_irqrestore+0x32/0x5f)
      
      vim:ft=help
      =======
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      81d68a96