1. 22 Mar, 2009 2 commits
    • Dmitri Vorobiev's avatar
      tracing: fix four sparse warnings · b8b94265
      Dmitri Vorobiev authored
      
      
      Impact: cleanup.
      
      This patch fixes the following sparse warnings:
      
       kernel/trace/trace.c:385:9: warning: symbol 'trace_seq_to_buffer' was
       not declared. Should it be static?
      
       kernel/trace/trace_clock.c:29:13: warning: symbol 'trace_clock_local'
       was not declared. Should it be static?
      
       kernel/trace/trace_clock.c:54:13: warning: symbol 'trace_clock' was not
       declared. Should it be static?
      
       kernel/trace/trace_clock.c:74:13: warning: symbol 'trace_clock_global'
       was not declared. Should it be static?
      
      Signed-off-by: default avatarDmitri Vorobiev <dmitri.vorobiev@movial.com>
      LKML-Reference: <1237741871-5827-4-git-send-email-dmitri.vorobiev@movial.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      b8b94265
    • Frederic Weisbecker's avatar
      tracing/function-graph-tracer: prevent hangs during self-tests · cf586b61
      Frederic Weisbecker authored
      
      
      Impact: detect tracing related hangs
      
      Sometimes, with some configs, the function graph tracer can make
      the timer interrupt too much slow, hanging the kernel in an endless
      loop of timer interrupts servicing.
      
      As suggested by Ingo, this patch brings a watchdog which stops the
      selftest after a defined number of functions traced, definitely
      disabling this tracer.
      
      For those who want to debug the cause of the function graph trace
      hang, you can pass the ftrace_dump_on_oops kernel parameter to dump
      the traces after this hang detection.
      
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Cc: Steven Rostedt <rostedt@goodmis.org>
      LKML-Reference: <1237694675-23509-1-git-send-email-fweisbec@gmail.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      cf586b61
  2. 19 Mar, 2009 2 commits
  3. 18 Mar, 2009 7 commits
  4. 17 Mar, 2009 2 commits
    • Steven Rostedt's avatar
      tracing: stop comm recording on tracing off · 6adaad14
      Steven Rostedt authored
      
      
      Impact: fix for losing comms in trace
      
      The command lines of tasks are cached at sched switch to not need
      to record them at every trace point.  Disabling the tracing on stops
      the recording of traces, but does not stop the caching of command lines.
      When the tracing is off the cache may overflow and cause the tracing
      to show incorrect tasks matching the PIDs.
      
      This patch disables prevents updates to the comm cache when the ring buffer
      is off.
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      6adaad14
    • Steven Rostedt's avatar
      tracing: protect reader of cmdline output · 4ca53085
      Steven Rostedt authored
      
      
      Impact: fix to one cause of incorrect comm outputs in trace
      
      The spinlock only protected the creation of a comm <=> pid pair.
      But it was possible that a reader could look up a pid, and get the
      wrong comm because it had no locking.
      
      This also required changing trace_find_cmdline to copy the comm cache
      and not just send back a pointer to it.
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      4ca53085
  5. 16 Mar, 2009 2 commits
  6. 13 Mar, 2009 5 commits
    • Steven Rostedt's avatar
      tracing: move binary buffers into per cpu directory · 7f96f93f
      Steven Rostedt authored
      
      
      The binary_buffers directory in /debugfs/tracing held the files
      to read the trace buffers in a binary format. This held one file
      per CPU buffer. But we also have a per_cpu directory that holds
      a way to read the pretty-print formats.
      
      This patch moves the binary buffers into the per_cpu_directory:
      
       # ls /debug/tracing/per_cpu/cpu1/
      trace  trace_pipe  trace_pipe_raw
      
      The new name is called "trace_pipe_raw". The binary buffers always
      acted similar to trace_pipe, except that they produce raw data.
      
      Requested-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      7f96f93f
    • Frederic Weisbecker's avatar
      tracing/core: bring back raw trace_printk for dynamic formats strings · 48ead020
      Frederic Weisbecker authored
      
      
      Impact: fix callsites with dynamic format strings
      
      Since its new binary implementation, trace_printk() internally uses static
      containers for the format strings on each callsites. But the value is
      assigned once at build time, which means that it can't take dynamic
      formats.
      
      So this patch unearthes the raw trace_printk implementation for the callers
      that will need trace_printk to be able to carry these dynamic format
      strings. The trace_printk() macro will use the appropriate implementation
      for each callsite. Most of the time however, the binary implementation will
      still be used.
      
      The other impact of this patch is that mmiotrace_printk() will use the old
      implementation because it calls the low level trace_vprintk and we can't
      guess here whether the format passed in it is dynamic or not.
      
      Some parts of this patch have been written by Steven Rostedt (most notably
      the part that chooses the appropriate implementation for each callsites).
      
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      48ead020
    • Steven Rostedt's avatar
      tracing: show that buffer size is not expanded · db526ca3
      Steven Rostedt authored
      
      
      Impact: do not confuse user on small trace buffer sizes
      
      When the system boots up, the trace buffer is small to conserve memory.
      It is only two pages per online CPU. When the tracer is used, it expands
      to the default value.
      
      This can confuse the user if they look at the buffer size and see only
      7, but then later they see 1408.
      
       # cat /debug/tracing/buffer_size_kb
      7
      
       # echo sched_switch > /debug/tracing/current_tracer
      
       # cat /debug/tracing/buffer_size_kb
      1408
      
      This patch tries to help remove this confustion by showing that the
      buffer has not been expanded.
      
       # cat /debug/tracing/buffer_size_kb
      7 (expanded: 1408)
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      db526ca3
    • Steven Rostedt's avatar
      tracing: protect ring_buffer_expanded with trace_types_lock · 1027fcb2
      Steven Rostedt authored
      
      
      Impact: prevent races with ring_buffer_expanded
      
      This patch places the expanding of the tracing buffer under the
      protection of the trace_types_lock mutex. It is highly unlikely
      that there would be any contention, but better safe than sorry.
      
      Reported-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      1027fcb2
    • Steven Rostedt's avatar
      tracing: fix comments about trace buffer resizing · a123c52b
      Steven Rostedt authored
      
      
      Impact: cleanup
      
      Some of the comments about the trace buffer resizing is gobbledygook.
      And I wonder why people question if I'm a native English speaker.
      
      This patch makes the comments make a bit more sense.
      
      Reported-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      a123c52b
  7. 12 Mar, 2009 4 commits
    • Steven Rostedt's avatar
      ring-buffer: only allocate buffers for online cpus · 554f786e
      Steven Rostedt authored
      
      
      Impact: save on memory
      
      Currently, a ring buffer was allocated for each "possible_cpus". On
      some systems, this is the same as NR_CPUS. Thus, if a system defined
      NR_CPUS = 64 but it only had 1 CPU, we could have possibly 63 useless
      ring buffers taking up space. With a default buffer of 3 megs, this
      could be quite drastic.
      
      This patch changes the ring buffer code to only allocate ring buffers
      for online CPUs.  If a CPU goes off line, we do not free the buffer.
      This is because the user may still have trace data in that buffer
      that they would like to look at.
      
      Perhaps in the future we could add code to delete a ring buffer if
      the CPU is offline and the ring buffer becomes empty.
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      554f786e
    • Steven Rostedt's avatar
      tracing: fix trace_wait to know to wait on all cpus or just one · 9aba60fe
      Steven Rostedt authored
      
      
      Impact: fix to task live locking on reading trace_pipe on one CPU
      
      The same code is used for both trace_pipe (all CPUS) and the per_cpu
      trace_pipe file. When there is no data to read, it will check for
      signals and wait on the trace wait queue.
      
      The problem happens with the per_cpu wait. The trace_wait code checks
      all CPUs. Thus, if there's data in another CPU buffer, then it will
      exit the wait, without checking for signals or waiting on the wait queue.
      
      It would then try to read the empty buffer, and since that will just
      return nothing, then it will try to wait again. Unfortunately, that will
      again fail due to there still being data in the other buffers. This
      ends up with a live lock for the task.
      
      This patch fixes the trace_wait to be aware that the iterator may only
      be waiting on a single buffer.
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      9aba60fe
    • Steven Rostedt's avatar
      tracing: expand the ring buffers when an event is activated · 1852fcce
      Steven Rostedt authored
      
      
      To save memory, the tracer ring buffers are set to a minimum.
      The activating of a trace expands the ring buffer size. This patch
      adds this expanding, when an event is activated.
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      1852fcce
    • Steven Rostedt's avatar
      tracing: keep ring buffer to minimum size till used · 73c5162a
      Steven Rostedt authored
      
      
      Impact: less memory impact on systems not using tracer
      
      When the kernel boots up that has tracing configured, it allocates
      the default size of the ring buffer. This currently happens to be
      1.4Megs per possible CPU. This is quite a bit of wasted memory if
      the system is never using the tracer.
      
      The current solution is to keep the ring buffers to a minimum size
      until the user uses them. Once a tracer is piped into the current_tracer
      the ring buffer will be expanded to the default size. If the user
      changes the size of the ring buffer, it will take the size given
      by the user immediately.
      
      If the user adds a "ftrace=" to the kernel command line, then the ring
      buffers will be set to the default size on initialization.
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      73c5162a
  8. 10 Mar, 2009 2 commits
  9. 08 Mar, 2009 1 commit
    • KOSAKI Motohiro's avatar
      ftrace: tracing header should put '#' at the beginning of a line · 888b55dc
      KOSAKI Motohiro authored
      
      
      In a recent discussion, Andrew Morton pointed out that tracing header
      should put '#' at the beginning of a line.
      
      Then, we can easily filtered the header by following grep usage:
      
        cat trace | grep -v '^#'
      
      Wakeup trace also has the same header problem.
      
      Comparison of headers displayed:
      
      before this patch:
      
       # tracer: wakeup
       #
       wakeup latency trace v1.1.5 on 2.6.29-rc7-tip-tip
       --------------------------------------------------------------------
        latency: 19059 us, #21277/21277, CPU#1 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:4)
           -----------------
           | task: kondemand/1-1644 (uid:0 nice:-5 policy:0 rt_prio:0)
           -----------------
      
       #                  _------=> CPU#
       #                 / _-----=> irqs-off
       #                | / _----=> need-resched
       #                || / _---=> hardirq/softirq
       #                ||| / _--=> preempt-depth
       #                |||| /
       #                |||||     delay
       #  cmd     pid   ||||| time  |   caller
       #     \   /      |||||   \   |   /
       irqbalan-1887    1d.s.    0us :   1887:120:R   + [001]  1644:115:S kondemand/1
       irqbalan-1887    1d.s.    1us : default_wake_function <-autoremove_wake_function
       irqbalan-1887    1d.s.    2us : check_preempt_wakeup <-try_to_wake_up
      
      after this patch:
      
       # tracer: wakeup
       #
       # wakeup latency trace v1.1.5 on 2.6.29-rc7-tip-tip
       # --------------------------------------------------------------------
       # latency: 529 us, #530/530, CPU#0 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:4)
       #    -----------------
       #    | task: kondemand/0-1641 (uid:0 nice:-5 policy:0 rt_prio:0)
       #    -----------------
       #
       #                  _------=> CPU#
       #                 / _-----=> irqs-off
       #                | / _----=> need-resched
       #                || / _---=> hardirq/softirq
       #                ||| / _--=> preempt-depth
       #                |||| /
       #                |||||     delay
       #  cmd     pid   ||||| time  |   caller
       #     \   /      |||||   \   |   /
           sshd-2496    0d.s.    0us :   2496:120:R   + [000]  1641:115:S kondemand/0
           sshd-2496    0d.s.    1us : default_wake_function <-autoremove_wake_function
           sshd-2496    0d.s.    1us : check_preempt_wakeup <-try_to_wake_up
      
      Signed-off-by: default avatarKOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>
      Cc: Andrew Morton <akpm@linux-foundation.org>
      LKML-Reference: <20090308124421.23C3.A69D9226@jp.fujitsu.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      888b55dc
  10. 06 Mar, 2009 4 commits
    • Frederic Weisbecker's avatar
      tracing/core: drop the old trace_printk() implementation in favour of trace_bprintk() · 769b0441
      Frederic Weisbecker authored
      
      
      Impact: faster and lighter tracing
      
      Now that we have trace_bprintk() which is faster and consume lesser
      memory than trace_printk() and has the same purpose, we can now drop
      the old implementation in favour of the binary one from trace_bprintk(),
      which means we move all the implementation of trace_bprintk() to
      trace_printk(), so the Api doesn't change except that we must now use
      trace_seq_bprintk() to print the TRACE_PRINT entries.
      
      Some changes result of this:
      
      - Previously, trace_bprintk depended of a single tracer and couldn't
        work without. This tracer has been dropped and the whole implementation
        of trace_printk() (like the module formats management) is now integrated
        in the tracing core (comes with CONFIG_TRACING), though we keep the file
        trace_printk (previously trace_bprintk.c) where we can find the module
        management. Thus we don't overflow trace.c
      
      - changes some parts to use trace_seq_bprintk() to print TRACE_PRINT entries.
      
      - change a bit trace_printk/trace_vprintk macros to support non-builtin formats
        constants, and fix 'const' qualifiers warnings. But this is all transparent for
        developers.
      
      - etc...
      
      V2:
      
      - Rebase against last changes
      - Fix mispell on the changelog
      
      V3:
      
      - Rebase against last changes (moving trace_printk() to kernel.h)
      
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Acked-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      LKML-Reference: <1236356510-8381-5-git-send-email-fweisbec@gmail.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      769b0441
    • Lai Jiangshan's avatar
      tracing: add trace_bprintk() · 1ba28e02
      Lai Jiangshan authored
      
      
      Impact: add a generic printk() for tracing, like trace_printk()
      
      trace_bprintk() uses the infrastructure to record events on ring_buffer.
      
      [ fweisbec@gmail.com: ported to latest -tip, made it work if
        !CONFIG_MODULES, never free the format strings from modules
        because we can't keep track of them and conditionnaly create
        the ftrace format strings section (reported by Steven Rostedt) ]
      
      Signed-off-by: default avatarLai Jiangshan <laijs@cn.fujitsu.com>
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Acked-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      LKML-Reference: <1236356510-8381-4-git-send-email-fweisbec@gmail.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      1ba28e02
    • Lai Jiangshan's avatar
      tracing: infrastructure for supporting binary record · 1427cdf0
      Lai Jiangshan authored
      
      
      Impact: save on memory for tracing
      
      Current tracers are typically using a struct(like struct ftrace_entry,
      struct ctx_switch_entry, struct special_entr etc...)to record a binary
      event. These structs can only record a their own kind of events.
      A new kind of tracer need a new struct and a lot of code too handle it.
      
      So we need a generic binary record for events. This infrastructure
      is for this purpose.
      
      [fweisbec@gmail.com: rebase against latest -tip, make it safe while sched
      tracing as reported by Steven Rostedt]
      
      Signed-off-by: default avatarLai Jiangshan <laijs@cn.fujitsu.com>
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Acked-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      LKML-Reference: <1236356510-8381-3-git-send-email-fweisbec@gmail.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      1427cdf0
    • Steven Rostedt's avatar
      tracing: make all file_operations const · 5e2336a0
      Steven Rostedt authored
      
      
      Impact: cleanup
      
      All file_operations structures should be constant. No one is going to
      change them.
      
      Reported-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      5e2336a0
  11. 05 Mar, 2009 6 commits
  12. 04 Mar, 2009 3 commits
    • Steven Rostedt's avatar
      tracing: add cpu_file intialization for ftrace_dump · e543ad76
      Steven Rostedt authored
      Impact: fix to ftrace_dump output corruption
      
      The commit: b04cc6b1
      
      
        tracing/core: introduce per cpu tracing files
      
      added a new field to the iterator called cpu_file. This was a handle
      to differentiate between the per cpu trace output files and the
      all cpu "trace" file. The all cpu "trace" file required setting this
      to TRACE_PIPE_ALL_CPU.
      
      The problem is that the ftrace_dump sets up its own iterator but was
      not updated to handle this change. The result was only CPU 0 printing
      out on crash and a lot of "<0>"'s also being printed.
      
      Reported-by: default avatarThomas Gleixner <tglx@linuxtronix.de>
      Tested-by: default avatarDarren Hart <dvhtc@us.ibm.com>
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      e543ad76
    • Peter Zijlstra's avatar
      tracing: add lockdep tracepoints for lock acquire/release · efed792d
      Peter Zijlstra authored
      
      
      Augment the traces with lock names when lockdep is available:
      
       1)               |  down_read_trylock() {
       1)               |    _spin_lock_irqsave() {
       1)               |      /* lock_acquire: &sem->wait_lock */
       1)   4.201 us    |    }
       1)               |    _spin_unlock_irqrestore() {
       1)               |      /* lock_release: &sem->wait_lock */
       1)   3.523 us    |    }
       1)               |  /* lock_acquire: try read &mm->mmap_sem */
       1) + 13.386 us   |  }
       1)   1.635 us    |  find_vma();
       1)               |  handle_mm_fault() {
       1)               |    __do_fault() {
       1)               |      filemap_fault() {
       1)               |        find_lock_page() {
       1)               |          find_get_page() {
       1)               |            /* lock_acquire: read rcu_read_lock */
       1)               |            /* lock_release: rcu_read_lock */
       1)   5.697 us    |          }
       1)   8.158 us    |        }
       1) + 11.079 us   |      }
       1)               |      _spin_lock() {
       1)               |        /* lock_acquire: __pte_lockptr(page) */
       1)   3.949 us    |      }
       1)   1.460 us    |      page_add_file_rmap();
       1)               |      _spin_unlock() {
       1)               |        /* lock_release: __pte_lockptr(page) */
       1)   3.115 us    |      }
       1)               |      unlock_page() {
       1)   1.421 us    |        page_waitqueue();
       1)   1.220 us    |        __wake_up_bit();
       1)   6.519 us    |      }
       1) + 34.328 us   |    }
       1) + 37.452 us   |  }
       1)               |  up_read() {
       1)               |  /* lock_release: &mm->mmap_sem */
       1)               |    _spin_lock_irqsave() {
       1)               |      /* lock_acquire: &sem->wait_lock */
       1)   3.865 us    |    }
       1)               |    _spin_unlock_irqrestore() {
       1)               |      /* lock_release: &sem->wait_lock */
       1)   8.562 us    |    }
       1) + 17.370 us   |  }
      
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Steven Rostedt <rostedt@goodmis.org>
      Cc: =?ISO-8859-1?Q?T=F6r=F6k?= Edwin <edwintorok@gmail.com>
      Cc: Jason Baron <jbaron@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      LKML-Reference: <1236166375.5330.7209.camel@laptop>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      efed792d
    • Steven Rostedt's avatar
      tracing: add binary buffer files for use with splice · 2cadf913
      Steven Rostedt authored
      
      
      Impact: new feature
      
      This patch creates a directory of files that correspond to the
      per CPU ring buffers. These are binary files and are made to
      be used with splice. This is the fastest way to extract data from
      the ftrace ring buffers.
      
      Thanks to Jiaying Zhang for pushing me to get this code fixed,
       and to Eduard - Gabriel Munteanu for his splice code that helped
       me debug my code.
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      2cadf913