linux guest + nfsserver + virtio + vhost + vnet_hdr = tons of OOMs

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



I were debugging an unrelated issue today (in nfs server),
and noticed that the above combination, when doing lots
of read requests from an nfs client, quickly reaches OOM
condition which gets triggered very often.

I used a 512-Mb guest with 32bit kernel inside.  By doing
a cp of a large directory from it, in less than a minute,
the guest starts OOMing like crazy.  There's no other apps
running in it, except shell and a few gettys.

Removing vnet_hdr is enough to stop the OOMs from happening.

I can only guess nfs server isn't a requiriment, but is an
easy reproducer (a way to generate some network I/O load).

This happens with 3.0 and 3.2 stable kernels (in guest).
It does not happen with 2.6.32 obviously, as it lacks
vhost-net.

The OOMs appears to be warnings only, at least the NFS
works fine without externally visible errors.

Example:

[ 1263.216077] nfsd: page allocation failure: order:1, mode:0x20
[ 1263.216722] Pid: 596, comm: nfsd Tainted: G S      W   3.0.0-i686 #3.0.31
[ 1263.218222] Call Trace:
[ 1263.218523]  [<c10bf6f8>] ? warn_alloc_failed+0x98/0x100
[ 1263.219025]  [<c10c0480>] ? __alloc_pages_nodemask+0x4d0/0x770
[ 1263.219025]  [<c10efeb7>] ? cache_alloc_refill+0x2e7/0x510
[ 1263.219025]  [<c10f0434>] ? __kmalloc+0x124/0x140
[ 1263.219025]  [<c1249ebe>] ? pskb_expand_head+0x12e/0x210
[ 1263.219025]  [<c1249ebe>] ? pskb_expand_head+0x12e/0x210
[ 1263.219025]  [<e08f2541>] ? virtqueue_add_buf_gfp+0x191/0x340 [virtio_ring]
[ 1263.219025]  [<c124a41d>] ? __pskb_pull_tail+0x4d/0x2b0
[ 1263.219025]  [<e090f477>] ? start_xmit+0x137/0x330 [virtio_net]
[ 1263.219025]  [<c125377a>] ? dev_hard_start_xmit+0x29a/0x610
[ 1263.219025]  [<c10b934e>] ? find_get_pages_contig+0x2e/0x110
[ 1263.219025]  [<c111beab>] ? splice_to_pipe+0xeb/0x210
[ 1263.219025]  [<c126a9ba>] ? sch_direct_xmit+0xba/0x180
[ 1263.219025]  [<c1253c2c>] ? dev_queue_xmit+0x13c/0x530
[ 1263.219025]  [<c1281735>] ? ip_queue_xmit+0x55/0x3d0
[ 1263.219025]  [<c128200b>] ? ip_finish_output+0x13b/0x310
[ 1263.219025]  [<c1281418>] ? ip_local_out+0x18/0x20
[ 1263.219025]  [<c1294bc6>] ? tcp_transmit_skb+0x386/0x810
[ 1263.219025]  [<c12971c8>] ? tcp_write_xmit+0x198/0x980
[ 1263.219025]  [<c1297a14>] ? __tcp_push_pending_frames+0x24/0x90
[ 1263.219025]  [<c128b2b8>] ? tcp_sendpage+0x558/0x5f0
[ 1263.219025]  [<c111afb0>] ? page_cache_pipe_buf_release+0x10/0x10
[ 1263.219025]  [<c128ad60>] ? tcp_sendmsg+0xb50/0xb50
[ 1263.219025]  [<c12a9789>] ? inet_sendpage+0x69/0x110
[ 1263.219025]  [<c111b295>] ? splice_direct_to_actor+0x175/0x1e0
[ 1263.219025]  [<c12a9720>] ? inet_dgram_connect+0x80/0x80
[ 1263.219025]  [<c1240f6e>] ? kernel_sendpage+0x4e/0x90
[ 1263.219025]  [<e0a74d39>] ? svc_send_common+0xc9/0x120 [sunrpc]
[ 1263.219025]  [<e0a74df6>] ? svc_sendto+0x66/0x1e0 [sunrpc]
[ 1263.219025]  [<e0c00519>] ? nfsd4_encode_read+0xf9/0x200 [nfsd]
[ 1263.219025]  [<e0c00420>] ? nfsd4_encode_readdir+0x1e0/0x1e0 [nfsd]
[ 1263.219025]  [<e0bfa93c>] ? nfsd4_encode_operation+0x5c/0x170 [nfsd]
[ 1263.219025]  [<c110b6b4>] ? dput+0x14/0x140
[ 1263.219025]  [<e0bfae0e>] ? nfsd4_release_compoundargs+0x1e/0x50 [nfsd]
[ 1263.219025]  [<e0bf8b58>] ? nfsd4_proc_compound+0x1e8/0x490 [nfsd]
[ 1263.219025]  [<e0bffccf>] ? nfs4svc_decode_compoundargs+0x26f/0x340 [nfsd]
[ 1263.219025]  [<e0a74ff6>] ? svc_tcp_sendto+0x36/0xa0 [sunrpc]
[ 1263.219025]  [<e0a7e278>] ? svc_send+0x88/0xc0 [sunrpc]
[ 1263.219025]  [<e0a719b8>] ? svc_process+0x228/0x760 [sunrpc]
[ 1263.219025]  [<e0be998c>] ? nfsd+0xac/0x140 [nfsd]
[ 1263.219025]  [<c1032fc0>] ? complete+0x40/0x60
[ 1263.219025]  [<e0be98e0>] ? nfsd_svc+0x1d0/0x1d0 [nfsd]
[ 1263.219025]  [<c105d054>] ? kthread+0x74/0x80
[ 1263.219025]  [<c105cfe0>] ? kthread_worker_fn+0x160/0x160
[ 1263.219025]  [<c12e7b76>] ? kernel_thread_helper+0x6/0xd
[ 1263.219025] Mem-Info:
[ 1263.219025] DMA per-cpu:
[ 1263.219025] CPU    0: hi:    0, btch:   1 usd:   0
[ 1263.219025] CPU    1: hi:    0, btch:   1 usd:   0
[ 1263.219025] Normal per-cpu:
[ 1263.219025] CPU    0: hi:  186, btch:  31 usd:  63
[ 1263.219025] CPU    1: hi:  186, btch:  31 usd: 155
[ 1263.219025] active_anon:773 inactive_anon:8 isolated_anon:0
[ 1263.219025]  active_file:8114 inactive_file:114260 isolated_file:0
[ 1263.219025]  unevictable:0 dirty:5 writeback:0 unstable:0
[ 1263.219025]  free:1982 slab_reclaimable:940 slab_unreclaimable:1363
[ 1263.219025]  mapped:713 shmem:14 pagetables:74 bounce:0
[ 1263.219025] DMA free:2312kB min:84kB low:104kB high:124kB active_anon:0kB inactive_anon:0kB active_file:16kB inactive_file:11392kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15788kB mlocked:0kB dirty:0kB writeback:0kB mapped:4kB shmem:0kB slab_reclaimable:52kB slab_unreclaimable:1880kB kernel_stack:16kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 1263.219025] lowmem_reserve[]: 0 492 492 492
[ 1263.219025] Normal free:5616kB min:2792kB low:3488kB high:4188kB active_anon:3092kB inactive_anon:32kB active_file:32440kB inactive_file:445648kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:503928kB mlocked:0kB dirty:20kB writeback:0kB mapped:2848kB shmem:56kB slab_reclaimable:3708kB slab_unreclaimable:3572kB kernel_stack:472kB pagetables:296kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 1263.219025] lowmem_reserve[]: 0 0 0 0
[ 1263.219025] DMA: 34*4kB 28*8kB 0*16kB 7*32kB 7*64kB 2*128kB 0*256kB 0*512kB 1*1024kB 0*2048kB 0*4096kB = 2312kB
[ 1263.219025] Normal: 838*4kB 225*8kB 23*16kB 1*32kB 1*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 5616kB
[ 1263.219025] 122403 total pagecache pages
[ 1263.219025] 0 pages in swap cache
[ 1263.219025] Swap cache stats: add 0, delete 0, find 0/0
[ 1263.219025] Free swap  = 0kB
[ 1263.219025] Total swap = 0kB
[ 1263.219025] 131054 pages RAM
[ 1263.219025] 0 pages HighMem
[ 1263.219025] 2401 pages reserved
[ 1263.219025] 9617 pages shared
[ 1263.219025] 118383 pages non-shared

[ 1265.455155] nfsd: page allocation failure: order:1, mode:0x20
[ 1265.455940] Pid: 595, comm: nfsd Tainted: G S      W   3.0.0-i686 #3.0.31
[ 1265.456797] Call Trace:
[ 1265.463102]  [<c10bf6f8>] ? warn_alloc_failed+0x98/0x100
[ 1265.463102]  [<c10c0480>] ? __alloc_pages_nodemask+0x4d0/0x770
[ 1265.463102]  [<c10efeb7>] ? cache_alloc_refill+0x2e7/0x510
[ 1265.463102]  [<c10f0434>] ? __kmalloc+0x124/0x140
[ 1265.463102]  [<c1249ebe>] ? pskb_expand_head+0x12e/0x210
[ 1265.463102]  [<c1249ebe>] ? pskb_expand_head+0x12e/0x210
[ 1265.463102]  [<e08f2541>] ? virtqueue_add_buf_gfp+0x191/0x340 [virtio_ring]
[ 1265.463102]  [<c124a41d>] ? __pskb_pull_tail+0x4d/0x2b0
[ 1265.463102]  [<e090f477>] ? start_xmit+0x137/0x330 [virtio_net]
[ 1265.463102]  [<c125377a>] ? dev_hard_start_xmit+0x29a/0x610
[ 1265.463102]  [<c10b934e>] ? find_get_pages_contig+0x2e/0x110
[ 1265.463102]  [<c111beab>] ? splice_to_pipe+0xeb/0x210
[ 1265.463102]  [<c126a9ba>] ? sch_direct_xmit+0xba/0x180
[ 1265.463102]  [<c1253c2c>] ? dev_queue_xmit+0x13c/0x530
[ 1265.463102]  [<c1281735>] ? ip_queue_xmit+0x55/0x3d0
[ 1265.463102]  [<c128200b>] ? ip_finish_output+0x13b/0x310
[ 1265.463102]  [<c1281418>] ? ip_local_out+0x18/0x20
[ 1265.463102]  [<c1294bc6>] ? tcp_transmit_skb+0x386/0x810
[ 1265.463102]  [<c12971c8>] ? tcp_write_xmit+0x198/0x980
[ 1265.463102]  [<c1297a14>] ? __tcp_push_pending_frames+0x24/0x90
[ 1265.463102]  [<c128b2b8>] ? tcp_sendpage+0x558/0x5f0
[ 1265.463102]  [<c111afb0>] ? page_cache_pipe_buf_release+0x10/0x10
[ 1265.463102]  [<c128ad60>] ? tcp_sendmsg+0xb50/0xb50
[ 1265.463102]  [<c12a9789>] ? inet_sendpage+0x69/0x110
[ 1265.463102]  [<c111b295>] ? splice_direct_to_actor+0x175/0x1e0
[ 1265.463102]  [<c12a9720>] ? inet_dgram_connect+0x80/0x80
[ 1265.463102]  [<c1240f6e>] ? kernel_sendpage+0x4e/0x90
[ 1265.463102]  [<e0a74d39>] ? svc_send_common+0xc9/0x120 [sunrpc]
[ 1265.463102]  [<e0a74df6>] ? svc_sendto+0x66/0x1e0 [sunrpc]
[ 1265.463102]  [<e0c00519>] ? nfsd4_encode_read+0xf9/0x200 [nfsd]
[ 1265.463102]  [<e0c00420>] ? nfsd4_encode_readdir+0x1e0/0x1e0 [nfsd]
[ 1265.463102]  [<e0bfa93c>] ? nfsd4_encode_operation+0x5c/0x170 [nfsd]
[ 1265.463102]  [<c110b6b4>] ? dput+0x14/0x140
[ 1265.463102]  [<e0bfae0e>] ? nfsd4_release_compoundargs+0x1e/0x50 [nfsd]
[ 1265.463102]  [<e0bf8b58>] ? nfsd4_proc_compound+0x1e8/0x490 [nfsd]
[ 1265.463102]  [<e0bffccf>] ? nfs4svc_decode_compoundargs+0x26f/0x340 [nfsd]
[ 1265.463102]  [<e0a74ff6>] ? svc_tcp_sendto+0x36/0xa0 [sunrpc]
[ 1265.463102]  [<e0a7e278>] ? svc_send+0x88/0xc0 [sunrpc]
[ 1265.463102]  [<e0a719b8>] ? svc_process+0x228/0x760 [sunrpc]
[ 1265.463102]  [<e0be998c>] ? nfsd+0xac/0x140 [nfsd]
[ 1265.463102]  [<c1032fc0>] ? complete+0x40/0x60
[ 1265.463102]  [<e0be98e0>] ? nfsd_svc+0x1d0/0x1d0 [nfsd]
[ 1265.463102]  [<c105d054>] ? kthread+0x74/0x80
[ 1265.463102]  [<c105cfe0>] ? kthread_worker_fn+0x160/0x160
[ 1265.463102]  [<c12e7b76>] ? kernel_thread_helper+0x6/0xd
[ 1265.463102] Mem-Info:
[ 1265.463102] DMA per-cpu:
[ 1265.463102] CPU    0: hi:    0, btch:   1 usd:   0
[ 1265.463102] CPU    1: hi:    0, btch:   1 usd:   0
[ 1265.463102] Normal per-cpu:
[ 1265.463102] CPU    0: hi:  186, btch:  31 usd:  97
[ 1265.463102] CPU    1: hi:  186, btch:  31 usd: 164
[ 1265.463102] active_anon:773 inactive_anon:8 isolated_anon:0
[ 1265.463102]  active_file:8117 inactive_file:114259 isolated_file:0
[ 1265.463102]  unevictable:0 dirty:11 writeback:0 unstable:0
[ 1265.463102]  free:1971 slab_reclaimable:940 slab_unreclaimable:1332
[ 1265.463102]  mapped:713 shmem:14 pagetables:74 bounce:0
[ 1265.463102] DMA free:2308kB min:84kB low:104kB high:124kB active_anon:0kB inactive_anon:0kB active_file:16kB inactive_file:11660kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15788kB mlocked:0kB dirty:0kB writeback:0kB mapped:4kB shmem:0kB slab_reclaimable:52kB slab_unreclaimable:1704kB kernel_stack:16kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 1265.463102] lowmem_reserve[]: 0 492 492 492
[ 1265.463102] Normal free:5576kB min:2792kB low:3488kB high:4188kB active_anon:3092kB inactive_anon:32kB active_file:32452kB inactive_file:445376kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:503928kB mlocked:0kB dirty:44kB writeback:0kB mapped:2848kB shmem:56kB slab_reclaimable:3708kB slab_unreclaimable:3624kB kernel_stack:472kB pagetables:296kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 1265.463102] lowmem_reserve[]: 0 0 0 0
[ 1265.463102] DMA: 49*4kB 27*8kB 1*16kB 1*32kB 5*64kB 2*128kB 1*256kB 0*512kB 1*1024kB 0*2048kB 0*4096kB = 2316kB
[ 1265.463102] Normal: 852*4kB 223*8kB 24*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 5576kB
[ 1265.463102] 122394 total pagecache pages
[ 1265.463102] 0 pages in swap cache
[ 1265.463102] Swap cache stats: add 0, delete 0, find 0/0
[ 1265.463102] Free swap  = 0kB
[ 1265.463102] Total swap = 0kB
[ 1265.463102] 131054 pages RAM
[ 1265.463102] 0 pages HighMem
[ 1265.463102] 2401 pages reserved
[ 1265.463102] 9641 pages shared
[ 1265.463102] 118385 pages non-shared


I dunno yet if that's something to worry about, but the
warnings and especially amount of them is troubling.

Thanks,

/mjt
--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html


[Index of Archives]     [KVM ARM]     [KVM ia64]     [KVM ppc]     [Virtualization Tools]     [Spice Development]     [Libvirt]     [Libvirt Users]     [Linux USB Devel]     [Linux Audio Users]     [Yosemite Questions]     [Linux Kernel]     [Linux SCSI]     [XFree86]
  Powered by Linux