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

Groups > linux.kernel > #1634131 > unrolled thread

Re: 4.8.8 kernel trigger OOM killer repeatedly when I have lots of RAM that should be free

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: 4.8.8 kernel trigger OOM killer repeatedly when I have lots of  RAM that should be free Marc MERLIN <marc@merlins.org> - 2017-05-02 06:40 +0200
    Re: 4.8.8 kernel trigger OOM killer repeatedly when I have lots of  RAM that should be free Michal Hocko <mhocko@kernel.org> - 2017-05-02 09:50 +0200
    Re: 4.8.8 kernel trigger OOM killer repeatedly when I have lots of  RAM that should be free Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp> - 2017-05-02 12:50 +0200
      Re: 4.8.8 kernel trigger OOM killer repeatedly when I have lots of  RAM that should be free Marc MERLIN <marc@merlins.org> - 2017-05-02 16:20 +0200

#1634131 — Re: 4.8.8 kernel trigger OOM killer repeatedly when I have lots of RAM that should be free

Howdy,

Well, sadly, the problem is more or less back is 4.11.0. The system doesn't really 
crash but it goes into an infinite loop with
[34776.826800] BUG: workqueue lockup - pool cpus=6 node=0 flags=0x0 nice=0 stuck for 33s!
More logs: https://pastebin.com/YqE4riw0

(I upgraded from 4.8 with custom patches you gave me, and went to 4.11.0

gargamel:~# cat /proc/sys/vm/dirty_ratio
2
gargamel:~# cat /proc/sys/vm/dirty_background_ratio
1
gargamel:~# free
             total       used       free     shared    buffers     cached
Mem:      24392600   16362660    8029940          0       8884   13739000
-/+ buffers/cache:    2614776   21777824
Swap:     15616764          0   15616764

And yet, I was doing a btrfs check repair on a busy filesystem, within 40mn or so,
it triggered the workqueue lockup.

gargamel:~# grep CONFIG_COMPACTION /boot/config-4.11.0-amd64-preempt-sysrq-20170406 
CONFIG_COMPACTION=y

kernel config file: https://pastebin.com/7Tajse6L

To be fair, I didn't try to run btrfs check on 4.8 and now I'm busy
trying to recover a filesystem that apparently got corrupted by a bad
SAS driver in 4.8 which caused a lot of I/O errors and corruption.
This is just to say that btrfs on top of dmcrypt on top of bcache may
have been enough layers to hang on btrfs check on 4.8 too, but I can't
really go back to check right now due to the driver corruption issues.

Any idea what I should do next?

Thanks,
Marc

On Tue, Nov 29, 2016 at 03:01:35PM -0800, Marc MERLIN wrote:
> On Tue, Nov 29, 2016 at 09:40:19AM -0800, Marc MERLIN wrote:
> > Thanks for the reply and suggestions.
> > 
> > On Tue, Nov 29, 2016 at 09:07:03AM -0800, Linus Torvalds wrote:
> > > On Tue, Nov 29, 2016 at 8:34 AM, Marc MERLIN <marc@merlins.org> wrote:
> > > > Now, to be fair, this is not a new problem, it's just varying degrees of
> > > > bad and usually only happens when I do a lot of I/O with btrfs.
> > > 
> > > One situation where I've seen something like this happen is
> > > 
> > >  (a) lots and lots of dirty data queued up
> > >  (b) horribly slow storage
> > 
> > In my case, it is a 5x 4TB HDD with 
> > software raid 5 < bcache < dmcrypt < btrfs
> > bcache is currently half disabled (as in I removed the actual cache) or
> > too many bcache requests pile up, and the kernel dies when too many
> > workqueues have piled up.
> > I'm just kind of worried that since I'm going through 4 subsystems
> > before my data can hit disk, that's a lot of memory allocations and
> > places where data can accumulate and cause bottlenecks if the next
> > subsystem isn't as fast.
> > 
> > But this shouldn't be "horribly slow", should it? (it does copy a few
> > terabytes per day, not fast, but not horrible, about 30MB/s or so)
> > 
> > > Sadly, our defaults for "how much dirty data do we allow" are somewhat
> > > buggered. The global defaults are in "percent of memory", and are
> > > generally _much_ too high for big-memory machines:
> > > 
> > >     [torvalds@i7 linux]$ cat /proc/sys/vm/dirty_ratio
> > >     20
> > >     [torvalds@i7 linux]$ cat /proc/sys/vm/dirty_background_ratio
> > >     10
> > 
> > I can confirm I have the same.
> > 
> > > says that it only starts really throttling writes when you hit 20% of
> > > all memory used. You don't say how much memory you have in that
> > > machine, but if it's the same one you talked about earlier, it was
> > > 24GB. So you can have 4GB of dirty data waiting to be flushed out.
> > 
> > Correct, 24GB and 4GB.
> > 
> > > And we *try* to do this per-device backing-dev congestion thing to
> > > make things work better, but it generally seems to not work very well.
> > > Possibly because of inconsistent write speeds (ie _sometimes_ the SSD
> > > does really well, and we want to open up, and then it shuts down).
> > > 
> > > One thing you can try is to just make the global limits much lower. As in
> > > 
> > >    echo 2 > /proc/sys/vm/dirty_ratio
> > >    echo 1 > /proc/sys/vm/dirty_background_ratio
> > 
> > I will give that a shot, thank you.
> 
> And, after 5H of copying, not a single hang, or USB disconnect, or anything.
> Obviously this seems to point to other problems in the code, and I have no
> idea which layer is a culprit here, but reducing the buffers absolutely
> helped a lot.

-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

[toc] | [next] | [standalone]

#1634203

On Mon 01-05-17 21:12:35, Marc MERLIN wrote:
> Howdy,
> 
> Well, sadly, the problem is more or less back is 4.11.0. The system doesn't really 
> crash but it goes into an infinite loop with
> [34776.826800] BUG: workqueue lockup - pool cpus=6 node=0 flags=0x0 nice=0 stuck for 33s!
> More logs: https://pastebin.com/YqE4riw0

I am seeing a lot of traces where tasks is waiting for an IO. I do not
see any OOM report there. Why do you believe this is an OOM killer
issue?
-- 
Michal Hocko
SUSE Labs

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

#1634333

On 2017/05/02 13:12, Marc MERLIN wrote:
> Well, sadly, the problem is more or less back is 4.11.0. The system doesn't really 
> crash but it goes into an infinite loop with
> [34776.826800] BUG: workqueue lockup - pool cpus=6 node=0 flags=0x0 nice=0 stuck for 33s!

Wow, two of workqueues are reaching max active.

[34777.202267] workqueue btrfs-endio-write: flags=0xe
[34777.218313]   pwq 16: cpus=0-7 flags=0x4 nice=0 active=8/8
[34777.236548]     in-flight: 15168:btrfs_endio_write_helper, 13855:btrfs_endio_write_helper, 3360:btrfs_endio_write_helper, 14241:btrfs_endio_write_helper, 27092:btrfs_endio_write_helper, 15194:btrfs_endio_write_helper, 15169:btrfs_endio_write_helper, 27093:btrfs_endio_write_helper
[34777.316225]     delayed: btrfs_endio_write_helper, btrfs_endio_write_helper, btrfs_endio_write_helper, btrfs_endio_write_helper, btrfs_endio_write_helper, btrfs_endio_write_helper

[34777.450684] workqueue bcache: flags=0x8
[34779.956462]   pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=256/256
[34779.978283]     in-flight: 15320:cached_dev_read_done [bcache], 23385:cached_dev_read_done [bcache], 23371:cached_dev_read_done [bcache], 15321:cached_dev_read_done [bcache], 15395:cached_dev_read_done [bcache], 11101:cached_dev_read_done [bcache], 15300:cached_dev_read_done [bcache], 23349:cached_dev_read_done [bcache], 23425:cached_dev_read_done [bcache], 23399:cached_dev_read_done [bcache], 15293:cached_dev_read_done [bcache], 20529:cached_dev_read_done [bcache], 15402:cached_dev_read_done [bcache], 23422:cached_dev_read_done [bcache], 23417:cached_dev_read_done [bcache], 23409:cached_dev_read_done [bcache], 20539:cached_dev_read_done [bcache], 23431:cached_dev_read_done [bcache], 20544:cached_dev_read_done [bcache], 15355:cached_dev_read_done [bcache], 11085:cached_dev_read_done [bcache], 6511:cached_dev_read_done [bcache]   

Googling with btrfs_endio_write_helper shows a stuck report with 4.8-rc5, but
seems no response ( https://www.spinics.net/lists/linux-btrfs/msg58633.html ).

> Any idea what I should do next?

Maybe you can try collecting list of all in-flight allocations with backtraces
using kmallocwd patches at
http://lkml.kernel.org/r/1489578541-81526-1-git-send-email-penguin-kernel@I-love.SAKURA.ne.jp
and http://lkml.kernel.org/r/201704272019.JEH26057.SHFOtMLJOOVFQF@I-love.SAKURA.ne.jp
which also tracks mempool allocations.
(Well, the

-	cond_resched();
+	//cond_resched();

change in the latter patch would not be preferable.)

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

#1634444

On Tue, May 02, 2017 at 09:44:33AM +0200, Michal Hocko wrote:
> On Mon 01-05-17 21:12:35, Marc MERLIN wrote:
> > Howdy,
> > 
> > Well, sadly, the problem is more or less back is 4.11.0. The system doesn't really 
> > crash but it goes into an infinite loop with
> > [34776.826800] BUG: workqueue lockup - pool cpus=6 node=0 flags=0x0 nice=0 stuck for 33s!
> > More logs: https://pastebin.com/YqE4riw0
> 
> I am seeing a lot of traces where tasks is waiting for an IO. I do not
> see any OOM report there. Why do you believe this is an OOM killer
> issue?

Good question. This is a followup of the problem I had in 4.8.8 until I
got a patch to fix the issue. Then, it used to OOM and later, to pile up
I/O tasks like this.
Now it doesn't OOM anymore, but tasks still pile up.
I temporarily fixed the issue by doing this:
gargamel:~# echo 0 > /proc/sys/vm/dirty_ratio
gargamel:~# echo 0 > /proc/sys/vm/dirty_background_ratio

of course my performance is abysmal now, but I can at least run btrfs
scrub without piling up enough IO to deadlock the system.

On Tue, May 02, 2017 at 07:44:47PM +0900, Tetsuo Handa wrote:
> > Any idea what I should do next?
> 
> Maybe you can try collecting list of all in-flight allocations with backtraces
> using kmallocwd patches at
> http://lkml.kernel.org/r/1489578541-81526-1-git-send-email-penguin-kernel@I-love.SAKURA.ne.jp
> and http://lkml.kernel.org/r/201704272019.JEH26057.SHFOtMLJOOVFQF@I-love.SAKURA.ne.jp
> which also tracks mempool allocations.
> (Well, the
> 
> -	cond_resched();
> +	//cond_resched();
> 
> change in the latter patch would not be preferable.)

Thanks. I can give that a shot as soon as my current scrub is done, it
may take another 12 to 24H at this rate.
In the meantimne, as explained above, not allowing any dirty VM has
worked around the problem (Linus pointed out to me in the original
thread that on a lightly loaded 24GB system, even 1 or 2% could still be
a lot of memory for requests to pile up in and cause issues in
degenerative cases like mine).
Now I'm still curious what changed betweeen 4.8.8 + custom patches and 4.11 to cause
this.

Marc
-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web