[linus:master] [afs] f94f70d39c: WARNING:suspicious_RCU_usage

From: kernel test robot
Date: Wed Jan 17 2024 - 10:08:13 EST



Hello,

kernel test robot noticed "WARNING:suspicious_RCU_usage" on:

commit: f94f70d39cc2d54079ebae934862198516315db2 ("afs: Provide a way to configure address priorities")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

[test failed on linus/master 052d534373b7ed33712a63d5e17b2b6cdbce84fd]
[test failed on linux-next/master 8d04a7e2ee3fd6aabb8096b00c64db0d735bc874]

in testcase: trinity
version: trinity-i386-abe9de86-1_20230429
with following parameters:

runtime: 300s
group: group-01
nr_groups: 5

test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/


compiler: gcc-12
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

(please refer to attached dmesg/kmsg for entire log/backtrace)



If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <oliver.sang@xxxxxxxxx>
| Closes: https://lore.kernel.org/oe-lkp/202401172243.cd53d5f6-oliver.sang@xxxxxxxxx


[ 463.480579][ T6166]
[ 463.481694][ T6166] =============================
[ 463.482931][ T6166] WARNING: suspicious RCU usage
[ 463.484158][ T6166] 6.7.0-rc7-00024-gf94f70d39cc2 #1 Tainted: G W N
[ 463.485385][ T6166] -----------------------------
[ 463.486196][ T6166] include/linux/rcupdate.h:373 Illegal context switch in RCU read-side critical section!
[ 463.488096][ T6166]
[ 463.488096][ T6166] other info that might help us debug this:
[ 463.488096][ T6166]
[ 463.490824][ T6166]
[ 463.490824][ T6166] rcu_scheduler_active = 2, debug_locks = 1
[ 463.493075][ T6166] 3 locks held by trinity-c4/6166:
[ 463.494415][ T6166] #0: eafe0bac (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x42/0x64
[ 463.496294][ T6166] #1: ca58af5c (&p->lock){+.+.}-{3:3}, at: seq_read_iter+0x43/0x470
[ 463.497496][ T6166] #2: c42177b0 (rcu_read_lock){....}-{1:2}, at: afs_proc_addr_prefs_show+0x28/0x284
[ 463.499479][ T6166]
[ 463.499479][ T6166] stack backtrace:
[ 463.500797][ T6166] CPU: 1 PID: 6166 Comm: trinity-c4 Tainted: G W N 6.7.0-rc7-00024-gf94f70d39cc2 #1 8c9fc74f21af2a18f53bcba9406b4039ea273cf9
[ 463.503266][ T6166] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 463.505486][ T6166] Call Trace:
[ 463.506253][ T6166] dump_stack_lvl+0x9a/0xdc
[ 463.507029][ T6166] dump_stack+0xd/0x14
[ 463.507855][ T6166] lockdep_rcu_suspicious+0x127/0x16c
[ 463.508791][ T6166] __might_resched+0x284/0x2b4
[ 463.509656][ T6166] __might_sleep+0x2e/0x80
[ 463.510560][ T6166] __might_fault+0x29/0x78
[ 463.511471][ T6166] _copy_to_iter+0x2e/0x560
[ 463.512204][ T6166] ? __check_heap_object+0x32/0xc8
[ 463.513205][ T6166] ? check_heap_object+0x16b/0x19c
[ 463.514017][ T6166] ? __check_object_size+0x5e/0x118
[ 463.515030][ T6166] seq_read_iter+0x3bc/0x470
[ 463.515900][ T6166] seq_read+0x7f/0x9c
[ 463.516669][ T6166] ? seq_read_iter+0x470/0x470
[ 463.517552][ T6166] proc_reg_read+0x60/0x90
[ 463.518321][ T6166] ? proc_reg_write+0x90/0x90
[ 463.519126][ T6166] do_loop_readv_writev+0x4a/0xb4
[ 463.520161][ T6166] do_iter_read+0x105/0x170
[ 463.521040][ T6166] do_readv+0xac/0x190
[ 463.521836][ T6166] __ia32_sys_readv+0x12/0x18
[ 463.522679][ T6166] __do_fast_syscall_32+0x72/0xd8
[ 463.523573][ T6166] ? find_held_lock+0x24/0x74
[ 463.524397][ T6166] ? __lock_release+0x4a/0x14c
[ 463.525397][ T6166] ? __task_pid_nr_ns+0x78/0x1fc
[ 463.526245][ T6166] ? syscall_exit_work+0xe8/0x11c
[ 463.527101][ T6166] ? lockdep_hardirqs_on_prepare+0xa4/0x154
[ 463.528145][ T6166] ? syscall_exit_to_user_mode+0x3a/0x50
[ 463.529118][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.529997][ T6166] ? syscall_exit_to_user_mode+0x3a/0x50
[ 463.530959][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.531870][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.532739][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.533630][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.534507][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.535362][ T6166] ? irqentry_exit_to_user_mode+0x28/0x2c
[ 463.536356][ T6166] ? irqentry_exit+0x7f/0xc8
[ 463.537187][ T6166] do_fast_syscall_32+0x29/0x60
[ 463.538014][ T6166] do_SYSENTER_32+0x15/0x28
[ 463.538782][ T6166] entry_SYSENTER_32+0xa2/0xfb
[ 463.539573][ T6166] EIP: 0xb7f97579
[ 463.540223][ T6166] Code: b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 00 00 00 00 00 00 00 00 00 00 00 00 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76
[ 463.543212][ T6166] EAX: ffffffda EBX: 000000f0 ECX: 026d6120 EDX: 00000098
[ 463.544449][ T6166] ESI: 28282828 EDI: f0309dea EBP: 000000c2 ESP: bfa8f62c
[ 463.545572][ T6166] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000296
[ 463.546837][ T6166] BUG: sleeping function called from invalid context at lib/iov_iter.c:185
[ 463.548162][ T6166] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 6166, name: trinity-c4
[ 463.548958][ T6166] preempt_count: 1, expected: 0
[ 463.549406][ T6166] 3 locks held by trinity-c4/6166:
[ 463.550089][ T6166] #0: eafe0bac (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x42/0x64
[ 463.551473][ T6166] #1: ca58af5c (&p->lock){+.+.}-{3:3}, at: seq_read_iter+0x43/0x470
[ 463.552840][ T6166] #2: c42177b0 (rcu_read_lock){....}-{1:2}, at: afs_proc_addr_prefs_show+0x28/0x284
[ 463.554393][ T6166] CPU: 1 PID: 6166 Comm: trinity-c4 Tainted: G W N 6.7.0-rc7-00024-gf94f70d39cc2 #1 8c9fc74f21af2a18f53bcba9406b4039ea273cf9
[ 463.555905][ T6166] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 463.557701][ T6166] Call Trace:
[ 463.558373][ T6166] dump_stack_lvl+0x9a/0xdc
[ 463.559211][ T6166] dump_stack+0xd/0x14
[ 463.560000][ T6166] __might_resched+0x13d/0x2b4
[ 463.560840][ T6166] __might_sleep+0x2e/0x80
[ 463.561674][ T6166] __might_fault+0x29/0x78
[ 463.562476][ T6166] _copy_to_iter+0x2e/0x560
[ 463.563270][ T6166] ? __check_heap_object+0x32/0xc8
[ 463.564106][ T6166] ? check_heap_object+0x16b/0x19c
[ 463.565052][ T6166] ? __check_object_size+0x5e/0x118
[ 463.565935][ T6166] seq_read_iter+0x3bc/0x470
[ 463.566735][ T6166] seq_read+0x7f/0x9c
[ 463.567450][ T6166] ? seq_read_iter+0x470/0x470
[ 463.568297][ T6166] proc_reg_read+0x60/0x90
[ 463.569119][ T6166] ? proc_reg_write+0x90/0x90
[ 463.569926][ T6166] do_loop_readv_writev+0x4a/0xb4
[ 463.570855][ T6166] do_iter_read+0x105/0x170
[ 463.571623][ T6166] do_readv+0xac/0x190
[ 463.572011][ T6166] __ia32_sys_readv+0x12/0x18
[ 463.572437][ T6166] __do_fast_syscall_32+0x72/0xd8
[ 463.572890][ T6166] ? find_held_lock+0x24/0x74
[ 463.573320][ T6166] ? __lock_release+0x4a/0x14c
[ 463.573791][ T6166] ? __task_pid_nr_ns+0x78/0x1fc
[ 463.574233][ T6166] ? syscall_exit_work+0xe8/0x11c
[ 463.574682][ T6166] ? lockdep_hardirqs_on_prepare+0xa4/0x154
[ 463.577047][ T6166] ? syscall_exit_to_user_mode+0x3a/0x50
[ 463.577546][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.578005][ T6166] ? syscall_exit_to_user_mode+0x3a/0x50
[ 463.578496][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.578954][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.579408][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.579868][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.580330][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.580796][ T6166] ? irqentry_exit_to_user_mode+0x28/0x2c
[ 463.581306][ T6166] ? irqentry_exit+0x7f/0xc8
[ 463.581726][ T6166] do_fast_syscall_32+0x29/0x60
[ 463.582160][ T6166] do_SYSENTER_32+0x15/0x28
[ 463.582581][ T6166] entry_SYSENTER_32+0xa2/0xfb
[ 463.583021][ T6166] EIP: 0xb7f97579
[ 463.583376][ T6166] Code: b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 00 00 00 00 00 00 00 00 00 00 00 00 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76
[ 463.585266][ T6166] EAX: ffffffda EBX: 000000f0 ECX: 026d6120 EDX: 00000098
[ 463.585879][ T6166] ESI: 28282828 EDI: f0309dea EBP: 000000c2 ESP: bfa8f62c
[ 463.586476][ T6166] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000296
[ 463.587208][ T6166]
[ 463.587463][ T6166] =============================
[ 463.587892][ T6166] [ BUG: Invalid wait context ]
[ 463.588326][ T6166] 6.7.0-rc7-00024-gf94f70d39cc2 #1 Tainted: G W N
[ 463.588990][ T6166] -----------------------------
[ 463.589774][ T6166] trinity-c4/6166 is trying to lock:
[ 463.590685][ T6166] edb6caf8 (&mm->mmap_lock){++++}-{3:3}, at: __might_fault+0x33/0x78
[ 463.592172][ T6166] other info that might help us debug this:
[ 463.593196][ T6166] context-{4:4}
[ 463.593900][ T6166] 3 locks held by trinity-c4/6166:
[ 463.594815][ T6166] #0: eafe0bac (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x42/0x64
[ 463.596352][ T6166] #1: ca58af5c (&p->lock){+.+.}-{3:3}, at: seq_read_iter+0x43/0x470
[ 463.597784][ T6166] #2: c42177b0 (rcu_read_lock){....}-{1:2}, at: afs_proc_addr_prefs_show+0x28/0x284
[ 463.599462][ T6166] stack backtrace:
[ 463.600186][ T6166] CPU: 1 PID: 6166 Comm: trinity-c4 Tainted: G W N 6.7.0-rc7-00024-gf94f70d39cc2 #1 8c9fc74f21af2a18f53bcba9406b4039ea273cf9
[ 463.602527][ T6166] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 463.604314][ T6166] Call Trace:
[ 463.604966][ T6166] dump_stack_lvl+0x6a/0xdc
[ 463.605815][ T6166] dump_stack+0xd/0x14
[ 463.606518][ T6166] __lock_acquire+0x819/0xab4
[ 463.607301][ T6166] ? handle_exception+0x14d/0x14d
[ 463.608188][ T6166] lock_acquire+0x88/0x24c
[ 463.609025][ T6166] ? __might_fault+0x33/0x78
[ 463.609885][ T6166] ? dump_stack+0xd/0x14
[ 463.610678][ T6166] ? __might_resched+0x149/0x2b4
[ 463.611570][ T6166] __might_fault+0x52/0x78
[ 463.612346][ T6166] ? __might_fault+0x33/0x78
[ 463.613091][ T6166] _copy_to_iter+0x2e/0x560
[ 463.613884][ T6166] ? __check_heap_object+0x32/0xc8
[ 463.614734][ T6166] ? check_heap_object+0x16b/0x19c
[ 463.615576][ T6166] ? __check_object_size+0x5e/0x118
[ 463.616409][ T6166] seq_read_iter+0x3bc/0x470
[ 463.617267][ T6166] seq_read+0x7f/0x9c
[ 463.617968][ T6166] ? seq_read_iter+0x470/0x470
[ 463.618746][ T6166] proc_reg_read+0x60/0x90
[ 463.619605][ T6166] ? proc_reg_write+0x90/0x90
[ 463.620463][ T6166] do_loop_readv_writev+0x4a/0xb4
[ 463.621425][ T6166] do_iter_read+0x105/0x170
[ 463.622206][ T6166] do_readv+0xac/0x190
[ 463.622979][ T6166] __ia32_sys_readv+0x12/0x18
[ 463.623772][ T6166] __do_fast_syscall_32+0x72/0xd8
[ 463.624696][ T6166] ? find_held_lock+0x24/0x74
[ 463.625509][ T6166] ? __lock_release+0x4a/0x14c
[ 463.626438][ T6166] ? __task_pid_nr_ns+0x78/0x1fc
[ 463.627291][ T6166] ? syscall_exit_work+0xe8/0x11c
[ 463.628124][ T6166] ? lockdep_hardirqs_on_prepare+0xa4/0x154
[ 463.629190][ T6166] ? syscall_exit_to_user_mode+0x3a/0x50
[ 463.630134][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.631033][ T6166] ? syscall_exit_to_user_mode+0x3a/0x50
[ 463.631985][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.632844][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.633769][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.634643][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.635509][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.636422][ T6166] ? irqentry_exit_to_user_mode+0x28/0x2c
[ 463.637387][ T6166] ? irqentry_exit+0x7f/0xc8
[ 463.638147][ T6166] do_fast_syscall_32+0x29/0x60
[ 463.639006][ T6166] do_SYSENTER_32+0x15/0x28
[ 463.639801][ T6166] entry_SYSENTER_32+0xa2/0xfb
[ 463.640619][ T6166] EIP: 0xb7f97579
[ 463.641254][ T6166] Code: b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 00 00 00 00 00 00 00 00 00 00 00 00 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76
[ 463.644248][ T6166] EAX: ffffffda EBX: 000000f0 ECX: 026d6120 EDX: 00000098
[ 463.645377][ T6166] ESI: 28282828 EDI: f0309dea EBP: 000000c2 ESP: bfa8f62c
[ 463.646509][ T6166] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000296
[ 463.647839][ T6166] BUG: scheduling while atomic: trinity-c4/6166/0x00000002
[ 463.648647][ T6166] INFO: lockdep is turned off.
[ 463.649073][ T6166] Modules linked in:
[ 463.649442][ T6166] CPU: 1 PID: 6166 Comm: trinity-c4 Tainted: G W N 6.7.0-rc7-00024-gf94f70d39cc2 #1 8c9fc74f21af2a18f53bcba9406b4039ea273cf9
[ 463.651023][ T6166] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 463.652664][ T6166] Call Trace:
[ 463.653262][ T6166] dump_stack_lvl+0x9a/0xdc
[ 463.654054][ T6166] dump_stack+0xd/0x14
[ 463.654530][ T6166] __schedule_bug+0x5e/0x84
[ 463.655373][ T6166] schedule_debug+0x1e3/0x218
[ 463.656163][ T6166] __schedule+0x4d/0x774
[ 463.656896][ T6166] schedule+0x3b/0x130
[ 463.657618][ T6166] exit_to_user_mode_prepare+0xb9/0x1f0
[ 463.658529][ T6166] syscall_exit_to_user_mode+0x1a/0x50
[ 463.659522][ T6166] __do_fast_syscall_32+0x7c/0xd8
[ 463.660434][ T6166] ? find_held_lock+0x24/0x74
[ 463.661236][ T6166] ? __lock_release+0x4a/0x14c
[ 463.662112][ T6166] ? __task_pid_nr_ns+0x78/0x1fc
[ 463.662933][ T6166] ? syscall_exit_work+0xe8/0x11c
[ 463.663835][ T6166] ? lockdep_hardirqs_on_prepare+0xa4/0x154
[ 463.664901][ T6166] ? syscall_exit_to_user_mode+0x3a/0x50
[ 463.665826][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.666757][ T6166] ? syscall_exit_to_user_mode+0x3a/0x50
[ 463.667763][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.668716][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.669590][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.670485][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.671345][ T6166] ? __do_fast_syscall_32+0x7c/0xd8
[ 463.672263][ T6166] ? irqentry_exit_to_user_mode+0x28/0x2c
[ 463.673209][ T6166] ? irqentry_exit+0x7f/0xc8
[ 463.673998][ T6166] do_fast_syscall_32+0x29/0x60
[ 463.674808][ T6166] do_SYSENTER_32+0x15/0x28
[ 463.675583][ T6166] entry_SYSENTER_32+0xa2/0xfb
[ 463.676478][ T6166] EIP: 0xb7f97579
[ 463.677205][ T6166] Code: b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 00 00 00 00 00 00 00 00 00 00 00 00 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76
[ 463.680209][ T6166] EAX: 00000009 EBX: 000000f0 ECX: 026d6120 EDX: 00000098
[ 463.681363][ T6166] ESI: 28282828 EDI: f0309dea EBP: 000000c2 ESP: bfa8f62c
[ 463.682516][ T6166] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000296



The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240117/202401172243.cd53d5f6-oliver.sang@xxxxxxxxx



--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki