Re: [vfs-next] RCU call-traces (task: modprobe)

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On Tue, Aug 9, 2022 at 11:06 AM Sedat Dilek <sedat.dilek@xxxxxxxxx> wrote:
>
> On Mon, Aug 8, 2022 at 3:43 PM Paul E. McKenney <paulmck@xxxxxxxxxx> wrote:
> >
> > On Sun, Aug 07, 2022 at 08:56:25AM +0200, Greg KH wrote:
> > > On Sat, Aug 06, 2022 at 09:32:47AM -0700, Paul E. McKenney wrote:
> > > > On Sat, Aug 06, 2022 at 08:31:26AM +0200, Sedat Dilek wrote:
> > > > > Hi Al and Paul,
> > > > >
> > > > > I pulled latest vfs-next on top of Linux v5.19 and see this in dmesg-logs:
> > > > >
> > > > > root# LC_ALL=C dmesg -T | egrep -B5 -A15 'Call Trace:'
> > > > > [Sat Aug  6 06:51:15 2022] Bluetooth: SCO socket layer initialized
> > > > > [Sat Aug  6 06:51:15 2022] rcu: INFO: rcu_preempt detected expedited
> > > > > stalls on CPUs/tasks: { 0-... } 6 jiffies s: 101 root: 0x1/.
> > > >
> > > > This is because of the CONFIG_RCU_EXP_CPU_STALL_TIMEOUT=20 in your
> > > > .config file.  This is selected in kernels built with CONFIG_ANDROID=y,
> > > > and results in an ultra-short 20-millisecond RCU CPU stall timeout for
> > > > expedited grace periods.  Yes, the Android guys want and are getting
> > > > milliseconds-scale response times from synchronize_rcu_expedited().
> > > >
> > > > The last time someone ran into this, the upshot was that CONFIG_ANDROID
> > > > was to be removed: https://lwn.net/Articles/899743/
> > > >
> > > > My guess is that the CONFIG_ANDROID-removal patches are still on their way
> > > > into mainline (they are in -next), but I added Greg KH and Christoph on CC
> > > > just in case some other issue arose.
> > >
> > > Not that I know of, those changes are all now in Linus's tree.
> >
> > And now that I do another pull, I do see them, thank you!
> >
> > So Sedat and Ben can just merge current mainline and be fine.
> >
>
> For the records:
>
> commit 1045a06724f322ed61f1ffb994427c7bdbe64647
> "remove CONFIG_ANDROID"
>
> diff --git a/kernel/rcu/Kconfig.debug b/kernel/rcu/Kconfig.debug
> index 9b64e55d4f615..e875f4f889656 100644
> --- a/kernel/rcu/Kconfig.debug
> +++ b/kernel/rcu/Kconfig.debug
> @@ -86,8 +86,7 @@ config RCU_EXP_CPU_STALL_TIMEOUT
>   int "Expedited RCU CPU stall timeout in milliseconds"
>   depends on RCU_STALL_COMMON
>   range 0 21000
> - default 20 if ANDROID
> - default 0 if !ANDROID
> + default 0
>   help
>     If a given expedited RCU grace period extends more than the
>     specified number of milliseconds, a CPU stall warning is printed.
>
> -Sedat-
>
> [1] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=1045a06724f322ed61f1ffb994427c7bdbe64647

Hmm, with latest Debian-kernel I see the same call-trace as reported:

root# grep -B5 -A15 'Call Trace:' dmesg-T_5.19.0-trunk-amd64.txt
836-[Tue Aug  9 10:56:52 2022] iwlwifi 0000:01:00.0 wlp1s0: renamed from wlan0
837-[Tue Aug  9 10:56:52 2022] rcu: INFO: rcu_preempt detected
expedited stalls on CPUs/tasks: { 2-... } 6 jiffies s: 213 root: 0x4/.
838-[Tue Aug  9 10:56:52 2022] rcu: blocking rcu_node structures
(internal RCU debug):
839-[Tue Aug  9 10:56:52 2022] Task dump for CPU 2:
840-[Tue Aug  9 10:56:52 2022] task:systemd-udevd   state:R  running
task     stack:    0 pid:  347 ppid:   303 flags:0x00004008
841:[Tue Aug  9 10:56:52 2022] Call Trace:
842-[Tue Aug  9 10:56:52 2022]  <TASK>
843-[Tue Aug  9 10:56:52 2022]  ? change_page_attr_set_clr+0x155/0x1c0
844-[Tue Aug  9 10:56:52 2022]  ? ftrace_module_enable+0xad/0x370
845-[Tue Aug  9 10:56:52 2022]  ? load_module+0x1bbc/0x2050
846-[Tue Aug  9 10:56:52 2022]  ? __do_sys_finit_module+0xb4/0x130
847-[Tue Aug  9 10:56:52 2022]  ? __do_sys_finit_module+0xb4/0x130
848-[Tue Aug  9 10:56:52 2022]  ? do_syscall_64+0x3b/0xc0
849-[Tue Aug  9 10:56:52 2022]  ? entry_SYSCALL_64_after_hwframe+0x63/0xcd
850-[Tue Aug  9 10:56:52 2022]  </TASK>
851-[Tue Aug  9 10:56:52 2022] rcu: INFO: rcu_preempt detected
expedited stalls on CPUs/tasks: { 2-... } 25 jiffies s: 213 root:
0x4/.
852-[Tue Aug  9 10:56:52 2022] rcu: blocking rcu_node structures
(internal RCU debug):
853-[Tue Aug  9 10:56:52 2022] Task dump for CPU 2:
854-[Tue Aug  9 10:56:52 2022] task:systemd-udevd   state:R  running
task     stack:    0 pid:  347 ppid:   303 flags:0x00004008
855:[Tue Aug  9 10:56:52 2022] Call Trace:
856-[Tue Aug  9 10:56:52 2022]  <TASK>
857-[Tue Aug  9 10:56:52 2022]  ? change_page_attr_set_clr+0x155/0x1c0
858-[Tue Aug  9 10:56:52 2022]  ? ftrace_module_enable+0xad/0x370
859-[Tue Aug  9 10:56:52 2022]  ? load_module+0x1bbc/0x2050
860-[Tue Aug  9 10:56:52 2022]  ? __do_sys_finit_module+0xb4/0x130
861-[Tue Aug  9 10:56:52 2022]  ? __do_sys_finit_module+0xb4/0x130
862-[Tue Aug  9 10:56:52 2022]  ? do_syscall_64+0x3b/0xc0
863-[Tue Aug  9 10:56:52 2022]  ? entry_SYSCALL_64_after_hwframe+0x63/0xcd
864-[Tue Aug  9 10:56:52 2022]  </TASK>
865-[Tue Aug  9 10:56:53 2022] rcu: INFO: rcu_preempt detected
expedited stalls on CPUs/tasks: { 2-... } 44 jiffies s: 213 root:
0x4/.
866-[Tue Aug  9 10:56:53 2022] rcu: blocking rcu_node structures
(internal RCU debug):
867-[Tue Aug  9 10:56:53 2022] Task dump for CPU 2:
868-[Tue Aug  9 10:56:53 2022] task:systemd-udevd   state:R  running
task     stack:    0 pid:  347 ppid:   303 flags:0x00004008
869:[Tue Aug  9 10:56:53 2022] Call Trace:
870-[Tue Aug  9 10:56:53 2022]  <TASK>
871-[Tue Aug  9 10:56:53 2022]  ? change_page_attr_set_clr+0x155/0x1c0
872-[Tue Aug  9 10:56:53 2022]  ? ftrace_module_enable+0xad/0x370
873-[Tue Aug  9 10:56:53 2022]  ? load_module+0x1bbc/0x2050
874-[Tue Aug  9 10:56:53 2022]  ? __do_sys_finit_module+0xb4/0x130
875-[Tue Aug  9 10:56:53 2022]  ? __do_sys_finit_module+0xb4/0x130
876-[Tue Aug  9 10:56:53 2022]  ? do_syscall_64+0x3b/0xc0
877-[Tue Aug  9 10:56:53 2022]  ? entry_SYSCALL_64_after_hwframe+0x63/0xcd
878-[Tue Aug  9 10:56:53 2022]  </TASK>
879-[Tue Aug  9 10:56:53 2022] rcu: INFO: rcu_preempt detected
expedited stalls on CPUs/tasks: { 2-... } 63 jiffies s: 213 root:
0x4/.
880-[Tue Aug  9 10:56:53 2022] rcu: blocking rcu_node structures
(internal RCU debug):
881-[Tue Aug  9 10:56:53 2022] Task dump for CPU 2:
882-[Tue Aug  9 10:56:53 2022] task:systemd-udevd   state:R  running
task     stack:    0 pid:  347 ppid:   303 flags:0x00004008
883:[Tue Aug  9 10:56:53 2022] Call Trace:
884-[Tue Aug  9 10:56:53 2022]  <TASK>
885-[Tue Aug  9 10:56:53 2022]  ? change_page_attr_set_clr+0x155/0x1c0
886-[Tue Aug  9 10:56:53 2022]  ? ftrace_module_enable+0xad/0x370
887-[Tue Aug  9 10:56:53 2022]  ? load_module+0x1bbc/0x2050
888-[Tue Aug  9 10:56:53 2022]  ? __do_sys_finit_module+0xb4/0x130
889-[Tue Aug  9 10:56:53 2022]  ? __do_sys_finit_module+0xb4/0x130
890-[Tue Aug  9 10:56:53 2022]  ? do_syscall_64+0x3b/0xc0
891-[Tue Aug  9 10:56:53 2022]  ? entry_SYSCALL_64_after_hwframe+0x63/0xcd
892-[Tue Aug  9 10:56:53 2022]  </TASK>
893-[Tue Aug  9 10:56:53 2022] zram0: detected capacity change from 0 to 1004656
894-[Tue Aug  9 10:56:53 2022] i915 0000:00:02.0: vgaarb: deactivate vga console
895-[Tue Aug  9 10:56:53 2022] Console: switching to colour dummy device 80x25
896-[Tue Aug  9 10:56:53 2022] i915 0000:00:02.0: vgaarb: changed VGA
decodes: olddecodes=io+mem,decodes=io+mem:owns=io+mem
897-[Tue Aug  9 10:56:53 2022] [drm] Initialized i915 1.6.0 20201103
for 0000:00:02.0 on minor 0
898-[Tue Aug  9 10:56:53 2022] ACPI: video: Video Device [GFX0]
(multi-head: yes  rom: no  post: no)

Just see Ben integrated [1]:

android: Remove CONFIG_ANDROID
- Drop "wireguard: Clear keys after suspend despite CONFIG_ANDROID=y"
- pm/sleep: Add PM_USERSPACE_AUTOSLEEP Kconfig
- remove CONFIG_ANDROID
- Enable/disable ANDROID_BINDER_IPC to match previous configuration

This fixes two more cases where kernel behaviour was changed by
CONFIG_ANDROID.

-Sedat-

[1] https://salsa.debian.org/kernel-team/linux/-/commit/78fcd943947d24bb162fcebf1a9ca86795e1b2b1



[Index of Archives]     [Linux Samsung SoC]     [Linux Rockchip SoC]     [Linux Actions SoC]     [Linux for Synopsys ARC Processors]     [Linux NFS]     [Linux NILFS]     [Linux USB Devel]     [Video for Linux]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]


  Powered by Linux