rcu.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called
@ 2020-08-08 18:21 William Tambe
  2020-08-08 21:17 ` William Tambe
  0 siblings, 1 reply; 10+ messages in thread
From: William Tambe @ 2020-08-08 18:21 UTC (permalink / raw)
  To: rcu

I am having an issue in my kernel where delayed_put_task_struct() used
through call_rcu() by put_task_struct_rcu_user() never gets called.

Any idea ?

^ permalink raw reply	[flat|nested] 10+ messages in thread

* Re: delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called
  2020-08-08 18:21 delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called William Tambe
@ 2020-08-08 21:17 ` William Tambe
  2020-08-08 21:19   ` William Tambe
  0 siblings, 1 reply; 10+ messages in thread
From: William Tambe @ 2020-08-08 21:17 UTC (permalink / raw)
  To: rcu

On Sat, Aug 8, 2020 at 1:21 PM William Tambe <tambewilliam@gmail.com> wrote:
>
> I am having an issue in my kernel where delayed_put_task_struct() used
> through call_rcu() by put_task_struct_rcu_user() never gets called.

I am able to trace this issue to invoke_rcu_core() not getting called
in __call_rcu_core() due to rcu_is_watching() always returning true.

Any idea why I am seeing such an issue ?

>
> Any idea ?

^ permalink raw reply	[flat|nested] 10+ messages in thread

* Re: delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called
  2020-08-08 21:17 ` William Tambe
@ 2020-08-08 21:19   ` William Tambe
  2020-08-08 22:09     ` Paul E. McKenney
  0 siblings, 1 reply; 10+ messages in thread
From: William Tambe @ 2020-08-08 21:19 UTC (permalink / raw)
  To: rcu

On Sat, Aug 8, 2020 at 4:17 PM William Tambe <tambewilliam@gmail.com> wrote:
>
> On Sat, Aug 8, 2020 at 1:21 PM William Tambe <tambewilliam@gmail.com> wrote:
> >
> > I am having an issue in my kernel where delayed_put_task_struct() used
> > through call_rcu() by put_task_struct_rcu_user() never gets called.
>
> I am able to trace this issue to invoke_rcu_core() not getting called
> in __call_rcu_core() due to rcu_is_watching() always returning true.
>
> Any idea why I am seeing such an issue ?

Also, the issue is not happening when using highres=off .

>
> >
> > Any idea ?

^ permalink raw reply	[flat|nested] 10+ messages in thread

* Re: delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called
  2020-08-08 21:19   ` William Tambe
@ 2020-08-08 22:09     ` Paul E. McKenney
  2020-08-09  2:31       ` William Tambe
  0 siblings, 1 reply; 10+ messages in thread
From: Paul E. McKenney @ 2020-08-08 22:09 UTC (permalink / raw)
  To: William Tambe; +Cc: rcu

On Sat, Aug 08, 2020 at 04:19:42PM -0500, William Tambe wrote:
> On Sat, Aug 8, 2020 at 4:17 PM William Tambe <tambewilliam@gmail.com> wrote:
> >
> > On Sat, Aug 8, 2020 at 1:21 PM William Tambe <tambewilliam@gmail.com> wrote:
> > >
> > > I am having an issue in my kernel where delayed_put_task_struct() used
> > > through call_rcu() by put_task_struct_rcu_user() never gets called.
> >
> > I am able to trace this issue to invoke_rcu_core() not getting called
> > in __call_rcu_core() due to rcu_is_watching() always returning true.

That in fact should be the common case.  Normally, you would be invoking
call_rcu() and thus __call_rcu_core() from a context that RCU is watching.

But what happens after that in __call_rcu_core()?

> > Any idea why I am seeing such an issue ?

One way would be if every single one of your call_rcu() invocations was
done with irqs disabled.  And if the scheduling-clock interrupt was turned
off.  And if the CPU in question never received any other interrupts.

As in all of those things have to be in effect in order to indefinitely
postpone the call to delayed_put_task_struct().  In this case, v5.8's
__call_rcu_core() would always exit via this path:

	if (irqs_disabled_flags(flags) || cpu_is_offline(smp_processor_id()))
		return;

> Also, the issue is not happening when using highres=off .

Might highres=off be forcing the scheduling-clock interrupt to be
enabled?

> > > Any idea ?

If you are running oldish kernels and the CPU in question is a nohz_full
CPU, the scheduling-clock interrupt would be turned off.  (In more recent
kernel versions, RCU will force it back on if things are not progressing.)

To say more, I would need your exact kernel version (including any
patches and any other out-of-tree source code) and your .config file.

							Thanx, Paul

^ permalink raw reply	[flat|nested] 10+ messages in thread

* Re: delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called
  2020-08-08 22:09     ` Paul E. McKenney
@ 2020-08-09  2:31       ` William Tambe
  2020-08-09  3:46         ` Paul E. McKenney
  0 siblings, 1 reply; 10+ messages in thread
From: William Tambe @ 2020-08-09  2:31 UTC (permalink / raw)
  To: paulmck; +Cc: rcu

On Sat, Aug 8, 2020 at 5:09 PM Paul E. McKenney <paulmck@kernel.org> wrote:
>
> On Sat, Aug 08, 2020 at 04:19:42PM -0500, William Tambe wrote:
> > On Sat, Aug 8, 2020 at 4:17 PM William Tambe <tambewilliam@gmail.com> wrote:
> > >
> > > On Sat, Aug 8, 2020 at 1:21 PM William Tambe <tambewilliam@gmail.com> wrote:
> > > >
> > > > I am having an issue in my kernel where delayed_put_task_struct() used
> > > > through call_rcu() by put_task_struct_rcu_user() never gets called.
> > >
> > > I am able to trace this issue to invoke_rcu_core() not getting called
> > > in __call_rcu_core() due to rcu_is_watching() always returning true.
>
> That in fact should be the common case.  Normally, you would be invoking
> call_rcu() and thus __call_rcu_core() from a context that RCU is watching.
>
> But what happens after that in __call_rcu_core()?
>
> > > Any idea why I am seeing such an issue ?
>
> One way would be if every single one of your call_rcu() invocations was
> done with irqs disabled.  And if the scheduling-clock interrupt was turned
> off.  And if the CPU in question never received any other interrupts.
>
> As in all of those things have to be in effect in order to indefinitely
> postpone the call to delayed_put_task_struct().  In this case, v5.8's
> __call_rcu_core() would always exit via this path:
>
>         if (irqs_disabled_flags(flags) || cpu_is_offline(smp_processor_id()))
>                 return;
>
> > Also, the issue is not happening when using highres=off .
>
> Might highres=off be forcing the scheduling-clock interrupt to be
> enabled?
>
> > > > Any idea ?
>
> If you are running oldish kernels and the CPU in question is a nohz_full
> CPU, the scheduling-clock interrupt would be turned off.  (In more recent
> kernel versions, RCU will force it back on if things are not progressing.)

I am running v5.8.

I further observed that without highres=off, the function
tick_nohz_handler() is not getting called, hence
update_process_times() and rcu_sched_clock_irq() are not getting
called.

How can I debug why tick_nohz_handler() is not getting called when
booting without highres=off ?

The timer interrupt is implemented as follow:

void timer_intr (void) {
     arch_local_irq_disable();
     irq_enter();
     struct clock_event_device *e =
     per_cpu(clkevtdevs, smp_processor_id());
     e->event_handler(e);
    irq_exit();
    arch_local_irq_enable();
}

>
> To say more, I would need your exact kernel version (including any
> patches and any other out-of-tree source code) and your .config file.

I am using v5.8; currently unable to release out-of-tree source.

The defconfig is as follow:
CONFIG_NO_HZ_IDLE=y
CONFIG_HIGH_RES_TIMERS=y
CONFIG_PREEMPT=y
CONFIG_IKCONFIG=y
CONFIG_IKCONFIG_PROC=y
CONFIG_KALLSYMS_ALL=y
CONFIG_USERFAULTFD=y
CONFIG_EMBEDDED=y
# CONFIG_SLUB_DEBUG is not set
CONFIG_SIMHDD=y
# CONFIG_MQ_IOSCHED_DEADLINE is not set
# CONFIG_MQ_IOSCHED_KYBER is not set
CONFIG_BINFMT_MISC=y
CONFIG_NET=y
CONFIG_PACKET=y
CONFIG_PACKET_DIAG=y
CONFIG_UNIX=y
CONFIG_UNIX_DIAG=y
CONFIG_INET=y
CONFIG_INET_UDP_DIAG=y
CONFIG_INET_RAW_DIAG=y
CONFIG_INET_DIAG_DESTROY=y
# CONFIG_IPV6 is not set
CONFIG_BRIDGE=y
CONFIG_NETLINK_DIAG=y
# CONFIG_WIRELESS is not set
# CONFIG_ETHTOOL_NETLINK is not set
CONFIG_DEVTMPFS=y
CONFIG_DEVTMPFS_MOUNT=y
CONFIG_BLK_DEV_LOOP=y
CONFIG_VT_HW_CONSOLE_BINDING=y
# CONFIG_LEGACY_PTYS is not set
# CONFIG_VGA_CONSOLE is not set
# CONFIG_VIRTIO_MENU is not set
# CONFIG_VHOST_MENU is not set
CONFIG_EXT4_FS=y
CONFIG_TMPFS=y
CONFIG_TMPFS_POSIX_ACL=y
# CONFIG_MISC_FILESYSTEMS is not set
CONFIG_NFS_FS=y
CONFIG_NFS_V3_ACL=y
CONFIG_NFS_V4=y
CONFIG_NFS_V4_1=y
CONFIG_DEBUG_INFO=y
CONFIG_GDB_SCRIPTS=y
CONFIG_DEBUG_KMEMLEAK=y
CONFIG_DEBUG_KMEMLEAK_DEFAULT_OFF=y
CONFIG_SCHED_STACK_END_CHECK=y
CONFIG_DEBUG_MEMORY_INIT=y
CONFIG_PANIC_TIMEOUT=1
CONFIG_SOFTLOCKUP_DETECTOR=y
CONFIG_WQ_WATCHDOG=y
# CONFIG_RCU_TRACE is not set
CONFIG_RCU_EQS_DEBUG=y
# CONFIG_RUNTIME_TESTING_MENU is not set
CONFIG_MEMTEST=y

>
>                                                         Thanx, Paul

^ permalink raw reply	[flat|nested] 10+ messages in thread

* Re: delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called
  2020-08-09  2:31       ` William Tambe
@ 2020-08-09  3:46         ` Paul E. McKenney
  2020-08-09 14:22           ` William Tambe
  0 siblings, 1 reply; 10+ messages in thread
From: Paul E. McKenney @ 2020-08-09  3:46 UTC (permalink / raw)
  To: William Tambe; +Cc: rcu

On Sat, Aug 08, 2020 at 09:31:11PM -0500, William Tambe wrote:
> On Sat, Aug 8, 2020 at 5:09 PM Paul E. McKenney <paulmck@kernel.org> wrote:
> >
> > On Sat, Aug 08, 2020 at 04:19:42PM -0500, William Tambe wrote:
> > > On Sat, Aug 8, 2020 at 4:17 PM William Tambe <tambewilliam@gmail.com> wrote:
> > > >
> > > > On Sat, Aug 8, 2020 at 1:21 PM William Tambe <tambewilliam@gmail.com> wrote:
> > > > >
> > > > > I am having an issue in my kernel where delayed_put_task_struct() used
> > > > > through call_rcu() by put_task_struct_rcu_user() never gets called.
> > > >
> > > > I am able to trace this issue to invoke_rcu_core() not getting called
> > > > in __call_rcu_core() due to rcu_is_watching() always returning true.
> >
> > That in fact should be the common case.  Normally, you would be invoking
> > call_rcu() and thus __call_rcu_core() from a context that RCU is watching.
> >
> > But what happens after that in __call_rcu_core()?
> >
> > > > Any idea why I am seeing such an issue ?
> >
> > One way would be if every single one of your call_rcu() invocations was
> > done with irqs disabled.  And if the scheduling-clock interrupt was turned
> > off.  And if the CPU in question never received any other interrupts.
> >
> > As in all of those things have to be in effect in order to indefinitely
> > postpone the call to delayed_put_task_struct().  In this case, v5.8's
> > __call_rcu_core() would always exit via this path:
> >
> >         if (irqs_disabled_flags(flags) || cpu_is_offline(smp_processor_id()))
> >                 return;

Any status on this?

> > > Also, the issue is not happening when using highres=off .
> >
> > Might highres=off be forcing the scheduling-clock interrupt to be
> > enabled?
> >
> > > > > Any idea ?
> >
> > If you are running oldish kernels and the CPU in question is a nohz_full
> > CPU, the scheduling-clock interrupt would be turned off.  (In more recent
> > kernel versions, RCU will force it back on if things are not progressing.)
> 
> I am running v5.8.

OK, good to know, and that means no need to worry about the various
behaviors of older kernels.

> I further observed that without highres=off, the function
> tick_nohz_handler() is not getting called, hence
> update_process_times() and rcu_sched_clock_irq() are not getting
> called.

But update_process_times() is invoked from various placed depending
on configuration.

> How can I debug why tick_nohz_handler() is not getting called when
> booting without highres=off ?

Given that tick_nohz_handler() is, according to it header comment,
"The nohz low res interrupt handler", might this be expected behavior?

> The timer interrupt is implemented as follow:
> 
> void timer_intr (void) {
>      arch_local_irq_disable();
>      irq_enter();
>      struct clock_event_device *e =
>      per_cpu(clkevtdevs, smp_processor_id());
>      e->event_handler(e);
>     irq_exit();
>     arch_local_irq_enable();
> }
> 
> >
> > To say more, I would need your exact kernel version (including any
> > patches and any other out-of-tree source code) and your .config file.
> 
> I am using v5.8; currently unable to release out-of-tree source.

I suggest comparing v5.8's actions on a hardware platform that is
directly supported by v5.8 to its actions with your out-of-tree source.
Given that v5.8 is running just fine elsewhere, the hope would be that
this will help you find the bug, whether that bug be in v5.8 itself,
or, as has historically been much more likely, in your out-of-tree source.

For example, do your out-of-tree patches do anything with timer hardware?
Bugs in that area commonly cause problems that look similar to what you
are seeing.

Alternatively, if you hardware platform is supported by stock v5.8,
please try that for comparison purposes.

> The defconfig is as follow:
> CONFIG_NO_HZ_IDLE=y

OK, non-idle CPUs should see scheduling-clock interrupts.

> CONFIG_HIGH_RES_TIMERS=y
> CONFIG_PREEMPT=y
> CONFIG_IKCONFIG=y
> CONFIG_IKCONFIG_PROC=y
> CONFIG_KALLSYMS_ALL=y
> CONFIG_USERFAULTFD=y
> CONFIG_EMBEDDED=y
> # CONFIG_SLUB_DEBUG is not set
> CONFIG_SIMHDD=y
> # CONFIG_MQ_IOSCHED_DEADLINE is not set
> # CONFIG_MQ_IOSCHED_KYBER is not set
> CONFIG_BINFMT_MISC=y
> CONFIG_NET=y
> CONFIG_PACKET=y
> CONFIG_PACKET_DIAG=y
> CONFIG_UNIX=y
> CONFIG_UNIX_DIAG=y
> CONFIG_INET=y
> CONFIG_INET_UDP_DIAG=y
> CONFIG_INET_RAW_DIAG=y
> CONFIG_INET_DIAG_DESTROY=y
> # CONFIG_IPV6 is not set
> CONFIG_BRIDGE=y
> CONFIG_NETLINK_DIAG=y
> # CONFIG_WIRELESS is not set
> # CONFIG_ETHTOOL_NETLINK is not set
> CONFIG_DEVTMPFS=y
> CONFIG_DEVTMPFS_MOUNT=y
> CONFIG_BLK_DEV_LOOP=y
> CONFIG_VT_HW_CONSOLE_BINDING=y
> # CONFIG_LEGACY_PTYS is not set
> # CONFIG_VGA_CONSOLE is not set
> # CONFIG_VIRTIO_MENU is not set
> # CONFIG_VHOST_MENU is not set
> CONFIG_EXT4_FS=y
> CONFIG_TMPFS=y
> CONFIG_TMPFS_POSIX_ACL=y
> # CONFIG_MISC_FILESYSTEMS is not set
> CONFIG_NFS_FS=y
> CONFIG_NFS_V3_ACL=y
> CONFIG_NFS_V4=y
> CONFIG_NFS_V4_1=y
> CONFIG_DEBUG_INFO=y
> CONFIG_GDB_SCRIPTS=y
> CONFIG_DEBUG_KMEMLEAK=y
> CONFIG_DEBUG_KMEMLEAK_DEFAULT_OFF=y
> CONFIG_SCHED_STACK_END_CHECK=y
> CONFIG_DEBUG_MEMORY_INIT=y
> CONFIG_PANIC_TIMEOUT=1
> CONFIG_SOFTLOCKUP_DETECTOR=y
> CONFIG_WQ_WATCHDOG=y
> # CONFIG_RCU_TRACE is not set
> CONFIG_RCU_EQS_DEBUG=y

This should detect interrupt handlers and similar that are not properly
announcing their entry and exit, so good.

> # CONFIG_RUNTIME_TESTING_MENU is not set
> CONFIG_MEMTEST=y

Best of everything tracking this down!

							Thanx, Paul

^ permalink raw reply	[flat|nested] 10+ messages in thread

* Re: delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called
  2020-08-09  3:46         ` Paul E. McKenney
@ 2020-08-09 14:22           ` William Tambe
  2020-08-09 15:35             ` Paul E. McKenney
  0 siblings, 1 reply; 10+ messages in thread
From: William Tambe @ 2020-08-09 14:22 UTC (permalink / raw)
  To: paulmck; +Cc: rcu

On Sat, Aug 8, 2020 at 10:46 PM Paul E. McKenney <paulmck@kernel.org> wrote:
>
> On Sat, Aug 08, 2020 at 09:31:11PM -0500, William Tambe wrote:
> > On Sat, Aug 8, 2020 at 5:09 PM Paul E. McKenney <paulmck@kernel.org> wrote:
> > >
> > > On Sat, Aug 08, 2020 at 04:19:42PM -0500, William Tambe wrote:
> > > > On Sat, Aug 8, 2020 at 4:17 PM William Tambe <tambewilliam@gmail.com> wrote:
> > > > >
> > > > > On Sat, Aug 8, 2020 at 1:21 PM William Tambe <tambewilliam@gmail.com> wrote:
> > > > > >
> > > > > > I am having an issue in my kernel where delayed_put_task_struct() used
> > > > > > through call_rcu() by put_task_struct_rcu_user() never gets called.
> > > > >
> > > > > I am able to trace this issue to invoke_rcu_core() not getting called
> > > > > in __call_rcu_core() due to rcu_is_watching() always returning true.
> > >
> > > That in fact should be the common case.  Normally, you would be invoking
> > > call_rcu() and thus __call_rcu_core() from a context that RCU is watching.
> > >
> > > But what happens after that in __call_rcu_core()?
> > >
> > > > > Any idea why I am seeing such an issue ?
> > >
> > > One way would be if every single one of your call_rcu() invocations was
> > > done with irqs disabled.  And if the scheduling-clock interrupt was turned
> > > off.  And if the CPU in question never received any other interrupts.
> > >
> > > As in all of those things have to be in effect in order to indefinitely
> > > postpone the call to delayed_put_task_struct().  In this case, v5.8's
> > > __call_rcu_core() would always exit via this path:
> > >
> > >         if (irqs_disabled_flags(flags) || cpu_is_offline(smp_processor_id()))
> > >                 return;
>
> Any status on this?

It does not return there and __call_rcu_core() continues executing.

>
> > > > Also, the issue is not happening when using highres=off .
> > >
> > > Might highres=off be forcing the scheduling-clock interrupt to be
> > > enabled?
> > >
> > > > > > Any idea ?
> > >
> > > If you are running oldish kernels and the CPU in question is a nohz_full
> > > CPU, the scheduling-clock interrupt would be turned off.  (In more recent
> > > kernel versions, RCU will force it back on if things are not progressing.)
> >
> > I am running v5.8.
>
> OK, good to know, and that means no need to worry about the various
> behaviors of older kernels.
>
> > I further observed that without highres=off, the function
> > tick_nohz_handler() is not getting called, hence
> > update_process_times() and rcu_sched_clock_irq() are not getting
> > called.
>
> But update_process_times() is invoked from various placed depending
> on configuration.
>
> > How can I debug why tick_nohz_handler() is not getting called when
> > booting without highres=off ?
>
> Given that tick_nohz_handler() is, according to it header comment,
> "The nohz low res interrupt handler", might this be expected behavior?
>
> > The timer interrupt is implemented as follow:
> >
> > void timer_intr (void) {
> >      arch_local_irq_disable();
> >      irq_enter();
> >      struct clock_event_device *e =
> >      per_cpu(clkevtdevs, smp_processor_id());
> >      e->event_handler(e);
> >     irq_exit();
> >     arch_local_irq_enable();
> > }
> >
> > >
> > > To say more, I would need your exact kernel version (including any
> > > patches and any other out-of-tree source code) and your .config file.
> >
> > I am using v5.8; currently unable to release out-of-tree source.
>
> I suggest comparing v5.8's actions on a hardware platform that is
> directly supported by v5.8 to its actions with your out-of-tree source.
> Given that v5.8 is running just fine elsewhere, the hope would be that
> this will help you find the bug, whether that bug be in v5.8 itself,
> or, as has historically been much more likely, in your out-of-tree source.
>
> For example, do your out-of-tree patches do anything with timer hardware?
> Bugs in that area commonly cause problems that look similar to what you
> are seeing.
>
> Alternatively, if you hardware platform is supported by stock v5.8,
> please try that for comparison purposes.
>
> > The defconfig is as follow:
> > CONFIG_NO_HZ_IDLE=y
>
> OK, non-idle CPUs should see scheduling-clock interrupts.
>
> > CONFIG_HIGH_RES_TIMERS=y
> > CONFIG_PREEMPT=y
> > CONFIG_IKCONFIG=y
> > CONFIG_IKCONFIG_PROC=y
> > CONFIG_KALLSYMS_ALL=y
> > CONFIG_USERFAULTFD=y
> > CONFIG_EMBEDDED=y
> > # CONFIG_SLUB_DEBUG is not set
> > CONFIG_SIMHDD=y
> > # CONFIG_MQ_IOSCHED_DEADLINE is not set
> > # CONFIG_MQ_IOSCHED_KYBER is not set
> > CONFIG_BINFMT_MISC=y
> > CONFIG_NET=y
> > CONFIG_PACKET=y
> > CONFIG_PACKET_DIAG=y
> > CONFIG_UNIX=y
> > CONFIG_UNIX_DIAG=y
> > CONFIG_INET=y
> > CONFIG_INET_UDP_DIAG=y
> > CONFIG_INET_RAW_DIAG=y
> > CONFIG_INET_DIAG_DESTROY=y
> > # CONFIG_IPV6 is not set
> > CONFIG_BRIDGE=y
> > CONFIG_NETLINK_DIAG=y
> > # CONFIG_WIRELESS is not set
> > # CONFIG_ETHTOOL_NETLINK is not set
> > CONFIG_DEVTMPFS=y
> > CONFIG_DEVTMPFS_MOUNT=y
> > CONFIG_BLK_DEV_LOOP=y
> > CONFIG_VT_HW_CONSOLE_BINDING=y
> > # CONFIG_LEGACY_PTYS is not set
> > # CONFIG_VGA_CONSOLE is not set
> > # CONFIG_VIRTIO_MENU is not set
> > # CONFIG_VHOST_MENU is not set
> > CONFIG_EXT4_FS=y
> > CONFIG_TMPFS=y
> > CONFIG_TMPFS_POSIX_ACL=y
> > # CONFIG_MISC_FILESYSTEMS is not set
> > CONFIG_NFS_FS=y
> > CONFIG_NFS_V3_ACL=y
> > CONFIG_NFS_V4=y
> > CONFIG_NFS_V4_1=y
> > CONFIG_DEBUG_INFO=y
> > CONFIG_GDB_SCRIPTS=y
> > CONFIG_DEBUG_KMEMLEAK=y
> > CONFIG_DEBUG_KMEMLEAK_DEFAULT_OFF=y
> > CONFIG_SCHED_STACK_END_CHECK=y
> > CONFIG_DEBUG_MEMORY_INIT=y
> > CONFIG_PANIC_TIMEOUT=1
> > CONFIG_SOFTLOCKUP_DETECTOR=y
> > CONFIG_WQ_WATCHDOG=y
> > # CONFIG_RCU_TRACE is not set
> > CONFIG_RCU_EQS_DEBUG=y
>
> This should detect interrupt handlers and similar that are not properly
> announcing their entry and exit, so good.
>
> > # CONFIG_RUNTIME_TESTING_MENU is not set
> > CONFIG_MEMTEST=y
>
> Best of everything tracking this down!

Thanks

>
>                                                         Thanx, Paul

^ permalink raw reply	[flat|nested] 10+ messages in thread

* Re: delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called
  2020-08-09 14:22           ` William Tambe
@ 2020-08-09 15:35             ` Paul E. McKenney
  2020-08-09 16:26               ` William Tambe
  0 siblings, 1 reply; 10+ messages in thread
From: Paul E. McKenney @ 2020-08-09 15:35 UTC (permalink / raw)
  To: William Tambe; +Cc: rcu

On Sun, Aug 09, 2020 at 09:22:54AM -0500, William Tambe wrote:
> On Sat, Aug 8, 2020 at 10:46 PM Paul E. McKenney <paulmck@kernel.org> wrote:
> >
> > On Sat, Aug 08, 2020 at 09:31:11PM -0500, William Tambe wrote:
> > > On Sat, Aug 8, 2020 at 5:09 PM Paul E. McKenney <paulmck@kernel.org> wrote:
> > > >
> > > > On Sat, Aug 08, 2020 at 04:19:42PM -0500, William Tambe wrote:
> > > > > On Sat, Aug 8, 2020 at 4:17 PM William Tambe <tambewilliam@gmail.com> wrote:
> > > > > >
> > > > > > On Sat, Aug 8, 2020 at 1:21 PM William Tambe <tambewilliam@gmail.com> wrote:
> > > > > > >
> > > > > > > I am having an issue in my kernel where delayed_put_task_struct() used
> > > > > > > through call_rcu() by put_task_struct_rcu_user() never gets called.
> > > > > >
> > > > > > I am able to trace this issue to invoke_rcu_core() not getting called
> > > > > > in __call_rcu_core() due to rcu_is_watching() always returning true.
> > > >
> > > > That in fact should be the common case.  Normally, you would be invoking
> > > > call_rcu() and thus __call_rcu_core() from a context that RCU is watching.
> > > >
> > > > But what happens after that in __call_rcu_core()?
> > > >
> > > > > > Any idea why I am seeing such an issue ?
> > > >
> > > > One way would be if every single one of your call_rcu() invocations was
> > > > done with irqs disabled.  And if the scheduling-clock interrupt was turned
> > > > off.  And if the CPU in question never received any other interrupts.
> > > >
> > > > As in all of those things have to be in effect in order to indefinitely
> > > > postpone the call to delayed_put_task_struct().  In this case, v5.8's
> > > > __call_rcu_core() would always exit via this path:
> > > >
> > > >         if (irqs_disabled_flags(flags) || cpu_is_offline(smp_processor_id()))
> > > >                 return;
> >
> > Any status on this?
> 
> It does not return there and __call_rcu_core() continues executing.

Thank you, and presumably the next "if" does not trigger, at least not
unless that CPU has more than 10,000 callbacks queued (given the usual
default settings).

I am also assuming that callbacks are -not- offloaded because I did
not see CONFIG_RCU_NOCB_CPUS=y

Until that 10,000th callback is queued, RCU is relying on either a return
to idle or a scheduling-clock interrupt.  In the idle case:

o	If CONFIG_RCU_FAST_NO_HZ=y, RCU will ask for a four-jiffies timer
	out of idle.  It will also periodically assign grace periods to
	new callbacks.  The question in this case is "What is preventing
	the call out of idle?"  I didn't see this in your defconfig, so
	I am assuming this is -not- your system is set up.

o	If CONFIG_RCU_FAST_NO_HZ=n, RCU will ask that the scheduling-clock
	interrupt be left enabled, despite the return to idle.	This puts
	us into the next case, the scheduling-clock interrupt.

	You should be able to check this by looking at the return value
	from the rcu_needs_cpu() function on this CPU, which should be
	non-zero given that you have a callback queued on the current CPU.
	(It is just fine for other CPUs without callbacks to return zero,
	by the way.)

A scheduling-clock interrupt invokes rcu_sched_clock_irq(), which
invokes rcu_pending(), which on a CPU with newly queued callbacks
should return non-zero via this path or some earlier one:

	/* Has RCU gone idle with this CPU needing another grace period? */
	if (!gp_in_progress && rcu_segcblist_is_enabled(&rdp->cblist) &&
	    (!IS_ENABLED(CONFIG_RCU_NOCB_CPU) ||
	     !rcu_segcblist_is_offloaded(&rdp->cblist)) &&
	    !rcu_segcblist_restempty(&rdp->cblist, RCU_NEXT_READY_TAIL))
		return 1;

If the CPU is not getting scheduling-clock interrupts (as in no calls to
update_process_times() and thus no calls to rcu_sched_clock_irq()), then
that is a bug that you need to fix.  Note that different CPU architectures
invoke update_process_times() in different ways from different places.
And even the generic support invokes update_process_times() from either
tick_periodic() or tick_sched_handle(), depending on configuration.

Then you will need to work out what is happening instead, given the
expectations for whatever CPU architecture and configuration you are
using.

							Thanx, Paul

> > > > > Also, the issue is not happening when using highres=off .
> > > >
> > > > Might highres=off be forcing the scheduling-clock interrupt to be
> > > > enabled?
> > > >
> > > > > > > Any idea ?
> > > >
> > > > If you are running oldish kernels and the CPU in question is a nohz_full
> > > > CPU, the scheduling-clock interrupt would be turned off.  (In more recent
> > > > kernel versions, RCU will force it back on if things are not progressing.)
> > >
> > > I am running v5.8.
> >
> > OK, good to know, and that means no need to worry about the various
> > behaviors of older kernels.
> >
> > > I further observed that without highres=off, the function
> > > tick_nohz_handler() is not getting called, hence
> > > update_process_times() and rcu_sched_clock_irq() are not getting
> > > called.
> >
> > But update_process_times() is invoked from various placed depending
> > on configuration.
> >
> > > How can I debug why tick_nohz_handler() is not getting called when
> > > booting without highres=off ?
> >
> > Given that tick_nohz_handler() is, according to it header comment,
> > "The nohz low res interrupt handler", might this be expected behavior?
> >
> > > The timer interrupt is implemented as follow:
> > >
> > > void timer_intr (void) {
> > >      arch_local_irq_disable();
> > >      irq_enter();
> > >      struct clock_event_device *e =
> > >      per_cpu(clkevtdevs, smp_processor_id());
> > >      e->event_handler(e);
> > >     irq_exit();
> > >     arch_local_irq_enable();
> > > }
> > >
> > > >
> > > > To say more, I would need your exact kernel version (including any
> > > > patches and any other out-of-tree source code) and your .config file.
> > >
> > > I am using v5.8; currently unable to release out-of-tree source.
> >
> > I suggest comparing v5.8's actions on a hardware platform that is
> > directly supported by v5.8 to its actions with your out-of-tree source.
> > Given that v5.8 is running just fine elsewhere, the hope would be that
> > this will help you find the bug, whether that bug be in v5.8 itself,
> > or, as has historically been much more likely, in your out-of-tree source.
> >
> > For example, do your out-of-tree patches do anything with timer hardware?
> > Bugs in that area commonly cause problems that look similar to what you
> > are seeing.
> >
> > Alternatively, if you hardware platform is supported by stock v5.8,
> > please try that for comparison purposes.
> >
> > > The defconfig is as follow:
> > > CONFIG_NO_HZ_IDLE=y
> >
> > OK, non-idle CPUs should see scheduling-clock interrupts.
> >
> > > CONFIG_HIGH_RES_TIMERS=y
> > > CONFIG_PREEMPT=y
> > > CONFIG_IKCONFIG=y
> > > CONFIG_IKCONFIG_PROC=y
> > > CONFIG_KALLSYMS_ALL=y
> > > CONFIG_USERFAULTFD=y
> > > CONFIG_EMBEDDED=y
> > > # CONFIG_SLUB_DEBUG is not set
> > > CONFIG_SIMHDD=y
> > > # CONFIG_MQ_IOSCHED_DEADLINE is not set
> > > # CONFIG_MQ_IOSCHED_KYBER is not set
> > > CONFIG_BINFMT_MISC=y
> > > CONFIG_NET=y
> > > CONFIG_PACKET=y
> > > CONFIG_PACKET_DIAG=y
> > > CONFIG_UNIX=y
> > > CONFIG_UNIX_DIAG=y
> > > CONFIG_INET=y
> > > CONFIG_INET_UDP_DIAG=y
> > > CONFIG_INET_RAW_DIAG=y
> > > CONFIG_INET_DIAG_DESTROY=y
> > > # CONFIG_IPV6 is not set
> > > CONFIG_BRIDGE=y
> > > CONFIG_NETLINK_DIAG=y
> > > # CONFIG_WIRELESS is not set
> > > # CONFIG_ETHTOOL_NETLINK is not set
> > > CONFIG_DEVTMPFS=y
> > > CONFIG_DEVTMPFS_MOUNT=y
> > > CONFIG_BLK_DEV_LOOP=y
> > > CONFIG_VT_HW_CONSOLE_BINDING=y
> > > # CONFIG_LEGACY_PTYS is not set
> > > # CONFIG_VGA_CONSOLE is not set
> > > # CONFIG_VIRTIO_MENU is not set
> > > # CONFIG_VHOST_MENU is not set
> > > CONFIG_EXT4_FS=y
> > > CONFIG_TMPFS=y
> > > CONFIG_TMPFS_POSIX_ACL=y
> > > # CONFIG_MISC_FILESYSTEMS is not set
> > > CONFIG_NFS_FS=y
> > > CONFIG_NFS_V3_ACL=y
> > > CONFIG_NFS_V4=y
> > > CONFIG_NFS_V4_1=y
> > > CONFIG_DEBUG_INFO=y
> > > CONFIG_GDB_SCRIPTS=y
> > > CONFIG_DEBUG_KMEMLEAK=y
> > > CONFIG_DEBUG_KMEMLEAK_DEFAULT_OFF=y
> > > CONFIG_SCHED_STACK_END_CHECK=y
> > > CONFIG_DEBUG_MEMORY_INIT=y
> > > CONFIG_PANIC_TIMEOUT=1
> > > CONFIG_SOFTLOCKUP_DETECTOR=y
> > > CONFIG_WQ_WATCHDOG=y
> > > # CONFIG_RCU_TRACE is not set
> > > CONFIG_RCU_EQS_DEBUG=y
> >
> > This should detect interrupt handlers and similar that are not properly
> > announcing their entry and exit, so good.
> >
> > > # CONFIG_RUNTIME_TESTING_MENU is not set
> > > CONFIG_MEMTEST=y
> >
> > Best of everything tracking this down!
> 
> Thanks
> 
> >
> >                                                         Thanx, Paul

^ permalink raw reply	[flat|nested] 10+ messages in thread

* Re: delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called
  2020-08-09 15:35             ` Paul E. McKenney
@ 2020-08-09 16:26               ` William Tambe
  2020-08-09 20:46                 ` Paul E. McKenney
  0 siblings, 1 reply; 10+ messages in thread
From: William Tambe @ 2020-08-09 16:26 UTC (permalink / raw)
  To: paulmck; +Cc: rcu

On Sun, Aug 9, 2020 at 10:35 AM Paul E. McKenney <paulmck@kernel.org> wrote:
>
> On Sun, Aug 09, 2020 at 09:22:54AM -0500, William Tambe wrote:
> > On Sat, Aug 8, 2020 at 10:46 PM Paul E. McKenney <paulmck@kernel.org> wrote:
> > >
> > > On Sat, Aug 08, 2020 at 09:31:11PM -0500, William Tambe wrote:
> > > > On Sat, Aug 8, 2020 at 5:09 PM Paul E. McKenney <paulmck@kernel.org> wrote:
> > > > >
> > > > > On Sat, Aug 08, 2020 at 04:19:42PM -0500, William Tambe wrote:
> > > > > > On Sat, Aug 8, 2020 at 4:17 PM William Tambe <tambewilliam@gmail.com> wrote:
> > > > > > >
> > > > > > > On Sat, Aug 8, 2020 at 1:21 PM William Tambe <tambewilliam@gmail.com> wrote:
> > > > > > > >
> > > > > > > > I am having an issue in my kernel where delayed_put_task_struct() used
> > > > > > > > through call_rcu() by put_task_struct_rcu_user() never gets called.
> > > > > > >
> > > > > > > I am able to trace this issue to invoke_rcu_core() not getting called
> > > > > > > in __call_rcu_core() due to rcu_is_watching() always returning true.
> > > > >
> > > > > That in fact should be the common case.  Normally, you would be invoking
> > > > > call_rcu() and thus __call_rcu_core() from a context that RCU is watching.
> > > > >
> > > > > But what happens after that in __call_rcu_core()?
> > > > >
> > > > > > > Any idea why I am seeing such an issue ?
> > > > >
> > > > > One way would be if every single one of your call_rcu() invocations was
> > > > > done with irqs disabled.  And if the scheduling-clock interrupt was turned
> > > > > off.  And if the CPU in question never received any other interrupts.
> > > > >
> > > > > As in all of those things have to be in effect in order to indefinitely
> > > > > postpone the call to delayed_put_task_struct().  In this case, v5.8's
> > > > > __call_rcu_core() would always exit via this path:
> > > > >
> > > > >         if (irqs_disabled_flags(flags) || cpu_is_offline(smp_processor_id()))
> > > > >                 return;
> > >
> > > Any status on this?
> >
> > It does not return there and __call_rcu_core() continues executing.
>
> Thank you, and presumably the next "if" does not trigger, at least not
> unless that CPU has more than 10,000 callbacks queued (given the usual
> default settings).
>
> I am also assuming that callbacks are -not- offloaded because I did
> not see CONFIG_RCU_NOCB_CPUS=y
>
> Until that 10,000th callback is queued, RCU is relying on either a return
> to idle or a scheduling-clock interrupt.  In the idle case:
>
> o       If CONFIG_RCU_FAST_NO_HZ=y, RCU will ask for a four-jiffies timer
>         out of idle.  It will also periodically assign grace periods to
>         new callbacks.  The question in this case is "What is preventing
>         the call out of idle?"  I didn't see this in your defconfig, so
>         I am assuming this is -not- your system is set up.
>
> o       If CONFIG_RCU_FAST_NO_HZ=n, RCU will ask that the scheduling-clock
>         interrupt be left enabled, despite the return to idle.  This puts
>         us into the next case, the scheduling-clock interrupt.
>
>         You should be able to check this by looking at the return value
>         from the rcu_needs_cpu() function on this CPU, which should be
>         non-zero given that you have a callback queued on the current CPU.
>         (It is just fine for other CPUs without callbacks to return zero,
>         by the way.)

I do not have CONFIG_RCU_FAST_NO_HZ; it is not defined in my config.

Using a breakpoint at rcu_needs_cpu(), I see it always returning 1.

Note that my setup is a single CPU, and without SMP in the kernel.

>
> A scheduling-clock interrupt invokes rcu_sched_clock_irq(), which
> invokes rcu_pending(), which on a CPU with newly queued callbacks
> should return non-zero via this path or some earlier one:
>
>         /* Has RCU gone idle with this CPU needing another grace period? */
>         if (!gp_in_progress && rcu_segcblist_is_enabled(&rdp->cblist) &&
>             (!IS_ENABLED(CONFIG_RCU_NOCB_CPU) ||
>              !rcu_segcblist_is_offloaded(&rdp->cblist)) &&
>             !rcu_segcblist_restempty(&rdp->cblist, RCU_NEXT_READY_TAIL))
>                 return 1;
>
> If the CPU is not getting scheduling-clock interrupts (as in no calls to
> update_process_times() and thus no calls to rcu_sched_clock_irq()), then
> that is a bug that you need to fix.  Note that different CPU architectures
> invoke update_process_times() in different ways from different places.
> And even the generic support invokes update_process_times() from either
> tick_periodic() or tick_sched_handle(), depending on configuration.

I am expecting update_process_times() to be called by the timer
interrupt through e->event_handler(e);

Without using highres=off, the timer interrupt is calling
hrtimer_interrupt() through e->event_handler(e);
With using highres=off, the timer interrupt is calling
tick_nohz_handler() through e->event_handler(e);

When tick_nohz_handler() is used, update_process_times() gets called.
When hrtimer_interrupt() is used, update_process_times() does not get called.

Note that the issue I am seeing occurs when I do not use highres=off ,
in other words issue occurs with high resolution timers enabled.

>
> Then you will need to work out what is happening instead, given the
> expectations for whatever CPU architecture and configuration you are
> using.
>
>                                                         Thanx, Paul
>
> > > > > > Also, the issue is not happening when using highres=off .
> > > > >
> > > > > Might highres=off be forcing the scheduling-clock interrupt to be
> > > > > enabled?
> > > > >
> > > > > > > > Any idea ?
> > > > >
> > > > > If you are running oldish kernels and the CPU in question is a nohz_full
> > > > > CPU, the scheduling-clock interrupt would be turned off.  (In more recent
> > > > > kernel versions, RCU will force it back on if things are not progressing.)
> > > >
> > > > I am running v5.8.
> > >
> > > OK, good to know, and that means no need to worry about the various
> > > behaviors of older kernels.
> > >
> > > > I further observed that without highres=off, the function
> > > > tick_nohz_handler() is not getting called, hence
> > > > update_process_times() and rcu_sched_clock_irq() are not getting
> > > > called.
> > >
> > > But update_process_times() is invoked from various placed depending
> > > on configuration.
> > >
> > > > How can I debug why tick_nohz_handler() is not getting called when
> > > > booting without highres=off ?
> > >
> > > Given that tick_nohz_handler() is, according to it header comment,
> > > "The nohz low res interrupt handler", might this be expected behavior?
> > >
> > > > The timer interrupt is implemented as follow:
> > > >
> > > > void timer_intr (void) {
> > > >      arch_local_irq_disable();
> > > >      irq_enter();
> > > >      struct clock_event_device *e =
> > > >      per_cpu(clkevtdevs, smp_processor_id());
> > > >      e->event_handler(e);
> > > >     irq_exit();
> > > >     arch_local_irq_enable();
> > > > }
> > > >
> > > > >
> > > > > To say more, I would need your exact kernel version (including any
> > > > > patches and any other out-of-tree source code) and your .config file.
> > > >
> > > > I am using v5.8; currently unable to release out-of-tree source.
> > >
> > > I suggest comparing v5.8's actions on a hardware platform that is
> > > directly supported by v5.8 to its actions with your out-of-tree source.
> > > Given that v5.8 is running just fine elsewhere, the hope would be that
> > > this will help you find the bug, whether that bug be in v5.8 itself,
> > > or, as has historically been much more likely, in your out-of-tree source.
> > >
> > > For example, do your out-of-tree patches do anything with timer hardware?
> > > Bugs in that area commonly cause problems that look similar to what you
> > > are seeing.
> > >
> > > Alternatively, if you hardware platform is supported by stock v5.8,
> > > please try that for comparison purposes.
> > >
> > > > The defconfig is as follow:
> > > > CONFIG_NO_HZ_IDLE=y
> > >
> > > OK, non-idle CPUs should see scheduling-clock interrupts.
> > >
> > > > CONFIG_HIGH_RES_TIMERS=y
> > > > CONFIG_PREEMPT=y
> > > > CONFIG_IKCONFIG=y
> > > > CONFIG_IKCONFIG_PROC=y
> > > > CONFIG_KALLSYMS_ALL=y
> > > > CONFIG_USERFAULTFD=y
> > > > CONFIG_EMBEDDED=y
> > > > # CONFIG_SLUB_DEBUG is not set
> > > > CONFIG_SIMHDD=y
> > > > # CONFIG_MQ_IOSCHED_DEADLINE is not set
> > > > # CONFIG_MQ_IOSCHED_KYBER is not set
> > > > CONFIG_BINFMT_MISC=y
> > > > CONFIG_NET=y
> > > > CONFIG_PACKET=y
> > > > CONFIG_PACKET_DIAG=y
> > > > CONFIG_UNIX=y
> > > > CONFIG_UNIX_DIAG=y
> > > > CONFIG_INET=y
> > > > CONFIG_INET_UDP_DIAG=y
> > > > CONFIG_INET_RAW_DIAG=y
> > > > CONFIG_INET_DIAG_DESTROY=y
> > > > # CONFIG_IPV6 is not set
> > > > CONFIG_BRIDGE=y
> > > > CONFIG_NETLINK_DIAG=y
> > > > # CONFIG_WIRELESS is not set
> > > > # CONFIG_ETHTOOL_NETLINK is not set
> > > > CONFIG_DEVTMPFS=y
> > > > CONFIG_DEVTMPFS_MOUNT=y
> > > > CONFIG_BLK_DEV_LOOP=y
> > > > CONFIG_VT_HW_CONSOLE_BINDING=y
> > > > # CONFIG_LEGACY_PTYS is not set
> > > > # CONFIG_VGA_CONSOLE is not set
> > > > # CONFIG_VIRTIO_MENU is not set
> > > > # CONFIG_VHOST_MENU is not set
> > > > CONFIG_EXT4_FS=y
> > > > CONFIG_TMPFS=y
> > > > CONFIG_TMPFS_POSIX_ACL=y
> > > > # CONFIG_MISC_FILESYSTEMS is not set
> > > > CONFIG_NFS_FS=y
> > > > CONFIG_NFS_V3_ACL=y
> > > > CONFIG_NFS_V4=y
> > > > CONFIG_NFS_V4_1=y
> > > > CONFIG_DEBUG_INFO=y
> > > > CONFIG_GDB_SCRIPTS=y
> > > > CONFIG_DEBUG_KMEMLEAK=y
> > > > CONFIG_DEBUG_KMEMLEAK_DEFAULT_OFF=y
> > > > CONFIG_SCHED_STACK_END_CHECK=y
> > > > CONFIG_DEBUG_MEMORY_INIT=y
> > > > CONFIG_PANIC_TIMEOUT=1
> > > > CONFIG_SOFTLOCKUP_DETECTOR=y
> > > > CONFIG_WQ_WATCHDOG=y
> > > > # CONFIG_RCU_TRACE is not set
> > > > CONFIG_RCU_EQS_DEBUG=y
> > >
> > > This should detect interrupt handlers and similar that are not properly
> > > announcing their entry and exit, so good.
> > >
> > > > # CONFIG_RUNTIME_TESTING_MENU is not set
> > > > CONFIG_MEMTEST=y
> > >
> > > Best of everything tracking this down!
> >
> > Thanks
> >
> > >
> > >                                                         Thanx, Paul

^ permalink raw reply	[flat|nested] 10+ messages in thread

* Re: delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called
  2020-08-09 16:26               ` William Tambe
@ 2020-08-09 20:46                 ` Paul E. McKenney
  0 siblings, 0 replies; 10+ messages in thread
From: Paul E. McKenney @ 2020-08-09 20:46 UTC (permalink / raw)
  To: William Tambe; +Cc: rcu

On Sun, Aug 09, 2020 at 11:26:27AM -0500, William Tambe wrote:
> On Sun, Aug 9, 2020 at 10:35 AM Paul E. McKenney <paulmck@kernel.org> wrote:
> >
> > On Sun, Aug 09, 2020 at 09:22:54AM -0500, William Tambe wrote:
> > > On Sat, Aug 8, 2020 at 10:46 PM Paul E. McKenney <paulmck@kernel.org> wrote:
> > > >
> > > > On Sat, Aug 08, 2020 at 09:31:11PM -0500, William Tambe wrote:
> > > > > On Sat, Aug 8, 2020 at 5:09 PM Paul E. McKenney <paulmck@kernel.org> wrote:
> > > > > >
> > > > > > On Sat, Aug 08, 2020 at 04:19:42PM -0500, William Tambe wrote:
> > > > > > > On Sat, Aug 8, 2020 at 4:17 PM William Tambe <tambewilliam@gmail.com> wrote:
> > > > > > > >
> > > > > > > > On Sat, Aug 8, 2020 at 1:21 PM William Tambe <tambewilliam@gmail.com> wrote:
> > > > > > > > >
> > > > > > > > > I am having an issue in my kernel where delayed_put_task_struct() used
> > > > > > > > > through call_rcu() by put_task_struct_rcu_user() never gets called.
> > > > > > > >
> > > > > > > > I am able to trace this issue to invoke_rcu_core() not getting called
> > > > > > > > in __call_rcu_core() due to rcu_is_watching() always returning true.
> > > > > >
> > > > > > That in fact should be the common case.  Normally, you would be invoking
> > > > > > call_rcu() and thus __call_rcu_core() from a context that RCU is watching.
> > > > > >
> > > > > > But what happens after that in __call_rcu_core()?
> > > > > >
> > > > > > > > Any idea why I am seeing such an issue ?
> > > > > >
> > > > > > One way would be if every single one of your call_rcu() invocations was
> > > > > > done with irqs disabled.  And if the scheduling-clock interrupt was turned
> > > > > > off.  And if the CPU in question never received any other interrupts.
> > > > > >
> > > > > > As in all of those things have to be in effect in order to indefinitely
> > > > > > postpone the call to delayed_put_task_struct().  In this case, v5.8's
> > > > > > __call_rcu_core() would always exit via this path:
> > > > > >
> > > > > >         if (irqs_disabled_flags(flags) || cpu_is_offline(smp_processor_id()))
> > > > > >                 return;
> > > >
> > > > Any status on this?
> > >
> > > It does not return there and __call_rcu_core() continues executing.
> >
> > Thank you, and presumably the next "if" does not trigger, at least not
> > unless that CPU has more than 10,000 callbacks queued (given the usual
> > default settings).
> >
> > I am also assuming that callbacks are -not- offloaded because I did
> > not see CONFIG_RCU_NOCB_CPUS=y
> >
> > Until that 10,000th callback is queued, RCU is relying on either a return
> > to idle or a scheduling-clock interrupt.  In the idle case:
> >
> > o       If CONFIG_RCU_FAST_NO_HZ=y, RCU will ask for a four-jiffies timer
> >         out of idle.  It will also periodically assign grace periods to
> >         new callbacks.  The question in this case is "What is preventing
> >         the call out of idle?"  I didn't see this in your defconfig, so
> >         I am assuming this is -not- your system is set up.
> >
> > o       If CONFIG_RCU_FAST_NO_HZ=n, RCU will ask that the scheduling-clock
> >         interrupt be left enabled, despite the return to idle.  This puts
> >         us into the next case, the scheduling-clock interrupt.
> >
> >         You should be able to check this by looking at the return value
> >         from the rcu_needs_cpu() function on this CPU, which should be
> >         non-zero given that you have a callback queued on the current CPU.
> >         (It is just fine for other CPUs without callbacks to return zero,
> >         by the way.)
> 
> I do not have CONFIG_RCU_FAST_NO_HZ; it is not defined in my config.
> 
> Using a breakpoint at rcu_needs_cpu(), I see it always returning 1.

OK, good, that is what it should be doing when you have callbacks posted
that have not yet been associated with a particular grace period.

> Note that my setup is a single CPU, and without SMP in the kernel.

And with CONFIG_PREEMPT=y, correct?

> > A scheduling-clock interrupt invokes rcu_sched_clock_irq(), which
> > invokes rcu_pending(), which on a CPU with newly queued callbacks
> > should return non-zero via this path or some earlier one:
> >
> >         /* Has RCU gone idle with this CPU needing another grace period? */
> >         if (!gp_in_progress && rcu_segcblist_is_enabled(&rdp->cblist) &&
> >             (!IS_ENABLED(CONFIG_RCU_NOCB_CPU) ||
> >              !rcu_segcblist_is_offloaded(&rdp->cblist)) &&
> >             !rcu_segcblist_restempty(&rdp->cblist, RCU_NEXT_READY_TAIL))
> >                 return 1;
> >
> > If the CPU is not getting scheduling-clock interrupts (as in no calls to
> > update_process_times() and thus no calls to rcu_sched_clock_irq()), then
> > that is a bug that you need to fix.  Note that different CPU architectures
> > invoke update_process_times() in different ways from different places.
> > And even the generic support invokes update_process_times() from either
> > tick_periodic() or tick_sched_handle(), depending on configuration.
> 
> I am expecting update_process_times() to be called by the timer
> interrupt through e->event_handler(e);
> 
> Without using highres=off, the timer interrupt is calling
> hrtimer_interrupt() through e->event_handler(e);
> With using highres=off, the timer interrupt is calling
> tick_nohz_handler() through e->event_handler(e);
> 
> When tick_nohz_handler() is used, update_process_times() gets called.
> When hrtimer_interrupt() is used, update_process_times() does not get called.
> 
> Note that the issue I am seeing occurs when I do not use highres=off ,
> in other words issue occurs with high resolution timers enabled.

Given what you have told me about your system, if your system does not
invoke update_process_times() when needed, what you are seeing with RCU
is expected behavior.  You need to debug this.  RCU does not have much
influence on this code path.

I once again suggest comparing the behavior of a system that does run
v5.8.  Trace both and see where they diverge from hrtimer_interrupt().
Or from calls to post hrtimers.

I also suggest carefully checking the private patches/modules/whatever
that you are using.

Again, you need update_process_times() to be called from time to time
in order for RCU to function given the configuration you are using.

							Thanx, Paul

> > Then you will need to work out what is happening instead, given the
> > expectations for whatever CPU architecture and configuration you are
> > using.
> >
> >                                                         Thanx, Paul
> >
> > > > > > > Also, the issue is not happening when using highres=off .
> > > > > >
> > > > > > Might highres=off be forcing the scheduling-clock interrupt to be
> > > > > > enabled?
> > > > > >
> > > > > > > > > Any idea ?
> > > > > >
> > > > > > If you are running oldish kernels and the CPU in question is a nohz_full
> > > > > > CPU, the scheduling-clock interrupt would be turned off.  (In more recent
> > > > > > kernel versions, RCU will force it back on if things are not progressing.)
> > > > >
> > > > > I am running v5.8.
> > > >
> > > > OK, good to know, and that means no need to worry about the various
> > > > behaviors of older kernels.
> > > >
> > > > > I further observed that without highres=off, the function
> > > > > tick_nohz_handler() is not getting called, hence
> > > > > update_process_times() and rcu_sched_clock_irq() are not getting
> > > > > called.
> > > >
> > > > But update_process_times() is invoked from various placed depending
> > > > on configuration.
> > > >
> > > > > How can I debug why tick_nohz_handler() is not getting called when
> > > > > booting without highres=off ?
> > > >
> > > > Given that tick_nohz_handler() is, according to it header comment,
> > > > "The nohz low res interrupt handler", might this be expected behavior?
> > > >
> > > > > The timer interrupt is implemented as follow:
> > > > >
> > > > > void timer_intr (void) {
> > > > >      arch_local_irq_disable();
> > > > >      irq_enter();
> > > > >      struct clock_event_device *e =
> > > > >      per_cpu(clkevtdevs, smp_processor_id());
> > > > >      e->event_handler(e);
> > > > >     irq_exit();
> > > > >     arch_local_irq_enable();
> > > > > }
> > > > >
> > > > > >
> > > > > > To say more, I would need your exact kernel version (including any
> > > > > > patches and any other out-of-tree source code) and your .config file.
> > > > >
> > > > > I am using v5.8; currently unable to release out-of-tree source.
> > > >
> > > > I suggest comparing v5.8's actions on a hardware platform that is
> > > > directly supported by v5.8 to its actions with your out-of-tree source.
> > > > Given that v5.8 is running just fine elsewhere, the hope would be that
> > > > this will help you find the bug, whether that bug be in v5.8 itself,
> > > > or, as has historically been much more likely, in your out-of-tree source.
> > > >
> > > > For example, do your out-of-tree patches do anything with timer hardware?
> > > > Bugs in that area commonly cause problems that look similar to what you
> > > > are seeing.
> > > >
> > > > Alternatively, if you hardware platform is supported by stock v5.8,
> > > > please try that for comparison purposes.
> > > >
> > > > > The defconfig is as follow:
> > > > > CONFIG_NO_HZ_IDLE=y
> > > >
> > > > OK, non-idle CPUs should see scheduling-clock interrupts.
> > > >
> > > > > CONFIG_HIGH_RES_TIMERS=y
> > > > > CONFIG_PREEMPT=y
> > > > > CONFIG_IKCONFIG=y
> > > > > CONFIG_IKCONFIG_PROC=y
> > > > > CONFIG_KALLSYMS_ALL=y
> > > > > CONFIG_USERFAULTFD=y
> > > > > CONFIG_EMBEDDED=y
> > > > > # CONFIG_SLUB_DEBUG is not set
> > > > > CONFIG_SIMHDD=y
> > > > > # CONFIG_MQ_IOSCHED_DEADLINE is not set
> > > > > # CONFIG_MQ_IOSCHED_KYBER is not set
> > > > > CONFIG_BINFMT_MISC=y
> > > > > CONFIG_NET=y
> > > > > CONFIG_PACKET=y
> > > > > CONFIG_PACKET_DIAG=y
> > > > > CONFIG_UNIX=y
> > > > > CONFIG_UNIX_DIAG=y
> > > > > CONFIG_INET=y
> > > > > CONFIG_INET_UDP_DIAG=y
> > > > > CONFIG_INET_RAW_DIAG=y
> > > > > CONFIG_INET_DIAG_DESTROY=y
> > > > > # CONFIG_IPV6 is not set
> > > > > CONFIG_BRIDGE=y
> > > > > CONFIG_NETLINK_DIAG=y
> > > > > # CONFIG_WIRELESS is not set
> > > > > # CONFIG_ETHTOOL_NETLINK is not set
> > > > > CONFIG_DEVTMPFS=y
> > > > > CONFIG_DEVTMPFS_MOUNT=y
> > > > > CONFIG_BLK_DEV_LOOP=y
> > > > > CONFIG_VT_HW_CONSOLE_BINDING=y
> > > > > # CONFIG_LEGACY_PTYS is not set
> > > > > # CONFIG_VGA_CONSOLE is not set
> > > > > # CONFIG_VIRTIO_MENU is not set
> > > > > # CONFIG_VHOST_MENU is not set
> > > > > CONFIG_EXT4_FS=y
> > > > > CONFIG_TMPFS=y
> > > > > CONFIG_TMPFS_POSIX_ACL=y
> > > > > # CONFIG_MISC_FILESYSTEMS is not set
> > > > > CONFIG_NFS_FS=y
> > > > > CONFIG_NFS_V3_ACL=y
> > > > > CONFIG_NFS_V4=y
> > > > > CONFIG_NFS_V4_1=y
> > > > > CONFIG_DEBUG_INFO=y
> > > > > CONFIG_GDB_SCRIPTS=y
> > > > > CONFIG_DEBUG_KMEMLEAK=y
> > > > > CONFIG_DEBUG_KMEMLEAK_DEFAULT_OFF=y
> > > > > CONFIG_SCHED_STACK_END_CHECK=y
> > > > > CONFIG_DEBUG_MEMORY_INIT=y
> > > > > CONFIG_PANIC_TIMEOUT=1
> > > > > CONFIG_SOFTLOCKUP_DETECTOR=y
> > > > > CONFIG_WQ_WATCHDOG=y
> > > > > # CONFIG_RCU_TRACE is not set
> > > > > CONFIG_RCU_EQS_DEBUG=y
> > > >
> > > > This should detect interrupt handlers and similar that are not properly
> > > > announcing their entry and exit, so good.
> > > >
> > > > > # CONFIG_RUNTIME_TESTING_MENU is not set
> > > > > CONFIG_MEMTEST=y
> > > >
> > > > Best of everything tracking this down!
> > >
> > > Thanks
> > >
> > > >
> > > >                                                         Thanx, Paul

^ permalink raw reply	[flat|nested] 10+ messages in thread

end of thread, other threads:[~2020-08-09 20:46 UTC | newest]

Thread overview: 10+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-08-08 18:21 delayed_put_task_struct() used through call_rcu() by put_task_struct_rcu_user() never gets called William Tambe
2020-08-08 21:17 ` William Tambe
2020-08-08 21:19   ` William Tambe
2020-08-08 22:09     ` Paul E. McKenney
2020-08-09  2:31       ` William Tambe
2020-08-09  3:46         ` Paul E. McKenney
2020-08-09 14:22           ` William Tambe
2020-08-09 15:35             ` Paul E. McKenney
2020-08-09 16:26               ` William Tambe
2020-08-09 20:46                 ` Paul E. McKenney

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).