Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]
Groups > linux.kernel > #1533196
| From | Donald Buczek <buczek@molgen.mpg.de> |
|---|---|
| Newsgroups | linux.kernel |
| Subject | Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` |
| Date | 2016-11-30 11:30 +0100 |
| Message-ID | <sJajf-4SL-21@gated-at.bofh.it> (permalink) |
| References | (7 earlier) <sFYRk-2Wx-29@gated-at.bofh.it> <sGZii-1lC-27@gated-at.bofh.it> <sI3MR-2o2-3@gated-at.bofh.it> <sIrYT-1kN-65@gated-at.bofh.it> <sIteh-22H-15@gated-at.bofh.it> |
| Organization | linux.* mail to news gateway |
On 11/28/16 13:26, Paul Menzel wrote:
> [...]
>
> On 11/28/16 12:04, Michal Hocko wrote:
>> [...]
>>
>> OK, so one of the stall is reported at
>> [118077.988410] INFO: rcu_sched detected stalls on CPUs/tasks:
>> [118077.988416] 1-...: (181 ticks this GP)
>> idle=6d5/140000000000000/0 softirq=46417663/46417663 fqs=10691
>> [118077.988417] (detected by 4, t=60002 jiffies, g=11845915,
>> c=11845914, q=46475)
>> [118077.988421] Task dump for CPU 1:
>> [118077.988421] kswapd1 R running task 0 86 2
>> 0x00000008
>> [118077.988424] ffff88080ad87c58 ffff88080ad87c58 ffff88080ad87cf8
>> ffff88100c1e5200
>> [118077.988426] 0000000000000003 0000000000000000 ffff88080ad87e60
>> ffff88080ad87d90
>> [118077.988428] ffffffff811345f5 ffff88080ad87da0 ffff88100c1e5200
>> ffff88080ad87dd0
>> [118077.988430] Call Trace:
>> [118077.988436] [<ffffffff811345f5>] ? shrink_node_memcg+0x605/0x870
>> [118077.988438] [<ffffffff8113491f>] ? shrink_node+0xbf/0x1c0
>> [118077.988440] [<ffffffff81135642>] ? kswapd+0x342/0x6b0
>>
>> the interesting part of the traces would be around the same time:
>> clusterd-989 [009] .... 118023.654491:
>> mm_vmscan_direct_reclaim_end: nr_reclaimed=193
>> kswapd1-86 [001] dN.. 118023.987475:
>> mm_vmscan_lru_isolate: isolate_mode=0 classzone=0 order=0
>> nr_requested=32 nr_scanned=4239830 nr_taken=0 file=1
>> kswapd1-86 [001] dN.. 118024.320968:
>> mm_vmscan_lru_isolate: isolate_mode=0 classzone=0 order=0
>> nr_requested=32 nr_scanned=4239844 nr_taken=0 file=1
>> kswapd1-86 [001] dN.. 118024.654375:
>> mm_vmscan_lru_isolate: isolate_mode=0 classzone=0 order=0
>> nr_requested=32 nr_scanned=4239858 nr_taken=0 file=1
>> kswapd1-86 [001] dN.. 118024.987036:
>> mm_vmscan_lru_isolate: isolate_mode=0 classzone=0 order=0
>> nr_requested=32 nr_scanned=4239872 nr_taken=0 file=1
>> kswapd1-86 [001] dN.. 118025.319651:
>> mm_vmscan_lru_isolate: isolate_mode=0 classzone=0 order=0
>> nr_requested=32 nr_scanned=4239886 nr_taken=0 file=1
>> kswapd1-86 [001] dN.. 118025.652248:
>> mm_vmscan_lru_isolate: isolate_mode=0 classzone=0 order=0
>> nr_requested=32 nr_scanned=4239900 nr_taken=0 file=1
>> kswapd1-86 [001] dN.. 118025.984870:
>> mm_vmscan_lru_isolate: isolate_mode=0 classzone=0 order=0
>> nr_requested=32 nr_scanned=4239914 nr_taken=0 file=1
>> [...]
>> kswapd1-86 [001] dN.. 118084.274403:
>> mm_vmscan_lru_isolate: isolate_mode=0 classzone=0 order=0
>> nr_requested=32 nr_scanned=4241133 nr_taken=0 file=1
>>
>> Note the Need resched flag. The IRQ off part is expected because we are
>> holding the LRU lock which is IRQ safe.
Hmmm. With the lock held, preemption is disabled. If we are in that
state for some time, I'd expect need_resched just because of time
quantum. But... :
The call stack always has
> [<ffffffff811345f5>] ? shrink_node_memcg+0x605/0x870
which translates to
> (gdb) list *0xffffffff811345f5
> 0xffffffff811345f5 is in shrink_node_memcg (mm/vmscan.c:2065).
> 2060 static unsigned long shrink_list(enum lru_list lru, unsigned
long nr_to_scan,
> 2061 struct lruvec *lruvec, struct scan_control *sc)
> 2062 {
> 2063 if (is_active_lru(lru)) {
> 2064 if (inactive_list_is_low(lruvec, is_file_lru(lru), sc))
> 2065 shrink_active_list(nr_to_scan, lruvec, sc, lru);
> 2066 return 0;
> 2067 }
> 2068
> 2069 return shrink_inactive_list(nr_to_scan, lruvec, sc, lru);
So we are in shrink_active_list. I made a small change without keeping
the old vmlinux and the addresses are off by 16 bytes, but it can be
verified exactly on another machine:
> buczek@void:/scratch/local/linux-4.8.10-121.x86_64/source$ grep
shrink_node_memcg /var/log/messages
> [...]
> void kernel: [508779.136016] [<ffffffff8114833a>] ?
shrink_node_memcg+0x60a/0x870
> (gdb) disas 0xffffffff8114833a
> [...]
> 0xffffffff81148330 <+1536>: mov %r10,0x38(%rsp)
> 0xffffffff81148335 <+1541>: callq 0xffffffff81147a00
<shrink_active_list>
> 0xffffffff8114833a <+1546>: mov 0x38(%rsp),%r10
> 0xffffffff8114833f <+1551>: jmpq 0xffffffff81147f80
<shrink_node_memcg+592>
> 0xffffffff81148344 <+1556>: mov %r13,0x78(%r12)
shrink_active_list gets and releases the spinlock and calls
cond_resched(). This should give other tasks a chance to run. Just as an
experiment, I'm trying
--- a/mm/vmscan.c
+++ b/mm/vmscan.c
@@ -1921,7 +1921,7 @@ static void shrink_active_list(unsigned long
nr_to_scan,
spin_unlock_irq(&pgdat->lru_lock);
while (!list_empty(&l_hold)) {
- cond_resched();
+ cond_resched_rcu_qs();
page = lru_to_page(&l_hold);
list_del(&page->lru);
and didn't hit a rcu_sched warning for >21 hours uptime now. We'll see.
Is preemption disabled for another reason?
Regards
Donald
>> That is not a problem because
>> the lock is only held for SWAP_CLUSTER_MAX pages at maximum. It is also
>> interesing to see that we have scanned only 1303 pages during that 1
>> minute. That would be dead slow. None of them were good enough for the
>> reclaim but that doesn't sound like a problem. The trace simply suggests
>> that the reclaim was preempted by something else. Otherwise I cannot
>> imagine such a slow scanning.
>>
>> Is it possible that something else is hogging the CPU and the RCU just
>> happens to blame kswapd which is running in the standard user process
>> context?
>
> From looking at the monitoring graphs, there was always enough CPU
> resources available. The machine has 12x E5-2630 @ 2.30GHz. So that
> shouldn’t have been a problem.
>
>
> Kind regards,
>
> Paul Menzel
--
Donald Buczek
buczek@molgen.mpg.de
Tel: +49 30 8413 1433
Back to linux.kernel | Previous | Next — Previous in thread | Next in thread | Find similar | Unroll thread
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Donald Buczek <buczek@molgen.mpg.de> - 2016-11-27 10:20 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Michal Hocko <mhocko@kernel.org> - 2016-11-28 12:10 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Paul Menzel <pmenzel@molgen.mpg.de> - 2016-11-28 13:30 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Donald Buczek <buczek@molgen.mpg.de> - 2016-11-30 11:30 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Michal Hocko <mhocko@kernel.org> - 2016-11-30 12:20 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Donald Buczek <buczek@molgen.mpg.de> - 2016-11-30 12:50 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Donald Buczek <buczek@molgen.mpg.de> - 2016-12-02 10:20 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Donald Buczek <buczek@molgen.mpg.de> - 2016-12-06 09:40 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-11-30 13:00 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Paul Menzel <pmenzel@molgen.mpg.de> - 2016-11-30 13:40 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-11-30 15:40 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-11-30 13:00 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Michal Hocko <mhocko@kernel.org> - 2016-11-30 14:20 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-11-30 15:40 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Peter Zijlstra <peterz@infradead.org> - 2016-11-30 17:40 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Michal Hocko <mhocko@kernel.org> - 2016-11-30 18:10 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-11-30 18:30 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Michal Hocko <mhocko@kernel.org> - 2016-11-30 18:40 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Peter Zijlstra <peterz@infradead.org> - 2016-11-30 19:00 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-11-30 22:40 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Peter Zijlstra <peterz@infradead.org> - 2016-12-01 06:40 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-12-01 13:50 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Peter Zijlstra <peterz@infradead.org> - 2016-12-01 17:40 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-12-01 18:00 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Peter Zijlstra <peterz@infradead.org> - 2016-12-01 19:20 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-12-01 19:50 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` Peter Zijlstra <peterz@infradead.org> - 2016-12-01 20:00 +0100
Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node` "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-11-30 18:10 +0100
csiph-web