1. 24 Jul, 2013 2 commits
    • Oleg Nesterov's avatar
      tracing: Change tracing_pipe_fops() to rely on tracing_get_cpu() · 15544209
      Oleg Nesterov authored
      tracing_open_pipe() is racy, the memory inode->i_private points to
      can be already freed.
      
      Change debugfs_create_file("trace_pipe", data) callers to to pass
      "data = tr", tracing_open_pipe() can use tracing_get_cpu().
      
      Link: http://lkml.kernel.org/r/20130723152557.GA23717@redhat.com
      
      Signed-off-by: default avatarOleg Nesterov <oleg@redhat.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      15544209
    • Oleg Nesterov's avatar
      tracing: Introduce trace_create_cpu_file() and tracing_get_cpu() · 649e9c70
      Oleg Nesterov authored
      Every "file_operations" used by tracing_init_debugfs_percpu is buggy.
      f_op->open/etc does:
      
      	1. struct trace_cpu *tc = inode->i_private;
      	   struct trace_array *tr = tc->tr;
      
      	2. trace_array_get(tr) or fail;
      
      	3. do_something(tc);
      
      But tc (and tr) can be already freed before trace_array_get() is called.
      And it doesn't matter whether this file is per-cpu or it was created by
      init_tracer_debugfs(), free_percpu() or kfree() are equally bad.
      
      Note that even 1. is not safe, the freed memory can be unmapped. But even
      if it was safe trace_array_get() can wrongly succeed if we also race with
      the next new_instance_create() which can re-allocate the same tr, or tc
      was overwritten and ->tr points to the valid tr. In this case 3. uses the
      freed/reused memory.
      
      Add the new trivial helper, trace_create_cpu_file() which simply calls
      trace_create_file() and encodes "cpu" in "struct inode". Another helper,
      tracing_get_cpu() will be used to read cpu_nr-or-RING_BUFFER_ALL_CPUS.
      
      The patch abuses ->i_cdev to encode the number, it is never used unless
      the file is S_ISCHR(). But we could use something else, say, i_bytes or
      even ->d_fsdata. In any case this hack is hidden inside these 2 helpers,
      it would be trivial to change them if needed.
      
      This patch only changes tracing_init_debugfs_percpu() to use the new
      trace_create_cpu_file(), the next patches will change file_operations.
      
      Note: tracing_get_cpu(inode) is always safe but you can't trust the
      result unless trace_array_get() was called, without trace_types_lock
      which acts as a barrier it can wrongly return RING_BUFFER_ALL_CPUS.
      
      Link: http://lkml.kernel.org/r/20130723152554.GA23710@redhat.com
      
      
      
      Cc: Al Viro <viro@zeniv.linux.org.uk>
      Signed-off-by: default avatarOleg Nesterov <oleg@redhat.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      649e9c70
  2. 19 Jul, 2013 3 commits
  3. 15 Jul, 2013 1 commit
  4. 03 Jul, 2013 3 commits
  5. 02 Jul, 2013 5 commits
  6. 20 Jun, 2013 1 commit
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Disable tracing on warning · de7edd31
      Steven Rostedt (Red Hat) authored
      
      
      Add a traceoff_on_warning option in both the kernel command line as well
      as a sysctl option. When set, any WARN*() function that is hit will cause
      the tracing_on variable to be cleared, which disables writing to the
      ring buffer.
      
      This is useful especially when tracing a bug with function tracing. When
      a warning is hit, the print caused by the warning can flood the trace with
      the functions that producing the output for the warning. This can make the
      resulting trace useless by either hiding where the bug happened, or worse,
      by overflowing the buffer and losing the trace of the bug totally.
      Acked-by: default avatarPeter Zijlstra <peterz@infradead.org>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      de7edd31
  7. 11 Jun, 2013 2 commits
  8. 06 Jun, 2013 1 commit
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Use current_uid() for critical time tracing · f17a5194
      Steven Rostedt (Red Hat) authored
      
      
      The irqsoff tracer records the max time that interrupts are disabled.
      There are hooks in the assembly code that calls back into the tracer when
      interrupts are disabled or enabled.
      
      When they are enabled, the tracer checks if the amount of time they
      were disabled is larger than the previous recorded max interrupts off
      time. If it is, it creates a snapshot of the currently running trace
      to store where the last largest interrupts off time was held and how
      it happened.
      
      During testing, this RCU lockdep dump appeared:
      
      [ 1257.829021] ===============================
      [ 1257.829021] [ INFO: suspicious RCU usage. ]
      [ 1257.829021] 3.10.0-rc1-test+ #171 Tainted: G        W
      [ 1257.829021] -------------------------------
      [ 1257.829021] /home/rostedt/work/git/linux-trace.git/include/linux/rcupdate.h:780 rcu_read_lock() used illegally while idle!
      [ 1257.829021]
      [ 1257.829021] other info that might help us debug this:
      [ 1257.829021]
      [ 1257.829021]
      [ 1257.829021] RCU used illegally from idle CPU!
      [ 1257.829021] rcu_scheduler_active = 1, debug_locks = 0
      [ 1257.829021] RCU used illegally from extended quiescent state!
      [ 1257.829021] 2 locks held by trace-cmd/4831:
      [ 1257.829021]  #0:  (max_trace_lock){......}, at: [<ffffffff810e2b77>] stop_critical_timing+0x1a3/0x209
      [ 1257.829021]  #1:  (rcu_read_lock){.+.+..}, at: [<ffffffff810dae5a>] __update_max_tr+0x88/0x1ee
      [ 1257.829021]
      [ 1257.829021] stack backtrace:
      [ 1257.829021] CPU: 3 PID: 4831 Comm: trace-cmd Tainted: G        W    3.10.0-rc1-test+ #171
      [ 1257.829021] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./To be filled by O.E.M., BIOS SDBLI944.86P 05/08/2007
      [ 1257.829021]  0000000000000001 ffff880065f49da8 ffffffff8153dd2b ffff880065f49dd8
      [ 1257.829021]  ffffffff81092a00 ffff88006bd78680 ffff88007add7500 0000000000000003
      [ 1257.829021]  ffff88006bd78680 ffff880065f49e18 ffffffff810daebf ffffffff810dae5a
      [ 1257.829021] Call Trace:
      [ 1257.829021]  [<ffffffff8153dd2b>] dump_stack+0x19/0x1b
      [ 1257.829021]  [<ffffffff81092a00>] lockdep_rcu_suspicious+0x109/0x112
      [ 1257.829021]  [<ffffffff810daebf>] __update_max_tr+0xed/0x1ee
      [ 1257.829021]  [<ffffffff810dae5a>] ? __update_max_tr+0x88/0x1ee
      [ 1257.829021]  [<ffffffff811002b9>] ? user_enter+0xfd/0x107
      [ 1257.829021]  [<ffffffff810dbf85>] update_max_tr_single+0x11d/0x12d
      [ 1257.829021]  [<ffffffff811002b9>] ? user_enter+0xfd/0x107
      [ 1257.829021]  [<ffffffff810e2b15>] stop_critical_timing+0x141/0x209
      [ 1257.829021]  [<ffffffff8109569a>] ? trace_hardirqs_on+0xd/0xf
      [ 1257.829021]  [<ffffffff811002b9>] ? user_enter+0xfd/0x107
      [ 1257.829021]  [<ffffffff810e3057>] time_hardirqs_on+0x2a/0x2f
      [ 1257.829021]  [<ffffffff811002b9>] ? user_enter+0xfd/0x107
      [ 1257.829021]  [<ffffffff8109550c>] trace_hardirqs_on_caller+0x16/0x197
      [ 1257.829021]  [<ffffffff8109569a>] trace_hardirqs_on+0xd/0xf
      [ 1257.829021]  [<ffffffff811002b9>] user_enter+0xfd/0x107
      [ 1257.829021]  [<ffffffff810029b4>] do_notify_resume+0x92/0x97
      [ 1257.829021]  [<ffffffff8154bdca>] int_signal+0x12/0x17
      
      What happened was entering into the user code, the interrupts were enabled
      and a max interrupts off was recorded. The trace buffer was saved along with
      various information about the task: comm, pid, uid, priority, etc.
      
      The uid is recorded with task_uid(tsk). But this is a macro that uses rcu_read_lock()
      to retrieve the data, and this happened to happen where RCU is blind (user_enter).
      
      As only the preempt and irqs off tracers can have this happen, and they both
      only have the tsk == current, if tsk == current, use current_uid() instead of
      task_uid(), as current_uid() does not use RCU as only current can change its uid.
      
      This fixes the RCU suspicious splat.
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      f17a5194
  9. 23 May, 2013 1 commit
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Fix crash when ftrace=nop on the kernel command line · ca164318
      Steven Rostedt (Red Hat) authored
      
      
      If ftrace=<tracer> is on the kernel command line, when that tracer is
      registered, it will be initiated by tracing_set_tracer() to execute that
      tracer.
      
      The nop tracer is just a stub tracer that is used to have no tracer
      enabled. It is assigned at early bootup as it is the default tracer.
      
      But if ftrace=nop is on the kernel command line, the registering of the
      nop tracer will call tracing_set_tracer() which will try to execute
      the nop tracer. But it expects tr->current_trace to be assigned something
      as it usually is assigned to the nop tracer. As it hasn't been assigned
      to anything yet, it causes the system to crash.
      
      The simple fix is to move the tr->current_trace = nop before registering
      the nop tracer. The functionality is still the same as the nop tracer
      doesn't do anything anyway.
      Reported-by: default avatarPeter Zijlstra <peterz@infradead.org>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      ca164318
  10. 30 Apr, 2013 1 commit
  11. 13 Apr, 2013 1 commit
  12. 09 Apr, 2013 1 commit
  13. 08 Apr, 2013 2 commits
  14. 21 Mar, 2013 1 commit
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Update debugfs README file · 22f45649
      Steven Rostedt (Red Hat) authored
      
      
      Update the README file in debugfs/tracing to something more useful.
      What's currently in the file is very old and what it shows doesn't
      have much use. Heck, it tells you how to mount debugfs! But to read
      this file you would have already needed to mount it.
      
      Replace the file with current up-to-date information. It's rather
      limited, but what do you expect from a pseudo README file.
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      22f45649
  15. 15 Mar, 2013 15 commits
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Fix ftrace_dump() · 7fe70b57
      Steven Rostedt (Red Hat) authored
      
      
      ftrace_dump() had a lot of issues. What ftrace_dump() does, is when
      ftrace_dump_on_oops is set (via a kernel parameter or sysctl), it
      will dump out the ftrace buffers to the console when either a oops,
      panic, or a sysrq-z occurs.
      
      This was written a long time ago when ftrace was fragile to recursion.
      But it wasn't written well even for that.
      
      There's a possible deadlock that can occur if a ftrace_dump() is happening
      and an NMI triggers another dump. This is because it grabs a lock
      before checking if the dump ran.
      
      It also totally disables ftrace, and tracing for no good reasons.
      
      As the ring_buffer now checks if it is read via a oops or NMI, where
      there's a chance that the buffer gets corrupted, it will disable
      itself. No need to have ftrace_dump() do the same.
      
      ftrace_dump() is now cleaned up where it uses an atomic counter to
      make sure only one dump happens at a time. A simple atomic_inc_return()
      is enough that is needed for both other CPUs and NMIs. No need for
      a spinlock, as if one CPU is running the dump, no other CPU needs
      to do it too.
      
      The tracing_on variable is turned off and not turned on. The original
      code did this, but it wasn't pretty. By just disabling this variable
      we get the result of not seeing traces that happen between crashes.
      
      For sysrq-z, it doesn't get turned on, but the user can always write
      a '1' to the tracing_on file. If they are using sysrq-z, then they should
      know about tracing_on.
      
      The new code is much easier to read and less error prone. No more
      deadlock possibility when an NMI triggers here.
      Reported-by: default avatarzhangwei(Jovi) <jovi.zhangwei@huawei.com>
      Cc: stable@vger.kernel.org
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      7fe70b57
    • zhangwei(Jovi)'s avatar
      tracing: Use TRACE_MAX_PRINT instead of constant · bd6df187
      zhangwei(Jovi) authored
      TRACE_MAX_PRINT macro is defined, but is not used.
      
      Link: http://lkml.kernel.org/r/513D8421.4070404@huawei.com
      
      Signed-off-by: default avatarzhangwei(Jovi) <jovi.zhangwei@huawei.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      bd6df187
    • zhangwei(Jovi)'s avatar
      tracing: Use pr_warn_once instead of open coded implementation · 687c878a
      zhangwei(Jovi) authored
      Use pr_warn_once, instead of making an open coded implementation.
      
      Link: http://lkml.kernel.org/r/513D8419.20400@huawei.com
      
      Signed-off-by: default avatarzhangwei(Jovi) <jovi.zhangwei@huawei.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      687c878a
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add "perf" trace_clock · 76f11917
      Steven Rostedt (Red Hat) authored
      
      
      The function trace_clock() calls "local_clock()" which is exactly
      the same clock that perf uses. I'm not sure why perf doesn't call
      trace_clock(), as trace_clock() doesn't have any users.
      
      But now it does. As trace_clock() calls local_clock() like perf does,
      I added the trace_clock "perf" option that uses trace_clock().
      
      Now the ftrace buffers can use the same clock as perf uses. This
      will be useful when perf starts reading the ftrace buffers, and will
      be able to interleave them with the same clock data.
      
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      76f11917
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add "uptime" trace clock that uses jiffies · 8aacf017
      Steven Rostedt (Red Hat) authored
      
      
      Add a simple trace clock called "uptime" for those that are
      interested in the uptime of the trace. It uses jiffies as that's
      the safest method, as other uptime clocks grab seq locks, which could
      cause a deadlock if taken from an event or function tracer.
      Requested-by: default avatarMauro Carvalho Chehab <mchehab@redhat.com>
      Cc: Thomas Gleixner <tglx@linutronix.de
      Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      8aacf017
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add function-trace option to disable function tracing of latency tracers · 328df475
      Steven Rostedt (Red Hat) authored
      
      
      Currently, the only way to stop the latency tracers from doing function
      tracing is to fully disable the function tracer from the proc file
      system:
      
        echo 0 > /proc/sys/kernel/ftrace_enabled
      
      This is a big hammer approach as it disables function tracing for
      all users. This includes kprobes, perf, stack tracer, etc.
      
      Instead, create a function-trace option that the latency tracers can
      check to determine if it should enable function tracing or not.
      This option can be set or cleared even while the tracer is active
      and the tracers will disable or enable function tracing depending
      on how the option was set.
      
      Instead of using the proc file, disable latency function tracing with
      
        echo 0 > /debug/tracing/options/function-trace
      
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Clark Williams <williams@redhat.com>
      Cc: John Kacur <jkacur@redhat.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      328df475
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add skip argument to trace_dump_stack() · c142be8e
      Steven Rostedt (Red Hat) authored
      
      
      Altough the trace_dump_stack() already skips three functions in
      the call to stack trace, which gets the stack trace to start
      at the caller of the function, the caller may want to skip some
      more too (as it may have helper functions).
      
      Add a skip argument to the trace_dump_stack() that lets the caller
      skip back tracing functions that it doesn't care about.
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      c142be8e
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add snapshot trigger to function probes · 77fd5c15
      Steven Rostedt (Red Hat) authored
      
      
       echo 'schedule:snapshot:1' > /debug/tracing/set_ftrace_filter
      
      This will cause the scheduler to trigger a snapshot the next time
      it's called (you can use any function that's not called by NMI).
      
      Even though it triggers only once, you still need to remove it with:
      
       echo '!schedule:snapshot:0' > /debug/tracing/set_ftrace_filter
      
      The :1 can be left off for the first command:
      
       echo 'schedule:snapshot' > /debug/tracing/set_ftrace_filter
      
      But this will cause all calls to schedule to trigger a snapshot.
      This must be removed without the ':0'
      
       echo '!schedule:snapshot' > /debug/tracing/set_ftrace_filter
      
      As adding a "count" is a different operation (internally).
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      77fd5c15
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add alloc/free_snapshot() to replace duplicate code · 3209cff4
      Steven Rostedt (Red Hat) authored
      
      
      Add alloc_snapshot() and free_snapshot() to allocate and free the
      snapshot buffer respectively, and use these to remove duplicate
      code.
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      3209cff4
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Let tracing_snapshot() be used by modules but not NMI · 1b22e382
      Steven Rostedt (Red Hat) authored
      
      
      Add EXPORT_SYMBOL_GPL() to let the tracing_snapshot() functions be
      called from modules.
      
      Also add a test to see if the snapshot was called from NMI context
      and just warn in the tracing buffer if so, and return.
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      1b22e382
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add internal ftrace trace_puts() for ftrace to use · ca268da6
      Steven Rostedt (Red Hat) authored
      
      
      There's a few places that ftrace uses trace_printk() for internal
      use, but this requires context (normal, softirq, irq, NMI) buffers
      to keep things lockless. But the trace_puts() does not, as it can
      write the string directly into the ring buffer. Make a internal helper
      for trace_puts() and have the internal functions use that.
      
      This way the extra context buffers are not used.
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      ca268da6
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add trace_puts() for even faster trace_printk() tracing · 09ae7234
      Steven Rostedt (Red Hat) authored
      
      
      The trace_printk() is extremely fast and is very handy as it can be
      used in any context (including NMIs!). But it still requires scanning
      the fmt string for parsing the args. Even the trace_bprintk() requires
      a scan to know what args will be saved, although it doesn't copy the
      format string itself.
      
      Several times trace_printk() has no args, and wastes cpu cycles scanning
      the fmt string.
      
      Adding trace_puts() allows the developer to use an even faster
      tracing method that only saves the pointer to the string in the
      ring buffer without doing any format parsing at all. This will
      help remove even more of the "Heisenbug" effect, when debugging.
      
      Also fixed up the F_printk()s for the ftrace internal bprint and print events.
      
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      09ae7234
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add alloc_snapshot kernel command line parameter · 55034cd6
      Steven Rostedt (Red Hat) authored
      
      
      If debugging the kernel, and the developer wants to use
      tracing_snapshot() in places where tracing_snapshot_alloc() may
      be difficult (or more likely, the developer is lazy and doesn't
      want to bother with tracing_snapshot_alloc() at all), then adding
      
        alloc_snapshot
      
      to the kernel command line parameter will tell ftrace to allocate
      the snapshot buffer (if configured) when it allocates the main
      tracing buffer.
      
      I also noticed that ring_buffer_expanded and tracing_selftest_disabled
      had inconsistent use of boolean "true" and "false" with "0" and "1".
      I cleaned that up too.
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      55034cd6
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Move the tracing selftest code into its own function · f4e781c0
      Steven Rostedt (Red Hat) authored
      
      
      Move the tracing startup selftest code into its own function and
      when not enabled, always have that function succeed.
      
      This makes the register_tracer() function much more readable.
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      f4e781c0
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add internal tracing_snapshot() functions · ad909e21
      Steven Rostedt (Red Hat) authored
      
      
      The new snapshot feature is quite handy. It's a way for the user
      to take advantage of the spare buffer that, until then, only
      the latency tracers used to "snapshot" the buffer when it hit
      a max latency. Now users can trigger a "snapshot" manually when
      some condition is hit in a program. But a snapshot currently can
      not be triggered by a condition inside the kernel.
      
      With the addition of tracing_snapshot() and tracing_snapshot_alloc(),
      snapshots can now be taking when a condition is hit, and the
      developer wants to snapshot the case without stopping the trace.
      
      Note, any snapshot will overwrite the old one, so take care
      in how this is done.
      
      These new functions are to be used like tracing_on(), tracing_off()
      and trace_printk() are. That is, they should never be called
      in the mainline Linux kernel. They are solely for the purpose
      of debugging.
      
      The tracing_snapshot() will not allocate a buffer, but it is
      safe to be called from any context (except NMIs). But if a
      snapshot buffer isn't allocated when it is called, it will write
      to the live buffer, complaining about the lack of a snapshot
      buffer, and then stop tracing (giving you the "permanent snapshot").
      
      tracing_snapshot_alloc() will allocate the snapshot buffer if
      it was not already allocated and then take the snapshot. This routine
      *may sleep*, and must be called from context that can sleep.
      The allocation is done with GFP_KERNEL and not atomic.
      
      If you need a snapshot in an atomic context, say in early boot,
      then it is best to call the tracing_snapshot_alloc() before then,
      where it will allocate the buffer, and then you can use the
      tracing_snapshot() anywhere you want and still get snapshots.
      
      Cc: Hiraku Toyooka <hiraku.toyooka.gu@hitachi.com>
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      ad909e21