linux-toradex.git/kernel/trace, branch tegra

ftrace: Fix unregister ftrace_ops accounting

2012-02-10T02:20:25+00:00

commit 30fb6aa74011dcf595f306ca2727254d708b786e upstream.

Multiple users of the function tracer can register their functions
with the ftrace_ops structure. The accounting within ftrace will
update the counter on each function record that is being traced.
When the ftrace_ops filtering adds or removes functions, the
function records will be updated accordingly if the ftrace_ops is
still registered.

When a ftrace_ops is removed, the counter of the function records,
that the ftrace_ops traces, are decremented. When they reach zero
the functions that they represent are modified to stop calling the
mcount code.

When changes are made, the code is updated via stop_machine() with
a command passed to the function to tell it what to do. There is an
ENABLE and DISABLE command that tells the called function to enable
or disable the functions. But the ENABLE is really a misnomer as it
should just update the records, as records that have been enabled
and now have a count of zero should be disabled.

The DISABLE command is used to disable all functions regardless of
their counter values. This is the big off switch and is not the
complement of the ENABLE command.

To make matters worse, when a ftrace_ops is unregistered and there
is another ftrace_ops registered, neither the DISABLE nor the
ENABLE command are set when calling into the stop_machine() function
and the records will not be updated to match their counter. A command
is passed to that function that will update the mcount code to call
the registered callback directly if it is the only one left. This
means that the ftrace_ops that is still registered will have its callback
called by all functions that have been set for it as well as the ftrace_ops
that was just unregistered.

Here's a way to trigger this bug. Compile the kernel with
CONFIG_FUNCTION_PROFILER set and with CONFIG_FUNCTION_GRAPH not set:

 CONFIG_FUNCTION_PROFILER=y
 # CONFIG_FUNCTION_GRAPH is not set

This will force the function profiler to use the function tracer instead
of the function graph tracer.

  # cd /sys/kernel/debug/tracing
  # echo schedule > set_ftrace_filter
  # echo function > current_tracer
  # cat set_ftrace_filter
 schedule
  # cat trace
 # tracer: nop
 #
 # entries-in-buffer/entries-written: 692/68108025   #P:4
 #
 #                              _-----=> irqs-off
 #                             / _----=> need-resched
 #                            | / _---=> hardirq/softirq
 #                            || / _--=> preempt-depth
 #                            ||| /     delay
 #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
 #              | |       |   ||||       |         |
      kworker/0:2-909   [000] ....   531.235574: schedule <-worker_thread
           -0     [001] .N..   531.235575: schedule <-cpu_idle
      kworker/0:2-909   [000] ....   531.235597: schedule <-worker_thread
             sshd-2563  [001] ....   531.235647: schedule <-schedule_hrtimeout_range_clock

  # echo 1 > function_profile_enabled
  # echo 0 > function_porfile_enabled
  # cat set_ftrace_filter
 schedule
  # cat trace
 # tracer: function
 #
 # entries-in-buffer/entries-written: 159701/118821262   #P:4
 #
 #                              _-----=> irqs-off
 #                             / _----=> need-resched
 #                            | / _---=> hardirq/softirq
 #                            || / _--=> preempt-depth
 #                            ||| /     delay
 #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
 #              | |       |   ||||       |         |
           -0     [002] ...1   604.870655: local_touch_nmi <-cpu_idle
           -0     [002] d..1   604.870655: enter_idle <-cpu_idle
           -0     [002] d..1   604.870656: atomic_notifier_call_chain <-enter_idle
           -0     [002] d..1   604.870656: __atomic_notifier_call_chain <-atomic_notifier_call_chain

The same problem could have happened with the trace_probe_ops,
but they are modified with the set_frace_filter file which does the
update at closure of the file.

The simple solution is to change ENABLE to UPDATE and call it every
time an ftrace_ops is unregistered.

Link: http://lkml.kernel.org/r/1323105776-26961-3-git-send-email-jolsa@redhat.com

Change-Id: Ifdc1c97df0d069226d6818648aade1519106950d
Signed-off-by: Jiri Olsa 
Signed-off-by: Steven Rostedt 
Signed-off-by: Greg Kroah-Hartman 
Signed-off-by: Varun Wadekar 
Reviewed-on: http://git-master/r/79658

tracedump: Fix build error

2012-02-03T13:24:06+00:00

Change-Id: Ica22a3f92c8ca33a5779a74d3afad775736b1663
Signed-off-by: Prashant Gaikwad 
Reviewed-on: http://git-master/r/78450
Reviewed-by: Automatic_Commit_Validation_User
Reviewed-by: Bharat Nihalani 
Reviewed-by: Varun Wadekar

tracedump: Dump ftrace ring buffer data

2011-12-22T05:59:19+00:00

Add a new module that will dump the contents of the ftrace ring buffer.
Data is compressed and can be in ascii or binary form. Data will
automatically dump on kernel panic to console. Data can be dumped by
reading /proc/tracedump. See tracedump.h for details.

Change-Id: I7b7afc3def0b88629dd120d17e43858306a8f357
Signed-off-by: Liang Cheng 
Reviewed-on: http://git-master/r/69494
Reviewed-by: Automatic_Commit_Validation_User
Reviewed-by: Dan Willemsen

Merge branch 'linux-3.1.5' into android-tegra-nv-3.1

2011-12-14T10:03:34+00:00

Conflicts:
	arch/arm/Kconfig

Change-Id: If8aaaf3efcbbf6c9017b38efb6d76ef933f147fa
Signed-off-by: Varun Wadekar

tracing: fix event_subsystem ref counting

2011-12-09T16:55:52+00:00

commit cb59974742aea24adf6637eb0c4b8e7b48bca6fb upstream.

Fix a bug introduced by e9dbfae5, which prevents event_subsystem from
ever being released.

Ref_count was added to keep track of subsystem users, not for counting
events.  Subsystem is created with ref_count = 1, so there is no need to
increment it for every event, we have nr_events for that.  Fix this by
touching ref_count only when we actually have a new user -
subsystem_open().

Signed-off-by: Ilya Dryomov 
Link: http://lkml.kernel.org/r/1320052062-7846-1-git-send-email-idryomov@gmail.com
Signed-off-by: Steven Rostedt 
Signed-off-by: Greg Kroah-Hartman

trace_events_filter: Use rcu_assign_pointer() when setting ftrace_event_call->filter

2011-12-09T16:55:50+00:00

commit d3d9acf646679c1981032b0985b386d12fccc60c upstream.

ftrace_event_call->filter is sched RCU protected but didn't use
rcu_assign_pointer().  Use it.

TODO: Add proper __rcu annotation to call->filter and all its users.

-v2: Use RCU_INIT_POINTER() for %NULL clearing as suggested by Eric.

Link: http://lkml.kernel.org/r/20111123164949.GA29639@google.com

Cc: Eric Dumazet 
Cc: Frederic Weisbecker 
Cc: Jiri Olsa 
Signed-off-by: Tejun Heo 
Signed-off-by: Steven Rostedt 
Signed-off-by: Greg Kroah-Hartman

ftrace: Remove force undef config value left for testing

2011-12-09T16:55:49+00:00

commit c7c6ec8becaf742b223c7b491f4893014be23a07 upstream.

A forced undef of a config value was used for testing and was
accidently left in during the final commit. This causes x86 to
run slower than needed while running function tracing as well
as causes the function graph selftest to fail when DYNMAIC_FTRACE
is not set. This is because the code in MCOUNT expects the ftrace
code to be processed with the config value set that happened to
be forced not set.

The forced config option was left in by:
    commit 6331c28c962561aee59e5a493b7556a4bb585957
    ftrace: Fix dynamic selftest failure on some archs

Link: http://lkml.kernel.org/r/20111102150255.GA6973@debian

Reported-by: Rabin Vincent 
Signed-off-by: Steven Rostedt 
Signed-off-by: Greg Kroah-Hartman

tracelevel module: Prioritize trace events

2011-12-01T05:48:21+00:00

This module lets subsystem authors prioritize ftrace events
by calling tracelevel_register(...). High priority traces
will be automatically enabled on boot. See tracelevel.h
for more details

Original-Change-Id: If03699e96c598bdcf93b9a9f73918ce7b0c750cb
Reviewed-on: http://git-master/r/40290
Reviewed-by: Alon Farchy 
Tested-by: Alon Farchy 
Reviewed-by: Daniel Willemsen 
Tested-by: Daniel Solomon 
Tested-by: Simone Willett 

Rebase-Id: R49f59f81d61907f66fdf892130a1b4dc6575d40e

tracing: Fix returning of duplicate data after EOF in trace_pipe_raw

2011-11-11T17:43:13+00:00

commit 436fc280261dcfce5af38f08b89287750dc91cd2 upstream.

The trace_pipe_raw handler holds a cached page from the time the file
is opened to the time it is closed. The cached page is used to handle
the case of the user space buffer being smaller than what was read from
the ring buffer. The left over buffer is held in the cache so that the
next read will continue where the data left off.

After EOF is returned (no more data in the buffer), the index of
the cached page is set to zero. If a user app reads the page again
after EOF, the check in the buffer will see that the cached page
is less than page size and will return the cached page again. This
will cause reading the trace_pipe_raw again after EOF to return
duplicate data, making the output look like the time went backwards
but instead data is just repeated.

The fix is to not reset the index right after all data is read
from the cache, but to reset it after all data is read and more
data exists in the ring buffer.

Reported-by: Jeremy Eder 
Signed-off-by: Steven Rostedt 
Signed-off-by: Greg Kroah-Hartman

ftrace/kprobes: Fix not to delete probes if in use

2011-11-11T17:43:13+00:00

commit 02ca1521ad404cf566e0075848f80d064c0a0503 upstream.

Fix kprobe-tracer not to delete a probe if the probe is in use.
In that case, delete operation will return -EBUSY.

This bug can cause a kernel panic if enabled probes are deleted
during perf record.

(Add some probes on functions)
sh-4.2# perf probe --del probe:\*
sh-4.2# exit
(kernel panic)

This is originally reported on the fedora bugzilla:

 https://bugzilla.redhat.com/show_bug.cgi?id=742383

I've also checked that this problem doesn't happen on
tracepoints when module removing because perf event
locks target module.

$ sudo ./perf record -e xfs:\* -aR sh
sh-4.2# rmmod xfs
ERROR: Module xfs is in use
sh-4.2# exit
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.203 MB perf.data (~8862 samples) ]

Signed-off-by: Masami Hiramatsu 
Cc: Arnaldo Carvalho de Melo 
Cc: Ingo Molnar 
Cc: Frederic Weisbecker 
Cc: Frank Ch. Eigler 
Link: http://lkml.kernel.org/r/20111004104438.14591.6553.stgit@fedora15
Signed-off-by: Steven Rostedt 
Signed-off-by: Greg Kroah-Hartman