Re: 4.6.2 frequent crashes under memory + IO pressure

[Johannes Stezenbach <js@sig21.net>]

(adding back Cc:, just dropped it to send the logs)

On Mon, Jun 27, 2016 at 01:35:14AM +0900, Tetsuo Handa wrote:
> 
> It seems to me that GFP_NOIO allocation requests are depleting memory reserves
> because they are passing ALLOC_NO_WATERMARKS to get_page_from_freelist().
> But I'm not familiar with block layer / swap I/O operation. So, will you post
> to linux-mm ML for somebody else to help you?

Frankly I don't care that much about 4.6.y when 4.7 is fixed.
Or, maybe the root issue is not fixed but the new oom code
covers it.  Below I see both dm and kcryptd so there is no
surprise when using swap on lvm on dm-crypt triggers it.
Maybe it's not a new issue on 4.6 but just some random variation
that makes it trigger easier with my particular workload.

So, unless you would like to keep going at it I'd
like to put the issue at rest.

> kswapd0(766) 0x2201200
>  0xffffffff81167522 : get_page_from_freelist+0x0/0x82b [kernel]
>  0xffffffff81168127 : __alloc_pages_nodemask+0x3da/0x978 [kernel]
>  0xffffffff8119fb2a : new_slab+0xbc/0x3bb [kernel]
>  0xffffffff811a1acd : ___slab_alloc.constprop.22+0x2fb/0x37b [kernel]
>  0xffffffff81162a88 : mempool_alloc_slab+0x15/0x17 [kernel] (inexact)
>  0xffffffff810c502d : put_lock_stats.isra.9+0xe/0x20 [kernel] (inexact)
>  0xffffffff811a1ba4 : __slab_alloc.isra.17.constprop.21+0x57/0x8b [kernel] (inexact)
>  0xffffffff811a1ba4 : __slab_alloc.isra.17.constprop.21+0x57/0x8b [kernel] (inexact)
>  0xffffffff81162a88 : mempool_alloc_slab+0x15/0x17 [kernel] (inexact)
>  0xffffffff811a1c78 : kmem_cache_alloc+0xa0/0x1d6 [kernel] (inexact)
>  0xffffffff81162a88 : mempool_alloc_slab+0x15/0x17 [kernel] (inexact)
>  0xffffffff81162a88 : mempool_alloc_slab+0x15/0x17 [kernel] (inexact)
>  0xffffffff81162b7a : mempool_alloc+0x72/0x154 [kernel] (inexact)
>  0xffffffff810c6438 : __lock_acquire.isra.16+0x55e/0xb4c [kernel] (inexact)
>  0xffffffff8133fdc1 : bio_alloc_bioset+0xe8/0x1d7 [kernel] (inexact)
>  0xffffffff816342ea : alloc_tio+0x2d/0x47 [kernel] (inexact)
>  0xffffffff8163587e : __split_and_process_bio+0x310/0x3a3 [kernel] (inexact)
>  0xffffffff81635e15 : dm_make_request+0xb5/0xe2 [kernel] (inexact)
>  0xffffffff81347ae7 : generic_make_request+0xcc/0x180 [kernel] (inexact)
>  0xffffffff81347c98 : submit_bio+0xfd/0x145 [kernel] (inexact)
> 
> kswapd0(766) 0x2201200
>  0xffffffff81167522 : get_page_from_freelist+0x0/0x82b [kernel]
>  0xffffffff81168127 : __alloc_pages_nodemask+0x3da/0x978 [kernel]
>  0xffffffff8119fb2a : new_slab+0xbc/0x3bb [kernel]
>  0xffffffff811a1acd : ___slab_alloc.constprop.22+0x2fb/0x37b [kernel]
>  0xffffffff81162a88 : mempool_alloc_slab+0x15/0x17 [kernel] (inexact)
>  0xffffffff81640e29 : kcryptd_queue_crypt+0x63/0x68 [kernel] (inexact)
>  0xffffffff811a1ba4 : __slab_alloc.isra.17.constprop.21+0x57/0x8b [kernel] (inexact)
>  0xffffffff811a1ba4 : __slab_alloc.isra.17.constprop.21+0x57/0x8b [kernel] (inexact)
>  0xffffffff81162a88 : mempool_alloc_slab+0x15/0x17 [kernel] (inexact)
>  0xffffffff811a1c78 : kmem_cache_alloc+0xa0/0x1d6 [kernel] (inexact)
>  0xffffffff81162a88 : mempool_alloc_slab+0x15/0x17 [kernel] (inexact)
>  0xffffffff81162a88 : mempool_alloc_slab+0x15/0x17 [kernel] (inexact)
>  0xffffffff81162b7a : mempool_alloc+0x72/0x154 [kernel] (inexact)
>  0xffffffff8101f5ba : sched_clock+0x9/0xd [kernel] (inexact)
>  0xffffffff810ae420 : local_clock+0x20/0x22 [kernel] (inexact)
>  0xffffffff8133fdc1 : bio_alloc_bioset+0xe8/0x1d7 [kernel] (inexact)
>  0xffffffff811983d0 : end_swap_bio_write+0x0/0x6a [kernel] (inexact)
>  0xffffffff8119854b : get_swap_bio+0x25/0x6c [kernel] (inexact)
>  0xffffffff811983d0 : end_swap_bio_write+0x0/0x6a [kernel] (inexact)
>  0xffffffff811988ef : __swap_writepage+0x1a9/0x225 [kernel] (inexact)
> 
> > 
> > > # ~/systemtap.tmp/bin/stap -e 'global traces_bt[65536];
> > > probe begin { printf("Probe start!\n"); }
> > > function dump_if_new(mask:long) {
> > >   bt = backtrace();
> > >   if (traces_bt[bt]++ == 0) {
> > >     printf("%s(%u) 0x%lx\n", execname(), pid(), mask);
> > >     print_backtrace();
> > >     printf("\n");
> > >   }
> > > }
> > > probe kernel.function("get_page_from_freelist") { if ($alloc_flags & 0x4) dump_if_new($gfp_mask); }
> > > probe kernel.function("gfp_pfmemalloc_allowed").return { if ($return != 0) dump_if_new($gfp_mask); }
> > > probe end { delete traces_bt; }'
> > ...
> > > # addr2line -i -e /usr/src/linux-4.6.2/vmlinux 0xffffffff811b9c82
> > > /usr/src/linux-4.6.2/mm/memory.c:1162
> > > /usr/src/linux-4.6.2/mm/memory.c:1241
> > > /usr/src/linux-4.6.2/mm/memory.c:1262
> > > /usr/src/linux-4.6.2/mm/memory.c:1283
> > 
> > I'm attaching both the stap output and the serial console log,
> > not sure what you're looking for with addr2line.  Let me know.
> 
> I just meant how to find location in source code from addresses.

I meant the log is so large I wouldn't know which
addresses would be interesting to look up.

Thanks,
Johannes