1. 27 May, 2009 1 commit
    • Heiko Carstens's avatar
      trace: disable preemption before taking raw spinlocks · 5b6045a9
      Heiko Carstens authored
      
      
      s390 code uses smp_processor_id() in __raw_spin_lock() code which
      reveals that a (raw) spinlock is taken without preemption disabled.
      This can potentially deadlock.
      
      To fix this explicitly disable and enable preemption.
      
      BUG: using smp_processor_id() in preemptible [00000000] code: cat/2278
      caller is trace_find_cmdline+0x40/0xfc
      CPU: 0 Not tainted 2.6.30-rc7-dirty #39
      Process cat (pid: 2278, task: 000000003faedb68, ksp: 000000003b33b988)
      000000003b33b988 000000003b33bae0 0000000000000002 0000000000000000
             000000003b33bb80 000000003b33baf8 000000003b33baf8 00000000000175d6
             0000000000000001 000000003b33b988 000000003f9b0000 000000000000000b
             000000000000000c 000000003b33bb40 000000003b33bae0 0000000000000000
             0000000000000000 00000000000175d6 000000003b33bae0 000000003b33bb28
      Call Trace:
      ([<00000000000174b2>] show_trace+0x112/0x170)
       [<0000000000017582>] show_stack+0x72/0x100
       [<0000000000441538>] dump_stack+0xc8/0xd8
       [<000000000025c350>] debug_smp_processor_id+0x114/0x130
       [<00000000000bf0e4>] trace_find_cmdline+0x40/0xfc
       [<00000000000c35d4>] trace_print_context+0x58/0xac
       [<00000000000bb676>] print_trace_line+0x416/0x470
       [<00000000000bc8fe>] s_show+0x4e/0x428
       [<000000000013834e>] seq_read+0x36a/0x5d4
       [<0000000000112a78>] vfs_read+0xc8/0x174
       [<0000000000112c58>] SyS_read+0x74/0xc4
       [<000000000002c7ae>] sysc_noemu+0x10/0x16
       [<000002000012436c>] 0x2000012436c
      1 lock held by cat/2278:
       #0:  (&p->lock){+.+.+.}, at: [<0000000000138056>] seq_read+0x72/0x5d4
      
      [ Impact: fix preempt-unsafe raw spinlock ]
      
      Signed-off-by: default avatarHeiko Carstens <heiko.carstens@de.ibm.com>
      Acked-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      5b6045a9
  2. 25 May, 2009 1 commit
    • Lai Jiangshan's avatar
      tracing: add trace_event_read_lock() · 4f535968
      Lai Jiangshan authored
      
      
      I found that there is nothing to protect event_hash in
      ftrace_find_event(). Rcu protects the event hashlist
      but not the event itself while we use it after its extraction
      through ftrace_find_event().
      
      This lack of a proper locking in this spot opens a race
      window between any event dereferencing and module removal.
      
      Eg:
      
      --Task A--
      
      print_trace_line(trace) {
        event = find_ftrace_event(trace)
      
      --Task B--
      
      trace_module_remove_events(mod) {
        list_trace_events_module(ev, mod) {
          unregister_ftrace_event(ev->event) {
            hlist_del(ev->event->node)
              list_del(....)
          }
        }
      }
      |--> module removed, the event has been dropped
      
      --Task A--
      
        event->print(trace); // Dereferencing freed memory
      
      If the event retrieved belongs to a module and this module
      is concurrently removed, we may end up dereferencing a data
      from a freed module.
      
      RCU could solve this, but it would add latency to the kernel and
      forbid tracers output callbacks to call any sleepable code.
      So this fix converts 'trace_event_mutex' to a read/write semaphore,
      and adds trace_event_read_lock() to protect ftrace_find_event().
      
      [ Impact: fix possible freed memory dereference in ftrace ]
      
      Signed-off-by: default avatarLai Jiangshan <laijs@cn.fujitsu.com>
      Acked-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      LKML-Reference: <4A114806.7090302@cn.fujitsu.com>
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      4f535968
  3. 07 May, 2009 1 commit
    • Steven Rostedt's avatar
      tracing: reset ring buffer when removing modules with events · 9456f0fa
      Steven Rostedt authored
      
      
      Li Zefan found that there's a race using the event ids of events and
      modules. When a module is loaded, an event id is incremented. We only
      have 16 bits for event ids (65536) and there is a possible (but highly
      unlikely) race that we could load and unload a module that registers
      events so many times that the event id counter overflows.
      
      When it overflows, it then restarts and goes looking for available
      ids. An id is available if it was added by a module and released.
      
      The race is if you have one module add an id, and then is removed.
      Another module loaded can use that same event id. But if the old module
      still had events in the ring buffer, the new module's call back would
      get bogus data.  At best (and most likely) the output would just be
      garbage. But if the module for some reason used pointers (not recommended)
      then this could potentially crash.
      
      The safest thing to do is just reset the ring buffer if a module that
      registered events is removed.
      
      [ Impact: prevent unpredictable results of event id overflows ]
      
      Reported-by: default avatarLi Zefan <lizf@cn.fujitsu.com>
      LKML-Reference: <49FEAFD0.30106@cn.fujitsu.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      9456f0fa
  4. 05 May, 2009 2 commits
    • Steven Rostedt's avatar
      tracing: use proper export symbol for tracing api · 94487d6d
      Steven Rostedt authored
      
      
      When adding the EXPORT_SYMBOL to some of the tracing API, I accidently
      used EXPORT_SYMBOL instead of EXPORT_SYMBOL_GPL. This patch fixes
      that mistake.
      
      [ Impact: export the tracing code only for GPL modules ]
      
      Reported-by: default avatarChristoph Hellwig <hch@lst.de>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      94487d6d
    • Steven Rostedt's avatar
      tracing: export stats of ring buffers to userspace · c8d77183
      Steven Rostedt authored
      
      
      This patch adds stats to the ftrace ring buffers:
      
       # cat /debugfs/tracing/per_cpu/cpu0/stats
       entries: 42360
       overrun: 30509326
       commit overrun: 0
       nmi dropped: 0
      
      Where entries are the total number of data entries in the buffer.
      
      overrun is the number of entries not consumed and were overwritten by
      the writer.
      
      commit overrun is the number of entries dropped due to nested writers
      wrapping the buffer before the initial writer finished the commit.
      
      nmi dropped is the number of entries dropped due to the ring buffer
      lock being held when an nmi was going to write to the ring buffer.
      Note, this field will be meaningless and will go away when the ring
      buffer becomes lockless.
      
      [ Impact: let userspace know what is happening in the ring buffers ]
      
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      c8d77183
  5. 29 Apr, 2009 4 commits
    • Steven Rostedt's avatar
      tracing: fix ref count in splice pages · 7267fa68
      Steven Rostedt authored
      
      
      The pages allocated for the splice binary buffer did not initialize
      the ref count correctly. This caused pages not to be freed and causes
      a drastic memory leak.
      
      Thanks to logdev I was able to trace the tracer to find where the leak
      was.
      
      [ Impact: stop memory leak when using splice ]
      
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      7267fa68
    • Steven Rostedt's avatar
      tracing: have splice only copy full pages · f2957f1f
      Steven Rostedt authored
      
      
      Splice works with pages, it is much more effecient to use an entire
      page than to copy bits over several pages.
      
      Using logdev to trace the internals of the splice mechanism, I was
      able to see that splice can be very aggressive. When tracing is
      occurring, and the reader caught up to the writer, and the writer
      is on the reader page, the reader will copy what is there into the
      splice page. Splice may iterate over several pages and if the
      writer is still writing to the page, the reader will keep copying
      bits to new pages to pass to userspace.
      
      This patch changes it to only pass data to userspace if the page
      is full (the writer has left the page). This has a small side effect
      that splice can not read a partial page, and must wait for the
      page to fill. This should not be an issue. If tracing has stopped,
      then a use of "read" will still read all of the page.
      
      [ Impact: better performance for ring buffer splice code ]
      
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      f2957f1f
    • Steven Rostedt's avatar
      tracing: only add splice page if entries exist · 93459c6c
      Steven Rostedt authored
      
      
      The splice code allocates a page even when the ring buffer is empty.
      It detects the ring buffer being empty when it it fails to copy
      anything from the ring buffer into the page.
      
      This patch adds a check to see if there is anything in the ring buffer
      before allocating a page.
      
      Thanks to logdev for letting me trace the tracer to find this.
      
      [ Impact: speed up due to removing unnecessary allocation ]
      
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      93459c6c
    • Steven Rostedt's avatar
      tracing: fix ref count in splice pages · 5beae6ef
      Steven Rostedt authored
      
      
      The pages allocated for the splice binary buffer did not initialize
      the ref count correctly. This caused pages not to be freed and causes
      a drastic memory leak.
      
      Thanks to logdev I was able to trace the tracer to find where the leak
      was.
      
      [ Impact: stop memory leak when using splice ]
      
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      5beae6ef
  6. 28 Apr, 2009 1 commit
    • Steven Rostedt's avatar
      tracing: convert ftrace_dump spinlocks to raw · cd891ae0
      Steven Rostedt authored
      
      
      ftrace_dump is used for printing out the contents of the ftrace ring buffer
      to the console on failure. Currently it uses a spinlock to synchronize
      the output from multiple failures on different CPUs. This spin lock
      currently is a normal spinlock and can cause issues with lockdep and
      lock tracing.
      
      This patch converts it to raw since it is for error handling only.
      The lock is local to the ftrace_dump and is not used by any other
      infrastructure.
      
      [ Impact: prevent ftrace_dump from locking up by internal tracing ]
      
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      cd891ae0
  7. 22 Apr, 2009 1 commit
    • Li Zefan's avatar
      tracing/events: make struct trace_entry->type to be int type · 7a4f453b
      Li Zefan authored
      
      
      struct trace_entry->type is unsigned char, while trace event's id is
      int type, thus for a event with id >= 256, it's entry->type is cast
      to (id % 256), and then we can't see the trace output of this event.
      
       # insmod trace-events-sample.ko
       # echo foo_bar > /mnt/tracing/set_event
       # cat /debug/tracing/events/trace-events-sample/foo_bar/id
       256
       # cat /mnt/tracing/trace_pipe
                 <...>-3548  [001]   215.091142: Unknown type 0
                 <...>-3548  [001]   216.089207: Unknown type 0
                 <...>-3548  [001]   217.087271: Unknown type 0
                 <...>-3548  [001]   218.085332: Unknown type 0
      
      [ Impact: fix output for trace events with id >= 256 ]
      
      Signed-off-by: default avatarLi Zefan <lizf@cn.fujitsu.com>
      Acked-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Cc: Steven Rostedt <rostedt@goodmis.org>
      Cc: Tom Zanussi <tzanussi@gmail.com>
      LKML-Reference: <49EEDB0E.5070207@cn.fujitsu.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      7a4f453b
  8. 17 Apr, 2009 4 commits
  9. 14 Apr, 2009 1 commit
  10. 13 Apr, 2009 4 commits
    • Tom Zanussi's avatar
      tracing/filters: use ring_buffer_discard_commit() in filter_check_discard() · eb02ce01
      Tom Zanussi authored
      
      
      This patch changes filter_check_discard() to make use of the new
      ring_buffer_discard_commit() function and modifies the current users to
      call the old commit function in the non-discard case.
      
      It also introduces a version of filter_check_discard() that uses the
      global trace buffer (filter_current_check_discard()) for those cases.
      
      v2 changes:
      
      - fix compile error noticed by Ingo Molnar
      
      Signed-off-by: default avatarTom Zanussi <tzanussi@gmail.com>
      Cc: Steven Rostedt <rostedt@goodmis.org>
      Cc: fweisbec@gmail.com
      LKML-Reference: <1239178554.10295.36.camel@tropicana>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      eb02ce01
    • Steven Rostedt's avatar
      tracing/filters: use ring_buffer_discard_commit for discarded events · 77d9f465
      Steven Rostedt authored
      
      
      The ring_buffer_discard_commit makes better usage of the ring_buffer
      when an event has been discarded. It tries to remove it completely if
      possible.
      
      This patch converts the trace event filtering to use
      ring_buffer_discard_commit instead of the ring_buffer_event_discard.
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      77d9f465
    • Tom Zanussi's avatar
      tracing/filters: add TRACE_EVENT_FORMAT_NOFILTER event macro · e45f2e2b
      Tom Zanussi authored
      
      
      Frederic Weisbecker suggested that the trace_special event shouldn't be
      filterable; this patch adds a TRACE_EVENT_FORMAT_NOFILTER event macro
      that allows an event format to be exported without having a filter
      attached, and removes filtering from the trace_special event.
      
      Signed-off-by: default avatarTom Zanussi <tzanussi@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      e45f2e2b
    • Tom Zanussi's avatar
      tracing/filters: add run-time field descriptions to TRACE_EVENT_FORMAT events · e1112b4d
      Tom Zanussi authored
      
      
      This patch adds run-time field descriptions to all the event formats
      exported using TRACE_EVENT_FORMAT.  It also hooks up all the tracers
      that use them (i.e. the tracers in the 'ftrace subsystem') so they can
      also have their output filtered by the event-filtering mechanism.
      
      When I was testing this, there were a couple of things that fooled me
      into thinking the filters weren't working, when actually they were -
      I'll mention them here so others don't make the same mistakes (and file
      bug reports. ;-)
      
      One is that some of the tracers trace multiple events e.g. the
      sched_switch tracer uses the context_switch and wakeup events, and if
      you don't set filters on all of the traced events, the unfiltered output
      from the events without filters on them can make it look like the
      filtering as a whole isn't working properly, when actually it is doing
      what it was asked to do - it just wasn't asked to do the right thing.
      
      The other is that for the really high-volume tracers e.g. the function
      tracer, the volume of filtered events can be so high that it pushes the
      unfiltered events out of the ring buffer before they can be read so e.g.
      cat'ing the trace file repeatedly shows either no output, or once in
      awhile some output but that isn't there the next time you read the
      trace, which isn't what you normally expect when reading the trace file.
      If you read from the trace_pipe file though, you can catch them before
      they disappear.
      
      Changes from v1:
      
      As suggested by Frederic Weisbecker:
      
      - get rid of externs in functions
      - added unlikely() to filter_check_discard()
      
      Signed-off-by: default avatarTom Zanussi <tzanussi@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      e1112b4d
  11. 10 Apr, 2009 4 commits
    • Lai Jiangshan's avatar
      tracing: fix splice return too large · 93cfb3c9
      Lai Jiangshan authored
      
      
      I got these from strace:
      
       splice(0x3, 0, 0x5, 0, 0x1000, 0x1) = 12288
       splice(0x3, 0, 0x5, 0, 0x1000, 0x1) = 12288
       splice(0x3, 0, 0x5, 0, 0x1000, 0x1) = 12288
       splice(0x3, 0, 0x5, 0, 0x1000, 0x1) = 16384
       splice(0x3, 0, 0x5, 0, 0x1000, 0x1) = 8192
       splice(0x3, 0, 0x5, 0, 0x1000, 0x1) = 8192
       splice(0x3, 0, 0x5, 0, 0x1000, 0x1) = 8192
      
      I wanted to splice_read 4096 bytes, but it returns 8192 or larger.
      
      It is because the return value of tracing_buffers_splice_read()
      does not include "zero out any left over data" bytes.
      
      But tracing_buffers_read() includes these bytes, we make them
      consistent.
      
      Signed-off-by: default avatarLai Jiangshan <laijs@cn.fujitsu.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Steven Rostedt <srostedt@redhat.com>
      LKML-Reference: <49D46674.9030804@cn.fujitsu.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      93cfb3c9
    • Lai Jiangshan's avatar
      tracing: update file->f_pos when splice(2) it · c7625a55
      Lai Jiangshan authored
      
      
      Impact: Cleanup
      
      These two lines:
      
      	if (unlikely(*ppos))
      		return -ESPIPE;
      
      in tracing_buffers_splice_read() are not needed, VFS layer
      has disabled seek(2).
      
      We remove these two lines, and then we can update file->f_pos.
      
      And tracing_buffers_read() updates file->f_pos, this fix
      make tracing_buffers_splice_read() updates file->f_pos too.
      
      Signed-off-by: default avatarLai Jiangshan <laijs@cn.fujitsu.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Steven Rostedt <srostedt@redhat.com>
      LKML-Reference: <49D46670.4010503@cn.fujitsu.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      c7625a55
    • Lai Jiangshan's avatar
      tracing: allocate page when needed · ddd538f3
      Lai Jiangshan authored
      
      
      Impact: Cleanup
      
      Sometimes, we open trace_pipe_raw, but we don't read(2) it,
      we just splice(2) it, thus, the page is not used.
      
      Signed-off-by: default avatarLai Jiangshan <laijs@cn.fujitsu.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Steven Rostedt <srostedt@redhat.com>
      LKML-Reference: <49D4666B.4010608@cn.fujitsu.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      ddd538f3
    • Lai Jiangshan's avatar
      tracing: disable seeking for trace_pipe_raw · d1e7e02f
      Lai Jiangshan authored
      
      
      Impact: disable pread()
      
      We set tracing_buffers_fops.llseek to no_llseek,
      but we can still perform pread() to read this file.
      
      That is not expected.
      
      This fix uses nonseekable_open() to disable it.
      
      tracing_buffers_fops.llseek is still set to no_llseek,
      it mark this file is a "non-seekable device" and is used by
      sys_splice(). See also do_splice() or manual of splice(2):
      
      ERRORS
             EINVAL Target file system doesn't support  splicing;
                    neither  of the descriptors refers to a pipe;
                    or offset given for non-seekable device.
      
      Signed-off-by: default avatarLai Jiangshan <laijs@cn.fujitsu.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Steven Rostedt <srostedt@redhat.com>
      LKML-Reference: <49D46668.8030806@cn.fujitsu.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      d1e7e02f
  12. 07 Apr, 2009 5 commits
    • Frederic Weisbecker's avatar
      tracing/ftrace: factorize the tracing files creation · 5452af66
      Frederic Weisbecker authored
      
      
      Impact: cleanup
      
      Most of the tracing files creation follow the same pattern:
      
      ret = debugfs_create_file(...)
      if (!ret)
      	pr_warning("Couldn't create ... entry\n")
      
      Unify it!
      
      Reported-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      LKML-Reference: <1238109938-11840-1-git-send-email-fweisbec@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      5452af66
    • Nikanth Karthikesan's avatar
      Update /debug/tracing/README · bc2b6871
      Nikanth Karthikesan authored
      
      
      Some of the tracers have been renamed, which was not updated in the in-kernel
      run-time README file. Update it.
      
      Signed-off-by: default avatarNikanth Karthikesan <knikanth@suse.de>
      LKML-Reference: <200903231158.32151.knikanth@suse.de>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      bc2b6871
    • Frederic Weisbecker's avatar
      tracing/ftrace: alloc the started cpumask for the trace file · b0dfa978
      Frederic Weisbecker authored
      
      
      Impact: fix a crash while cat trace file
      
      Currently we are using a cpumask to remind each cpu where a
      trace occured. It lets us notice the user that a cpu just had
      its first trace.
      
      But on latest -tip we have the following crash once we cat the trace
      file:
      
      IP: [<c0270c4a>] print_trace_fmt+0x45/0xe7
      *pde = 00000000
      Oops: 0000 [#1] PREEMPT SMP
      last sysfs file: /sys/class/net/eth0/carrier
      Pid: 3897, comm: cat Not tainted (2.6.29-tip-02825-g0f22972-dirty #81)
      EIP: 0060:[<c0270c4a>] EFLAGS: 00010297 CPU: 0
      EIP is at print_trace_fmt+0x45/0xe7
      EAX: 00000000 EBX: 00000000 ECX: c12d9e98 EDX: ccdb7010
      ESI: d31f4000 EDI: 00322401 EBP: d31f3f10 ESP: d31f3efc
      DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
      Process cat (pid: 3897, ti=d31f2000 task=d3b3cf20 task.ti=d31f2000)
      Stack:
      d31f4080 ccdb7010 d31f4000 d691fe70 ccdb7010 d31f3f24 c0270e5c d31f4000
      d691fe70 d31f4000 d31f3f34 c02718e8 c12d9e98 d691fe70 d31f3f70 c02bfc33
      00001000 09130000 d3b46e00 d691fe98 00000000 00000079 00000001 00000000
      Call Trace:
      [<c0270e5c>] ? print_trace_line+0x170/0x17c
      [<c02718e8>] ? s_show+0xa7/0xbd
      [<c02bfc33>] ? seq_read+0x24a/0x327
      [<c02bf9e9>] ? seq_read+0x0/0x327
      [<c02ab18b>] ? vfs_read+0x86/0xe1
      [<c02ab289>] ? sys_read+0x40/0x65
      [<c0202d8f>] ? sysenter_do_call+0x12/0x3c
      Code: 00 00 00 89 45 ec f7 c7 00 20 00 00 89 55 f0 74 4e f6 86 98 10 00 00 02 74 45 8b 86 8c 10 00 00 8b 9e a8 10 00 00 e8 52 f3 ff ff <0f> a3 03 19 c0 85 c0 75 2b 8b 86 8c 10 00 00 8b 9e a8 10 00 00
      EIP: [<c0270c4a>] print_trace_fmt+0x45/0xe7 SS:ESP 0068:d31f3efc
      CR2: 0000000000000000
      ---[ end trace aa9cf38e5ebed9dd ]---
      
      This is because we alloc the iter->started cpumask on tracing_pipe_open but
      not on tracing_open.
      
      It hadn't been noticed until now because we need to have ring buffer overruns
      to activate the starting of cpu buffer detection.
      
      Also, we need a check to not print the messagge for the first trace on the file.
      
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      LKML-Reference: <1238619188-6109-1-git-send-email-fweisbec@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      b0dfa978
    • Frederic Weisbecker's avatar
      tracing/ftrace: fix missing include string.h · 5f0c6c03
      Frederic Weisbecker authored
      
      
      Building a kernel with tracing can raise the following warning on
      tip/master:
      
      kernel/trace/trace.c:1249: error: implicit declaration of function 'vbin_printf'
      
      We are missing an include to string.h
      
      Reported-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      LKML-Reference: <1238160130-7437-1-git-send-email-fweisbec@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      5f0c6c03
    • Lai Jiangshan's avatar
      tracing: fix incorrect return type of ns2usecs() · cf8e3474
      Lai Jiangshan authored
      
      
      Impact: fix time output bug in 32bits system
      
      ns2usecs() returns 'long', it's incorrect.
      
      (In i386)
      ...
                <idle>-0     [000]   521.442100: _spin_lock <-tick_do_update_jiffies64
                <idle>-0     [000]   521.442101: do_timer <-tick_do_update_jiffies64
                <idle>-0     [000]   521.442102: update_wall_time <-do_timer
                <idle>-0     [000]   521.442102: update_xtime_cache <-update_wall_time
      ....
      (It always print the time less than 2200 seconds besides ...)
      Because 'long' is 32bits in i386. ( (1<<31) useconds is about 2200 seconds)
      
      ...
                <idle>-0     [001] 4154502640.134759: rcu_bh_qsctr_inc <-__do_softirq
                <idle>-0     [001] 4154502640.134760: _local_bh_enable <-__do_softirq
                <idle>-0     [001] 4154502640.134761: idle_cpu <-irq_exit
      ...
      (very large value)
      Because 'long' is a signed type and it is 32bits in i386.
      
      Changes in v2:
      return 'unsigned long long' instead of 'cycle_t'
      
      Signed-off-by: default avatarLai Jiangshan <laijs@cn.fujitsu.com>
      LKML-Reference: <49D05D10.4030009@cn.fujitsu.com>
      Reported-by: default avatarLi Zefan <lizf@cn.fujitsu.com>
      Acked-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      cf8e3474
  13. 25 Mar, 2009 2 commits
    • Steven Rostedt's avatar
      function-graph: add option to calculate graph time or not · a2a16d6a
      Steven Rostedt authored
      
      
      graph time is the time that a function is executing another function.
      Thus if function A calls B, if graph-time is set, then the time for
      A includes B. This is the default behavior. But if graph-time is off,
      then the time spent executing B is subtracted from A.
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      a2a16d6a
    • Steven Rostedt's avatar
      tracing: adding function timings to function profiler · 0706f1c4
      Steven Rostedt authored
      
      
      If the function graph trace is enabled, the function profiler will
      use it to take the timing of the functions.
      
       cat /debug/tracing/trace_stat/functions
      
        Function                               Hit    Time
        --------                               ---    ----
        mwait_idle                             127    183028.4 us
        schedule                                26    151997.7 us
        __schedule                              31    151975.1 us
        sys_wait4                                2    74080.53 us
        do_wait                                  2    74077.80 us
        sys_newlstat                           138    39929.16 us
        do_path_lookup                         179    39845.79 us
        vfs_lstat_fd                           138    39761.97 us
        user_path_at                           153    39469.58 us
        path_walk                              179    39435.76 us
        __link_path_walk                       189    39143.73 us
      [...]
      
      Note the times are skewed due to the function graph tracer not taking
      into account schedules.
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      0706f1c4
  14. 24 Mar, 2009 1 commit
    • Steven Rostedt's avatar
      function-graph: add option for include sleep times · be6f164a
      Steven Rostedt authored
      
      
      Impact: give user a choice to show times spent while sleeping
      
      The user may want to see the time a function spent sleeping.
      This patch adds the trace option "sleep-time" to allow that.
      The "sleep-time" option is default on.
      
       echo sleep-time > /debug/tracing/trace_options
      
      produces:
      
       ------------------------------------------
       2)  avahi-d-3428  =>    <idle>-0
       ------------------------------------------
      
       2)               |      finish_task_switch() {
       2)   0.621 us    |        _spin_unlock_irq();
       2)   2.202 us    |      }
       2) ! 1002.197 us |    }
       2) ! 1003.521 us |  }
      
      where as,
      
       echo nosleep-time > /debug/tracing/trace_options
      
      produces:
      
       0)    <idle>-0    =>  yum-upd-3416
       ------------------------------------------
      
       0)               |              finish_task_switch() {
       0)   0.643 us    |                _spin_unlock_irq();
       0)   2.342 us    |              }
       0) + 41.302 us   |            }
       0) + 42.453 us   |          }
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      be6f164a
  15. 23 Mar, 2009 3 commits
    • Frederic Weisbecker's avatar
      tracing/function-graph-tracer: fix functions call traces imbalance · 16185369
      Frederic Weisbecker authored
      
      
      Impact: fix traces output
      
      Sometimes one can observe an imbalance in the traces between function
      calls and function return traces:
      
      func1() {
          }
      }
      
      The curly brace inside func1() is the return of another function nested
      inside func1. The return trace have been inserted in the buffer but not
      the entry.
      We are storing a return address on the function traces stack while we
      haven't inserted its entry on the buffer, hence the imbalance on the
      traces.
      
      This is because the tracers doesn't check all failures that can happen
      on buffer insertion.
      
      This patch reports the tracing recursion failures and the ring buffer
      failures. In such cases, we now restore the original return address for
      the function, giving up its return trace.
      
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Cc: Steven Rostedt <rostedt@goodmis.org>
      LKML-Reference: <1237843021-11695-1-git-send-email-fweisbec@gmail.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      16185369
    • Frederic Weisbecker's avatar
      tracing/ftrace: check if debugfs is registered before creating files · 3e1f60b8
      Frederic Weisbecker authored
      
      
      Impact: fix a crash with ftrace={nop,boot} parameter
      
      If the nop or initcall tracers are launched as boot tracers,
      they will attempt to create their option directory and files.
      But these tracers are registered very early and then assigned
      as "boot tracers" very early if asked to.
      
      Since they do this before debugfs has been registered (core initcall),
      a crash is triggered.
      
      Another early tracers could also come later. So we fix it by
      checking if debugfs is initialized before creating the root
      tracing directory.
      
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Cc: Greg Kroah-Hartman <gregkh@suse.de>
      Cc: Steven Rostedt <rostedt@goodmis.org>
      LKML-Reference: <1237759847-21025-3-git-send-email-fweisbec@gmail.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      3e1f60b8
    • Frederic Weisbecker's avatar
      tracing/events: don't use wake up for events · 07edf712
      Frederic Weisbecker authored
      
      
      Impact: fix hard-lockup with sched switch events
      
      Some ftrace events, such as sched wakeup, can be traced
      while the runqueue lock is hold. Since they are using
      trace_current_buffer_unlock_commit(), they call wake_up()
      which can try to grab the runqueue lock too, resulting in
      a deadlock.
      
      Now for all event, we call a new helper:
      trace_nowake_buffer_unlock_commit() which do pretty the same than
      trace_current_buffer_unlock_commit() except than it doesn't call
      trace_wake_up().
      
      Reported-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Cc: Steven Rostedt <rostedt@goodmis.org>
      LKML-Reference: <1237759847-21025-4-git-send-email-fweisbec@gmail.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      07edf712
  16. 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
  17. 19 Mar, 2009 2 commits
  18. 18 Mar, 2009 1 commit