Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 537472

Summary: ftrace function tracer triggers integrity check failure
Product: Red Hat Enterprise MRG Reporter: Steven Rostedt <srostedt>
Component: realtime-kernelAssignee: John Kacur <jkacur>
Status: CLOSED ERRATA QA Contact: David Sommerseth <davids>
Severity: medium Docs Contact:
Priority: low    
Version: 1.1CC: bhu, lgoncalv, ovasik
Target Milestone: 1.2.4   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
The "function tracer" from ftrace could eventually present problems when a module was unloaded during a tracing session. Some of the related call site entries for that module were not removed from ftrace's internal lists and could lead to confusing error ("oops") messages.
Story Points: ---
Clone Of: Environment:
Last Closed: 2010-01-21 14:11:05 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
ftrace: Only update $offset when we update $ref_func
none
ftrace: Fix removing of function entries from modules none

Description Steven Rostedt 2009-11-13 19:00:17 UTC
Description of problem:

When enabling the function tracer "ftrace" on 2.6.24-rt, the integrity check for modifying the text triggers a failure.

WARNING: at kernel/trace/ftrace.c:406 ftrace_bug()
Pid: 2518, comm: kstopmachine Not tainted 2.6.24.7-137.el5rttrace #1

Call Trace:
 [<ffffffff882ac00d>] ? :acpi_cpufreq:extract_freq+0xd/0x92
 [<ffffffff882ac00d>] ? :acpi_cpufreq:extract_freq+0xd/0x92
 [<ffffffff81089a18>] ftrace_replace_code+0x25a/0x3fd
 [<ffffffff81089be6>] __ftrace_modify_code+0x2b/0x6a
 [<ffffffff8107622e>] do_stop+0xdb/0x13e
 [<ffffffff81076153>] ? do_stop+0x0/0x13e
 [<ffffffff810550ea>] kthread+0x4e/0x7c
 [<ffffffff8100d418>] child_rip+0xa/0x12
 [<ffffffff8100cb00>] ? restore_args+0x0/0x30
 [<ffffffff8105509c>] ? kthread+0x0/0x7c
 [<ffffffff8100d40e>] ? child_rip+0x0/0x12

---------------------------
| preempt count: 00000001 ]
| 1-level deep critical section nesting:
----------------------------------------
.. [<ffffffff8107620b>] .... do_stop+0xb8/0x13e
.....[<ffffffff810550ea>] ..   ( <= kthread+0x4e/0x7c)

ftrace failed to modify [<ffffffff882ac00d>] extract_freq+0xd/0x92 [acpi_cpufreq]
 actual: f8:01:74:07:83
ftrace failed to modify [<ffffffff882ac0c0>] acpi_cpufreq_resume+0x17/0x40 [acpi_cpufreq]
 actual: 88:48:c7:c6:78
ftrace failed to modify [<ffffffff882ac0e8>] acpi_cpufreq_resume+0x3f/0x40 [acpi_cpufreq]
 actual: c3:55:48:89:e5
ftrace failed to modify [<ffffffff882ac235>] get_cur_val+0xe1/0x108 [acpi_cpufreq]
 actual: c0:48:c7:c2:af
ftrace failed to modify [<ffffffff882ac262>] acpi_cpufreq_target+0x6/0x32c [acpi_cpufreq]
 actual: 41:56:41:55:41
ftrace failed to modify [<ffffffff882ac294>] acpi_cpufreq_target+0x38/0x32c [acpi_cpufreq]
 actual: 00:00:00:c7:45
ftrace failed to modify [<ffffffff882ac2e6>] acpi_cpufreq_target+0x8a/0x32c [acpi_cpufreq]
 actual: c5:e8:50:20:f6
ftrace failed to modify [<ffffffff882ac323>] acpi_cpufreq_target+0xc7/0x32c [acpi_cpufreq]
 actual: 14:00:74:27:89
ftrace failed to modify [<ffffffff882ac43f>] acpi_cpufreq_target+0x1e3/0x32c [acpi_cpufreq]
 actual: 76:dc:65:48:8b
ftrace failed to modify [<ffffffff882ac5ca>] get_cur_freq_on_cpu+0x42/0x8a [acpi_cpufreq]
 actual: 7b:08:00:75:04
ftrace failed to modify [<ffffffff882ac76f>] acpi_cpufreq_cpu_init+0x118/0x4a5 [acpi_cpufreq]
 actual: 7c:24:28:01:77
ftrace failed to modify [<ffffffff882ac78e>] acpi_cpufreq_cpu_init+0x137/0x4a5 [acpi_cpufreq]
 actual: f8:e9:21:03:00
ftrace failed to modify [<ffffffff882ac977>] acpi_cpufreq_cpu_init+0x320/0x4a5 [acpi_cpufreq]
 actual: 00:8d:04:09:45
ftrace failed to modify [<ffffffff882ac98e>] acpi_cpufreq_cpu_init+0x337/0x4a5 [acpi_cpufreq]
 actual: 03:42:30:48:69
ftrace failed to modify [<ffffffff882ac9b5>] acpi_cpufreq_cpu_init+0x35e/0x4a5 [acpi_cpufreq]
 actual: 44:89:02:eb:0d
ftrace failed to modify [<ffffffff882acbf0>] get_measured_perf+0xf4/0x160 [acpi_cpufreq]
 actual: 65:48:8b:04:25


Looks like the acpi code may be read only, and it prevents ftrace from modifying that code. Will investigate.

This may also be an issue with vanilla linux. I'll test the latest Linus tree first, to see if the issues is there as well.

Comment 1 Steven Rostedt 2009-11-17 16:59:14 UTC
Found the error. It was with the ftrace_release that is called by the module code to release the functions used by the module. It was missing some due to the way the hash check was implemented. Will fix.

Comment 2 Steven Rostedt 2009-11-17 17:01:01 UTC
Created attachment 369916 [details]
ftrace: Only update $offset when we update $ref_func

This is not the fix, but it is related. I backported this patch to 2.6.24-rt.

Comment 3 Steven Rostedt 2009-11-17 17:01:48 UTC
Created attachment 369917 [details]
ftrace: Fix removing of function entries from modules

This is the fix for the bug.

Comment 6 Beth Uptagrafft 2010-01-13 15:43:41 UTC
Technical note added. If any revisions are required, please edit the "Technical Notes" field
accordingly. All revisions will be proofread by the Engineering Content Services team.

New Contents:
The "function tracer" from ftrace could eventually present problems when a module was unloaded during a tracing session. Some of the related call site entries for that module were not removed from ftrace's internal lists and could lead to confusing error ("oops") messages.

Comment 7 David Sommerseth 2010-01-14 19:55:32 UTC
Verified by reproducing the situation.

reproducer:
-------------------------------------------------------
- boot kernel-rt-trace kernel
- Log in as root, and run the following commands:
[root@host]# mount -t debugfs debugfs /sys/kernel/debug
[root@host]# cd /sys/kernel/debug
[root@host]# cat current_tracer
none
[root@host]# echo ftrace > current_tracer
[root@host]# modprobe -r acpi
-------------------------------------------------------

When checking dmesg, you'll find a similar backtrace to whats reported when running the kernel-rt-trace-2.6.24.7.139.  When running the 2.6.24.7-146 version, no error messages are found.

Comment 9 errata-xmlrpc 2010-01-21 14:11:05 UTC
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2010-0041.html