Subject: [xdp] 9cb54e254c: kernel/bpf/devmap.c:#suspicious_rcu_dereference_check()

From: kernel test robot <[email-masked]>
Date: Wed, 10 Apr 2019 15:59:55 +0800

FYI, we noticed the following commit (built with gcc-7):

commit: 9cb54e254ca479ce636857a1fd1e1a3e9f8796b1 ("[PATCH net-next v4 4/6] xdp: Always use a devmap for XDP_REDIRECT to a device")
url: https://github.com/0day-ci/linux/commits/Toke-H-iland-J-rgensen/xdp-Use-a-default-map-for-xdp_redirect-helper/20190409-161851

in testcase: trinity
with following parameters:

	runtime: 300s

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

on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 8G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):

+--------------------------------------------------------------+------------+------------+
|                                                              | c76c665440 | 9cb54e254c |
+--------------------------------------------------------------+------------+------------+
| boot_successes                                               | 0          | 0          |
| boot_failures                                                | 40         | 38         |
| BUG:kernel_reboot-without-warning_in_test_stage              | 28         | 10         |
| BUG:kernel_hang_in_boot_stage                                | 12         | 12         |
| WARNING:suspicious_RCU_usage                                 | 0          | 16         |
| kernel/bpf/devmap.c:#suspicious_rcu_dereference_check()usage | 0          | 16         |
+--------------------------------------------------------------+------------+------------+

[  413.653218] WARNING: suspicious RCU usage
[  413.654564] 5.1.0-rc4-00599-g9cb54e2 #43 Tainted: G                T
[  413.656563] -----------------------------
[  413.657808] kernel/bpf/devmap.c:807 suspicious rcu_dereference_check() usage!
[  413.660285] 
[  413.660285] other info that might help us debug this:
[  413.660285] 
[  413.662614] 
[  413.662614] rcu_scheduler_active = 2, debug_locks = 1
[  413.664483] 2 locks held by trinity-c3/2248:
[  413.665800]  #0: 00000000713e8e50 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x81/0x90
[  413.668184]  #1: 000000005e54a26c (&p->lock){+.+.}, at: seq_lseek+0x42/0x1c0
[  413.670412] 
[  413.670412] stack backtrace:
[  413.671876] CPU: 0 PID: 2248 Comm: trinity-c3 Tainted: G                T 5.1.0-rc4-00599-g9cb54e2 #43
[  413.674557] Call Trace:
[  413.675374]  dump_stack+0x1e/0x28
[  413.676366]  lockdep_rcu_suspicious+0xc6/0xd0
[  413.677802]  dev_map_default_show+0x84/0xd0
[  413.679118]  traverse+0x185/0x3a0
[  413.680144]  ? kasan_check_write+0x14/0x20
[  413.681584]  seq_lseek+0xc5/0x1c0
[  413.682625]  ? traverse+0x3a0/0x3a0
[  413.683709]  proc_reg_llseek+0x167/0x1c0
[  413.684868]  ? proc_reg_compat_ioctl+0x1c0/0x1c0
[  413.686259]  ? mutex_lock_nested+0x16/0x20
[  413.687564]  ? mutex_lock_nested+0x16/0x20
[  413.688837]  ? proc_reg_compat_ioctl+0x1c0/0x1c0
[  413.690192]  ksys_lseek+0xa0/0xf0
[  413.691236]  __x64_sys_lseek+0x43/0x50
[  413.692445]  do_syscall_64+0xe6/0x300
[  413.693583]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[  413.695037] RIP: 0033:0x7fb8e65fe229
[  413.696139] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 3f 4c 2b 00 f7 d8 64 89 01 48
[  413.701836] RSP: 002b:00007ffd1697bac8 EFLAGS: 00000246 ORIG_RAX: 0000000000000008
[  413.704257] RAX: ffffffffffffffda RBX: 0000000000000008 RCX: 00007fb8e65fe229
[  413.706652] RDX: 0000000000000000 RSI: 0000000063473000 RDI: 00000000000000f5
[  413.709095] RBP: 00007ffd1697bb70 R08: 00000000b0b0b0b0 R09: 00000000000000c3
[  413.711564] R10: 00000000000000e5 R11: 0000000000000246 R12: 0000000000000002
[  413.713741] R13: 00007fb8e6cbf058 R14: 00007fb8e6cdbad8 R15: 00007fb8e6cbf000
[  415.646701] audit: type=1326 audit(1554841252.872:9): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=2248 comm="trinity-c3" exe="/bin/trinity" sig=9 arch=c000003e syscall=8 compat=0 ip=0x7fb8e6602af7 code=0x0
[  415.693868] [main] 72412 iterations. [F:53177 S:18860 HI:6902]
[  415.693916] 
[  419.221834] audit: type=1326 audit(1554841256.447:10): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=2242 comm="trinity-c2" exe="/bin/trinity" sig=9 arch=c000003e syscall=8 compat=0 ip=0x7fb8e6602af7 code=0x0
[  429.312667] futex_wake_op: trinity-c1 tries to shift op by -1; fix this program
         Starting watchdog daemon...
         Starting Update UTMP about System Runlevel Changes...
[  432.328622] /usr/bin/wget -q --timeout=1800 --tries=1 --local-encoding=UTF-8 http://inn:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_file=/lkp/jobs/scheduled/vm-snb-8G-403/trinity-300s-debian-x86_64-2018-04-03.cgz-9cb54e254ca479ce636857a1f-20190410-37809-1kfa908-13.yaml&job_state=post_run -O /dev/null
[  432.328713] 
[  433.522651] [main] 82413 iterations. [F:60456 S:21535 HI:6902]
[  433.522701] 
[  434.281131] kill 425 vmstat --timestamp -n 10 
[  434.281178] 
[  434.581017] kill 421 dmesg --follow --decode 
[  434.581063] 
[  434.870409] wait for background processes: 427 430 meminfo oom-killer
[  434.870459] 
[  436.023637] audit: type=1326 audit(1554841273.249:11): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=2376 comm="trinity-c2" exe="/bin/trinity" sig=9 arch=c000003e syscall=8 compat=0 ip=0x7fb8e6602af7 code=0x0
[  438.850687] audit: type=1326 audit(1554841276.076:12): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=2505 comm="trinity-c2" exe="/bin/trinity" sig=9 arch=c000003e syscall=8 compat=0 ip=0x7fb8e6602af7 code=0x0
[  445.550815] sysrq: Emergency Sync
[  445.555099] Emergency Sync complete
[  445.560379] sysrq: Resetting

Elapsed time: 440

qemu-img create -f qcow2 disk-vm-snb-8G-403-0 256G
qemu-img create -f qcow2 disk-vm-snb-8G-403-1 256G
qemu-img create -f qcow2 disk-vm-snb-8G-403-2 256G
qemu-img create -f qcow2 disk-vm-snb-8G-403-3 256G
qemu-img create -f qcow2 disk-vm-snb-8G-403-4 256G
qemu-img create -f qcow2 disk-vm-snb-8G-403-5 256G
qemu-img create -f qcow2 disk-vm-snb-8G-403-6 256G

kvm=(
	qemu-system-x86_64
	-enable-kvm
	-cpu SandyBridge
	-kernel $kernel
	-initrd initrd-vm-snb-8G-403
	-m 8192
	-smp 2
	-device e1000,netdev=net0
	-netdev user,id=net0,hostfwd=tcp::26402-:22
	-boot order=nc
	-no-reboot
	-watchdog i6300esb
	-watchdog-action debug
	-rtc base=localtime
	-drive file=disk-vm-snb-8G-403-0,media=disk,if=virtio
	-drive file=disk-vm-snb-8G-403-1,media=disk,if=virtio
	-drive file=disk-vm-snb-8G-403-2,media=disk,if=virtio
	-drive file=disk-vm-snb-8G-403-3,media=disk,if=virtio
	-drive file=disk-vm-snb-8G-403-4,media=disk,if=virtio
	-drive file=disk-vm-snb-8G-403-5,media=disk,if=virtio
	-drive file=disk-vm-snb-8G-403-6,media=disk,if=virtio
	-serial stdio
	-display none
	-monitor null
)

append=(

To reproduce:

        # build kernel
	cd linux
	cp config-5.1.0-rc4-00599-g9cb54e2 .config
	make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 olddefconfig
	make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 prepare
	make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 modules_prepare
	make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 SHELL=/bin/bash
	make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 bzImage

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email

Thanks,
Rong Chen