Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1523688 > unrolled thread

Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node`

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  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-16 18: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-21 14:50 +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-21 15:10 +0100
        Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and  `mem_cgroup_shrink_node` Michal Hocko <mhocko@kernel.org> - 2016-11-21 15: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-21 15: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-21 16: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-24 11: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-24 20:00 +0100

#1523688 — Re: INFO: rcu_sched detected stalls on CPUs/tasks with `kswapd` and `mem_cgroup_shrink_node`

On Wed, Nov 16, 2016 at 06:01:19PM +0100, Paul Menzel wrote:
> Dear Linux folks,
> 
> 
> On 11/08/16 19:39, Paul E. McKenney wrote:
> >On Tue, Nov 08, 2016 at 06:38:18PM +0100, Paul Menzel wrote:
> >>On 11/08/16 18:03, Paul E. McKenney wrote:
> >>>On Tue, Nov 08, 2016 at 01:22:28PM +0100, Paul Menzel wrote:
> >>
> >>>>Could you please help me shedding some light into the messages below?
> >>>>
> >>>>With Linux 4.4.X, these messages were not seen. When updating to
> >>>>Linux 4.8.4, and Linux 4.8.6 they started to appear. In that
> >>>>version, we enabled several CGROUP options.
> >>>>
> >>>>>$ dmesg -T
> >>>>>[…]
> >>>>>[Mon Nov  7 15:09:45 2016] INFO: rcu_sched detected stalls on CPUs/tasks:
> >>>>>[Mon Nov  7 15:09:45 2016]     3-...: (493 ticks this GP) idle=515/140000000000000/0 softirq=5504423/5504423 fqs=13876
> >>>>>[Mon Nov  7 15:09:45 2016]     (detected by 5, t=60002 jiffies, g=1363193, c=1363192, q=268508)
> >>>>>[Mon Nov  7 15:09:45 2016] Task dump for CPU 3:
> >>>>>[Mon Nov  7 15:09:45 2016] kswapd1         R  running task        0    87      2 0x00000008
> >>>>>[Mon Nov  7 15:09:45 2016]  ffffffff81aabdfd ffff8810042a5cb8 ffff88080ad34000 ffff88080ad33dc8
> >>>>>[Mon Nov  7 15:09:45 2016]  ffff88080ad33d00 0000000000003501 0000000000000000 0000000000000000
> >>>>>[Mon Nov  7 15:09:45 2016]  0000000000000000 0000000000000000 0000000000022316 000000000002bc9f
> >>>>>[Mon Nov  7 15:09:45 2016] Call Trace:
> >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81aabdfd>] ? __schedule+0x21d/0x5b0
> >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81106dcf>] ? shrink_node+0xbf/0x1c0
> >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81107865>] ? kswapd+0x315/0x5f0
> >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81107550>] ? mem_cgroup_shrink_node+0x90/0x90
> >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff8106c614>] ? kthread+0xc4/0xe0
> >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81aaf64f>] ? ret_from_fork+0x1f/0x40
> >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff8106c550>] ? kthread_worker_fn+0x160/0x160
> >>>>
> >>>>Even after reading `stallwarn.txt` [1], I don’t know what could
> >>>>cause this. All items in the backtrace seem to belong to the Linux
> >>>>kernel.
> >>>>
> >>>>There is also nothing suspicious in the monitoring graphs during that time.
> >>>
> >>>If you let it be, do you get a later stall warning a few minutes later?
> >>>If so, how does the stack trace compare?
> >>
> >>With Linux 4.8.6 this is the only occurrence since yesterday.
> >>
> >>With Linux 4.8.3, and 4.8.4 the following stack traces were seen.
> >
> >Looks to me like one or both of the loops in shrink_node() need
> >an cond_resched_rcu_qs().
> 
> Thank you for the pointer. I haven’t had time yet to look into it.

In theory, it is quite straightforward, as shown by the patch below.
In practice, the MM guys might wish to call cond_resched_rcu_qs() less
frequently, but I will leave that to their judgment.  My guess is that
the overhead of the cond_resched_rcu_qs() is way down in the noise,
but I have been surprised in the past.

Anyway, please give this patch a try and let me know how it goes.

							Thanx, Paul

------------------------------------------------------------------------

commit 1a5595eec6c034c27e1c826a93292240bfea934e
Author: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
Date:   Wed Nov 16 09:26:28 2016 -0800

    mm: Prevent shrink_node() RCU CPU stall warnings
    
    This commit adds a couple cond_resched_rcu_qs() calls in the inner
    loop in shrink_node() in order to prevent RCU CPU stall warnings.
    
    Reported-by: Paul Menzel <pmenzel@molgen.mpg.de>
    Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>

diff --git a/mm/vmscan.c b/mm/vmscan.c
index 744f926af442..0d3b5f5a04ef 100644
--- a/mm/vmscan.c
+++ b/mm/vmscan.c
@@ -2529,8 +2529,11 @@ static bool shrink_node(pg_data_t *pgdat, struct scan_control *sc)
 			unsigned long scanned;
 
 			if (mem_cgroup_low(root, memcg)) {
-				if (!sc->may_thrash)
+				if (!sc->may_thrash) {
+					/* Prevent CPU CPU stalls. */
+					cond_resched_rcu_qs();
 					continue;
+				}
 				mem_cgroup_events(memcg, MEMCG_LOW, 1);
 			}
 
@@ -2565,6 +2568,7 @@ static bool shrink_node(pg_data_t *pgdat, struct scan_control *sc)
 				mem_cgroup_iter_break(root, memcg);
 				break;
 			}
+			cond_resched_rcu_qs(); /* Prevent CPU CPU stalls. */
 		} while ((memcg = mem_cgroup_iter(root, memcg, &reclaim)));
 
 		/*

[toc] | [next] | [standalone]

#1526680

On Wed 16-11-16 09:30:36, Paul E. McKenney wrote:
> On Wed, Nov 16, 2016 at 06:01:19PM +0100, Paul Menzel wrote:
> > Dear Linux folks,
> > 
> > 
> > On 11/08/16 19:39, Paul E. McKenney wrote:
> > >On Tue, Nov 08, 2016 at 06:38:18PM +0100, Paul Menzel wrote:
> > >>On 11/08/16 18:03, Paul E. McKenney wrote:
> > >>>On Tue, Nov 08, 2016 at 01:22:28PM +0100, Paul Menzel wrote:
> > >>
> > >>>>Could you please help me shedding some light into the messages below?
> > >>>>
> > >>>>With Linux 4.4.X, these messages were not seen. When updating to
> > >>>>Linux 4.8.4, and Linux 4.8.6 they started to appear. In that
> > >>>>version, we enabled several CGROUP options.
> > >>>>
> > >>>>>$ dmesg -T
> > >>>>>[…]
> > >>>>>[Mon Nov  7 15:09:45 2016] INFO: rcu_sched detected stalls on CPUs/tasks:
> > >>>>>[Mon Nov  7 15:09:45 2016]     3-...: (493 ticks this GP) idle=515/140000000000000/0 softirq=5504423/5504423 fqs=13876
> > >>>>>[Mon Nov  7 15:09:45 2016]     (detected by 5, t=60002 jiffies, g=1363193, c=1363192, q=268508)
> > >>>>>[Mon Nov  7 15:09:45 2016] Task dump for CPU 3:
> > >>>>>[Mon Nov  7 15:09:45 2016] kswapd1         R  running task        0    87      2 0x00000008
> > >>>>>[Mon Nov  7 15:09:45 2016]  ffffffff81aabdfd ffff8810042a5cb8 ffff88080ad34000 ffff88080ad33dc8
> > >>>>>[Mon Nov  7 15:09:45 2016]  ffff88080ad33d00 0000000000003501 0000000000000000 0000000000000000
> > >>>>>[Mon Nov  7 15:09:45 2016]  0000000000000000 0000000000000000 0000000000022316 000000000002bc9f
> > >>>>>[Mon Nov  7 15:09:45 2016] Call Trace:
> > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81aabdfd>] ? __schedule+0x21d/0x5b0
> > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81106dcf>] ? shrink_node+0xbf/0x1c0
> > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81107865>] ? kswapd+0x315/0x5f0
> > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81107550>] ? mem_cgroup_shrink_node+0x90/0x90
> > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff8106c614>] ? kthread+0xc4/0xe0
> > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81aaf64f>] ? ret_from_fork+0x1f/0x40
> > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff8106c550>] ? kthread_worker_fn+0x160/0x160
> > >>>>
> > >>>>Even after reading `stallwarn.txt` [1], I don’t know what could
> > >>>>cause this. All items in the backtrace seem to belong to the Linux
> > >>>>kernel.
> > >>>>
> > >>>>There is also nothing suspicious in the monitoring graphs during that time.
> > >>>
> > >>>If you let it be, do you get a later stall warning a few minutes later?
> > >>>If so, how does the stack trace compare?
> > >>
> > >>With Linux 4.8.6 this is the only occurrence since yesterday.
> > >>
> > >>With Linux 4.8.3, and 4.8.4 the following stack traces were seen.
> > >
> > >Looks to me like one or both of the loops in shrink_node() need
> > >an cond_resched_rcu_qs().
> > 
> > Thank you for the pointer. I haven’t had time yet to look into it.
> 
> In theory, it is quite straightforward, as shown by the patch below.
> In practice, the MM guys might wish to call cond_resched_rcu_qs() less
> frequently, but I will leave that to their judgment.  My guess is that
> the overhead of the cond_resched_rcu_qs() is way down in the noise,
> but I have been surprised in the past.
> 
> Anyway, please give this patch a try and let me know how it goes.

I am not seeing the full thread in my inbox but I am wondering what is
actually going on here. The reclaim path (shrink_node_memcg resp.
shrink_slab should have preemption points and there is not done much
except of iterating over all memcgs other than that. Are there
gazillions of memcgs configured (most of them with the low limit
configured)? In other words is the system configured properly?

To the patch. I cannot say I would like it. cond_resched_rcu_qs sounds
way too lowlevel for this usage. If anything cond_resched somewhere inside
mem_cgroup_iter would be more appropriate to me.
-- 
Michal Hocko
SUSE Labs

[toc] | [prev] | [next] | [standalone]

#1526691

On Mon, Nov 21, 2016 at 02:41:31PM +0100, Michal Hocko wrote:
> On Wed 16-11-16 09:30:36, Paul E. McKenney wrote:
> > On Wed, Nov 16, 2016 at 06:01:19PM +0100, Paul Menzel wrote:
> > > Dear Linux folks,
> > > 
> > > 
> > > On 11/08/16 19:39, Paul E. McKenney wrote:
> > > >On Tue, Nov 08, 2016 at 06:38:18PM +0100, Paul Menzel wrote:
> > > >>On 11/08/16 18:03, Paul E. McKenney wrote:
> > > >>>On Tue, Nov 08, 2016 at 01:22:28PM +0100, Paul Menzel wrote:
> > > >>
> > > >>>>Could you please help me shedding some light into the messages below?
> > > >>>>
> > > >>>>With Linux 4.4.X, these messages were not seen. When updating to
> > > >>>>Linux 4.8.4, and Linux 4.8.6 they started to appear. In that
> > > >>>>version, we enabled several CGROUP options.
> > > >>>>
> > > >>>>>$ dmesg -T
> > > >>>>>[…]
> > > >>>>>[Mon Nov  7 15:09:45 2016] INFO: rcu_sched detected stalls on CPUs/tasks:
> > > >>>>>[Mon Nov  7 15:09:45 2016]     3-...: (493 ticks this GP) idle=515/140000000000000/0 softirq=5504423/5504423 fqs=13876
> > > >>>>>[Mon Nov  7 15:09:45 2016]     (detected by 5, t=60002 jiffies, g=1363193, c=1363192, q=268508)
> > > >>>>>[Mon Nov  7 15:09:45 2016] Task dump for CPU 3:
> > > >>>>>[Mon Nov  7 15:09:45 2016] kswapd1         R  running task        0    87      2 0x00000008
> > > >>>>>[Mon Nov  7 15:09:45 2016]  ffffffff81aabdfd ffff8810042a5cb8 ffff88080ad34000 ffff88080ad33dc8
> > > >>>>>[Mon Nov  7 15:09:45 2016]  ffff88080ad33d00 0000000000003501 0000000000000000 0000000000000000
> > > >>>>>[Mon Nov  7 15:09:45 2016]  0000000000000000 0000000000000000 0000000000022316 000000000002bc9f
> > > >>>>>[Mon Nov  7 15:09:45 2016] Call Trace:
> > > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81aabdfd>] ? __schedule+0x21d/0x5b0
> > > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81106dcf>] ? shrink_node+0xbf/0x1c0
> > > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81107865>] ? kswapd+0x315/0x5f0
> > > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81107550>] ? mem_cgroup_shrink_node+0x90/0x90
> > > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff8106c614>] ? kthread+0xc4/0xe0
> > > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff81aaf64f>] ? ret_from_fork+0x1f/0x40
> > > >>>>>[Mon Nov  7 15:09:45 2016]  [<ffffffff8106c550>] ? kthread_worker_fn+0x160/0x160
> > > >>>>
> > > >>>>Even after reading `stallwarn.txt` [1], I don’t know what could
> > > >>>>cause this. All items in the backtrace seem to belong to the Linux
> > > >>>>kernel.
> > > >>>>
> > > >>>>There is also nothing suspicious in the monitoring graphs during that time.
> > > >>>
> > > >>>If you let it be, do you get a later stall warning a few minutes later?
> > > >>>If so, how does the stack trace compare?
> > > >>
> > > >>With Linux 4.8.6 this is the only occurrence since yesterday.
> > > >>
> > > >>With Linux 4.8.3, and 4.8.4 the following stack traces were seen.
> > > >
> > > >Looks to me like one or both of the loops in shrink_node() need
> > > >an cond_resched_rcu_qs().
> > > 
> > > Thank you for the pointer. I haven’t had time yet to look into it.
> > 
> > In theory, it is quite straightforward, as shown by the patch below.
> > In practice, the MM guys might wish to call cond_resched_rcu_qs() less
> > frequently, but I will leave that to their judgment.  My guess is that
> > the overhead of the cond_resched_rcu_qs() is way down in the noise,
> > but I have been surprised in the past.
> > 
> > Anyway, please give this patch a try and let me know how it goes.
> 
> I am not seeing the full thread in my inbox but I am wondering what is
> actually going on here. The reclaim path (shrink_node_memcg resp.
> shrink_slab should have preemption points and there is not done much
> except of iterating over all memcgs other than that. Are there
> gazillions of memcgs configured (most of them with the low limit
> configured)? In other words is the system configured properly?
> 
> To the patch. I cannot say I would like it. cond_resched_rcu_qs sounds
> way too lowlevel for this usage. If anything cond_resched somewhere inside
> mem_cgroup_iter would be more appropriate to me.

Like this?

							Thanx, Paul

------------------------------------------------------------------------

diff --git a/mm/memcontrol.c b/mm/memcontrol.c
index ae052b5e3315..81cb30d5b2fc 100644
--- a/mm/memcontrol.c
+++ b/mm/memcontrol.c
@@ -867,6 +867,7 @@ struct mem_cgroup *mem_cgroup_iter(struct mem_cgroup *root,
 out:
 	if (prev && prev != root)
 		css_put(&prev->css);
+	cond_resched_rcu_qs();
 
 	return memcg;
 }

[toc] | [prev] | [next] | [standalone]

#1526703

On Mon 21-11-16 06:01:22, Paul E. McKenney wrote:
> On Mon, Nov 21, 2016 at 02:41:31PM +0100, Michal Hocko wrote:
[...]
> > To the patch. I cannot say I would like it. cond_resched_rcu_qs sounds
> > way too lowlevel for this usage. If anything cond_resched somewhere inside
> > mem_cgroup_iter would be more appropriate to me.
> 
> Like this?
> 
> 							Thanx, Paul
> 
> ------------------------------------------------------------------------
> 
> diff --git a/mm/memcontrol.c b/mm/memcontrol.c
> index ae052b5e3315..81cb30d5b2fc 100644
> --- a/mm/memcontrol.c
> +++ b/mm/memcontrol.c
> @@ -867,6 +867,7 @@ struct mem_cgroup *mem_cgroup_iter(struct mem_cgroup *root,
>  out:
>  	if (prev && prev != root)
>  		css_put(&prev->css);
> +	cond_resched_rcu_qs();

I still do not understand why should we play with _rcu_qs at all and a
regular cond_resched is not sufficient. Anyway I would have to double
check whether we can do cond_resched in the iterator. I do not remember
having users which are atomic but I might be easily wrong here. Before
we touch this code, though, I would really like to understand what is
actually going on here because as I've already pointed out we should
have some resched points in the reclaim path.

-- 
Michal Hocko
SUSE Labs

[toc] | [prev] | [next] | [standalone]

#1526718

On Mon, Nov 21, 2016 at 03:18:19PM +0100, Michal Hocko wrote:
> On Mon 21-11-16 06:01:22, Paul E. McKenney wrote:
> > On Mon, Nov 21, 2016 at 02:41:31PM +0100, Michal Hocko wrote:
> [...]
> > > To the patch. I cannot say I would like it. cond_resched_rcu_qs sounds
> > > way too lowlevel for this usage. If anything cond_resched somewhere inside
> > > mem_cgroup_iter would be more appropriate to me.
> > 
> > Like this?
> > 
> > 							Thanx, Paul
> > 
> > ------------------------------------------------------------------------
> > 
> > diff --git a/mm/memcontrol.c b/mm/memcontrol.c
> > index ae052b5e3315..81cb30d5b2fc 100644
> > --- a/mm/memcontrol.c
> > +++ b/mm/memcontrol.c
> > @@ -867,6 +867,7 @@ struct mem_cgroup *mem_cgroup_iter(struct mem_cgroup *root,
> >  out:
> >  	if (prev && prev != root)
> >  		css_put(&prev->css);
> > +	cond_resched_rcu_qs();
> 
> I still do not understand why should we play with _rcu_qs at all and a
> regular cond_resched is not sufficient. Anyway I would have to double
> check whether we can do cond_resched in the iterator. I do not remember
> having users which are atomic but I might be easily wrong here. Before
> we touch this code, though, I would really like to understand what is
> actually going on here because as I've already pointed out we should
> have some resched points in the reclaim path.

If there is a tight loop in the kernel, cond_resched() will ensure that
other tasks get a chance to run, but if there are no such tasks, it does
nothing to give RCU the quiescent state that it needs from time to time.
So if there is a possibility of a long-running in-kernel loop without
preemption by some other task, cond_resched_rcu_qs() is required.

I welcome your deeper investigation -- I am very much treating symptoms
here, which might or might not have any relationship to fixing underlying
problems.

							Thanx, Paul

[toc] | [prev] | [next] | [standalone]

#1526798

On 11/21/16 15:29, Paul E. McKenney wrote:
> On Mon, Nov 21, 2016 at 03:18:19PM +0100, Michal Hocko wrote:
>> On Mon 21-11-16 06:01:22, Paul E. McKenney wrote:
>>> On Mon, Nov 21, 2016 at 02:41:31PM +0100, Michal Hocko wrote:
>> [...]
>>>> To the patch. I cannot say I would like it. cond_resched_rcu_qs sounds
>>>> way too lowlevel for this usage. If anything cond_resched somewhere inside
>>>> mem_cgroup_iter would be more appropriate to me.
>>> Like this?
>>>
>>> 							Thanx, Paul
>>>
>>> ------------------------------------------------------------------------
>>>
>>> diff --git a/mm/memcontrol.c b/mm/memcontrol.c
>>> index ae052b5e3315..81cb30d5b2fc 100644
>>> --- a/mm/memcontrol.c
>>> +++ b/mm/memcontrol.c
>>> @@ -867,6 +867,7 @@ struct mem_cgroup *mem_cgroup_iter(struct mem_cgroup *root,
>>>   out:
>>>   	if (prev && prev != root)
>>>   		css_put(&prev->css);
>>> +	cond_resched_rcu_qs();
>> I still do not understand why should we play with _rcu_qs at all and a
>> regular cond_resched is not sufficient. Anyway I would have to double
>> check whether we can do cond_resched in the iterator. I do not remember
>> having users which are atomic but I might be easily wrong here. Before
>> we touch this code, though, I would really like to understand what is
>> actually going on here because as I've already pointed out we should
>> have some resched points in the reclaim path.
> If there is a tight loop in the kernel, cond_resched() will ensure that
> other tasks get a chance to run, but if there are no such tasks, it does
> nothing to give RCU the quiescent state that it needs from time to time.
> So if there is a possibility of a long-running in-kernel loop without
> preemption by some other task, cond_resched_rcu_qs() is required.
>
> I welcome your deeper investigation -- I am very much treating symptoms
> here, which might or might not have any relationship to fixing underlying
> problems.
>
> 							Thanx, Paul
>

Hello,

thanks a lot for looking into this!

Let me add some information from the reporting site:

* We've tried the patch from Paul E. McKenney (the one posted Wed, 16 
Nov 2016)  and it doesn't shut up the rcu stall warnings.

* Log file from a boot with the patch applied ( grep kernel 
/var/log/messages ) is here : 
http://owww.molgen.mpg.de/~buczek/321322/2016-11-21_syslog.txt

* This system is a backup server and walks over thousands of files 
sometimes with multiple parallel rsync processes.

* No rcu_* warnings on that machine with 4.7.2, but with 4.8.4 , 4.8.6 , 
4.8.8 and now 4.9.0-rc5+Pauls patch

* When the backups are actually happening there might be relevant memory 
pressure from inode cache and the rsync processes. We saw the oom-killer 
kick in on another machine with same hardware and similar (a bit higher) 
workload. This other machine also shows a lot of rcu stall warnings 
since 4.8.4.

* We see "rcu_sched detected stalls" also on some other machines since 
we switched to 4.8 but not as frequently as on the two backup servers. 
Usually there's "shrink_node" and "kswapd" on the top of the stack. 
Often "xfs_reclaim_inodes" variants on top of that.

Donald

-- 
Donald Buczek
buczek@molgen.mpg.de
Tel: +49 30 8413 1433

[toc] | [prev] | [next] | [standalone]

#1529131

On Mon 21-11-16 16:35:53, Donald Buczek wrote:
[...]
> Hello,
> 
> thanks a lot for looking into this!
> 
> Let me add some information from the reporting site:
> 
> * We've tried the patch from Paul E. McKenney (the one posted Wed, 16 Nov
> 2016)  and it doesn't shut up the rcu stall warnings.
> 
> * Log file from a boot with the patch applied ( grep kernel
> /var/log/messages ) is here :
> http://owww.molgen.mpg.de/~buczek/321322/2016-11-21_syslog.txt
> 
> * This system is a backup server and walks over thousands of files sometimes
> with multiple parallel rsync processes.
> 
> * No rcu_* warnings on that machine with 4.7.2, but with 4.8.4 , 4.8.6 ,
> 4.8.8 and now 4.9.0-rc5+Pauls patch

I assume you haven't tried the Linus 4.8 kernel without any further
stable patches? Just to be sure we are not talking about some later
regression which found its way to the stable tree.

> * When the backups are actually happening there might be relevant memory
> pressure from inode cache and the rsync processes. We saw the oom-killer
> kick in on another machine with same hardware and similar (a bit higher)
> workload. This other machine also shows a lot of rcu stall warnings since
> 4.8.4.
> 
> * We see "rcu_sched detected stalls" also on some other machines since we
> switched to 4.8 but not as frequently as on the two backup servers. Usually
> there's "shrink_node" and "kswapd" on the top of the stack. Often
> "xfs_reclaim_inodes" variants on top of that.

I would be interested to see some reclaim tracepoints enabled. Could you
try that out? At least mm_shrink_slab_{start,end} and
mm_vmscan_lru_shrink_inactive. This should tell us more about how the
reclaim behaved.
-- 
Michal Hocko
SUSE Labs

[toc] | [prev] | [next] | [standalone]

#1529624

On 24.11.2016 11:15, Michal Hocko wrote:

> On Mon 21-11-16 16:35:53, Donald Buczek wrote:
> [...]
>> Hello,
>>
>> thanks a lot for looking into this!
>>
>> Let me add some information from the reporting site:
>>
>> * We've tried the patch from Paul E. McKenney (the one posted Wed, 16 Nov
>> 2016)  and it doesn't shut up the rcu stall warnings.
>>
>> * Log file from a boot with the patch applied ( grep kernel
>> /var/log/messages ) is here :
>> http://owww.molgen.mpg.de/~buczek/321322/2016-11-21_syslog.txt
>>
>> * This system is a backup server and walks over thousands of files sometimes
>> with multiple parallel rsync processes.
>>
>> * No rcu_* warnings on that machine with 4.7.2, but with 4.8.4 , 4.8.6 ,
>> 4.8.8 and now 4.9.0-rc5+Pauls patch
> I assume you haven't tried the Linus 4.8 kernel without any further
> stable patches? Just to be sure we are not talking about some later
> regression which found its way to the stable tree.
>
>> * When the backups are actually happening there might be relevant memory
>> pressure from inode cache and the rsync processes. We saw the oom-killer
>> kick in on another machine with same hardware and similar (a bit higher)
>> workload. This other machine also shows a lot of rcu stall warnings since
>> 4.8.4.
>>
>> * We see "rcu_sched detected stalls" also on some other machines since we
>> switched to 4.8 but not as frequently as on the two backup servers. Usually
>> there's "shrink_node" and "kswapd" on the top of the stack. Often
>> "xfs_reclaim_inodes" variants on top of that.
> I would be interested to see some reclaim tracepoints enabled. Could you
> try that out? At least mm_shrink_slab_{start,end} and
> mm_vmscan_lru_shrink_inactive. This should tell us more about how the
> reclaim behaved.

We'll try that tomorrow!

Donald

-- 
Donald Buczek
buczek@molgen.mpg.de
Tel: +49 30 8413 1433

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web