Message-ID: <202212141512.469bca4-yujie.liu@intel.com>
Date:   Wed, 14 Dec 2022 16:45:38 +0800
From:   kernel test robot <yujie.liu@...el.com>
To:     Yafang Shao <laoar.shao@...il.com>
CC:     <oe-lkp@...ts.linux.dev>, <lkp@...el.com>,
        <linux-kernel@...r.kernel.org>, <linux-fsdevel@...r.kernel.org>,
        <bpf@...r.kernel.org>, <ast@...nel.org>, <daniel@...earbox.net>,
        <andrii@...nel.org>, <kafai@...com>, <songliubraving@...com>,
        <yhs@...com>, <john.fastabend@...il.com>, <kpsingh@...nel.org>,
        <sdf@...gle.com>, <haoluo@...gle.com>, <jolsa@...nel.org>,
        <tj@...nel.org>, <dennis@...nel.org>, <cl@...ux.com>,
        <akpm@...ux-foundation.org>, <penberg@...nel.org>,
        <rientjes@...gle.com>, <iamjoonsoo.kim@....com>, <vbabka@...e.cz>,
        <roman.gushchin@...ux.dev>, <42.hyeyoo@...il.com>,
        <linux-mm@...ck.org>, Yafang Shao <laoar.shao@...il.com>
Subject: Re: [RFC PATCH bpf-next 9/9] bpf: Use active vm to account bpf map
 memory usage

Greeting,

FYI, we noticed WARNING:suspicious_RCU_usage due to commit (built with gcc-11):

commit: 8f13ff79ed924e23a36eb5c610ce48998ed69fd5 ("[RFC PATCH bpf-next 9/9] bpf: Use active vm to account bpf map memory usage")
url: https://github.com/intel-lab-lkp/linux/commits/Yafang-Shao/mm-bpf-Add-BPF-into-proc-meminfo/20221212-083842
base: https://git.kernel.org/cgit/linux/kernel/git/bpf/bpf-next.git master
patch link: https://lore.kernel.org/all/20221212003711.24977-10-laoar.shao@gmail.com/
patch subject: [RFC PATCH bpf-next 9/9] bpf: Use active vm to account bpf map memory usage

in testcase: boot

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

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


[   31.975760][    T1] WARNING: suspicious RCU usage
[   31.976682][    T1] 6.1.0-rc7-01609-g8f13ff79ed92 #5 Not tainted
[   31.977802][    T1] -----------------------------
[   31.978710][    T1] include/linux/rcupdate.h:376 Illegal context switch in RCU read-side critical section!
[   31.980465][    T1]
[   31.980465][    T1] other info that might help us debug this:
[   31.980465][    T1]
[   31.982355][    T1]
[   31.982355][    T1] rcu_scheduler_active = 2, debug_locks = 1
[   31.983818][    T1] 1 lock held by swapper/0/1:
[ 31.984695][ T1] #0: ffffffff853269a0 (rcu_read_lock){....}-{1:2}, at: page_ext_get (??:?) 
[   31.986346][    T1]
[   31.986346][    T1] stack backtrace:
[   31.987467][    T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.1.0-rc7-01609-g8f13ff79ed92 #5
[   31.989054][    T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
[   31.990880][    T1] Call Trace:
[   31.991554][    T1]  <TASK>
[ 31.992173][ T1] dump_stack_lvl (??:?) 
[ 31.993034][ T1] __might_resched (??:?) 
[ 31.993970][ T1] __kmem_cache_alloc_node (??:?) 
[ 31.994993][ T1] ? active_vm_slab_add (??:?) 
[ 31.995976][ T1] ? active_vm_slab_add (??:?) 
[ 31.996918][ T1] __kmalloc_node (??:?) 
[ 31.997789][ T1] active_vm_slab_add (??:?) 
[ 31.998727][ T1] ? kasan_unpoison (??:?) 
[ 31.999615][ T1] __kmem_cache_alloc_node (??:?) 
[ 32.000615][ T1] ? __bpf_map_area_alloc (syscall.c:?) 
[ 32.001599][ T1] ? __bpf_map_area_alloc (syscall.c:?) 
[ 32.002575][ T1] __kmalloc_node (??:?) 
[ 32.003439][ T1] __bpf_map_area_alloc (syscall.c:?) 
[ 32.004417][ T1] array_map_alloc (arraymap.c:?) 
[ 32.005326][ T1] map_create (syscall.c:?) 
[ 32.006173][ T1] __sys_bpf (syscall.c:?) 
[ 32.006988][ T1] ? link_create (syscall.c:?) 
[ 32.007873][ T1] ? lock_downgrade (lockdep.c:?) 
[ 32.008790][ T1] kern_sys_bpf (??:?) 
[ 32.009636][ T1] ? bpf_sys_bpf (??:?) 
[ 32.010469][ T1] ? trace_hardirqs_on (??:?) 
[ 32.011395][ T1] ? _raw_spin_unlock_irqrestore (??:?) 
[ 32.012432][ T1] ? __stack_depot_save (??:?) 
[ 32.013391][ T1] skel_map_create+0xba/0xeb 
[ 32.014423][ T1] ? skel_map_update_elem+0xe3/0xe3 
[ 32.015527][ T1] ? kasan_save_stack (??:?) 
[ 32.016422][ T1] ? kasan_set_track (??:?) 
[ 32.017308][ T1] ? __kasan_kmalloc (??:?) 
[ 32.018233][ T1] ? kernel_init (main.c:?) 
[ 32.019090][ T1] ? lock_acquire (??:?) 
[ 32.019968][ T1] ? find_held_lock (lockdep.c:?) 
[ 32.020858][ T1] ? __kmem_cache_alloc_node (??:?) 
[ 32.021875][ T1] bpf_load_and_run+0x93/0x3f5 
[ 32.022920][ T1] ? skel_map_create+0xeb/0xeb 
[ 32.023959][ T1] ? lock_downgrade (lockdep.c:?) 
[ 32.024885][ T1] ? __kmem_cache_alloc_node (??:?) 
[ 32.025919][ T1] ? load_skel (bpf_preload_kern.c:?) 
[ 32.026767][ T1] ? rcu_read_lock_sched_held (??:?) 
[ 32.027781][ T1] ? __kmalloc_node (??:?) 
[ 32.030065][ T1] load_skel (bpf_preload_kern.c:?) 
[ 32.030869][ T1] ? bpf_load_and_run+0x3f5/0x3f5 
[ 32.031963][ T1] ? kvm_clock_get_cycles (kvmclock.c:?) 
[ 32.032914][ T1] ? btf_vmlinux_init (bpf_preload_kern.c:?) 
[ 32.033801][ T1] load (bpf_preload_kern.c:?) 
[ 32.034501][ T1] ? btf_vmlinux_init (bpf_preload_kern.c:?) 
[ 32.035407][ T1] do_one_initcall (??:?) 
[ 32.036266][ T1] ? trace_event_raw_event_initcall_level (??:?) 
[ 32.037446][ T1] ? parse_one (??:?) 
[ 32.038320][ T1] ? __kmem_cache_alloc_node (??:?) 
[ 32.039369][ T1] do_initcalls (main.c:?) 
[ 32.040314][ T1] kernel_init_freeable (main.c:?) 
[ 32.041304][ T1] ? console_on_rootfs (main.c:?) 
[ 32.042213][ T1] ? usleep_range_state (??:?) 
[ 32.043197][ T1] ? rest_init (main.c:?) 
[ 32.044036][ T1] ? rest_init (main.c:?) 
[ 32.044879][ T1] kernel_init (main.c:?) 
[ 32.045715][ T1] ret_from_fork (??:?) 
[   32.046587][    T1]  </TASK>
[   32.047273][    T1] BUG: sleeping function called from invalid context at include/linux/sched/mm.h:274
[   32.048966][    T1] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 1, name: swapper/0
[   32.050596][    T1] preempt_count: 1, expected: 0
[   32.051521][    T1] 1 lock held by swapper/0/1:
[ 32.052424][ T1] #0: ffffffff853269a0 (rcu_read_lock){....}-{1:2}, at: page_ext_get (??:?) 
[   32.054113][    T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.1.0-rc7-01609-g8f13ff79ed92 #5
[   32.055686][    T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
[   32.057527][    T1] Call Trace:
[   32.058191][    T1]  <TASK>
[ 32.058803][ T1] dump_stack_lvl (??:?) 
[ 32.059668][ T1] __might_resched.cold (core.c:?) 
[ 32.060638][ T1] __kmem_cache_alloc_node (??:?) 
[ 32.061654][ T1] ? active_vm_slab_add (??:?) 
[ 32.062615][ T1] ? active_vm_slab_add (??:?) 
[ 32.063557][ T1] __kmalloc_node (??:?) 
[ 32.064421][ T1] active_vm_slab_add (??:?) 
[ 32.065373][ T1] ? kasan_unpoison (??:?) 
[ 32.066294][ T1] __kmem_cache_alloc_node (??:?) 
[ 32.067294][ T1] ? __bpf_map_area_alloc (syscall.c:?) 
[ 32.068314][ T1] ? __bpf_map_area_alloc (syscall.c:?) 
[ 32.069306][ T1] __kmalloc_node (??:?) 
[ 32.070215][ T1] __bpf_map_area_alloc (syscall.c:?) 
[ 32.071210][ T1] array_map_alloc (arraymap.c:?) 
[ 32.072134][ T1] map_create (syscall.c:?) 
[ 32.072972][ T1] __sys_bpf (syscall.c:?) 
[ 32.073810][ T1] ? link_create (syscall.c:?) 
[ 32.074693][ T1] ? lock_downgrade (lockdep.c:?) 
[ 32.075609][ T1] kern_sys_bpf (??:?) 
[ 32.076455][ T1] ? bpf_sys_bpf (??:?) 
[ 32.077295][ T1] ? trace_hardirqs_on (??:?) 
[ 32.078232][ T1] ? _raw_spin_unlock_irqrestore (??:?) 
[ 32.079288][ T1] ? __stack_depot_save (??:?) 
[ 32.080258][ T1] skel_map_create+0xba/0xeb 
[ 32.081264][ T1] ? skel_map_update_elem+0xe3/0xe3 
[ 32.082356][ T1] ? kasan_save_stack (??:?) 
[ 32.083234][ T1] ? kasan_set_track (??:?) 
[ 32.084107][ T1] ? __kasan_kmalloc (??:?) 
[ 32.085024][ T1] ? kernel_init (main.c:?) 
[ 32.085901][ T1] ? lock_acquire (??:?) 
[ 32.086784][ T1] ? find_held_lock (lockdep.c:?) 
[ 32.087674][ T1] ? __kmem_cache_alloc_node (??:?) 
[ 32.088715][ T1] bpf_load_and_run+0x93/0x3f5 
[ 32.090649][ T1] ? skel_map_create+0xeb/0xeb 
[ 32.091749][ T1] ? lock_downgrade (lockdep.c:?) 
[ 32.092728][ T1] ? __kmem_cache_alloc_node (??:?) 
[ 32.093794][ T1] ? load_skel (bpf_preload_kern.c:?) 
[ 32.094612][ T1] ? rcu_read_lock_sched_held (??:?) 
[ 32.095606][ T1] ? __kmalloc_node (??:?) 
[ 32.096490][ T1] load_skel (bpf_preload_kern.c:?) 
[ 32.097314][ T1] ? bpf_load_and_run+0x3f5/0x3f5 
[ 32.098412][ T1] ? kvm_clock_get_cycles (kvmclock.c:?) 
[ 32.099362][ T1] ? btf_vmlinux_init (bpf_preload_kern.c:?) 
[ 32.100271][ T1] load (bpf_preload_kern.c:?) 
[ 32.100966][ T1] ? btf_vmlinux_init (bpf_preload_kern.c:?) 
[ 32.101872][ T1] do_one_initcall (??:?) 
[ 32.102719][ T1] ? trace_event_raw_event_initcall_level (??:?) 
[ 32.103859][ T1] ? parse_one (??:?) 
[ 32.104645][ T1] ? __kmem_cache_alloc_node (??:?) 
[ 32.105625][ T1] do_initcalls (main.c:?) 
[ 32.106438][ T1] kernel_init_freeable (main.c:?) 
[ 32.107333][ T1] ? console_on_rootfs (main.c:?) 
[ 32.108213][ T1] ? usleep_range_state (??:?) 
[ 32.109175][ T1] ? rest_init (main.c:?) 
[ 32.110000][ T1] ? rest_init (main.c:?) 
[ 32.110836][ T1] kernel_init (main.c:?) 
[ 32.111633][ T1] ret_from_fork (??:?) 
[   32.112419][    T1]  </TASK>
[ 32.144051][ T1] initcall load+0x0/0x4a returned 0 after 169883 usecs 


If you fix the issue, kindly add following tag
| Reported-by: kernel test robot <yujie.liu@...el.com>
| Link: https://lore.kernel.org/oe-lkp/202212141512.469bca4-yujie.liu@intel.com


To reproduce:

        # build kernel
	cd linux
	cp config-6.1.0-rc7-01609-g8f13ff79ed92 .config
	make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
	make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 INSTALL_MOD_PATH=<mod-install-dir> modules_install
	cd <mod-install-dir>
	find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz


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

        # if come across any failure that blocks the test,
        # please remove ~/.lkp and /lkp dir to run from a clean state.


-- 
0-DAY CI Kernel Test Service
https://01.org/lkp

View attachment "config-6.1.0-rc7-01609-g8f13ff79ed92" of type "text/plain" (171166 bytes)

View attachment "job-script" of type "text/plain" (5162 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (32844 bytes)

Powered by blists - more mailing lists