Skip to content
  1. Nov 20, 2014
  2. Nov 19, 2014
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Fix race of function probes counting · a9ce7c36
      Steven Rostedt (Red Hat) authored
      
      
      The function probe counting for traceon and traceoff suffered a race
      condition where if the probe was executing on two or more CPUs at the
      same time, it could decrement the counter by more than one when
      disabling (or enabling) the tracer only once.
      
      The way the traceon and traceoff probes are suppose to work is that
      they disable (or enable) tracing once per count. If a user were to
      echo 'schedule:traceoff:3' into set_ftrace_filter, then when the
      schedule function was called, it would disable tracing. But the count
      should only be decremented once (to 2). Then if the user enabled tracing
      again (via tracing_on file), the next call to schedule would disable
      tracing again and the count would be decremented to 1.
      
      But if multiple CPUS called schedule at the same time, it is possible
      that the count would be decremented more than once because of the
      simple "count--" used.
      
      By reading the count into a local variable and using memory barriers
      we can guarantee that the count would only be decremented once per
      disable (or enable).
      
      The stack trace probe had a similar race, but here the stack trace will
      decrement for each time it is called. But this had the read-modify-
      write race, where it could stack trace more than the number of times
      that was specified. This case we use a cmpxchg to stack trace only the
      number of times specified.
      
      The dump probes can still use the old "update_count()" function as
      they only run once, and that is controlled by the dump logic
      itself.
      
      Link: http://lkml.kernel.org/r/20141118134643.4b550ee4@gandalf.local.home
      
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      a9ce7c36
  3. Nov 14, 2014
    • Byungchul Park's avatar
      function_graph: Fix micro seconds notations · 4526d067
      Byungchul Park authored
      
      
      Usually, "msecs" notation means milli-seconds, and "usecs" notation
      means micro-seconds. Since the unit used in the code is micro-seconds,
      the notation should be replaced from msecs to usecs.
      
      Link: http://lkml.kernel.org/r/1415171926-9782-2-git-send-email-byungchul.park@lge.com
      
      Signed-off-by: default avatarByungchul Park <byungchul.park@lge.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      4526d067
    • Daniel Bristot de Oliveira's avatar
      ftrace-graph: show latency-format on print_graph_irq() · 678f845e
      Daniel Bristot de Oliveira authored
      
      
      On the function_graph tracer, the print_graph_irq() function prints a
      trace line with the flag ==========> on an irq handler entry, and the
      flag <========== on an irq handler return.
      
      But when the latency-format is enable, it is not printing the
      latency-format flags, causing the following error in the trace output:
      
       0)   ==========> |
       0)  d...              |  smp_apic_timer_interrupt() {
      
      This patch fixes this issue by printing the latency-format flags when
      it is enable.
      
      Link: http://lkml.kernel.org/r/7c2e226dac20c940b6242178fab7f0e3c9b5ce58.1415233316.git.bristot@redhat.com
      
      Reviewed-by: default avatarLuis Claudio R. Goncalves <lgoncalv@redhat.com>
      Signed-off-by: default avatarDaniel Bristot de Oliveira <bristot@redhat.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      678f845e
    • Rasmus Villemoes's avatar
      trace: Replace single-character seq_puts with seq_putc · 1177e436
      Rasmus Villemoes authored
      
      
      Printing a single character to a seqfile might as well be done with
      seq_putc instead of seq_puts; this avoids a strlen() call and a memory
      access. It also shaves another few bytes off the generated code.
      
      Link: http://lkml.kernel.org/r/1415479332-25944-4-git-send-email-linux@rasmusvillemoes.dk
      
      Signed-off-by: default avatarRasmus Villemoes <linux@rasmusvillemoes.dk>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      1177e436
    • Rasmus Villemoes's avatar
      tracing: Merge consecutive seq_puts calls · d79ac28f
      Rasmus Villemoes authored
      
      
      Consecutive seq_puts calls with literal strings can be merged to a
      single call. This reduces the size of the generated code, and can also
      lead to slight .rodata reduction (because of fewer nul and padding
      bytes). It should also shave a off a few clock cycles.
      
      Link: http://lkml.kernel.org/r/1415479332-25944-3-git-send-email-linux@rasmusvillemoes.dk
      
      Signed-off-by: default avatarRasmus Villemoes <linux@rasmusvillemoes.dk>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      d79ac28f
    • Rasmus Villemoes's avatar
      tracing: Replace seq_printf by simpler equivalents · fa6f0cc7
      Rasmus Villemoes authored
      
      
      Using seq_printf to print a simple string or a single character is a
      lot more expensive than it needs to be, since seq_puts and seq_putc
      exist.
      
      These patches do
      
        seq_printf(m, s) -> seq_puts(m, s)
        seq_printf(m, "%s", s) -> seq_puts(m, s)
        seq_printf(m, "%c", c) -> seq_putc(m, c)
      
      Subsequent patches will simplify further.
      
      Link: http://lkml.kernel.org/r/1415479332-25944-2-git-send-email-linux@rasmusvillemoes.dk
      
      Signed-off-by: default avatarRasmus Villemoes <linux@rasmusvillemoes.dk>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      fa6f0cc7
    • Daniel Thompson's avatar
      tracing: kdb: Fix kernel livelock with empty buffers · 8520dedb
      Daniel Thompson authored
      
      
      Currently kdb's ftdump command will livelock by constantly printk'ing
      the empty string at KERN_EMERG level if it run when the ftrace system is
      not in use. This occurs because trace_empty() never returns false when
      the ring buffers are left at the start of a non-consuming read [launched
      by ring_buffer_read_start()].
      
      This patch changes the loop exit condition to use the result of
      trace_find_next_entry_inc(). Effectively this switches the non-consuming
      kdb dumper to follow the approach of the non-consuming userspace
      interface [s_next()] rather than the consuming ftrace_dump().
      
      Link: http://lkml.kernel.org/r/1415277716-19419-3-git-send-email-daniel.thompson@linaro.org
      
      Cc: Ingo Molnar <mingo@redhat.com>
      Cc: Andrew Morton <akpm@linux-foundation.org>
      Cc: John Stultz <john.stultz@linaro.org>
      Cc: Sumit Semwal <sumit.semwal@linaro.org>
      Cc: Jason Wessel <jason.wessel@windriver.com>
      Signed-off-by: default avatarDaniel Thompson <daniel.thompson@linaro.org>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      8520dedb
    • Daniel Thompson's avatar
      tracing: kdb: Fix kernel panic during ftdump · c270cc75
      Daniel Thompson authored
      Currently kdb's ftdump command unconditionally crashes due to a null
      pointer de-reference whenever the command is run. This in turn causes
      the kernel to panic.
      
      The abridged stacktrace (gathered with ARCH=arm) is:
      
      --- cut here ---
      [<c09535ac>] (panic) from [<c02132dc>] (die+0x264/0x440)
      [<c02132dc>] (die) from [<c0952eb8>]
      (__do_kernel_fault.part.11+0x74/0x84)
      [<c0952eb8>] (__do_kernel_fault.part.11) from [<c021f954>]
      (do_page_fault+0x1d0/0x3c4)
      [<c021f954>] (do_page_fault) from [<c020846c>] (do_DataAbort+0x48/0xac)
      
      [<c020846c>] (do_DataAbort) from [<c0213c58>] (__dabt_svc+0x38/0x60)
      Exception stack(0xc0deba88 to 0xc0debad0)
      ba80:                   e8c29180 00000001 e9854304 e9854300 c0f567d8
      c0df2580
      baa0: 00000000 00000000 00000000 c0f117b8 c0e3a3c0 c0debb0c 00000000
      c0debad0
      bac0: 0000672e c02f4d60 60000193 ffffffff
      [<c0213c58>] (__dabt_svc) from [<c02f4d60>] (kdb_ftdump+0x1e4/0x3d8)
      [<c02f4d60>] (kdb_ftdump) from [<c02ce328>] (kdb_parse+0x2b8/0x698)
      [<c02ce328>] (kdb_parse) from [<c02ceef0>] (kdb_main_loop+0x52c/0x784)
      [<c02ceef0>] (kdb_main_loop) from [<c02d1b0c>] (kdb_stub+0x238/0x490)
      --- cut here ---
      
      The NULL deref occurs due to the initialized use of struct trace_iter's
      buffer_iter member.
      
      This is a regression, albeit a fairly elderly one. It was introduced
      by commit 6d158a81
      
       ("tracing: Remove NR_CPUS array from
      trace_iterator").
      
      This patch solves this by providing a collection of ring_buffer_iter(s)
      and using this to initialize buffer_iter. Note that static allocation
      is used solely because the trace_iter itself is also static allocated.
      Static allocation also means that we have to NULL-ify the pointer during
      cleanup to avoid use-after-free problems.
      
      Link: http://lkml.kernel.org/r/1415277716-19419-2-git-send-email-daniel.thompson@linaro.org
      
      Cc: Jason Wessel <jason.wessel@windriver.com>
      Signed-off-by: default avatarDaniel Thompson <daniel.thompson@linaro.org>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      c270cc75