Bug 708149

Summary: strange kvm log
Product: Red Hat Enterprise Linux 6 Reporter: Levente Farkas <lfarkas>
Component: qemu-kvmAssignee: Amit Shah <amit.shah>
Status: CLOSED NOTABUG QA Contact: Virtualization Bugs <virt-bugs>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 6.1CC: aarcange, amit.shah, juzhang, mkenneth, mtosatti, riel, virt-maint
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-06-23 09:54:52 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Levente Farkas 2011-05-26 20:27:12 UTC
one of our kvm guest produce this log on the host:
---------------------------------
2097151 pages RAM
50444 pages reserved
757134 pages shared
1283714 pages non-shared
qemu-kvm: page allocation failure. order:1, mode:0x20
Pid: 27297, comm: qemu-kvm Not tainted 2.6.32-71.24.1.el6.x86_64 #1
Call Trace:
 <IRQ>  [<ffffffff8111ea66>] __alloc_pages_nodemask+0x706/0x850
 [<ffffffffa046d400>] ? br_dev_queue_push_xmit+0x0/0xa0 [bridge]
 [<ffffffff811561a2>] kmem_getpages+0x62/0x170
 [<ffffffff81156dba>] fallback_alloc+0x1ba/0x270
 [<ffffffff8115680f>] ? cache_grow+0x2cf/0x320
 [<ffffffff81156b39>] ____cache_alloc_node+0x99/0x160
 [<ffffffff8115749b>] kmem_cache_alloc+0x11b/0x190
 [<ffffffff81404328>] sk_prot_alloc+0x48/0x180
 [<ffffffff81404572>] sk_clone+0x22/0x2a0
 [<ffffffff8144c116>] inet_csk_clone+0x16/0xd0
 [<ffffffff81465063>] tcp_create_openreq_child+0x23/0x450
 [<ffffffff81462aad>] tcp_v4_syn_recv_sock+0x4d/0x280
 [<ffffffff81464e21>] tcp_check_req+0x201/0x420
 [<ffffffff814624cb>] tcp_v4_do_rcv+0x35b/0x430
 [<ffffffff81463ce0>] tcp_v4_rcv+0x5b0/0x7e0
 [<ffffffff81441c40>] ? ip_local_deliver_finish+0x0/0x2d0
 [<ffffffff814370f4>] ? nf_hook_slow+0x74/0x100
 [<ffffffff81441c40>] ? ip_local_deliver_finish+0x0/0x2d0
 [<ffffffff81441d1d>] ip_local_deliver_finish+0xdd/0x2d0
 [<ffffffff81441fa8>] ip_local_deliver+0x98/0xa0
 [<ffffffff8144146d>] ip_rcv_finish+0x12d/0x440
 [<ffffffff814419f5>] ip_rcv+0x275/0x350
 [<ffffffff8140fb40>] ? netif_receive_skb+0x0/0x670
 [<ffffffff8140fecb>] netif_receive_skb+0x38b/0x670
 [<ffffffff8140fb40>] ? netif_receive_skb+0x0/0x670
 [<ffffffffa046e3c8>] br_handle_frame_finish+0x198/0x260 [bridge]
 [<ffffffffa0473f88>] br_nf_pre_routing_finish+0x228/0x340 [bridge]
 [<ffffffff814370f4>] ? nf_hook_slow+0x74/0x100
 [<ffffffffa0473d60>] ? br_nf_pre_routing_finish+0x0/0x340 [bridge]
 [<ffffffffa04744ef>] br_nf_pre_routing+0x44f/0x750 [bridge]
 [<ffffffff8143703c>] nf_iterate+0x6c/0xb0
 [<ffffffffa046e230>] ? br_handle_frame_finish+0x0/0x260 [bridge]
 [<ffffffff814370f4>] nf_hook_slow+0x74/0x100
 [<ffffffffa046e230>] ? br_handle_frame_finish+0x0/0x260 [bridge]
 [<ffffffffa046e61c>] br_handle_frame+0x18c/0x250 [bridge]
 [<ffffffff81091e66>] ? autoremove_wake_function+0x16/0x40
 [<ffffffff8140fd03>] netif_receive_skb+0x1c3/0x670
 [<ffffffff81410233>] process_backlog+0x83/0xe0
 [<ffffffff81410a53>] net_rx_action+0x103/0x210
 [<ffffffff81073d17>] __do_softirq+0xb7/0x1e0
 [<ffffffff810142cc>] call_softirq+0x1c/0x30
 <EOI>  [<ffffffff81015f35>] ? do_softirq+0x65/0xa0
 [<ffffffff81414ac8>] netif_rx_ni+0x28/0x30
 [<ffffffffa0593415>] tun_chr_aio_write+0x295/0x580 [tun]
 [<ffffffffa028bf76>] ? kvm_arch_vcpu_ioctl_run+0x4f6/0xdd0 [kvm]
 [<ffffffffa0593180>] ? tun_chr_aio_write+0x0/0x580 [tun]
 [<ffffffff8116ceab>] do_sync_readv_writev+0xfb/0x140
 [<ffffffff81091e50>] ? autoremove_wake_function+0x0/0x40
 [<ffffffff81013c8e>] ? apic_timer_interrupt+0xe/0x20
 [<ffffffff811ffe96>] ? security_file_permission+0x16/0x20
 [<ffffffff8116df6f>] do_readv_writev+0xcf/0x1f0
 [<ffffffff81059dc2>] ? finish_task_switch+0x42/0xd0
 [<ffffffff8118024a>] ? do_vfs_ioctl+0x3aa/0x580
 [<ffffffff814c9276>] ? thread_return+0x4e/0x778
 [<ffffffff8116e0d6>] vfs_writev+0x46/0x60
 [<ffffffff8116e201>] sys_writev+0x51/0xb0
 [<ffffffff81013172>] system_call_fastpath+0x16/0x1b
Mem-Info:
Node 0 DMA per-cpu:
CPU    0: hi:    0, btch:   1 usd:   0
CPU    1: hi:    0, btch:   1 usd:   0
CPU    2: hi:    0, btch:   1 usd:   0
CPU    3: hi:    0, btch:   1 usd:   0
Node 0 DMA32 per-cpu:
CPU    0: hi:  186, btch:  31 usd: 127
CPU    1: hi:  186, btch:  31 usd: 156
CPU    2: hi:  186, btch:  31 usd:  20
CPU    3: hi:  186, btch:  31 usd: 154
Node 0 Normal per-cpu:
CPU    0: hi:  186, btch:  31 usd: 177
CPU    1: hi:  186, btch:  31 usd:  67
CPU    2: hi:  186, btch:  31 usd:  63
CPU    3: hi:  186, btch:  31 usd: 103
active_anon:912198 inactive_anon:164275 isolated_anon:0
 active_file:394410 inactive_file:352145 isolated_file:0
 unevictable:0 dirty:2 writeback:0 unstable:0
 free:30108 slab_reclaimable:53770 slab_unreclaimable:68803
 mapped:1836 shmem:21 pagetables:4545 bounce:0
Node 0 DMA free:15716kB min:124kB low:152kB high:184kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15320kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
lowmem_reserve[]: 0 3506 8051 8051
Node 0 DMA32 free:57280kB min:29376kB low:36720kB high:44064kB active_anon:1574888kB inactive_anon:312940kB active_file:701384kB inactive_file:544704kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3590660kB mlocked:0kB dirty:4kB writeback:0kB mapped:1132kB shmem:16kB slab_reclaimable:128504kB slab_unreclaimable:46332kB kernel_stack:168kB pagetables:552kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 0 4545 4545
Node 0 Normal free:47436kB min:38076kB low:47592kB high:57112kB active_anon:2073904kB inactive_anon:344160kB active_file:876256kB inactive_file:863876kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:4654080kB mlocked:0kB dirty:4kB writeback:0kB mapped:6212kB shmem:68kB slab_reclaimable:86576kB slab_unreclaimable:228880kB kernel_stack:1496kB pagetables:17628kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:32 all_unreclaimable? no
lowmem_reserve[]: 0 0 0 0
Node 0 DMA: 3*4kB 1*8kB 1*16kB 2*32kB 2*64kB 1*128kB 0*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15716kB
Node 0 DMA32: 14289*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 57156kB
Node 0 Normal: 11859*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 47436kB
767816 total pagecache pages
21277 pages in swap cache
---------------------------------

Comment 4 Michael S. Tsirkin 2011-05-30 15:50:08 UTC
As far as I can make out, the host is out of memory here
so qemu kvm can't open a socket. It says guest but qemu-kvm
does not run on guest - I think it's a mistake and
the log triggers on host.

Can you confirm please?

Is the host really out of memory? Did you overcommit the host memory aggressively?

Comment 5 Levente Farkas 2011-05-30 16:04:24 UTC
this log is on the host. and no we do not overcommit the memory. there're 6 guest with 512MB and one with 2G while the host has 8GB ram.

Comment 7 Rik van Riel 2011-05-31 12:37:24 UTC
Looks like the host is receiving a (large) network packet and wants to allocate two contiguous pages of memory with the GFP_ATOMIC allocation flag, which is an allocation that cannot wait for memory to be defragmented.

Levente, does the warning message you get result in any problem for your KVM guests at all?

Judging from the backtrace, the likely result is just the loss of a network packet, which will no doubt be retransmitted and delivered later.

Comment 8 Levente Farkas 2011-05-31 12:51:39 UTC
the truth is that i don''t know:-(
i've just found this message in the log just before we reboot the host since we've got problem with our pxe setup (but turn out that was completely different from this, and even from this server). 
i just report this since imho it's not a 'normal' behavior...

Comment 9 Rik van Riel 2011-05-31 14:31:47 UTC
Since the backtrace looks harmless (dropped packet) and you did not notice any malfunction, lets assume for now that nothing serious happened.

Having occasional packet loss is pretty much expected on modern computers, since networking is incredibly fast and memory cannot always be freed in time for the next packets.

Comment 10 Andrea Arcangeli 2011-05-31 18:38:23 UTC
Agree with Rik.

Comment 11 Amit Shah 2011-06-23 09:54:52 UTC
Closing for now.  If problem persists, let us know.