Hi Steve,
I got this suspicious RCU usage warning when I ran ftracetest on
tracing/urgent branch.
[1] Basic trace file check[ 17.172817]
[ 17.174621] =============================
[ 17.177730] WARNING: suspicious RCU usage
[ 17.180962] 6.5.0-10750-g595efe1079cd #47 Tainted: G N
[ 17.185528] -----------------------------
[ 17.188685] fs/tracefs/event_inode.c:455 RCU-list traversed in non-reader
section!!
[ 17.194633]
[ 17.194633] other info that might help us debug this:
[ 17.194633]
[ 17.200969]
[ 17.200969] rcu_scheduler_active = 2, debug_locks = 1
[ 17.206086] 1 lock held by ftracetest/171:
[ 17.209265] #0: ffffffff829c2d30 (eventfs_srcu){.+.+}-{0:0}, at:
dcache_dir_open_wrapper+0x3f/0x190
[ 17.215551]
[ 17.215551] stack backtrace:
[ 17.218498] CPU: 5 PID: 171 Comm: ftracetest Tainted: G N
6.5.0-10750-g595efe1079cd #47
[ 17.223364] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.15.0-1 04/01/2014
[ 17.228206] Call Trace:
[ 17.230076] <TASK>
[ 17.231812] dump_stack_lvl+0x66/0x80
[ 17.234260] lockdep_rcu_suspicious+0x158/0x1c0
[ 17.237113] ? __pfx_dcache_dir_open_wrapper+0x10/0x10
[ 17.240026] dcache_dir_open_wrapper+0x14c/0x190
[ 17.242663] ? __pfx_dcache_dir_open_wrapper+0x10/0x10
[ 17.245592] do_dentry_open+0x16a/0x550
[ 17.248203] do_open+0x272/0x3d0
[ 17.250584] path_openat+0x119/0x290
[ 17.253046] ? __lock_acquire+0x504/0xb70
[ 17.255658] do_filp_open+0xb6/0x160
[ 17.258015] ? find_held_lock+0x2b/0x80
[ 17.260421] ? alloc_fd+0x12b/0x220
[ 17.262839] ? trace_preempt_on+0x7a/0x90
[ 17.265763] ? preempt_count_sub+0x4b/0x60
[ 17.268631] ? _raw_spin_unlock+0x2d/0x50
[ 17.271249] do_sys_openat2+0x96/0xd0
[ 17.273499] __x64_sys_openat+0x57/0xa0
[ 17.275808] do_syscall_64+0x3f/0x90
[ 17.277995] entry_SYSCALL_64_after_hwframe+0x6e/0xd8
[ 17.281250] RIP: 0033:0x4bce8c
[ 17.283498] Code: 24 18 31 c0 41 83 e2 40 75 44 89 f0 25 00 00 41 00 3d 00
00 41 00 74 36 44 89 c2 4c 89 ce bf 9c ff ff ff b8 01 01 00 00 0f 05 <48> 3d 00
f0 ff ff 77 44 48 8b 4c 24 18 64 48 33 0c 25 28 00 00 00
[ 17.294543] RSP: 002b:00007fffa59a3e20 EFLAGS: 00000287 ORIG_RAX:
0000000000000101
[ 17.299479] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00000000004bce8c
[ 17.303935] RDX: 0000000000090800 RSI: 000000000130b0c0 RDI: 00000000ffffff9c
[ 17.308187] RBP: 00007fffa59a4098 R08: 0000000000090800 R09: 000000000130b0c0
[ 17.312483] R10: 0000000000000000 R11: 0000000000000287 R12: 00000000013099ff
[ 17.316401] R13: 0000000000000012 R14: 0000000001309a00 R15: 000000000130b0c7
[ 17.320543] </TASK>
But it seems correctly taking srcu_read_lock().
452
453 ei = ti->private;
454 idx = srcu_read_lock(&eventfs_srcu);
455 list_for_each_entry_rcu(ef, &ei->e_top_files, list) {
456 create_dentry(ef, dentry, false);
457 }
458 srcu_read_unlock(&eventfs_srcu, idx);
459 return dcache_dir_open(inode, file);
460 }
461
This may false-positive warning, or srcu_read_lock() is not enough for
list_for_each_entry_rcu(). In latter case, maybe we need to use a
mutex instead of srcu for update the ef.
BTW, the ftracetest itself passed without any problem.
Thank you,
--
Masami Hiramatsu (Google) <mhira...@kernel.org>
