linux-stable.git/kernel/trace/ftrace.c, branch v3.2.54

ftrace: Fix function graph with loading of modules

2014-01-03T04:33:36+00:00

commit 8a56d7761d2d041ae5e8215d20b4167d8aa93f51 upstream.

Commit 8c4f3c3fa9681 "ftrace: Check module functions being traced on reload"
fixed module loading and unloading with respect to function tracing, but
it missed the function graph tracer. If you perform the following

 # cd /sys/kernel/debug/tracing
 # echo function_graph > current_tracer
 # modprobe nfsd
 # echo nop > current_tracer

You'll get the following oops message:

 ------------[ cut here ]------------
 WARNING: CPU: 2 PID: 2910 at /linux.git/kernel/trace/ftrace.c:1640 __ftrace_hash_rec_update.part.35+0x168/0x1b9()
 Modules linked in: nfsd exportfs nfs_acl lockd ipt_MASQUERADE sunrpc ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 ip6table_filter ip6_tables uinput snd_hda_codec_idt
 CPU: 2 PID: 2910 Comm: bash Not tainted 3.13.0-rc1-test #7
 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
  0000000000000668 ffff8800787efcf8 ffffffff814fe193 ffff88007d500000
  0000000000000000 ffff8800787efd38 ffffffff8103b80a 0000000000000668
  ffffffff810b2b9a ffffffff81a48370 0000000000000001 ffff880037aea000
 Call Trace:
  [] dump_stack+0x4f/0x7c
  [] warn_slowpath_common+0x81/0x9b
  [] ? __ftrace_hash_rec_update.part.35+0x168/0x1b9
  [] warn_slowpath_null+0x1a/0x1c
  [] __ftrace_hash_rec_update.part.35+0x168/0x1b9
  [] ? __mutex_lock_slowpath+0x364/0x364
  [] ftrace_shutdown+0xd7/0x12b
  [] unregister_ftrace_graph+0x49/0x78
  [] graph_trace_reset+0xe/0x10
  [] tracing_set_tracer+0xa7/0x26a
  [] tracing_set_trace_write+0x8b/0xbd
  [] ? ftrace_return_to_handler+0xb2/0xde
  [] ? __sb_end_write+0x5e/0x5e
  [] vfs_write+0xab/0xf6
  [] ftrace_graph_caller+0x85/0x85
  [] SyS_write+0x59/0x82
  [] ftrace_graph_caller+0x85/0x85
  [] system_call_fastpath+0x16/0x1b
 ---[ end trace 940358030751eafb ]---

The above mentioned commit didn't go far enough. Well, it covered the
function tracer by adding checks in __register_ftrace_function(). The
problem is that the function graph tracer circumvents that (for a slight
efficiency gain when function graph trace is running with a function
tracer. The gain was not worth this).

The problem came with ftrace_startup() which should always be called after
__register_ftrace_function(), if you want this bug to be completely fixed.

Anyway, this solution moves __register_ftrace_function() inside of
ftrace_startup() and removes the need to call them both.

Reported-by: Dave Wysochanski 
Fixes: ed926f9b35cd ("ftrace: Use counters to enable functions to trace")
Signed-off-by: Steven Rostedt 
Signed-off-by: Ben Hutchings

ftrace: Check module functions being traced on reload

2014-01-03T04:33:36+00:00

commit 8c4f3c3fa9681dc549cd35419b259496082fef8b upstream.

There's been a nasty bug that would show up and not give much info.
The bug displayed the following warning:

 WARNING: at kernel/trace/ftrace.c:1529 __ftrace_hash_rec_update+0x1e3/0x230()
 Pid: 20903, comm: bash Tainted: G           O 3.6.11+ #38405.trunk
 Call Trace:
  [] warn_slowpath_common+0x7f/0xc0
  [] warn_slowpath_null+0x1a/0x20
  [] __ftrace_hash_rec_update+0x1e3/0x230
  [] ftrace_hash_move+0x28/0x1d0
  [] ? kfree+0x2c/0x110
  [] ftrace_regex_release+0x8e/0x150
  [] __fput+0xae/0x220
  [] ____fput+0xe/0x10
  [] task_work_run+0x72/0x90
  [] do_notify_resume+0x6c/0xc0
  [] ? trace_hardirqs_on_thunk+0x3a/0x3c
  [] int_signal+0x12/0x17
 ---[ end trace 793179526ee09b2c ]---

It was finally narrowed down to unloading a module that was being traced.

It was actually more than that. When functions are being traced, there's
a table of all functions that have a ref count of the number of active
tracers attached to that function. When a function trace callback is
registered to a function, the function's record ref count is incremented.
When it is unregistered, the function's record ref count is decremented.
If an inconsistency is detected (ref count goes below zero) the above
warning is shown and the function tracing is permanently disabled until
reboot.

The ftrace callback ops holds a hash of functions that it filters on
(and/or filters off). If the hash is empty, the default means to filter
all functions (for the filter_hash) or to disable no functions (for the
notrace_hash).

When a module is unloaded, it frees the function records that represent
the module functions. These records exist on their own pages, that is
function records for one module will not exist on the same page as
function records for other modules or even the core kernel.

Now when a module unloads, the records that represents its functions are
freed. When the module is loaded again, the records are recreated with
a default ref count of zero (unless there's a callback that traces all
functions, then they will also be traced, and the ref count will be
incremented).

The problem is that if an ftrace callback hash includes functions of the
module being unloaded, those hash entries will not be removed. If the
module is reloaded in the same location, the hash entries still point
to the functions of the module but the module's ref counts do not reflect
that.

With the help of Steve and Joern, we found a reproducer:

 Using uinput module and uinput_release function.

 cd /sys/kernel/debug/tracing
 modprobe uinput
 echo uinput_release > set_ftrace_filter
 echo function > current_tracer
 rmmod uinput
 modprobe uinput
 # check /proc/modules to see if loaded in same addr, otherwise try again
 echo nop > current_tracer

 [BOOM]

The above loads the uinput module, which creates a table of functions that
can be traced within the module.

We add uinput_release to the filter_hash to trace just that function.

Enable function tracincg, which increments the ref count of the record
associated to uinput_release.

Remove uinput, which frees the records including the one that represents
uinput_release.

Load the uinput module again (and make sure it's at the same address).
This recreates the function records all with a ref count of zero,
including uinput_release.

Disable function tracing, which will decrement the ref count for uinput_release
which is now zero because of the module removal and reload, and we have
a mismatch (below zero ref count).

The solution is to check all currently tracing ftrace callbacks to see if any
are tracing any of the module's functions when a module is loaded (it already does
that with callbacks that trace all functions). If a callback happens to have
a module function being traced, it increments that records ref count and starts
tracing that function.

There may be a strange side effect with this, where tracing module functions
on unload and then reloading a new module may have that new module's functions
being traced. This may be something that confuses the user, but it's not
a big deal. Another approach is to disable all callback hashes on module unload,
but this leaves some ftrace callbacks that may not be registered, but can
still have hashes tracing the module's function where ftrace doesn't know about
it. That situation can cause the same bug. This solution solves that case too.
Another benefit of this solution, is it is possible to trace a module's
function on unload and load.

Link: http://lkml.kernel.org/r/20130705142629.GA325@redhat.com

Reported-by: Jörn Engel 
Reported-by: Dave Jones 
Reported-by: Steve Hodgson 
Tested-by: Steve Hodgson 
Signed-off-by: Steven Rostedt 
[bwh: Backported to 3.2: adjust context, indentation]
Signed-off-by: Ben Hutchings

ftrace: Create ftrace_hash_empty() helper routine

2014-01-03T04:33:36+00:00

commit 06a51d9307380c78bb5c92e68fc80ad2c7d7f890 upstream.

There are two types of hashes in the ftrace_ops; one type
is the filter_hash and the other is the notrace_hash. Either
one may be null, meaning it has no elements. But when elements
are added, the hash is allocated.

Throughout the code, a check needs to be made to see if a hash
exists or the hash has elements, but the check if the hash exists
is usually missing causing the possible "NULL pointer dereference bug".

Add a helper routine called "ftrace_hash_empty()" that returns
true if the hash doesn't exist or its count is zero. As they mean
the same thing.

Last-bug-reported-by: Jiri Olsa 
Signed-off-by: Steven Rostedt 
Signed-off-by: Ben Hutchings

ftrace: Fix ftrace hash record update with notrace

2014-01-03T04:33:35+00:00

commit c842e975520f8ab09e293cc92f51a1f396251fd5 upstream.

When disabling the "notrace" records, that means we want to trace them.
If the notrace_hash is zero, it means that we want to trace all
records. But to disable a zero notrace_hash means nothing.

The check for the notrace_hash count was incorrect with:

	if (hash && !hash->count)
		return

With the correct comment above it that states that we do nothing
if the notrace_hash has zero count. But !hash also means that
the notrace hash has zero count. I think this was done to
protect against dereferencing NULL. But if !hash is true, then
we go through the following loop without doing a single thing.

Fix it to:

	if (!hash || !hash->count)
		return;

Signed-off-by: Steven Rostedt 
Signed-off-by: Ben Hutchings

ftrace: Move ftrace_filter_lseek out of CONFIG_DYNAMIC_FTRACE section

2013-06-19T01:16:47+00:00

commit 7f49ef69db6bbf756c0abca7e9b65b32e999eec8 upstream.

As ftrace_filter_lseek is now used with ftrace_pid_fops, it needs to
be moved out of the #ifdef CONFIG_DYNAMIC_FTRACE section as the
ftrace_pid_fops is defined when DYNAMIC_FTRACE is not.

Cc: Namhyung Kim 
Signed-off-by: Steven Rostedt 
[bwh: Backported to 3.2:
 - ftrace_filter_lseek() is static and not declared in ftrace.h
 - 'whence' parameter was called 'origin']
Signed-off-by: Ben Hutchings

tracing: Reset ftrace_graph_filter_enabled if count is zero

2013-05-13T14:02:17+00:00

commit 9f50afccfdc15d95d7331acddcb0f7703df089ae upstream.

The ftrace_graph_count can be decreased with a "!" pattern, so that
the enabled flag should be updated too.

Link: http://lkml.kernel.org/r/1365663698-2413-1-git-send-email-namhyung@kernel.org

Cc: Frederic Weisbecker 
Cc: Ingo Molnar 
Cc: Namhyung Kim 
Signed-off-by: Namhyung Kim 
Signed-off-by: Steven Rostedt 
Signed-off-by: Ben Hutchings

tracing: Fix off-by-one on allocating stat->pages

2013-05-13T14:02:16+00:00

commit 39e30cd1537937d3c00ef87e865324e981434e5b upstream.

The first page was allocated separately, so no need to start from 0.

Link: http://lkml.kernel.org/r/1364820385-32027-2-git-send-email-namhyung@kernel.org

Cc: Frederic Weisbecker 
Cc: Namhyung Kim 
Signed-off-by: Namhyung Kim 
Signed-off-by: Steven Rostedt 
Signed-off-by: Ben Hutchings

tracing: Fix possible NULL pointer dereferences

2013-04-25T19:25:38+00:00

commit 6a76f8c0ab19f215af2a3442870eeb5f0e81998d upstream.

Currently set_ftrace_pid and set_graph_function files use seq_lseek
for their fops.  However seq_open() is called only for FMODE_READ in
the fops->open() so that if an user tries to seek one of those file
when she open it for writing, it sees NULL seq_file and then panic.

It can be easily reproduced with following command:

  $ cd /sys/kernel/debug/tracing
  $ echo 1234 | sudo tee -a set_ftrace_pid

In this example, GNU coreutils' tee opens the file with fopen(, "a")
and then the fopen() internally calls lseek().

Link: http://lkml.kernel.org/r/1365663302-2170-1-git-send-email-namhyung@kernel.org

Cc: Frederic Weisbecker 
Cc: Ingo Molnar 
Cc: Namhyung Kim 
Signed-off-by: Namhyung Kim 
Signed-off-by: Steven Rostedt 
[bwh: Backported to 3.2: ftrace_regex_lseek() is static]
Signed-off-by: Ben Hutchings

tracing: Fix double free when function profile init failed

2013-04-25T19:25:36+00:00

commit 83e03b3fe4daffdebbb42151d5410d730ae50bd1 upstream.

On the failure path, stat->start and stat->pages will refer same page.
So it'll attempt to free the same page again and get kernel panic.

Link: http://lkml.kernel.org/r/1364820385-32027-1-git-send-email-namhyung@kernel.org

Cc: Frederic Weisbecker 
Cc: Namhyung Kim 
Signed-off-by: Namhyung Kim 
Signed-off-by: Steven Rostedt 
Signed-off-by: Ben Hutchings

ftrace: Consistently restore trace function on sysctl enabling

2013-04-25T19:25:34+00:00

commit 5000c418840b309251c5887f0b56503aae30f84c upstream.

If we reenable ftrace via syctl, we currently set ftrace_trace_function
based on the previous simplistic algorithm. This is inconsistent with
what update_ftrace_function does. So better call that helper instead.

Link: http://lkml.kernel.org/r/5151D26F.1070702@siemens.com

Signed-off-by: Jan Kiszka 
Signed-off-by: Steven Rostedt 
Signed-off-by: Ben Hutchings