| Message ID | 20200623002147.25750-2-paulmck@kernel.org (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | None | expand |
On Mon, Jun 22, 2020 at 5:22 PM <paulmck@kernel.org> wrote: > > From: "Paul E. McKenney" <paulmck@kernel.org> > > A large process running on a heavily loaded system can encounter the > following RCU CPU stall warning: > > rcu: INFO: rcu_sched self-detected stall on CPU > rcu: \x093-....: (20998 ticks this GP) idle=4ea/1/0x4000000000000002 softirq=556558/556558 fqs=5190 > \x09(t=21013 jiffies g=1005461 q=132576) > NMI backtrace for cpu 3 > CPU: 3 PID: 501900 Comm: aio-free-ring-w Kdump: loaded Not tainted 5.2.9-108_fbk12_rc3_3858_gb83b75af7909 #1 > Hardware name: Wiwynn HoneyBadger/PantherPlus, BIOS HBM6.71 02/03/2016 > Call Trace: > <IRQ> > dump_stack+0x46/0x60 > nmi_cpu_backtrace.cold.3+0x13/0x50 > ? lapic_can_unplug_cpu.cold.27+0x34/0x34 > nmi_trigger_cpumask_backtrace+0xba/0xca > rcu_dump_cpu_stacks+0x99/0xc7 > rcu_sched_clock_irq.cold.87+0x1aa/0x397 > ? tick_sched_do_timer+0x60/0x60 > update_process_times+0x28/0x60 > tick_sched_timer+0x37/0x70 > __hrtimer_run_queues+0xfe/0x270 > hrtimer_interrupt+0xf4/0x210 > smp_apic_timer_interrupt+0x5e/0x120 > apic_timer_interrupt+0xf/0x20 > </IRQ> > RIP: 0010:kmem_cache_free+0x223/0x300 > Code: 88 00 00 00 0f 85 ca 00 00 00 41 8b 55 18 31 f6 f7 da 41 f6 45 0a 02 40 0f 94 c6 83 c6 05 9c 41 5e fa e8 a0 a7 01 00 41 56 9d <49> 8b 47 08 a8 03 0f 85 87 00 00 00 65 48 ff 08 e9 3d fe ff ff 65 > RSP: 0018:ffffc9000e8e3da8 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13 > RAX: 0000000000020000 RBX: ffff88861b9de960 RCX: 0000000000000030 > RDX: fffffffffffe41e8 RSI: 000060777fe3a100 RDI: 000000000001be18 > RBP: ffffea00186e7780 R08: ffffffffffffffff R09: ffffffffffffffff > R10: ffff88861b9dea28 R11: ffff88887ffde000 R12: ffffffff81230a1f > R13: ffff888854684dc0 R14: 0000000000000206 R15: ffff8888547dbc00 > ? remove_vma+0x4f/0x60 > remove_vma+0x4f/0x60 > exit_mmap+0xd6/0x160 > mmput+0x4a/0x110 > do_exit+0x278/0xae0 > ? syscall_trace_enter+0x1d3/0x2b0 > ? handle_mm_fault+0xaa/0x1c0 > do_group_exit+0x3a/0xa0 > __x64_sys_exit_group+0x14/0x20 > do_syscall_64+0x42/0x100 > entry_SYSCALL_64_after_hwframe+0x44/0xa9 > > And on a PREEMPT=n kernel, the "while (vma)" loop in exit_mmap() can run > for a very long time given a large process. This commit therefore adds > a cond_resched() to this loop, providing RCU any needed quiescent states. > > Cc: Andrew Morton <akpm@linux-foundation.org> > Cc: <linux-mm@kvack.org> > Signed-off-by: Paul E. McKenney <paulmck@kernel.org> We have exactly the same change in our internal kernel since 2018. We mostly observed the need_resched warnings on the processes mapping the hugetlbfs. Reviewed-by: Shakeel Butt <shakeelb@google.com> > --- > mm/mmap.c | 1 + > 1 file changed, 1 insertion(+) > > diff --git a/mm/mmap.c b/mm/mmap.c > index 59a4682..972f839 100644 > --- a/mm/mmap.c > +++ b/mm/mmap.c > @@ -3159,6 +3159,7 @@ void exit_mmap(struct mm_struct *mm) > if (vma->vm_flags & VM_ACCOUNT) > nr_accounted += vma_pages(vma); > vma = remove_vma(vma); > + cond_resched(); > } > vm_unacct_memory(nr_accounted); > } > -- > 2.9.5 >
On Mon, Jun 22, 2020 at 05:47:19PM -0700, Shakeel Butt wrote: > On Mon, Jun 22, 2020 at 5:22 PM <paulmck@kernel.org> wrote: > > > > From: "Paul E. McKenney" <paulmck@kernel.org> > > > > A large process running on a heavily loaded system can encounter the > > following RCU CPU stall warning: > > > > rcu: INFO: rcu_sched self-detected stall on CPU > > rcu: \x093-....: (20998 ticks this GP) idle=4ea/1/0x4000000000000002 softirq=556558/556558 fqs=5190 > > \x09(t=21013 jiffies g=1005461 q=132576) > > NMI backtrace for cpu 3 > > CPU: 3 PID: 501900 Comm: aio-free-ring-w Kdump: loaded Not tainted 5.2.9-108_fbk12_rc3_3858_gb83b75af7909 #1 > > Hardware name: Wiwynn HoneyBadger/PantherPlus, BIOS HBM6.71 02/03/2016 > > Call Trace: > > <IRQ> > > dump_stack+0x46/0x60 > > nmi_cpu_backtrace.cold.3+0x13/0x50 > > ? lapic_can_unplug_cpu.cold.27+0x34/0x34 > > nmi_trigger_cpumask_backtrace+0xba/0xca > > rcu_dump_cpu_stacks+0x99/0xc7 > > rcu_sched_clock_irq.cold.87+0x1aa/0x397 > > ? tick_sched_do_timer+0x60/0x60 > > update_process_times+0x28/0x60 > > tick_sched_timer+0x37/0x70 > > __hrtimer_run_queues+0xfe/0x270 > > hrtimer_interrupt+0xf4/0x210 > > smp_apic_timer_interrupt+0x5e/0x120 > > apic_timer_interrupt+0xf/0x20 > > </IRQ> > > RIP: 0010:kmem_cache_free+0x223/0x300 > > Code: 88 00 00 00 0f 85 ca 00 00 00 41 8b 55 18 31 f6 f7 da 41 f6 45 0a 02 40 0f 94 c6 83 c6 05 9c 41 5e fa e8 a0 a7 01 00 41 56 9d <49> 8b 47 08 a8 03 0f 85 87 00 00 00 65 48 ff 08 e9 3d fe ff ff 65 > > RSP: 0018:ffffc9000e8e3da8 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13 > > RAX: 0000000000020000 RBX: ffff88861b9de960 RCX: 0000000000000030 > > RDX: fffffffffffe41e8 RSI: 000060777fe3a100 RDI: 000000000001be18 > > RBP: ffffea00186e7780 R08: ffffffffffffffff R09: ffffffffffffffff > > R10: ffff88861b9dea28 R11: ffff88887ffde000 R12: ffffffff81230a1f > > R13: ffff888854684dc0 R14: 0000000000000206 R15: ffff8888547dbc00 > > ? remove_vma+0x4f/0x60 > > remove_vma+0x4f/0x60 > > exit_mmap+0xd6/0x160 > > mmput+0x4a/0x110 > > do_exit+0x278/0xae0 > > ? syscall_trace_enter+0x1d3/0x2b0 > > ? handle_mm_fault+0xaa/0x1c0 > > do_group_exit+0x3a/0xa0 > > __x64_sys_exit_group+0x14/0x20 > > do_syscall_64+0x42/0x100 > > entry_SYSCALL_64_after_hwframe+0x44/0xa9 > > > > And on a PREEMPT=n kernel, the "while (vma)" loop in exit_mmap() can run > > for a very long time given a large process. This commit therefore adds > > a cond_resched() to this loop, providing RCU any needed quiescent states. > > > > Cc: Andrew Morton <akpm@linux-foundation.org> > > Cc: <linux-mm@kvack.org> > > Signed-off-by: Paul E. McKenney <paulmck@kernel.org> > > We have exactly the same change in our internal kernel since 2018. We > mostly observed the need_resched warnings on the processes mapping the > hugetlbfs. > > Reviewed-by: Shakeel Butt <shakeelb@google.com> Thank you very much, I will apply your Reviewed-by on the next rebase. Any other patches we should know about? ;-) Thanx, Paul > > --- > > mm/mmap.c | 1 + > > 1 file changed, 1 insertion(+) > > > > diff --git a/mm/mmap.c b/mm/mmap.c > > index 59a4682..972f839 100644 > > --- a/mm/mmap.c > > +++ b/mm/mmap.c > > @@ -3159,6 +3159,7 @@ void exit_mmap(struct mm_struct *mm) > > if (vma->vm_flags & VM_ACCOUNT) > > nr_accounted += vma_pages(vma); > > vma = remove_vma(vma); > > + cond_resched(); > > } > > vm_unacct_memory(nr_accounted); > > } > > -- > > 2.9.5 > >
On Mon, Jun 22, 2020 at 05:21:23PM -0700, paulmck@kernel.org wrote: > From: "Paul E. McKenney" <paulmck@kernel.org> > > A large process running on a heavily loaded system can encounter the > following RCU CPU stall warning: > > rcu: INFO: rcu_sched self-detected stall on CPU > rcu: \x093-....: (20998 ticks this GP) idle=4ea/1/0x4000000000000002 softirq=556558/556558 fqs=5190 > \x09(t=21013 jiffies g=1005461 q=132576) > NMI backtrace for cpu 3 > CPU: 3 PID: 501900 Comm: aio-free-ring-w Kdump: loaded Not tainted 5.2.9-108_fbk12_rc3_3858_gb83b75af7909 #1 > Hardware name: Wiwynn HoneyBadger/PantherPlus, BIOS HBM6.71 02/03/2016 > Call Trace: > <IRQ> > dump_stack+0x46/0x60 > nmi_cpu_backtrace.cold.3+0x13/0x50 > ? lapic_can_unplug_cpu.cold.27+0x34/0x34 > nmi_trigger_cpumask_backtrace+0xba/0xca > rcu_dump_cpu_stacks+0x99/0xc7 > rcu_sched_clock_irq.cold.87+0x1aa/0x397 > ? tick_sched_do_timer+0x60/0x60 > update_process_times+0x28/0x60 > tick_sched_timer+0x37/0x70 > __hrtimer_run_queues+0xfe/0x270 > hrtimer_interrupt+0xf4/0x210 > smp_apic_timer_interrupt+0x5e/0x120 > apic_timer_interrupt+0xf/0x20 > </IRQ> > RIP: 0010:kmem_cache_free+0x223/0x300 > Code: 88 00 00 00 0f 85 ca 00 00 00 41 8b 55 18 31 f6 f7 da 41 f6 45 0a 02 40 0f 94 c6 83 c6 05 9c 41 5e fa e8 a0 a7 01 00 41 56 9d <49> 8b 47 08 a8 03 0f 85 87 00 00 00 65 48 ff 08 e9 3d fe ff ff 65 > RSP: 0018:ffffc9000e8e3da8 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13 > RAX: 0000000000020000 RBX: ffff88861b9de960 RCX: 0000000000000030 > RDX: fffffffffffe41e8 RSI: 000060777fe3a100 RDI: 000000000001be18 > RBP: ffffea00186e7780 R08: ffffffffffffffff R09: ffffffffffffffff > R10: ffff88861b9dea28 R11: ffff88887ffde000 R12: ffffffff81230a1f > R13: ffff888854684dc0 R14: 0000000000000206 R15: ffff8888547dbc00 > ? remove_vma+0x4f/0x60 > remove_vma+0x4f/0x60 > exit_mmap+0xd6/0x160 > mmput+0x4a/0x110 > do_exit+0x278/0xae0 > ? syscall_trace_enter+0x1d3/0x2b0 > ? handle_mm_fault+0xaa/0x1c0 > do_group_exit+0x3a/0xa0 > __x64_sys_exit_group+0x14/0x20 > do_syscall_64+0x42/0x100 > entry_SYSCALL_64_after_hwframe+0x44/0xa9 > > And on a PREEMPT=n kernel, the "while (vma)" loop in exit_mmap() can run > for a very long time given a large process. This commit therefore adds > a cond_resched() to this loop, providing RCU any needed quiescent states. > > Cc: Andrew Morton <akpm@linux-foundation.org> > Cc: <linux-mm@kvack.org> > Signed-off-by: Paul E. McKenney <paulmck@kernel.org> > --- > mm/mmap.c | 1 + > 1 file changed, 1 insertion(+) > > diff --git a/mm/mmap.c b/mm/mmap.c > index 59a4682..972f839 100644 > --- a/mm/mmap.c > +++ b/mm/mmap.c > @@ -3159,6 +3159,7 @@ void exit_mmap(struct mm_struct *mm) > if (vma->vm_flags & VM_ACCOUNT) > nr_accounted += vma_pages(vma); > vma = remove_vma(vma); > + cond_resched(); Reviewed-by: Joel Fernandes (Google) <joel@joelfernandes.org> Just for my understanding, cond_resched_tasks_rcu_qs() may not help here because preemption is not disabled right? Still I see no harm in using it here either as it may give a slight speed up for tasks-RCU. thanks, - Joel > } > vm_unacct_memory(nr_accounted); > } > -- > 2.9.5 >
On Tue, Jun 23, 2020 at 03:34:31PM -0400, Joel Fernandes wrote: > On Mon, Jun 22, 2020 at 05:21:23PM -0700, paulmck@kernel.org wrote: > > From: "Paul E. McKenney" <paulmck@kernel.org> > > > > A large process running on a heavily loaded system can encounter the > > following RCU CPU stall warning: > > > > rcu: INFO: rcu_sched self-detected stall on CPU > > rcu: \x093-....: (20998 ticks this GP) idle=4ea/1/0x4000000000000002 softirq=556558/556558 fqs=5190 > > \x09(t=21013 jiffies g=1005461 q=132576) > > NMI backtrace for cpu 3 > > CPU: 3 PID: 501900 Comm: aio-free-ring-w Kdump: loaded Not tainted 5.2.9-108_fbk12_rc3_3858_gb83b75af7909 #1 > > Hardware name: Wiwynn HoneyBadger/PantherPlus, BIOS HBM6.71 02/03/2016 > > Call Trace: > > <IRQ> > > dump_stack+0x46/0x60 > > nmi_cpu_backtrace.cold.3+0x13/0x50 > > ? lapic_can_unplug_cpu.cold.27+0x34/0x34 > > nmi_trigger_cpumask_backtrace+0xba/0xca > > rcu_dump_cpu_stacks+0x99/0xc7 > > rcu_sched_clock_irq.cold.87+0x1aa/0x397 > > ? tick_sched_do_timer+0x60/0x60 > > update_process_times+0x28/0x60 > > tick_sched_timer+0x37/0x70 > > __hrtimer_run_queues+0xfe/0x270 > > hrtimer_interrupt+0xf4/0x210 > > smp_apic_timer_interrupt+0x5e/0x120 > > apic_timer_interrupt+0xf/0x20 > > </IRQ> > > RIP: 0010:kmem_cache_free+0x223/0x300 > > Code: 88 00 00 00 0f 85 ca 00 00 00 41 8b 55 18 31 f6 f7 da 41 f6 45 0a 02 40 0f 94 c6 83 c6 05 9c 41 5e fa e8 a0 a7 01 00 41 56 9d <49> 8b 47 08 a8 03 0f 85 87 00 00 00 65 48 ff 08 e9 3d fe ff ff 65 > > RSP: 0018:ffffc9000e8e3da8 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13 > > RAX: 0000000000020000 RBX: ffff88861b9de960 RCX: 0000000000000030 > > RDX: fffffffffffe41e8 RSI: 000060777fe3a100 RDI: 000000000001be18 > > RBP: ffffea00186e7780 R08: ffffffffffffffff R09: ffffffffffffffff > > R10: ffff88861b9dea28 R11: ffff88887ffde000 R12: ffffffff81230a1f > > R13: ffff888854684dc0 R14: 0000000000000206 R15: ffff8888547dbc00 > > ? remove_vma+0x4f/0x60 > > remove_vma+0x4f/0x60 > > exit_mmap+0xd6/0x160 > > mmput+0x4a/0x110 > > do_exit+0x278/0xae0 > > ? syscall_trace_enter+0x1d3/0x2b0 > > ? handle_mm_fault+0xaa/0x1c0 > > do_group_exit+0x3a/0xa0 > > __x64_sys_exit_group+0x14/0x20 > > do_syscall_64+0x42/0x100 > > entry_SYSCALL_64_after_hwframe+0x44/0xa9 > > > > And on a PREEMPT=n kernel, the "while (vma)" loop in exit_mmap() can run > > for a very long time given a large process. This commit therefore adds > > a cond_resched() to this loop, providing RCU any needed quiescent states. > > > > Cc: Andrew Morton <akpm@linux-foundation.org> > > Cc: <linux-mm@kvack.org> > > Signed-off-by: Paul E. McKenney <paulmck@kernel.org> > > --- > > mm/mmap.c | 1 + > > 1 file changed, 1 insertion(+) > > > > diff --git a/mm/mmap.c b/mm/mmap.c > > index 59a4682..972f839 100644 > > --- a/mm/mmap.c > > +++ b/mm/mmap.c > > @@ -3159,6 +3159,7 @@ void exit_mmap(struct mm_struct *mm) > > if (vma->vm_flags & VM_ACCOUNT) > > nr_accounted += vma_pages(vma); > > vma = remove_vma(vma); > > + cond_resched(); > > Reviewed-by: Joel Fernandes (Google) <joel@joelfernandes.org> Thank you! I will apply this on my next rebase. > Just for my understanding, cond_resched_tasks_rcu_qs() may not help here > because preemption is not disabled right? Still I see no harm in using it > here either as it may give a slight speed up for tasks-RCU. The RCU-tasks stall-warning interval is ten minutes, and I have not yet seen evidence that we are getting close to that. If we do, then yes, a cond_resched_tasks_rcu_qs() might be in this code's future. But it does add overhead, so we need to see the evidence first. Thanx, Paul > thanks, > > - Joel > > > } > > vm_unacct_memory(nr_accounted); > > } > > -- > > 2.9.5 > >
On Tue, Jun 23, 2020 at 01:55:08PM -0700, Paul E. McKenney wrote: [..] > > Just for my understanding, cond_resched_tasks_rcu_qs() may not help here > > because preemption is not disabled right? Still I see no harm in using it > > here either as it may give a slight speed up for tasks-RCU. > > The RCU-tasks stall-warning interval is ten minutes, and I have not yet > seen evidence that we are getting close to that. If we do, then yes, > a cond_resched_tasks_rcu_qs() might be in this code's future. But it > does add overhead, so we need to see the evidence first. Yes, true about that overhead. Ok, this is fine with me too, thanks :) - Joel
diff --git a/mm/mmap.c b/mm/mmap.c index 59a4682..972f839 100644 --- a/mm/mmap.c +++ b/mm/mmap.c @@ -3159,6 +3159,7 @@ void exit_mmap(struct mm_struct *mm) if (vma->vm_flags & VM_ACCOUNT) nr_accounted += vma_pages(vma); vma = remove_vma(vma); + cond_resched(); } vm_unacct_memory(nr_accounted); }