Currently, only tree RCU support leak callbacks setting when do
duplicate call_rcu(). this commit add leak callbacks setting when
fo duplicate call_rcu() for tiny RCU.
Signed-off-by: Zqiang <[email protected]>
---
v1->v2:
for do duplicate kvfree_call_rcu(), not set leak callbacks.
kernel/rcu/tiny.c | 17 ++++++++++++++++-
1 file changed, 16 insertions(+), 1 deletion(-)
diff --git a/kernel/rcu/tiny.c b/kernel/rcu/tiny.c
index f0561ee16b9c..943d431b908f 100644
--- a/kernel/rcu/tiny.c
+++ b/kernel/rcu/tiny.c
@@ -158,6 +158,10 @@ void synchronize_rcu(void)
}
EXPORT_SYMBOL_GPL(synchronize_rcu);
+static void tiny_rcu_leak_callback(struct rcu_head *rhp)
+{
+}
+
/*
* Post an RCU callback to be invoked after the end of an RCU grace
* period. But since we have but one CPU, that would be after any
@@ -165,9 +169,20 @@ EXPORT_SYMBOL_GPL(synchronize_rcu);
*/
void call_rcu(struct rcu_head *head, rcu_callback_t func)
{
+ static atomic_t doublefrees;
unsigned long flags;
- debug_rcu_head_queue(head);
+ if (debug_rcu_head_queue(head)) {
+ if (atomic_inc_return(&doublefrees) < 4) {
+ pr_err("%s(): Double-freed CB %p->%pS()!!! ", __func__, head, head->func);
+ mem_dump_obj(head);
+ }
+
+ if (!__is_kvfree_rcu_offset((unsigned long)head->func))
+ WRITE_ONCE(head->func, tiny_rcu_leak_callback);
+ return;
+ }
+
head->func = func;
head->next = NULL;
--
2.25.1
On Fri, Jul 01, 2022 at 10:44:04AM +0800, Zqiang wrote:
> Currently, only tree RCU support leak callbacks setting when do
> duplicate call_rcu(). this commit add leak callbacks setting when
> fo duplicate call_rcu() for tiny RCU.
>
> Signed-off-by: Zqiang <[email protected]>
This does look plausible, thank you!
What testing have you done?
One important test for Tiny RCU is that the size of the kernel not
grow without a very good reason. In this case, the added code should
be dead code in a production build (CONFIG_DEBUG_OBJECTS_RCU_HEAD=n),
but it is good to check.
It is of course also good to check that the messages print as expected,
which is what rcutorture.object_debug is there to help with.
Thanx, Paul
> ---
> v1->v2:
> for do duplicate kvfree_call_rcu(), not set leak callbacks.
>
> kernel/rcu/tiny.c | 17 ++++++++++++++++-
> 1 file changed, 16 insertions(+), 1 deletion(-)
>
> diff --git a/kernel/rcu/tiny.c b/kernel/rcu/tiny.c
> index f0561ee16b9c..943d431b908f 100644
> --- a/kernel/rcu/tiny.c
> +++ b/kernel/rcu/tiny.c
> @@ -158,6 +158,10 @@ void synchronize_rcu(void)
> }
> EXPORT_SYMBOL_GPL(synchronize_rcu);
>
> +static void tiny_rcu_leak_callback(struct rcu_head *rhp)
> +{
> +}
> +
> /*
> * Post an RCU callback to be invoked after the end of an RCU grace
> * period. But since we have but one CPU, that would be after any
> @@ -165,9 +169,20 @@ EXPORT_SYMBOL_GPL(synchronize_rcu);
> */
> void call_rcu(struct rcu_head *head, rcu_callback_t func)
> {
> + static atomic_t doublefrees;
> unsigned long flags;
>
> - debug_rcu_head_queue(head);
> + if (debug_rcu_head_queue(head)) {
> + if (atomic_inc_return(&doublefrees) < 4) {
> + pr_err("%s(): Double-freed CB %p->%pS()!!! ", __func__, head, head->func);
> + mem_dump_obj(head);
> + }
> +
> + if (!__is_kvfree_rcu_offset((unsigned long)head->func))
> + WRITE_ONCE(head->func, tiny_rcu_leak_callback);
> + return;
> + }
> +
> head->func = func;
> head->next = NULL;
>
> --
> 2.25.1
>
On Fri, Jul 01, 2022 at 10:44:04AM +0800, Zqiang wrote:
> Currently, only tree RCU support leak callbacks setting when do
> duplicate call_rcu(). this commit add leak callbacks setting when
> fo duplicate call_rcu() for tiny RCU.
>
> Signed-off-by: Zqiang <[email protected]>
>This does look plausible, thank you!
>
>What testing have you done?
>
>One important test for Tiny RCU is that the size of the kernel not
>grow without a very good reason. In this case, the added code should
>be dead code in a production build (CONFIG_DEBUG_OBJECTS_RCU_HEAD=n),
>but it is good to check.
>
>It is of course also good to check that the messages print as expected,
>which is what rcutorture.object_debug is there to help with.
In the condition that the CONFIG_DEBUG_OBJECTS_RCU_HEAD=n, the function directly returns zero.
#else /* !CONFIG_DEBUG_OBJECTS_RCU_HEAD */
static inline int debug_rcu_head_queue(struct rcu_head *head)
{
return 0;
}
My test results are as follows:
runqemu kvm slirp nographic qemuparams="-m 2048 -smp 1" bootparams="rcutorture.object_debug=1" -d
log:
root@qemux86-64:/# zcat /proc/config.gz | grep RCU
# RCU Subsystem
CONFIG_TINY_RCU=y
CONFIG_DEBUG_OBJECTS_RCU_HEAD=y
[ 1.015657] rcutorture: WARN: Duplicate call_rcu() test starting.
[ 1.015659] ------------[ cut here ]------------
[ 1.015659] ODEBUG: activate active (active state 1) object type: rcu_head hint: 0x0
[ 1.015680] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
[ 1.016329] Modules linked in:
[ 1.016329] CPU: 0 PID: 1 Comm: swapper Not tainted 5.19.0-rc3-yoctodev-standard+ #214
[ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
[ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
[ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
[ 1.016329] RSP: 0000:ffff888001337be0 EFLAGS: 00010086
[ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
[ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6e
[ 1.016329] RBP: ffff888001337c10 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
[ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
[ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e8a0 R15: 0000000000000000
[ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
[ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
[ 1.016329] Call Trace:
[ 1.016329] <TASK>
[ 1.016329] debug_object_activate+0x2b9/0x300
[ 1.016329] ? debug_object_assert_init+0x220/0x220
[ 1.016329] ? lockdep_hardirqs_on_prepare+0x13/0x210
[ 1.016329] ? call_rcu+0xde/0x150
[ 1.016329] ? trace_hardirqs_on+0x54/0x120
[ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
[ 1.016329] call_rcu+0x20/0x150
[ 1.016329] rcu_torture_init+0x1687/0x1759
[ 1.016329] ? srcu_init+0xaa/0xaa
[ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
[ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
[ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
[ 1.016329] ? irq_pm_init_ops+0x19/0x19
[ 1.016329] ? mutex_unlock+0x12/0x20
[ 1.016329] ? srcu_init+0xaa/0xaa
[ 1.016329] do_one_initcall+0xc1/0x310
[ 1.016329] ? initcall_blacklisted+0x140/0x140
[ 1.016329] ? parameq+0x20/0x90
[ 1.016329] ? __kmalloc+0x238/0x5d0
[ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
[ 1.016329] kernel_init_freeable+0x20a/0x268
[ 1.016329] ? rest_init+0x160/0x160
[ 1.016329] kernel_init+0x1e/0x140
[ 1.016329] ret_from_fork+0x22/0x30
[ 1.016329] </TASK>
[ 1.016329] irq event stamp: 152
[ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
[ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
[ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
[ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
[ 1.016329] ---[ end trace 0000000000000000 ]---
[ 1.016329] ------------[ cut here ]------------
[ 1.016329] ODEBUG: active_state active (active state 1) object type: rcu_head hint: 0x0
[ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
[ 1.016329] Modules linked in:
[ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
[ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
[ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
[ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
[ 1.016329] RSP: 0000:ffff888001337bd0 EFLAGS: 00010082
[ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
[ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6c
[ 1.016329] RBP: ffff888001337c00 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
[ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
[ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e640 R15: 0000000000000000
[ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
[ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
[ 1.016329] Call Trace:
[ 1.016329] <TASK>
[ 1.016329] debug_object_active_state+0x1d7/0x210
[ 1.016329] ? debug_object_deactivate+0x210/0x210
[ 1.016329] ? lockdep_hardirqs_on_prepare+0x13/0x210
[ 1.016329] ? call_rcu+0xde/0x150
[ 1.016329] ? trace_hardirqs_on+0x54/0x120
[ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
[ 1.016329] call_rcu+0x39/0x150
[ 1.016329] rcu_torture_init+0x1687/0x1759
[ 1.016329] ? srcu_init+0xaa/0xaa
[ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
[ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
[ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
[ 1.016329] ? irq_pm_init_ops+0x19/0x19
[ 1.016329] ? mutex_unlock+0x12/0x20
[ 1.016329] ? srcu_init+0xaa/0xaa
[ 1.016329] do_one_initcall+0xc1/0x310
[ 1.016329] ? initcall_blacklisted+0x140/0x140
[ 1.016329] ? parameq+0x20/0x90
[ 1.016329] ? __kmalloc+0x238/0x5d0
[ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
[ 1.016329] kernel_init_freeable+0x20a/0x268
[ 1.016329] ? rest_init+0x160/0x160
[ 1.016329] kernel_init+0x1e/0x140
[ 1.016329] ret_from_fork+0x22/0x30
[ 1.016329] </TASK>
[ 1.016329] irq event stamp: 152
[ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
[ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
[ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
[ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
[ 1.016329] ---[ end trace 0000000000000000 ]---
[ 1.016329] call_rcu(): Double-freed CB (____ptrval____)->rcu_torture_leak_cb+0x0/0x10()!!! non-slab/vmalloc memory
[ 1.016329] ------------[ cut here ]------------
[ 1.016329] ODEBUG: activate active (active state 1) object type: rcu_head hint: 0x0
[ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
[ 1.016329] Modules linked in:
[ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
[ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
[ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
[ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
[ 1.016329] RSP: 0000:ffff888001337be0 EFLAGS: 00010086
[ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
[ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6e
[ 1.016329] RBP: ffff888001337c10 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
[ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
[ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e8a0 R15: 0000000000000000
[ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
[ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
[ 1.016329] Call Trace:
[ 1.016329] <TASK>
[ 1.016329] debug_object_activate+0x2b9/0x300
[ 1.016329] ? debug_object_assert_init+0x220/0x220
[ 1.016329] ? _raw_spin_unlock+0x23/0x30
[ 1.016329] ? find_vmap_area+0x5c/0x90
[ 1.016329] ? do_raw_spin_unlock+0x85/0xe0
[ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
[ 1.016329] call_rcu+0x20/0x150
[ 1.016329] rcu_torture_init+0x16aa/0x1759
[ 1.016329] ? srcu_init+0xaa/0xaa
[ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
[ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
[ 1.016329] ? srcu_torture_completed+0x10/0x10
[ 1.016329] ? irq_pm_init_ops+0x19/0x19
[ 1.016329] ? mutex_unlock+0x12/0x20
[ 1.016329] ? srcu_init+0xaa/0xaa
[ 1.016329] do_one_initcall+0xc1/0x310
[ 1.016329] ? initcall_blacklisted+0x140/0x140
[ 1.016329] ? parameq+0x20/0x90
[ 1.016329] ? __kmalloc+0x238/0x5d0
[ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
[ 1.016329] kernel_init_freeable+0x20a/0x268
[ 1.016329] ? rest_init+0x160/0x160
[ 1.016329] kernel_init+0x1e/0x140
[ 1.016329] ret_from_fork+0x22/0x30
[ 1.016329] </TASK>
[ 1.016329] irq event stamp: 152
[ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
[ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
[ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
[ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
[ 1.016329] ---[ end trace 0000000000000000 ]---
[ 1.016329] ------------[ cut here ]------------
[ 1.016329] ODEBUG: active_state active (active state 1) object type: rcu_head hint: 0x0
[ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
[ 1.016329] Modules linked in:
[ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
[ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
[ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
[ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
[ 1.016329] RSP: 0000:ffff888001337bd0 EFLAGS: 00010082
[ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
[ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6c
[ 1.016329] RBP: ffff888001337c00 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
[ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
[ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e640 R15: 0000000000000000
[ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
[ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
[ 1.016329] Call Trace:
[ 1.016329] <TASK>
[ 1.016329] debug_object_active_state+0x1d7/0x210
[ 1.016329] ? debug_object_deactivate+0x210/0x210
[ 1.016329] ? _raw_spin_unlock+0x23/0x30
[ 1.016329] ? find_vmap_area+0x5c/0x90
[ 1.016329] ? do_raw_spin_unlock+0x85/0xe0
[ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
[ 1.016329] call_rcu+0x39/0x150
[ 1.016329] rcu_torture_init+0x16aa/0x1759
[ 1.016329] ? srcu_init+0xaa/0xaa
[ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
[ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
[ 1.016329] ? srcu_torture_completed+0x10/0x10
[ 1.016329] ? irq_pm_init_ops+0x19/0x19
[ 1.016329] ? mutex_unlock+0x12/0x20
[ 1.016329] ? srcu_init+0xaa/0xaa
[ 1.016329] do_one_initcall+0xc1/0x310
[ 1.016329] ? initcall_blacklisted+0x140/0x140
[ 1.016329] ? parameq+0x20/0x90
[ 1.016329] ? __kmalloc+0x238/0x5d0
[ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
[ 1.016329] kernel_init_freeable+0x20a/0x268
[ 1.016329] ? rest_init+0x160/0x160
[ 1.016329] kernel_init+0x1e/0x140
[ 1.016329] ret_from_fork+0x22/0x30
[ 1.016329] </TASK>
[ 1.016329] irq event stamp: 152
[ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
[ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
[ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
[ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
[ 1.016329] ---[ end trace 0000000000000000 ]---
[ 1.016329] call_rcu(): Double-freed CB (____ptrval____)->rcu_torture_leak_cb+0x0/0x10()!!! slab kmalloc-16 start ffff888003f49240 pointer offset 06
[ 1.101401] rcu-torture: rcu_torture_read_exit: Start of test
Thanks
Zqiang
>
> Thanx, Paul
> ---
> v1->v2:
> for do duplicate kvfree_call_rcu(), not set leak callbacks.
>
> kernel/rcu/tiny.c | 17 ++++++++++++++++-
> 1 file changed, 16 insertions(+), 1 deletion(-)
>
> diff --git a/kernel/rcu/tiny.c b/kernel/rcu/tiny.c
> index f0561ee16b9c..943d431b908f 100644
> --- a/kernel/rcu/tiny.c
> +++ b/kernel/rcu/tiny.c
> @@ -158,6 +158,10 @@ void synchronize_rcu(void)
> }
> EXPORT_SYMBOL_GPL(synchronize_rcu);
>
> +static void tiny_rcu_leak_callback(struct rcu_head *rhp)
> +{
> +}
> +
> /*
> * Post an RCU callback to be invoked after the end of an RCU grace
> * period. But since we have but one CPU, that would be after any
> @@ -165,9 +169,20 @@ EXPORT_SYMBOL_GPL(synchronize_rcu);
> */
> void call_rcu(struct rcu_head *head, rcu_callback_t func)
> {
> + static atomic_t doublefrees;
> unsigned long flags;
>
> - debug_rcu_head_queue(head);
> + if (debug_rcu_head_queue(head)) {
> + if (atomic_inc_return(&doublefrees) < 4) {
> + pr_err("%s(): Double-freed CB %p->%pS()!!! ", __func__, head, head->func);
> + mem_dump_obj(head);
> + }
> +
> + if (!__is_kvfree_rcu_offset((unsigned long)head->func))
> + WRITE_ONCE(head->func, tiny_rcu_leak_callback);
> + return;
> + }
> +
> head->func = func;
> head->next = NULL;
>
> --
> 2.25.1
>
On Wed, Jul 06, 2022 at 02:00:51AM +0000, Zhang, Qiang1 wrote:
> On Fri, Jul 01, 2022 at 10:44:04AM +0800, Zqiang wrote:
> > Currently, only tree RCU support leak callbacks setting when do
> > duplicate call_rcu(). this commit add leak callbacks setting when
> > fo duplicate call_rcu() for tiny RCU.
> >
> > Signed-off-by: Zqiang <[email protected]>
>
> >This does look plausible, thank you!
> >
> >What testing have you done?
> >
> >One important test for Tiny RCU is that the size of the kernel not
> >grow without a very good reason. In this case, the added code should
> >be dead code in a production build (CONFIG_DEBUG_OBJECTS_RCU_HEAD=n),
> >but it is good to check.
> >
> >It is of course also good to check that the messages print as expected,
> >which is what rcutorture.object_debug is there to help with.
>
> In the condition that the CONFIG_DEBUG_OBJECTS_RCU_HEAD=n, the function directly returns zero.
>
> #else /* !CONFIG_DEBUG_OBJECTS_RCU_HEAD */
> static inline int debug_rcu_head_queue(struct rcu_head *head)
> {
> return 0;
> }
Yes, like I said, the added code -should- be dead code. But there is
often a gap between "should" and "is", for example, compilers don't
always do what we would like them to. So please use the "size vmlinux"
command with and without your patch for a kernel built (both times)
with CONFIG_TINY_RCU=y and CONFIG_DEBUG_OBJECTS_RCU_HEAD==n.
The rest of the test results look good, thank you!
Thanx, Paul
> My test results are as follows:
>
> runqemu kvm slirp nographic qemuparams="-m 2048 -smp 1" bootparams="rcutorture.object_debug=1" -d
>
> log:
> root@qemux86-64:/# zcat /proc/config.gz | grep RCU
> # RCU Subsystem
> CONFIG_TINY_RCU=y
> CONFIG_DEBUG_OBJECTS_RCU_HEAD=y
>
> [ 1.015657] rcutorture: WARN: Duplicate call_rcu() test starting.
> [ 1.015659] ------------[ cut here ]------------
> [ 1.015659] ODEBUG: activate active (active state 1) object type: rcu_head hint: 0x0
> [ 1.015680] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Not tainted 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337be0 EFLAGS: 00010086
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6e
> [ 1.016329] RBP: ffff888001337c10 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e8a0 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_activate+0x2b9/0x300
> [ 1.016329] ? debug_object_assert_init+0x220/0x220
> [ 1.016329] ? lockdep_hardirqs_on_prepare+0x13/0x210
> [ 1.016329] ? call_rcu+0xde/0x150
> [ 1.016329] ? trace_hardirqs_on+0x54/0x120
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x20/0x150
> [ 1.016329] rcu_torture_init+0x1687/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] ------------[ cut here ]------------
> [ 1.016329] ODEBUG: active_state active (active state 1) object type: rcu_head hint: 0x0
> [ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337bd0 EFLAGS: 00010082
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6c
> [ 1.016329] RBP: ffff888001337c00 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e640 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_active_state+0x1d7/0x210
> [ 1.016329] ? debug_object_deactivate+0x210/0x210
> [ 1.016329] ? lockdep_hardirqs_on_prepare+0x13/0x210
> [ 1.016329] ? call_rcu+0xde/0x150
> [ 1.016329] ? trace_hardirqs_on+0x54/0x120
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x39/0x150
> [ 1.016329] rcu_torture_init+0x1687/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] call_rcu(): Double-freed CB (____ptrval____)->rcu_torture_leak_cb+0x0/0x10()!!! non-slab/vmalloc memory
> [ 1.016329] ------------[ cut here ]------------
> [ 1.016329] ODEBUG: activate active (active state 1) object type: rcu_head hint: 0x0
> [ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337be0 EFLAGS: 00010086
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6e
> [ 1.016329] RBP: ffff888001337c10 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e8a0 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_activate+0x2b9/0x300
> [ 1.016329] ? debug_object_assert_init+0x220/0x220
> [ 1.016329] ? _raw_spin_unlock+0x23/0x30
> [ 1.016329] ? find_vmap_area+0x5c/0x90
> [ 1.016329] ? do_raw_spin_unlock+0x85/0xe0
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x20/0x150
> [ 1.016329] rcu_torture_init+0x16aa/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? srcu_torture_completed+0x10/0x10
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] ------------[ cut here ]------------
> [ 1.016329] ODEBUG: active_state active (active state 1) object type: rcu_head hint: 0x0
> [ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337bd0 EFLAGS: 00010082
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6c
> [ 1.016329] RBP: ffff888001337c00 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e640 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_active_state+0x1d7/0x210
> [ 1.016329] ? debug_object_deactivate+0x210/0x210
> [ 1.016329] ? _raw_spin_unlock+0x23/0x30
> [ 1.016329] ? find_vmap_area+0x5c/0x90
> [ 1.016329] ? do_raw_spin_unlock+0x85/0xe0
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x39/0x150
> [ 1.016329] rcu_torture_init+0x16aa/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? srcu_torture_completed+0x10/0x10
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] call_rcu(): Double-freed CB (____ptrval____)->rcu_torture_leak_cb+0x0/0x10()!!! slab kmalloc-16 start ffff888003f49240 pointer offset 06
> [ 1.101401] rcu-torture: rcu_torture_read_exit: Start of test
>
> Thanks
> Zqiang
>
>
> >
> > Thanx, Paul
>
> > ---
> > v1->v2:
> > for do duplicate kvfree_call_rcu(), not set leak callbacks.
> >
> > kernel/rcu/tiny.c | 17 ++++++++++++++++-
> > 1 file changed, 16 insertions(+), 1 deletion(-)
> >
> > diff --git a/kernel/rcu/tiny.c b/kernel/rcu/tiny.c
> > index f0561ee16b9c..943d431b908f 100644
> > --- a/kernel/rcu/tiny.c
> > +++ b/kernel/rcu/tiny.c
> > @@ -158,6 +158,10 @@ void synchronize_rcu(void)
> > }
> > EXPORT_SYMBOL_GPL(synchronize_rcu);
> >
> > +static void tiny_rcu_leak_callback(struct rcu_head *rhp)
> > +{
> > +}
> > +
> > /*
> > * Post an RCU callback to be invoked after the end of an RCU grace
> > * period. But since we have but one CPU, that would be after any
> > @@ -165,9 +169,20 @@ EXPORT_SYMBOL_GPL(synchronize_rcu);
> > */
> > void call_rcu(struct rcu_head *head, rcu_callback_t func)
> > {
> > + static atomic_t doublefrees;
> > unsigned long flags;
> >
> > - debug_rcu_head_queue(head);
> > + if (debug_rcu_head_queue(head)) {
> > + if (atomic_inc_return(&doublefrees) < 4) {
> > + pr_err("%s(): Double-freed CB %p->%pS()!!! ", __func__, head, head->func);
> > + mem_dump_obj(head);
> > + }
> > +
> > + if (!__is_kvfree_rcu_offset((unsigned long)head->func))
> > + WRITE_ONCE(head->func, tiny_rcu_leak_callback);
> > + return;
> > + }
> > +
> > head->func = func;
> > head->next = NULL;
> >
> > --
> > 2.25.1
> >
On Wed, Jul 06, 2022 at 02:00:51AM +0000, Zhang, Qiang1 wrote:
> On Fri, Jul 01, 2022 at 10:44:04AM +0800, Zqiang wrote:
> > Currently, only tree RCU support leak callbacks setting when do
> > duplicate call_rcu(). this commit add leak callbacks setting when
> > fo duplicate call_rcu() for tiny RCU.
> >
> > Signed-off-by: Zqiang <[email protected]>
>
> >This does look plausible, thank you!
> >
> >What testing have you done?
> >
> >One important test for Tiny RCU is that the size of the kernel not
> >grow without a very good reason. In this case, the added code should
> >be dead code in a production build (CONFIG_DEBUG_OBJECTS_RCU_HEAD=n),
> >but it is good to check.
> >
> >It is of course also good to check that the messages print as expected,
> >which is what rcutorture.object_debug is there to help with.
>
> In the condition that the CONFIG_DEBUG_OBJECTS_RCU_HEAD=n, the function directly returns zero.
>
> #else /* !CONFIG_DEBUG_OBJECTS_RCU_HEAD */
> static inline int debug_rcu_head_queue(struct rcu_head *head)
> {
> return 0;
> }
>
>Yes, like I said, the added code -should- be dead code. But there is
>often a gap between "should" and "is", for example, compilers don't
>always do what we would like them to. So please use the "size vmlinux"
>command with and without your patch for a kernel built (both times)
>with CONFIG_TINY_RCU=y and CONFIG_DEBUG_OBJECTS_RCU_HEAD==n.
>
>The rest of the test results look good, thank you!
Hi Paul
Original:
text data bss dec hex filename
26291319 20160143 15212544 61664006 3aceb06 vmlinux
Applay patch:
text data bss dec hex filename
26291319 20160431 15212544 61664294 3acec26 vmlinux
Thanks
Zqiang
>
> Thanx, Paul
>
> My test results are as follows:
>
> runqemu kvm slirp nographic qemuparams="-m 2048 -smp 1" bootparams="rcutorture.object_debug=1" -d
>
> log:
> root@qemux86-64:/# zcat /proc/config.gz | grep RCU
> # RCU Subsystem
> CONFIG_TINY_RCU=y
> CONFIG_DEBUG_OBJECTS_RCU_HEAD=y
>
> [ 1.015657] rcutorture: WARN: Duplicate call_rcu() test starting.
> [ 1.015659] ------------[ cut here ]------------
> [ 1.015659] ODEBUG: activate active (active state 1) object type: rcu_head hint: 0x0
> [ 1.015680] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Not tainted 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337be0 EFLAGS: 00010086
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6e
> [ 1.016329] RBP: ffff888001337c10 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e8a0 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_activate+0x2b9/0x300
> [ 1.016329] ? debug_object_assert_init+0x220/0x220
> [ 1.016329] ? lockdep_hardirqs_on_prepare+0x13/0x210
> [ 1.016329] ? call_rcu+0xde/0x150
> [ 1.016329] ? trace_hardirqs_on+0x54/0x120
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x20/0x150
> [ 1.016329] rcu_torture_init+0x1687/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] ------------[ cut here ]------------
> [ 1.016329] ODEBUG: active_state active (active state 1) object type: rcu_head hint: 0x0
> [ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337bd0 EFLAGS: 00010082
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6c
> [ 1.016329] RBP: ffff888001337c00 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e640 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_active_state+0x1d7/0x210
> [ 1.016329] ? debug_object_deactivate+0x210/0x210
> [ 1.016329] ? lockdep_hardirqs_on_prepare+0x13/0x210
> [ 1.016329] ? call_rcu+0xde/0x150
> [ 1.016329] ? trace_hardirqs_on+0x54/0x120
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x39/0x150
> [ 1.016329] rcu_torture_init+0x1687/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] call_rcu(): Double-freed CB (____ptrval____)->rcu_torture_leak_cb+0x0/0x10()!!! non-slab/vmalloc memory
> [ 1.016329] ------------[ cut here ]------------
> [ 1.016329] ODEBUG: activate active (active state 1) object type: rcu_head hint: 0x0
> [ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337be0 EFLAGS: 00010086
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6e
> [ 1.016329] RBP: ffff888001337c10 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e8a0 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_activate+0x2b9/0x300
> [ 1.016329] ? debug_object_assert_init+0x220/0x220
> [ 1.016329] ? _raw_spin_unlock+0x23/0x30
> [ 1.016329] ? find_vmap_area+0x5c/0x90
> [ 1.016329] ? do_raw_spin_unlock+0x85/0xe0
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x20/0x150
> [ 1.016329] rcu_torture_init+0x16aa/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? srcu_torture_completed+0x10/0x10
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] ------------[ cut here ]------------
> [ 1.016329] ODEBUG: active_state active (active state 1) object type: rcu_head hint: 0x0
> [ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337bd0 EFLAGS: 00010082
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6c
> [ 1.016329] RBP: ffff888001337c00 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e640 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_active_state+0x1d7/0x210
> [ 1.016329] ? debug_object_deactivate+0x210/0x210
> [ 1.016329] ? _raw_spin_unlock+0x23/0x30
> [ 1.016329] ? find_vmap_area+0x5c/0x90
> [ 1.016329] ? do_raw_spin_unlock+0x85/0xe0
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x39/0x150
> [ 1.016329] rcu_torture_init+0x16aa/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? srcu_torture_completed+0x10/0x10
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] call_rcu(): Double-freed CB (____ptrval____)->rcu_torture_leak_cb+0x0/0x10()!!! slab kmalloc-16 start ffff888003f49240 pointer offset 06
> [ 1.101401] rcu-torture: rcu_torture_read_exit: Start of test
>
> Thanks
> Zqiang
>
>
> >
> > Thanx, Paul
>
> > ---
> > v1->v2:
> > for do duplicate kvfree_call_rcu(), not set leak callbacks.
> >
> > kernel/rcu/tiny.c | 17 ++++++++++++++++-
> > 1 file changed, 16 insertions(+), 1 deletion(-)
> >
> > diff --git a/kernel/rcu/tiny.c b/kernel/rcu/tiny.c
> > index f0561ee16b9c..943d431b908f 100644
> > --- a/kernel/rcu/tiny.c
> > +++ b/kernel/rcu/tiny.c
> > @@ -158,6 +158,10 @@ void synchronize_rcu(void)
> > }
> > EXPORT_SYMBOL_GPL(synchronize_rcu);
> >
> > +static void tiny_rcu_leak_callback(struct rcu_head *rhp)
> > +{
> > +}
> > +
> > /*
> > * Post an RCU callback to be invoked after the end of an RCU grace
> > * period. But since we have but one CPU, that would be after any
> > @@ -165,9 +169,20 @@ EXPORT_SYMBOL_GPL(synchronize_rcu);
> > */
> > void call_rcu(struct rcu_head *head, rcu_callback_t func)
> > {
> > + static atomic_t doublefrees;
> > unsigned long flags;
> >
> > - debug_rcu_head_queue(head);
> > + if (debug_rcu_head_queue(head)) {
> > + if (atomic_inc_return(&doublefrees) < 4) {
> > + pr_err("%s(): Double-freed CB %p->%pS()!!! ", __func__, head, head->func);
> > + mem_dump_obj(head);
> > + }
> > +
> > + if (!__is_kvfree_rcu_offset((unsigned long)head->func))
> > + WRITE_ONCE(head->func, tiny_rcu_leak_callback);
> > + return;
> > + }
> > +
> > head->func = func;
> > head->next = NULL;
> >
> > --
> > 2.25.1
> >
On Wed, Jul 06, 2022 at 02:00:51AM +0000, Zhang, Qiang1 wrote:
> On Fri, Jul 01, 2022 at 10:44:04AM +0800, Zqiang wrote:
> > Currently, only tree RCU support leak callbacks setting when do
> > duplicate call_rcu(). this commit add leak callbacks setting when
> > fo duplicate call_rcu() for tiny RCU.
> >
> > Signed-off-by: Zqiang <[email protected]>
>
> >This does look plausible, thank you!
> >
> >What testing have you done?
> >
> >One important test for Tiny RCU is that the size of the kernel not
> >grow without a very good reason. In this case, the added code should
> >be dead code in a production build (CONFIG_DEBUG_OBJECTS_RCU_HEAD=n),
> >but it is good to check.
> >
> >It is of course also good to check that the messages print as expected,
> >which is what rcutorture.object_debug is there to help with.
>
> In the condition that the CONFIG_DEBUG_OBJECTS_RCU_HEAD=n, the function directly returns zero.
>
> #else /* !CONFIG_DEBUG_OBJECTS_RCU_HEAD */
> static inline int debug_rcu_head_queue(struct rcu_head *head)
> {
> return 0;
> }
>
>Yes, like I said, the added code -should- be dead code. But there is
>often a gap between "should" and "is", for example, compilers don't
>always do what we would like them to. So please use the "size vmlinux"
>command with and without your patch for a kernel built (both times)
>with CONFIG_TINY_RCU=y and CONFIG_DEBUG_OBJECTS_RCU_HEAD==n.
>
>The rest of the test results look good, thank you!
Hi Paul
1. CONFIG_TINY_RCU=y and CONFIG_DEBUG_OBJECTS_RCU_HEAD=y
Original:
text data bss dec hex filename
26291319 20160143 15212544 61664006 3aceb06 vmlinux
Applay patch:
text data bss dec hex filename
26291319 20160431 15212544 61664294 3acec26 vmlinux
2. CONFIG_TINY_RCU=y and CONFIG_DEBUG_OBJECTS_RCU_HEAD=n
Original:
text data bss dec hex filename
26290663 20159823 15212544 61663030 3ace736 vmlinux
Applay patch:
text data bss dec hex filename
26290663 20159823 15212544 61663030 3ace736 vmlinux
Thanks
Zqiang
>
> Thanx, Paul
>
> My test results are as follows:
>
> runqemu kvm slirp nographic qemuparams="-m 2048 -smp 1" bootparams="rcutorture.object_debug=1" -d
>
> log:
> root@qemux86-64:/# zcat /proc/config.gz | grep RCU
> # RCU Subsystem
> CONFIG_TINY_RCU=y
> CONFIG_DEBUG_OBJECTS_RCU_HEAD=y
>
> [ 1.015657] rcutorture: WARN: Duplicate call_rcu() test starting.
> [ 1.015659] ------------[ cut here ]------------
> [ 1.015659] ODEBUG: activate active (active state 1) object type: rcu_head hint: 0x0
> [ 1.015680] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Not tainted 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337be0 EFLAGS: 00010086
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6e
> [ 1.016329] RBP: ffff888001337c10 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e8a0 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_activate+0x2b9/0x300
> [ 1.016329] ? debug_object_assert_init+0x220/0x220
> [ 1.016329] ? lockdep_hardirqs_on_prepare+0x13/0x210
> [ 1.016329] ? call_rcu+0xde/0x150
> [ 1.016329] ? trace_hardirqs_on+0x54/0x120
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x20/0x150
> [ 1.016329] rcu_torture_init+0x1687/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] ------------[ cut here ]------------
> [ 1.016329] ODEBUG: active_state active (active state 1) object type: rcu_head hint: 0x0
> [ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337bd0 EFLAGS: 00010082
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6c
> [ 1.016329] RBP: ffff888001337c00 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e640 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_active_state+0x1d7/0x210
> [ 1.016329] ? debug_object_deactivate+0x210/0x210
> [ 1.016329] ? lockdep_hardirqs_on_prepare+0x13/0x210
> [ 1.016329] ? call_rcu+0xde/0x150
> [ 1.016329] ? trace_hardirqs_on+0x54/0x120
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x39/0x150
> [ 1.016329] rcu_torture_init+0x1687/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] call_rcu(): Double-freed CB (____ptrval____)->rcu_torture_leak_cb+0x0/0x10()!!! non-slab/vmalloc memory
> [ 1.016329] ------------[ cut here ]------------
> [ 1.016329] ODEBUG: activate active (active state 1) object type: rcu_head hint: 0x0
> [ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337be0 EFLAGS: 00010086
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6e
> [ 1.016329] RBP: ffff888001337c10 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e8a0 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_activate+0x2b9/0x300
> [ 1.016329] ? debug_object_assert_init+0x220/0x220
> [ 1.016329] ? _raw_spin_unlock+0x23/0x30
> [ 1.016329] ? find_vmap_area+0x5c/0x90
> [ 1.016329] ? do_raw_spin_unlock+0x85/0xe0
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x20/0x150
> [ 1.016329] rcu_torture_init+0x16aa/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? srcu_torture_completed+0x10/0x10
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] ------------[ cut here ]------------
> [ 1.016329] ODEBUG: active_state active (active state 1) object type: rcu_head hint: 0x0
> [ 1.016329] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:502 debug_print_object+0xda/0x100
> [ 1.016329] Modules linked in:
> [ 1.016329] CPU: 0 PID: 1 Comm: swapper Tainted: G W 5.19.0-rc3-yoctodev-standard+ #214
> [ 1.016329] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1.016329] RIP: 0010:debug_print_object+0xda/0x100
> [ 1.016329] Code: 60 ec 45 92 e8 a7 7b a0 ff 4d 89 f9 4d 89 e8 44 89 e1 48 8b 14 dd 60 ec 45 92 4c 89 f6 48 c7 c7 e0 e1 45 92 e8 f9 d1 b3 00 90 <0f> e
> [ 1.016329] RSP: 0000:ffff888001337bd0 EFLAGS: 00010082
> [ 1.016329] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
> [ 1.016329] RDX: 00000000ffffffd8 RSI: 0000000000000004 RDI: ffffed1000266f6c
> [ 1.016329] RBP: ffff888001337c00 R08: ffffffff90a56ee6 R09: fffffbfff25df5c2
> [ 1.016329] R10: ffffffff92efae0b R11: fffffbfff25df5c1 R12: 0000000000000001
> [ 1.016329] R13: ffffffff9227f520 R14: ffffffff9245e640 R15: 0000000000000000
> [ 1.016329] FS: 0000000000000000(0000) GS:ffffffff92cbb000(0000) knlGS:0000000000000000
> [ 1.016329] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1.016329] CR2: ffff888017401000 CR3: 0000000015a3c000 CR4: 00000000001506f0
> [ 1.016329] Call Trace:
> [ 1.016329] <TASK>
> [ 1.016329] debug_object_active_state+0x1d7/0x210
> [ 1.016329] ? debug_object_deactivate+0x210/0x210
> [ 1.016329] ? _raw_spin_unlock+0x23/0x30
> [ 1.016329] ? find_vmap_area+0x5c/0x90
> [ 1.016329] ? do_raw_spin_unlock+0x85/0xe0
> [ 1.016329] ? rcu_torture_fwd_cb_hist.cold+0xe9/0xe9
> [ 1.016329] call_rcu+0x39/0x150
> [ 1.016329] rcu_torture_init+0x16aa/0x1759
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] ? irq_debugfs_copy_devname+0x70/0x70
> [ 1.016329] ? rcu_torture_barrier1cb+0x40/0x40
> [ 1.016329] ? srcu_torture_completed+0x10/0x10
> [ 1.016329] ? irq_pm_init_ops+0x19/0x19
> [ 1.016329] ? mutex_unlock+0x12/0x20
> [ 1.016329] ? srcu_init+0xaa/0xaa
> [ 1.016329] do_one_initcall+0xc1/0x310
> [ 1.016329] ? initcall_blacklisted+0x140/0x140
> [ 1.016329] ? parameq+0x20/0x90
> [ 1.016329] ? __kmalloc+0x238/0x5d0
> [ 1.016329] ? rcu_read_lock_sched_held+0xe/0x50
> [ 1.016329] kernel_init_freeable+0x20a/0x268
> [ 1.016329] ? rest_init+0x160/0x160
> [ 1.016329] kernel_init+0x1e/0x140
> [ 1.016329] ret_from_fork+0x22/0x30
> [ 1.016329] </TASK>
> [ 1.016329] irq event stamp: 152
> [ 1.016329] hardirqs last enabled at (151): [<ffffffff91da7a4c>] _raw_spin_unlock_irqrestore+0x4c/0x60
> [ 1.016329] hardirqs last disabled at (152): [<ffffffff91da7811>] _raw_spin_lock_irqsave+0x71/0x90
> [ 1.016329] softirqs last enabled at (0): [<ffffffff908a230c>] copy_process+0xc8c/0x31b0
> [ 1.016329] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [ 1.016329] ---[ end trace 0000000000000000 ]---
> [ 1.016329] call_rcu(): Double-freed CB (____ptrval____)->rcu_torture_leak_cb+0x0/0x10()!!! slab kmalloc-16 start ffff888003f49240 pointer offset 06
> [ 1.101401] rcu-torture: rcu_torture_read_exit: Start of test
>
> Thanks
> Zqiang
>
>
> >
> > Thanx, Paul
>
> > ---
> > v1->v2:
> > for do duplicate kvfree_call_rcu(), not set leak callbacks.
> >
> > kernel/rcu/tiny.c | 17 ++++++++++++++++-
> > 1 file changed, 16 insertions(+), 1 deletion(-)
> >
> > diff --git a/kernel/rcu/tiny.c b/kernel/rcu/tiny.c
> > index f0561ee16b9c..943d431b908f 100644
> > --- a/kernel/rcu/tiny.c
> > +++ b/kernel/rcu/tiny.c
> > @@ -158,6 +158,10 @@ void synchronize_rcu(void)
> > }
> > EXPORT_SYMBOL_GPL(synchronize_rcu);
> >
> > +static void tiny_rcu_leak_callback(struct rcu_head *rhp)
> > +{
> > +}
> > +
> > /*
> > * Post an RCU callback to be invoked after the end of an RCU grace
> > * period. But since we have but one CPU, that would be after any
> > @@ -165,9 +169,20 @@ EXPORT_SYMBOL_GPL(synchronize_rcu);
> > */
> > void call_rcu(struct rcu_head *head, rcu_callback_t func)
> > {
> > + static atomic_t doublefrees;
> > unsigned long flags;
> >
> > - debug_rcu_head_queue(head);
> > + if (debug_rcu_head_queue(head)) {
> > + if (atomic_inc_return(&doublefrees) < 4) {
> > + pr_err("%s(): Double-freed CB %p->%pS()!!! ", __func__, head, head->func);
> > + mem_dump_obj(head);
> > + }
> > +
> > + if (!__is_kvfree_rcu_offset((unsigned long)head->func))
> > + WRITE_ONCE(head->func, tiny_rcu_leak_callback);
> > + return;
> > + }
> > +
> > head->func = func;
> > head->next = NULL;
> >
> > --
> > 2.25.1
> >
On Wed, Jul 06, 2022 at 04:24:03AM +0000, Zhang, Qiang1 wrote:
>
> On Wed, Jul 06, 2022 at 02:00:51AM +0000, Zhang, Qiang1 wrote:
> > On Fri, Jul 01, 2022 at 10:44:04AM +0800, Zqiang wrote:
> > > Currently, only tree RCU support leak callbacks setting when do
> > > duplicate call_rcu(). this commit add leak callbacks setting when
> > > fo duplicate call_rcu() for tiny RCU.
> > >
> > > Signed-off-by: Zqiang <[email protected]>
> >
> > >This does look plausible, thank you!
> > >
> > >What testing have you done?
> > >
> > >One important test for Tiny RCU is that the size of the kernel not
> > >grow without a very good reason. In this case, the added code should
> > >be dead code in a production build (CONFIG_DEBUG_OBJECTS_RCU_HEAD=n),
> > >but it is good to check.
> > >
> > >It is of course also good to check that the messages print as expected,
> > >which is what rcutorture.object_debug is there to help with.
> >
> > In the condition that the CONFIG_DEBUG_OBJECTS_RCU_HEAD=n, the function directly returns zero.
> >
> > #else /* !CONFIG_DEBUG_OBJECTS_RCU_HEAD */
> > static inline int debug_rcu_head_queue(struct rcu_head *head)
> > {
> > return 0;
> > }
> >
> >Yes, like I said, the added code -should- be dead code. But there is
> >often a gap between "should" and "is", for example, compilers don't
> >always do what we would like them to. So please use the "size vmlinux"
> >command with and without your patch for a kernel built (both times)
> >with CONFIG_TINY_RCU=y and CONFIG_DEBUG_OBJECTS_RCU_HEAD==n.
> >
> >The rest of the test results look good, thank you!
>
> Hi Paul
>
> 1. CONFIG_TINY_RCU=y and CONFIG_DEBUG_OBJECTS_RCU_HEAD=y
>
> Original:
> text data bss dec hex filename
> 26291319 20160143 15212544 61664006 3aceb06 vmlinux
>
> Applay patch:
> text data bss dec hex filename
> 26291319 20160431 15212544 61664294 3acec26 vmlinux
>
> 2. CONFIG_TINY_RCU=y and CONFIG_DEBUG_OBJECTS_RCU_HEAD=n
>
> Original:
> text data bss dec hex filename
> 26290663 20159823 15212544 61663030 3ace736 vmlinux
>
> Applay patch:
> text data bss dec hex filename
> 26290663 20159823 15212544 61663030 3ace736 vmlinux
Much better, thank you!
Please see below for the commit updated with this information and
wordsmithed a bit. As always, please let me know if I messed something
up.
Thanx, Paul
------------------------------------------------------------------------
commit 88cea4e18ed430aa1187063450236fc00408eaac
Author: Zqiang <[email protected]>
Date: Fri Jul 1 10:44:04 2022 +0800
rcu: Make tiny RCU support leak callbacks for debug-object errors
Currently, only Tree RCU leaks callbacks setting when it detects a
duplicate call_rcu(). This commit causes Tiny RCU to also leak
callbacks in this situation.
Because this is Tiny RCU, kernel size is important:
1. CONFIG_TINY_RCU=y and CONFIG_DEBUG_OBJECTS_RCU_HEAD=n
(Production kernel)
Original:
text data bss dec hex filename
26290663 20159823 15212544 61663030 3ace736 vmlinux
With this commit:
text data bss dec hex filename
26290663 20159823 15212544 61663030 3ace736 vmlinux
2. CONFIG_TINY_RCU=y and CONFIG_DEBUG_OBJECTS_RCU_HEAD=y
(Debugging kernel)
Original:
text data bss dec hex filename
26291319 20160143 15212544 61664006 3aceb06 vmlinux
With this commit:
text data bss dec hex filename
26291319 20160431 15212544 61664294 3acec26 vmlinux
These results show that the kernel size is unchanged for production
kernels, as desired.
Signed-off-by: Zqiang <[email protected]>
Signed-off-by: Paul E. McKenney <[email protected]>
diff --git a/kernel/rcu/tiny.c b/kernel/rcu/tiny.c
index f0561ee16b9c2..943d431b908f6 100644
--- a/kernel/rcu/tiny.c
+++ b/kernel/rcu/tiny.c
@@ -158,6 +158,10 @@ void synchronize_rcu(void)
}
EXPORT_SYMBOL_GPL(synchronize_rcu);
+static void tiny_rcu_leak_callback(struct rcu_head *rhp)
+{
+}
+
/*
* Post an RCU callback to be invoked after the end of an RCU grace
* period. But since we have but one CPU, that would be after any
@@ -165,9 +169,20 @@ EXPORT_SYMBOL_GPL(synchronize_rcu);
*/
void call_rcu(struct rcu_head *head, rcu_callback_t func)
{
+ static atomic_t doublefrees;
unsigned long flags;
- debug_rcu_head_queue(head);
+ if (debug_rcu_head_queue(head)) {
+ if (atomic_inc_return(&doublefrees) < 4) {
+ pr_err("%s(): Double-freed CB %p->%pS()!!! ", __func__, head, head->func);
+ mem_dump_obj(head);
+ }
+
+ if (!__is_kvfree_rcu_offset((unsigned long)head->func))
+ WRITE_ONCE(head->func, tiny_rcu_leak_callback);
+ return;
+ }
+
head->func = func;
head->next = NULL;