ftrace: Clear module traced functions on unload module
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:
[<
ffffffff8103e5ff>] warn_slowpath_common+0x7f/0xc0
[<
ffffffff8103e65a>] warn_slowpath_null+0x1a/0x20
[<
ffffffff810c2ee3>] __ftrace_hash_rec_update+0x1e3/0x230
[<
ffffffff810c4f28>] ftrace_hash_move+0x28/0x1d0
[<
ffffffff811401cc>] ? kfree+0x2c/0x110
[<
ffffffff810c68ee>] ftrace_regex_release+0x8e/0x150
[<
ffffffff81149f1e>] __fput+0xae/0x220
[<
ffffffff8114a09e>] ____fput+0xe/0x10
[<
ffffffff8105fa22>] task_work_run+0x72/0x90
[<
ffffffff810028ec>] do_notify_resume+0x6c/0xc0
[<
ffffffff8126596e>] ? trace_hardirqs_on_thunk+0x3a/0x3c
[<
ffffffff815c0f88>] 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.
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 callback is registered to a function, it holds a "hash" of
function addresses that it traces. When it unregisters, the hash is
examined and any record that exists in the hash will decrement the
functions record's ref count. Hashes that point to a module function
that was freed are simply ignored.
But what happens if the trace is still going on and you reload the same
module. If the module is allocated in the same location, the hashes
of the registered functions will still be mapped to the module functions
(if it was tracing the module function). The problem is that the module
would allocate new function record tables with their ref counts as zero.
When a callback is unregistered, if the hash matches the function record
of a reloaded module, it will dec the ref count, but as it was zero it
would trigger the above warning and disable function tracing.
With the help of Steve and Joern, we found a reproducer:
Using uinput module and uinput_release function.
modprobe uinput
echo uinput_release > /sys/kernel/debug/tracing/set_ftrace_filter
rmmod uinput
modprobe uinput
// check /proc/modules to see if loaded in same addr, otherwise try again
echo > /sys/kernel/debug/tracing/set_ftrace_filter
[BOOM]
The solution here is on module unload, look at all the registered funtion
callbacks and remove any hash entry that points to any function in the
module that is about to be removed.
Link: http://lkml.kernel.org/r/CADHUQJ58icP+d3QTXheiCnZwu6hrAqG2heMhhcuQvghXavHRFw@mail.gmail.com
Reported-by: Jörn Engel <joern@logfs.org>
Reported-by: Dave Jones <davej@redhat.com>
Reported-by: Steve Hodgson <steve@purestorage.com>
Tested-by: Steve Hodgson <steve@purestorage.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>