lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite for Android: free password hash cracker in your pocket
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date:   Sat, 5 Mar 2022 09:47:00 +0800
From:   Zhouyi Zhou <zhouzhouyi@...il.com>
To:     Chengming Zhou <zhouchengming@...edance.com>
Cc:     "Paul E. McKenney" <paulmck@...nel.org>,
        Naresh Kamboju <naresh.kamboju@...aro.org>,
        Linux-Next Mailing List <linux-next@...r.kernel.org>,
        open list <linux-kernel@...r.kernel.org>,
        lkft-triage@...ts.linaro.org, rcu <rcu@...r.kernel.org>,
        Stephen Rothwell <sfr@...b.auug.org.au>,
        Peter Zijlstra <peterz@...radead.org>,
        Ingo Molnar <mingo@...hat.com>, Will Deacon <will@...nel.org>
Subject: Re: [External] Re: [next] WARNING: suspicious RCU usage :
 include/linux/cgroup.h:494 suspicious rcu_dereference_check() usage

Hi Chengming

On Sat, Mar 5, 2022 at 8:57 AM Chengming Zhou
<zhouchengming@...edance.com> wrote:
>
> On 2022/3/5 4:28 上午, Zhouyi Zhou wrote:
> > Hi Paul
> >
> > Yes, your suggestion works!
> > Thank you for your guidance, this is the first time I ever did a
> > bisection, I gained greatly during this process!
>
> Hi Zhouyi, thanks for the bisection test.
You are very welcome ;-)
> Could this patch solve RCU warning? I just tested on my machine and there
> is no RCU warning any more.
Yes! your patch solve RCU warnings!
>
> diff --git a/include/linux/cgroup.h b/include/linux/cgroup.h
> index 1e356c222756..0d1ada8968d7 100644
> --- a/include/linux/cgroup.h
> +++ b/include/linux/cgroup.h
> @@ -450,6 +450,7 @@ extern struct mutex cgroup_mutex;
>  extern spinlock_t css_set_lock;
>  #define task_css_set_check(task, __c)                                  \
>         rcu_dereference_check((task)->cgroups,                          \
> +               rcu_read_lock_sched_held() ||                           \
>                 lockdep_is_held(&cgroup_mutex) ||                       \
>                 lockdep_is_held(&css_set_lock) ||                       \
>                 ((task)->flags & PF_EXITING) || (__c))
>
before apply your patch, there are RCU warnings in most recent linux-next:
http://154.223.142.244/logs/20220305/log.6d284ba80c0c485bcaa7bdf67f232d572640edc4.txt

afte apply your patch, there are no RCU warnings:
http://154.223.142.244/logs/20220305/log.chengmin.txt

Tested-by: Zhouyi Zhou <zhouzhouyi@...il.com>

Thanks
Zhouyi
> Thanks.
>
> >
> > On Sat, Mar 5, 2022 at 3:44 AM Paul E. McKenney <paulmck@...nel.org> wrote:
> >>
> >> On Sat, Mar 05, 2022 at 03:38:33AM +0800, Zhouyi Zhou wrote:
> >>> Hi,
> >>> I can reproduce these warnings on my X86 VM.
> >>> Following the my backtrace:
> >>>
> >>> (gdb) bt
> >>> #0  lockdep_rcu_suspicious (file=file@...ry=0xffffffff825ea8ff
> >>> "include/linux/cgroup.h", line=line@...ry=494,
> >>>     s=s@...ry=0xffffffff825c5c50 "suspicious rcu_dereference_check()
> >>> usage") at ./arch/x86/include/asm/current.h:15
> >>> #1  0xffffffff81183103 in task_css (subsys_id=2,
> >>> task=0xffff888100804080) at ./include/linux/cgroup.h:494
> >>> #2  task_ca (tsk=0xffff888100804080) at kernel/sched/cpuacct.c:40
> >>> #3  cpuacct_charge (tsk=tsk@...ry=0xffff888100804080,
> >>> cputime=cputime@...ry=3344803) at kernel/sched/cpuacct.c:342
> >>> #4  0xffffffff81162655 in cgroup_account_cputime (delta_exec=3344803,
> >>> task=0xffff888100804080) at ./include/linux/cgroup.h:792
> >>> #5  update_curr (cfs_rq=cfs_rq@...ry=0xffff88813b63f500) at
> >>> kernel/sched/fair.c:907
> >>> #6  0xffffffff81164797 in dequeue_entity (flags=10,
> >>> se=0xffff888100804100, cfs_rq=0xffff88813b63f500) at
> >>> kernel/sched/fair.c:5771
> >>> #7  dequeue_task_fair (rq=0xffff88813b63f440, p=0xffff888100804080,
> >>> flags=10) at kernel/sched/fair.c:5771
> >>> #8  0xffffffff8115412a in dequeue_task (flags=10,
> >>> p=0xffff888100804080, rq=0xffff88813b63f440) at
> >>> kernel/sched/core.c:2019
> >>> #9  __do_set_cpus_allowed (p=0xffff888100804080,
> >>> new_mask=0xffffffff831b4d40 <housekeeping+512>, flags=0) at
> >>> kernel/sched/core.c:2508
> >>> #10 0xffffffff811564ca in __set_cpus_allowed_ptr_locked
> >>> (p=p@...ry=0xffff888100804080,
> >>> new_mask=new_mask@...ry=0xffffffff831b4d40 <housekeeping+512>,
> >>>     flags=flags@...ry=0, rq=0xffff88813b63f440,
> >>> rf=rf@...ry=0xffffc9000012bee8) at kernel/sched/core.c:2841
> >>> #11 0xffffffff81156573 in __set_cpus_allowed_ptr
> >>> (p=p@...ry=0xffff888100804080, new_mask=0xffffffff831b4d40
> >>> <housekeeping+512>, flags=flags@...ry=0)
> >>>     at kernel/sched/core.c:2874
> >>> #12 0xffffffff8115664c in set_cpus_allowed_ptr
> >>> (p=p@...ry=0xffff888100804080, new_mask=<optimized out>) at
> >>> kernel/sched/core.c:2879
> >>> #13 0xffffffff81144676 in kthreadd (unused=<optimized out>) at
> >>> kernel/kthread.c:724
> >>> #14 0xffffffff810019df in ret_from_fork () at arch/x86/entry/entry_64.S:295
> >>> #15 0x0000000000000000 in ?? ()
> >>>
> >>> Do the warnings have something to do with commit
> >>> dc6e0818bc9a0336d9accf3ea35d146d72aa7a18 (sched/cpuacct: Optimize away
> >>> RCU read lock) ?
> >>
> >> If you have not already done so, could you please try running on this
> >> commit and then on the commit immediately preceding it?  Just as a
> >> authoritative way to answer your question.  ;-)
> >>
> >>                                                         Thanx, Paul
> >>
> > git reset --hard dc6e0818bc9a0336d9accf3ea35d146d72aa7a18
> > make -j 16 bindeb-pkg
> > there are RCU WARNINGs:
> > http://154.223.142.244/logs/20220305/log.dc6e0818bc9a0336d9accf3ea35d146d72aa7a18.txt
> >
> > then I running on the commit immediately preceding it
> > git reset --hard 248cc9993d1cc12b8e9ed716cc3fc09f6c3517dd
> > make -j 16 bindeb-pkg
> > the WARNINGs are gone with the wind ;-)
> > http://154.223.142.244/logs/20220305/log.248cc9993d1cc12b8e9ed716cc3fc09f6c3517dd.txt
> >
> > Many thanks
> > Zhouyi
> >>> Many thanks
> >>> Zhouyi
> >>>
> >>> On Fri, Mar 4, 2022 at 10:43 PM Naresh Kamboju
> >>> <naresh.kamboju@...aro.org> wrote:
> >>>>
> >>>> While booting x86_64 with linux next-20220304 kernel the following kernel
> >>>> warning reported [1].
> >>>>
> >>>> metadata:
> >>>>   git_ref: master
> >>>>   git_repo: https://gitlab.com/Linaro/lkft/mirrors/next/linux-next
> >>>>   git_sha: 6d284ba80c0c485bcaa7bdf67f232d572640edc4
> >>>>   git_describe: next-20220304
> >>>>   kernel-config: https://builds.tuxbuild.com/25uuYdm2vTO275aZ3IewZY5sKbU/config
> >>>>
> >>>>
> >>>> warning log:
> >>>> ---------
> >>>> [    1.482171] MDS: Mitigation: Clear CPU buffers
> >>>> [    1.485680] Freeing SMP alternatives memory: 52K
> >>>> [    1.487341]
> >>>> [    1.488169] =============================
> >>>> [    1.488169] WARNING: suspicious RCU usage
> >>>> [    1.488169] 5.17.0-rc6-next-20220304 #1 Not tainted
> >>>> [    1.488169] -----------------------------
> >>>> [    1.488169] include/linux/cgroup.h:494 suspicious
> >>>> rcu_dereference_check() usage!
> >>>> [    1.488169]
> >>>> [    1.488169] other info that might help us debug this:
> >>>> [    1.488169]
> >>>> [    1.488169]
> >>>> [    1.488169] rcu_scheduler_active = 1, debug_locks = 1
> >>>> [    1.488169] 2 locks held by kthreadd/2:
> >>>> [    1.488169]  #0: ffff9ba440352330 (&p->pi_lock){....}-{2:2}, at:
> >>>> task_rq_lock+0x2e/0x130
> >>>> [    1.488169]  #1: ffff9ba7a7a2d058 (&rq->__lock){-...}-{2:2}, at:
> >>>> task_rq_lock+0x5d/0x130
> >>>> [    1.488169]
> >>>> [    1.488169] stack backtrace:
> >>>> [    1.488169] CPU: 0 PID: 2 Comm: kthreadd Not tainted
> >>>> 5.17.0-rc6-next-20220304 #1
> >>>> [    1.488169] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS
> >>>> 2.5 11/26/2020
> >>>> [    1.488169] Call Trace:
> >>>> [    1.488169]  <TASK>
> >>>> [    1.488169]  dump_stack_lvl+0x49/0x5e
> >>>> [    1.488169]  dump_stack+0x10/0x12
> >>>> [    1.488169]  lockdep_rcu_suspicious+0xed/0xf8
> >>>> [    1.488169]  cpuacct_charge+0x10c/0x120
> >>>> [    1.488169]  update_curr+0x165/0x340
> >>>> [    1.488169]  dequeue_entity+0x23/0x430
> >>>> [    1.488169]  dequeue_task_fair+0xba/0x3b0
> >>>> [    1.488169]  __do_set_cpus_allowed+0xca/0x2c0
> >>>> [    1.488169]  __set_cpus_allowed_ptr_locked+0x128/0x1b0
> >>>> [    1.488169]  set_cpus_allowed_ptr+0x43/0x70
> >>>> [    1.488169]  kthreadd+0x49/0x230
> >>>> [    1.488169]  ? kthread_is_per_cpu+0x30/0x30
> >>>> [    1.488169]  ret_from_fork+0x22/0x30
> >>>> [    1.488169]  </TASK>
> >>>> [    1.488169]
> >>>> [    1.488169] =============================
> >>>> [    1.488169] WARNING: suspicious RCU usage
> >>>> [    1.488169] 5.17.0-rc6-next-20220304 #1 Not tainted
> >>>> [    1.488169] -----------------------------
> >>>> [    1.488169] include/linux/cgroup.h:481 suspicious
> >>>> rcu_dereference_check() usage!
> >>>> [    1.488169]
> >>>> [    1.488169] other info that might help us debug this:
> >>>> [    1.488169]
> >>>> [    1.488169]
> >>>> [    1.488169] rcu_scheduler_active = 1, debug_locks = 1
> >>>> [    1.488169] 2 locks held by kthreadd/2:
> >>>> [    1.488169]  #0: ffff9ba440352330 (&p->pi_lock){....}-{2:2}, at:
> >>>> task_rq_lock+0x2e/0x130
> >>>> [    1.488169]  #1: ffff9ba7a7a2d058 (&rq->__lock){-...}-{2:2}, at:
> >>>> task_rq_lock+0x5d/0x130
> >>>> [    1.488169]
> >>>> [    1.488169] stack backtrace:
> >>>> [    1.488169] CPU: 0 PID: 2 Comm: kthreadd Not tainted
> >>>> 5.17.0-rc6-next-20220304 #1
> >>>> [    1.488169] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS
> >>>> 2.5 11/26/2020
> >>>> [    1.488169] Call Trace:
> >>>> [    1.488169]  <TASK>
> >>>> [    1.488169]  dump_stack_lvl+0x49/0x5e
> >>>> [    1.488169]  dump_stack+0x10/0x12
> >>>> [    1.488169]  lockdep_rcu_suspicious+0xed/0xf8
> >>>> [    1.488169]  update_curr+0x2b7/0x340
> >>>> [    1.488169]  dequeue_entity+0x23/0x430
> >>>> [    1.488169]  dequeue_task_fair+0xba/0x3b0
> >>>> [    1.488169]  __do_set_cpus_allowed+0xca/0x2c0
> >>>> [    1.488169]  __set_cpus_allowed_ptr_locked+0x128/0x1b0
> >>>> [    1.488169]  set_cpus_allowed_ptr+0x43/0x70
> >>>> [    1.488169]  kthreadd+0x49/0x230
> >>>> [    1.488169]  ? kthread_is_per_cpu+0x30/0x30
> >>>> [    1.488169]  ret_from_fork+0x22/0x30
> >>>> [    1.488169]  </TASK>
> >>>> [    1.488169]
> >>>> [    1.488169] =============================
> >>>> [    1.488169] WARNING: suspicious RCU usage
> >>>> [    1.488169] 5.17.0-rc6-next-20220304 #1 Not tainted
> >>>> [    1.488169] -----------------------------
> >>>> [    1.488169] include/linux/cgroup.h:481 suspicious
> >>>> rcu_dereference_check() usage!
> >>>> [    1.488169]
> >>>> [    1.488169] other info that might help us debug this:
> >>>> [    1.488169]
> >>>> [    1.488169]
> >>>> [    1.488169] rcu_scheduler_active = 1, debug_locks = 1
> >>>> [    1.488169] no locks held by kthreadd/2.
> >>>> [    1.488169]
> >>>> [    1.488169] stack backtrace:
> >>>> [    1.488169] CPU: 0 PID: 2 Comm: kthreadd Not tainted
> >>>> 5.17.0-rc6-next-20220304 #1
> >>>> [    1.488169] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS
> >>>> 2.5 11/26/2020
> >>>> [    1.488169] Call Trace:
> >>>> [    1.488169]  <IRQ>
> >>>> [    1.488169]  dump_stack_lvl+0x49/0x5e
> >>>> [    1.488169]  dump_stack+0x10/0x12
> >>>> [    1.488169]  lockdep_rcu_suspicious+0xed/0xf8
> >>>> [    1.488169]  account_system_index_time+0x127/0x130
> >>>> [    1.488169]  account_system_time+0x50/0x60
> >>>> [    1.488169]  account_process_tick+0x59/0x80
> >>>> [    1.488169]  update_process_times+0x58/0xe0
> >>>> [    1.488169]  tick_periodic+0x37/0xf0
> >>>> [    1.488169]  tick_handle_periodic+0x24/0x70
> >>>> [    1.488169]  timer_interrupt+0x18/0x20
> >>>> [    1.488169]  __handle_irq_event_percpu+0x95/0x2f0
> >>>> [    1.488169]  handle_irq_event+0x39/0x80
> >>>> [    1.488169]  handle_edge_irq+0xa4/0x240
> >>>> [    1.488169]  __common_interrupt+0x8d/0x170
> >>>> [    1.488169]  common_interrupt+0xbd/0xe0
> >>>> [    1.488169]  </IRQ>
> >>>> [    1.488169]  <TASK>
> >>>> [    1.488169]  asm_common_interrupt+0x1e/0x40
> >>>> [    1.488169] RIP: 0010:_raw_spin_unlock_irqrestore+0x37/0x60
> >>>> [    1.488169] Code: fc 48 83 c7 18 53 48 89 f3 48 8b 75 08 e8 21 83
> >>>> ed fe 4c 89 e7 e8 19 b0 ed fe 80 e7 02 74 06 e8 6f 77 fa fe fb bf 01
> >>>> 00 00 00 <e8> 24 6b e9 fe 65 8b 05 bd e1 28 66 85 c0 74 05 5b 41 5c 5d
> >>>> c3 0f
> >>>> [    1.488169] RSP: 0000:ffffb75b0002fd50 EFLAGS: 00000202
> >>>> [    1.488169] RAX: 0000000000000007 RBX: 0000000000000246 RCX: 0000000000000000
> >>>> [    1.488169] RDX: 0000000000000000 RSI: ffffffff9a800a7c RDI: 0000000000000001
> >>>> [    1.488169] RBP: ffffb75b0002fd60 R08: 0000000000000001 R09: 0000000000000001
> >>>> [    1.488169] R10: 0000000000000002 R11: 0000000000000001 R12: ffff9ba440352318
> >>>> [    1.488169] R13: 0000000000000000 R14: 0000000000000000 R15: ffff9ba7a7a2d040
> >>>> [    1.488169]  affine_move_task+0x2d4/0x5d0
> >>>> [    1.488169]  ? __this_cpu_preempt_check+0x13/0x20
> >>>> [    1.488169]  ? lock_is_held_type+0xdd/0x130
> >>>> [    1.488169]  ? enqueue_entity+0x1b8/0x520
> >>>> [    1.488169]  __set_cpus_allowed_ptr_locked+0x15c/0x1b0
> >>>> [    1.488169]  set_cpus_allowed_ptr+0x43/0x70
> >>>> [    1.488169]  kthreadd+0x49/0x230
> >>>> [    1.488169]  ? kthread_is_per_cpu+0x30/0x30
> >>>> [    1.488169]  ret_from_fork+0x22/0x30
> >>>> [    1.488169]  </TASK>
> >>>> [    1.489211] smpboot: Estimated ratio of average max frequency by
> >>>> base frequency (times 1024): 1126
> >>>> [    1.490189] smpboot: CPU0: Intel(R) Xeon(R) CPU E3-1220 v6 @
> >>>> 3.00GHz (family: 0x6, model: 0x9e, stepping: 0x9)
> >>>> [    1.491635] cblist_init_generic: Setting adjustable number of
> >>>> callback queues.
> >>>> [    1.492171] cblist_init_generic: Setting shift to 2 and lim to 1.
> >>>> [    1.493226] cblist_init_generic: Setting shift to 2 and lim to 1.
> >>>> [    1.494226] cblist_init_generic: Setting shift to 2 and lim to 1.
> >>>> [    1.495219] Running RCU-tasks wait API self tests
> >>>> [    1.598317] Performance Events: PEBS fmt3+, Skylake events, 32-deep
> >>>> LBR, full-width counters, Intel PMU driver.
> >>>> [    1.599176] ... version:                4
> >>>> [    1.600171] ... bit width:              48
> >>>> [    1.601171] ... generic registers:      8
> >>>> [    1.602171] ... value mask:             0000ffffffffffff
> >>>> [    1.603171] ... max period:             00007fffffffffff
> >>>> [    1.604176] ... fixed-purpose events:   3
> >>>> [    1.605171] ... event mask:             00000007000000ff
> >>>> [    1.606188] Callback from call_rcu_tasks_trace() invoked.
> >>>> [    1.607450] rcu: Hierarchical SRCU implementation.
> >>>> [    1.608310]
> >>>> [    1.609169] =============================
> >>>> [    1.609169] WARNING: suspicious RCU usage
> >>>> [    1.609169] 5.17.0-rc6-next-20220304 #1 Not tainted
> >>>> [    1.609169] -----------------------------
> >>>> [    1.609169] include/linux/cgroup.h:481 suspicious
> >>>> rcu_dereference_check() usage!
> >>>> [    1.609169]
> >>>> [    1.609169] other info that might help us debug this:
> >>>> [    1.609169]
> >>>> [    1.609169]
> >>>> [    1.609169] rcu_scheduler_active = 1, debug_locks = 1
> >>>> [    1.609169] 1 lock held by migration/0/17:
> >>>> [    1.609169]  #0: ffff9ba7a7a2d058 (&rq->__lock){-.-.}-{2:2}, at:
> >>>> __schedule+0x12d/0xcb0
> >>>> [    1.609169]
> >>>> [    1.609169] stack backtrace:
> >>>> [    1.609169] CPU: 0 PID: 17 Comm: migration/0 Not tainted
> >>>> 5.17.0-rc6-next-20220304 #1
> >>>> [    1.609169] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS
> >>>> 2.5 11/26/2020
> >>>> [    1.609169] Stopper: 0x0 <- 0x0
> >>>> [    1.609169] Call Trace:
> >>>> [    1.609169]  <TASK>
> >>>> [    1.609169]  dump_stack_lvl+0x49/0x5e
> >>>> [    1.609169]  dump_stack+0x10/0x12
> >>>> [    1.609169]  lockdep_rcu_suspicious+0xed/0xf8
> >>>> [    1.609169]  put_prev_task_stop+0x1dc/0x240
> >>>> [    1.609169]  __schedule+0x751/0xcb0
> >>>> [    1.609169]  ? trace_preempt_off+0x29/0xc0
> >>>> [    1.609169]  ? smpboot_thread_fn+0x33/0x290
> >>>> [    1.609169]  schedule+0x58/0xc0
> >>>> [    1.609169]  smpboot_thread_fn+0xec/0x290
> >>>> [    1.609169]  ? sort_range+0x30/0x30
> >>>> [    1.609169]  kthread+0x107/0x130
> >>>> [    1.609169]  ? kthread_complete_and_exit+0x20/0x20
> >>>> [    1.609169]  ret_from_fork+0x22/0x30
> >>>> [    1.609169]  </TASK>
> >>>> [    1.610276] smp: Bringing up secondary CPUs ...
> >>>> [    1.611596] x86: Booting SMP configuration:
> >>>> [    1.612179] .... node  #0, CPUs:      #1 #2 #3
> >>>> [    1.614396] smp: Brought up 1 node, 4 CPUs
> >>>>
> >>>> Reported-by: Linux Kernel Functional Testing <lkft@...aro.org>
> >>>>
> >>>> --
> >>>> Linaro LKFT
> >>>> https://lkft.linaro.org
> >>>>
> >>>> [1] https://qa-reports.linaro.org/lkft/linux-next-master/build/next-20220304/testrun/8235955/suite/linux-log-parser/test/check-kernel-warning-4655400/log

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ