FAILED: patch "[PATCH] tracing: Free buffers when a used dynamic event is removed" failed to apply to 4.19-stable tree
The patch below does not apply to the 4.19-stable tree. If someone wants it applied there, or to any other stable or longterm tree, then please email the backport, including the original git commit id to stable@vger.kernel.org.
Possible dependencies:
4313e5a61304 ("tracing: Free buffers when a used dynamic event is removed") 5448d44c3855 ("tracing: Add unified dynamic event framework")
thanks,
greg k-h
------------------ original commit in Linus's tree ------------------
From 4313e5a613049dfc1819a6dfb5f94cf2caff9452 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" rostedt@goodmis.org Date: Wed, 23 Nov 2022 17:14:34 -0500 Subject: [PATCH] tracing: Free buffers when a used dynamic event is removed MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit
After 65536 dynamic events have been added and removed, the "type" field of the event then uses the first type number that is available (not currently used by other events). A type number is the identifier of the binary blobs in the tracing ring buffer (known as events) to map them to logic that can parse the binary blob.
The issue is that if a dynamic event (like a kprobe event) is traced and is in the ring buffer, and then that event is removed (because it is dynamic, which means it can be created and destroyed), if another dynamic event is created that has the same number that new event's logic on parsing the binary blob will be used.
To show how this can be an issue, the following can crash the kernel:
# cd /sys/kernel/tracing # for i in `seq 65536`; do echo 'p:kprobes/foo do_sys_openat2 $arg1:u32' > kprobe_events # done
For every iteration of the above, the writing to the kprobe_events will remove the old event and create a new one (with the same format) and increase the type number to the next available on until the type number reaches over 65535 which is the max number for the 16 bit type. After it reaches that number, the logic to allocate a new number simply looks for the next available number. When an dynamic event is removed, that number is then available to be reused by the next dynamic event created. That is, once the above reaches the max number, the number assigned to the event in that loop will remain the same.
Now that means deleting one dynamic event and created another will reuse the previous events type number. This is where bad things can happen. After the above loop finishes, the kprobes/foo event which reads the do_sys_openat2 function call's first parameter as an integer.
# echo 1 > kprobes/foo/enable # cat /etc/passwd > /dev/null # cat trace cat-2211 [005] .... 2007.849603: foo: (do_sys_openat2+0x0/0x130) arg1=4294967196 cat-2211 [005] .... 2007.849620: foo: (do_sys_openat2+0x0/0x130) arg1=4294967196 cat-2211 [005] .... 2007.849838: foo: (do_sys_openat2+0x0/0x130) arg1=4294967196 cat-2211 [005] .... 2007.849880: foo: (do_sys_openat2+0x0/0x130) arg1=4294967196 # echo 0 > kprobes/foo/enable
Now if we delete the kprobe and create a new one that reads a string:
# echo 'p:kprobes/foo do_sys_openat2 +0($arg2):string' > kprobe_events
And now we can the trace:
# cat trace sendmail-1942 [002] ..... 530.136320: foo: (do_sys_openat2+0x0/0x240) arg1= cat-2046 [004] ..... 530.930817: foo: (do_sys_openat2+0x0/0x240) arg1="������������������������������������������������������������������������������������������������" cat-2046 [004] ..... 530.930961: foo: (do_sys_openat2+0x0/0x240) arg1="������������������������������������������������������������������������������������������������" cat-2046 [004] ..... 530.934278: foo: (do_sys_openat2+0x0/0x240) arg1="������������������������������������������������������������������������������������������������" cat-2046 [004] ..... 530.934563: foo: (do_sys_openat2+0x0/0x240) arg1="������������������������������������������������������������������������������������������������" bash-1515 [007] ..... 534.299093: foo: (do_sys_openat2+0x0/0x240) arg1="kkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkk���������@��4Z����;Y�����U
And dmesg has:
================================================================== BUG: KASAN: use-after-free in string+0xd4/0x1c0 Read of size 1 at addr ffff88805fdbbfa0 by task cat/2049
CPU: 0 PID: 2049 Comm: cat Not tainted 6.1.0-rc6-test+ #641 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v03.03 07/14/2016 Call Trace: <TASK> dump_stack_lvl+0x5b/0x77 print_report+0x17f/0x47b kasan_report+0xad/0x130 string+0xd4/0x1c0 vsnprintf+0x500/0x840 seq_buf_vprintf+0x62/0xc0 trace_seq_printf+0x10e/0x1e0 print_type_string+0x90/0xa0 print_kprobe_event+0x16b/0x290 print_trace_line+0x451/0x8e0 s_show+0x72/0x1f0 seq_read_iter+0x58e/0x750 seq_read+0x115/0x160 vfs_read+0x11d/0x460 ksys_read+0xa9/0x130 do_syscall_64+0x3a/0x90 entry_SYSCALL_64_after_hwframe+0x63/0xcd RIP: 0033:0x7fc2e972ade2 Code: c0 e9 b2 fe ff ff 50 48 8d 3d b2 3f 0a 00 e8 05 f0 01 00 0f 1f 44 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 0f 05 <48> 3d 00 f0 ff ff 77 56 c3 0f 1f 44 00 00 48 83 ec 28 48 89 54 24 RSP: 002b:00007ffc64e687c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 RAX: ffffffffffffffda RBX: 0000000000020000 RCX: 00007fc2e972ade2 RDX: 0000000000020000 RSI: 00007fc2e980d000 RDI: 0000000000000003 RBP: 00007fc2e980d000 R08: 00007fc2e980c010 R09: 0000000000000000 R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000020f00 R13: 0000000000000003 R14: 0000000000020000 R15: 0000000000020000 </TASK>
The buggy address belongs to the physical page: page:ffffea00017f6ec0 refcount:0 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x5fdbb flags: 0xfffffc0000000(node=0|zone=1|lastcpupid=0x1fffff) raw: 000fffffc0000000 0000000000000000 ffffea00017f6ec8 0000000000000000 raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000 page dumped because: kasan: bad access detected
Memory state around the buggy address: ffff88805fdbbe80: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ffff88805fdbbf00: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
ffff88805fdbbf80: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
^ ffff88805fdbc000: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ffff88805fdbc080: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ==================================================================
This was found when Zheng Yejian sent a patch to convert the event type number assignment to use IDA, which gives the next available number, and this bug showed up in the fuzz testing by Yujie Liu and the kernel test robot. But after further analysis, I found that this behavior is the same as when the event type numbers go past the 16bit max (and the above shows that).
As modules have a similar issue, but is dealt with by setting a "WAS_ENABLED" flag when a module event is enabled, and when the module is freed, if any of its events were enabled, the ring buffer that holds that event is also cleared, to prevent reading stale events. The same can be done for dynamic events.
If any dynamic event that is being removed was enabled, then make sure the buffers they were enabled in are now cleared.
Link: https://lkml.kernel.org/r/20221123171434.545706e3@gandalf.local.home Link: https://lore.kernel.org/all/20221110020319.1259291-1-zhengyejian1@huawei.com...
Cc: stable@vger.kernel.org Cc: Andrew Morton akpm@linux-foundation.org Depends-on: e18eb8783ec49 ("tracing: Add tracing_reset_all_online_cpus_unlocked() function") Depends-on: 5448d44c38557 ("tracing: Add unified dynamic event framework") Depends-on: 6212dd29683ee ("tracing/kprobes: Use dyn_event framework for kprobe events") Depends-on: 065e63f951432 ("tracing: Only have rmmod clear buffers that its events were active in") Depends-on: 575380da8b469 ("tracing: Only clear trace buffer on module unload if event was traced") Fixes: 77b44d1b7c283 ("tracing/kprobes: Rename Kprobe-tracer to kprobe-event") Reported-by: Zheng Yejian zhengyejian1@huawei.com Reported-by: Yujie Liu yujie.liu@intel.com Reported-by: kernel test robot yujie.liu@intel.com Acked-by: Masami Hiramatsu (Google) mhiramat@kernel.org Signed-off-by: Steven Rostedt (Google) rostedt@goodmis.org
diff --git a/kernel/trace/trace_dynevent.c b/kernel/trace/trace_dynevent.c index 154996684fb5..4376887e0d8a 100644 --- a/kernel/trace/trace_dynevent.c +++ b/kernel/trace/trace_dynevent.c @@ -118,6 +118,7 @@ int dyn_event_release(const char *raw_command, struct dyn_event_operations *type if (ret) break; } + tracing_reset_all_online_cpus(); mutex_unlock(&event_mutex); out: argv_free(argv); @@ -214,6 +215,7 @@ int dyn_events_release_all(struct dyn_event_operations *type) break; } out: + tracing_reset_all_online_cpus(); mutex_unlock(&event_mutex);
return ret; diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c index 78cd19e31dba..f71ea6e79b3c 100644 --- a/kernel/trace/trace_events.c +++ b/kernel/trace/trace_events.c @@ -2880,7 +2880,10 @@ static int probe_remove_event_call(struct trace_event_call *call) * TRACE_REG_UNREGISTER. */ if (file->flags & EVENT_FILE_FL_ENABLED) - return -EBUSY; + goto busy; + + if (file->flags & EVENT_FILE_FL_WAS_ENABLED) + tr->clear_trace = true; /* * The do_for_each_event_file_safe() is * a double loop. After finding the call for this @@ -2893,6 +2896,12 @@ static int probe_remove_event_call(struct trace_event_call *call) __trace_remove_event_call(call);
return 0; + busy: + /* No need to clear the trace now */ + list_for_each_entry(tr, &ftrace_trace_arrays, list) { + tr->clear_trace = false; + } + return -EBUSY; }
/* Remove an event_call */
On Sat, 03 Dec 2022 12:20:15 +0100 gregkh@linuxfoundation.org wrote:
The patch below does not apply to the 4.19-stable tree. If someone wants it applied there, or to any other stable or longterm tree, then please email the backport, including the original git commit id to stable@vger.kernel.org.
Possible dependencies:
4313e5a61304 ("tracing: Free buffers when a used dynamic event is removed")
Hmm, isn't the above the patch that failed to apply?
5448d44c3855 ("tracing: Add unified dynamic event framework")
And this is mentioned below.
[..]
If any dynamic event that is being removed was enabled, then make sure the buffers they were enabled in are now cleared.
Link: https://lkml.kernel.org/r/20221123171434.545706e3@gandalf.local.home Link: https://lore.kernel.org/all/20221110020319.1259291-1-zhengyejian1@huawei.com...
Cc: stable@vger.kernel.org Cc: Andrew Morton akpm@linux-foundation.org Depends-on: e18eb8783ec49 ("tracing: Add tracing_reset_all_online_cpus_unlocked() function")
Depends-on: 5448d44c38557 ("tracing: Add unified dynamic event framework")
^^^
-- Steve
Depends-on: 6212dd29683ee ("tracing/kprobes: Use dyn_event framework for kprobe events") Depends-on: 065e63f951432 ("tracing: Only have rmmod clear buffers that its events were active in") Depends-on: 575380da8b469 ("tracing: Only clear trace buffer on module unload if event was traced") Fixes: 77b44d1b7c283 ("tracing/kprobes: Rename Kprobe-tracer to kprobe-event") Reported-by: Zheng Yejian zhengyejian1@huawei.com Reported-by: Yujie Liu yujie.liu@intel.com Reported-by: kernel test robot yujie.liu@intel.com Acked-by: Masami Hiramatsu (Google) mhiramat@kernel.org Signed-off-by: Steven Rostedt (Google) rostedt@goodmis.org
diff --git a/kernel/trace/trace_dynevent.c b/kernel/trace/trace_dynevent.c index 154996684fb5..4376887e0d8a 100644 --- a/kernel/trace/trace_dynevent.c +++ b/kernel/trace/trace_dynevent.c @@ -118,6 +118,7 @@ int dyn_event_release(const char *raw_command, struct dyn_event_operations *type if (ret) break; }
- tracing_reset_all_online_cpus(); mutex_unlock(&event_mutex);
out: argv_free(argv); @@ -214,6 +215,7 @@ int dyn_events_release_all(struct dyn_event_operations *type) break; } out:
- tracing_reset_all_online_cpus(); mutex_unlock(&event_mutex);
return ret; diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c index 78cd19e31dba..f71ea6e79b3c 100644 --- a/kernel/trace/trace_events.c +++ b/kernel/trace/trace_events.c @@ -2880,7 +2880,10 @@ static int probe_remove_event_call(struct trace_event_call *call) * TRACE_REG_UNREGISTER. */ if (file->flags & EVENT_FILE_FL_ENABLED)
return -EBUSY;
goto busy;if (file->flags & EVENT_FILE_FL_WAS_ENABLED)tr->clear_trace = true;
- The do_for_each_event_file_safe() is
- a double loop. After finding the call for this
@@ -2893,6 +2896,12 @@ static int probe_remove_event_call(struct trace_event_call *call) __trace_remove_event_call(call); return 0;
- busy:
- /* No need to clear the trace now */
- list_for_each_entry(tr, &ftrace_trace_arrays, list) {
tr->clear_trace = false;- }
- return -EBUSY;
} /* Remove an event_call */
On Sat, Dec 03, 2022 at 05:36:55PM -0500, Steven Rostedt wrote:
On Sat, 03 Dec 2022 12:20:15 +0100 gregkh@linuxfoundation.org wrote:
The patch below does not apply to the 4.19-stable tree. If someone wants it applied there, or to any other stable or longterm tree, then please email the backport, including the original git commit id to stable@vger.kernel.org.
Possible dependencies:
4313e5a61304 ("tracing: Free buffers when a used dynamic event is removed")
Hmm, isn't the above the patch that failed to apply?
yes, tools are not the smartest at times :)
5448d44c3855 ("tracing: Add unified dynamic event framework")
And this is mentioned below.
[..]
If any dynamic event that is being removed was enabled, then make sure the buffers they were enabled in are now cleared.
Link: https://lkml.kernel.org/r/20221123171434.545706e3@gandalf.local.home Link: https://lore.kernel.org/all/20221110020319.1259291-1-zhengyejian1@huawei.com...
Cc: stable@vger.kernel.org Cc: Andrew Morton akpm@linux-foundation.org Depends-on: e18eb8783ec49 ("tracing: Add tracing_reset_all_online_cpus_unlocked() function")
Depends-on: 5448d44c38557 ("tracing: Add unified dynamic event framework")
^^^
Did you just make up a new field? We have a documented way to show dependancies for stable patches, please let's not create a new one :(
Depends-on: 6212dd29683ee ("tracing/kprobes: Use dyn_event framework for kprobe events") Depends-on: 065e63f951432 ("tracing: Only have rmmod clear buffers that its events were active in") Depends-on: 575380da8b469 ("tracing: Only clear trace buffer on module unload if event was traced") Fixes: 77b44d1b7c283 ("tracing/kprobes: Rename Kprobe-tracer to kprobe-event")
Adding the "unified framework" seems like way too much for a stable patch, are you sure all of these are required and should be applied to 4.19.y?
thanks,
greg k-h
On Sun, 4 Dec 2022 09:21:23 +0100 Greg KH gregkh@linuxfoundation.org wrote:
5448d44c3855 ("tracing: Add unified dynamic event framework")
And this is mentioned below.
[..]
If any dynamic event that is being removed was enabled, then make sure the buffers they were enabled in are now cleared.
Link: https://lkml.kernel.org/r/20221123171434.545706e3@gandalf.local.home Link: https://lore.kernel.org/all/20221110020319.1259291-1-zhengyejian1@huawei.com...
Cc: stable@vger.kernel.org Cc: Andrew Morton akpm@linux-foundation.org Depends-on: e18eb8783ec49 ("tracing: Add tracing_reset_all_online_cpus_unlocked() function")
Depends-on: 5448d44c38557 ("tracing: Add unified dynamic event framework")
^^^
Did you just make up a new field? We have a documented way to show dependancies for stable patches, please let's not create a new one :(
Ug, I've seen this tag used before:
example: e3f0c638f428fd66b5871154b62706772045f91a
And just assumed that was the method. I guess I should have looked deeper.
Depends-on: 6212dd29683ee ("tracing/kprobes: Use dyn_event framework for kprobe events") Depends-on: 065e63f951432 ("tracing: Only have rmmod clear buffers that its events were active in") Depends-on: 575380da8b469 ("tracing: Only clear trace buffer on module unload if event was traced") Fixes: 77b44d1b7c283 ("tracing/kprobes: Rename Kprobe-tracer to kprobe-event")
Adding the "unified framework" seems like way too much for a stable patch, are you sure all of these are required and should be applied to 4.19.y?
It's that balance between rewriting it to the bare minimum, which is not as intrusive, but tested much less and may be even more buggy, to backporting a larger change that has been verified by real world use cases.
Or we just do not backport it. The bug will still exist, but you really have to work hard to hit it. And because it's only controlled by privileged users, maybe it's OK to just ignore it. I think I've seen only one report of this issue in the last 10 years.
Thoughts?
-- Steve
On Sun, Dec 04, 2022 at 11:14:51AM -0500, Steven Rostedt wrote:
On Sun, 4 Dec 2022 09:21:23 +0100 Greg KH gregkh@linuxfoundation.org wrote:
5448d44c3855 ("tracing: Add unified dynamic event framework")
And this is mentioned below.
[..]
If any dynamic event that is being removed was enabled, then make sure the buffers they were enabled in are now cleared.
Link: https://lkml.kernel.org/r/20221123171434.545706e3@gandalf.local.home Link: https://lore.kernel.org/all/20221110020319.1259291-1-zhengyejian1@huawei.com...
Cc: stable@vger.kernel.org Cc: Andrew Morton akpm@linux-foundation.org Depends-on: e18eb8783ec49 ("tracing: Add tracing_reset_all_online_cpus_unlocked() function")
Depends-on: 5448d44c38557 ("tracing: Add unified dynamic event framework")
^^^
Did you just make up a new field? We have a documented way to show dependancies for stable patches, please let's not create a new one :(
Ug, I've seen this tag used before:
example: e3f0c638f428fd66b5871154b62706772045f91a
And just assumed that was the method. I guess I should have looked deeper.
Depends-on: 6212dd29683ee ("tracing/kprobes: Use dyn_event framework for kprobe events") Depends-on: 065e63f951432 ("tracing: Only have rmmod clear buffers that its events were active in") Depends-on: 575380da8b469 ("tracing: Only clear trace buffer on module unload if event was traced") Fixes: 77b44d1b7c283 ("tracing/kprobes: Rename Kprobe-tracer to kprobe-event")
Adding the "unified framework" seems like way too much for a stable patch, are you sure all of these are required and should be applied to 4.19.y?
It's that balance between rewriting it to the bare minimum, which is not as intrusive, but tested much less and may be even more buggy, to backporting a larger change that has been verified by real world use cases.
Or we just do not backport it. The bug will still exist, but you really have to work hard to hit it. And because it's only controlled by privileged users, maybe it's OK to just ignore it. I think I've seen only one report of this issue in the last 10 years.
Thoughts?
Sasha backported this to 5.4 and newer without needing the full new feature to be added, so I think we are now ok.
thanks,
greg k-h
On Sun, 4 Dec 2022 17:34:15 +0100 Greg KH gregkh@linuxfoundation.org wrote:
Depends-on: 5448d44c38557 ("tracing: Add unified dynamic event framework")
^^^
Did you just make up a new field? We have a documented way to show dependancies for stable patches, please let's not create a new one :(
Ug, I've seen this tag used before:
example: e3f0c638f428fd66b5871154b62706772045f91a
And just assumed that was the method. I guess I should have looked deeper.
I may need to denote patches again that are to be marked for stable but depend on other commits. I'm looking for the "proper" way to do this so that your scripts pick this up.
I searched Documentation for "depends" and the only thing I see in there is in Documentation/process/submitting-patches.rst:
If one patch depends on another patch in order for a change to be complete, that is OK. Simply note **"this patch depends on patch X"** in your patch description.
But that looks to be used for a patch that depends on some other patch in the series. I'm doing something that will depend on an existing commit. And do your scripts pick up on that line anyway?
Where's this documented way to show dependencies for stable patches?
-- Steve
On Fri, Mar 10, 2023 at 02:52:37PM -0500, Steven Rostedt wrote:
On Sun, 4 Dec 2022 17:34:15 +0100 Greg KH gregkh@linuxfoundation.org wrote:
Depends-on: 5448d44c38557 ("tracing: Add unified dynamic event framework")
^^^
Did you just make up a new field? We have a documented way to show dependancies for stable patches, please let's not create a new one :(
Ug, I've seen this tag used before:
example: e3f0c638f428fd66b5871154b62706772045f91a
And just assumed that was the method. I guess I should have looked deeper.
I may need to denote patches again that are to be marked for stable but depend on other commits. I'm looking for the "proper" way to do this so that your scripts pick this up.
I searched Documentation for "depends" and the only thing I see in there is in Documentation/process/submitting-patches.rst:
If one patch depends on another patch in order for a change to be complete, that is OK. Simply note **"this patch depends on patch X"** in your patch description.
But that looks to be used for a patch that depends on some other patch in the series. I'm doing something that will depend on an existing commit. And do your scripts pick up on that line anyway?
Where's this documented way to show dependencies for stable patches?
Please see: https://www.kernel.org/doc/html/latest/process/stable-kernel-rules.html for how to do this properly, specifically the section below "Option 3" that starts with, "Additionally, some patches submitted..."
does that help?
thanks,
greg k-h
On Sun, Dec 04, 2022 at 09:21:23AM +0100, Greg KH wrote:
On Sat, Dec 03, 2022 at 05:36:55PM -0500, Steven Rostedt wrote:
On Sat, 03 Dec 2022 12:20:15 +0100 gregkh@linuxfoundation.org wrote:
The patch below does not apply to the 4.19-stable tree. If someone wants it applied there, or to any other stable or longterm tree, then please email the backport, including the original git commit id to stable@vger.kernel.org.
Possible dependencies:
4313e5a61304 ("tracing: Free buffers when a used dynamic event is removed")
Hmm, isn't the above the patch that failed to apply?
yes, tools are not the smartest at times :)
It's just what the script does: it always lists the commit we actually want to apply, makes it easier for the rest of my scripts :)
linux-stable-mirror@lists.linaro.org
-
Greg KH -
gregkh＠linuxfoundation.org
-
Sasha Levin -
Steven Rostedt