Bug 93251

Summary: qemu-kvm guests randomly hangs after reboot command in guest
Product: Virtualization Reporter: Ondřej Súkup (mimi.vx)
Component: kvmAssignee: virtualization_kvm
Status: NEW ---    
Severity: normal CC: bsd, himbeere, imammedo, lee295012, mtosatti
Priority: P1    
Hardware: Intel   
OS: Linux   
Kernel Version: 3.19.0 Subsystem:
Regression: No Bisected commit-id:

Description Ondřej Súkup 2015-02-14 12:46:35 UTC

    
Comment 1 Ondřej Súkup 2015-02-14 12:52:26 UTC
I run about 7 nodes, an simulate build of openstack cloud in qemu-kvm env ..

nodes randomly after reboot stop working, or hangs in few sec after reboot 


from journalctl:

úno 13 18:10:22 argus kernel: qemu-system-x86: page allocation failure: order:4, mode:0x40d0
úno 13 18:10:23 argus kernel: CPU: 2 PID: 2731 Comm: qemu-system-x86 Not tainted 3.19.0-gentoo #2
úno 13 18:10:27 argus kernel: Hardware name: Dell Inc. OptiPlex 9010/0M9KCM, BIOS A19 08/18/2014
úno 13 18:10:27 argus kernel:  0000000000000004 00000000a9baffad 0000000000000000 ffffffff9d5cdf0c
úno 13 18:10:27 argus kernel:  00000000000040d0 ffffffff9d0d5f1e 0000000000000040 0000000000000000
úno 13 18:10:27 argus kernel:  ffffffff9d807080 ffffffff9d0d8dda ffffffff9d806180 00000000a9baffad
úno 13 18:10:27 argus kernel: Call Trace:
úno 13 18:10:27 argus kernel:  [<ffffffff9d5cdf0c>] ? dump_stack+0x47/0x67
úno 13 18:10:27 argus kernel:  [<ffffffff9d0d5f1e>] ? warn_alloc_failed+0xee/0x150
úno 13 18:10:27 argus kernel:  [<ffffffff9d0d8dda>] ? __alloc_pages_direct_compact+0x14a/0x150
úno 13 18:10:27 argus kernel:  [<ffffffff9d0d9556>] ? __alloc_pages_nodemask+0x776/0xb80
úno 13 18:10:27 argus kernel:  [<ffffffff9d0d9a3a>] ? alloc_kmem_pages+0x3a/0x110
úno 13 18:10:27 argus kernel:  [<ffffffff9d0ee4e3>] ? kmalloc_order+0x13/0x50
úno 13 18:10:27 argus kernel:  [<ffffffff9d0e954b>] ? kmemdup+0x1b/0x40
úno 13 18:10:27 argus kernel:  [<ffffffffc0aeb1fa>] ? __kvm_set_memory_region+0x24a/0x9f0 [kvm]
úno 13 18:10:27 argus kernel:  [<ffffffffc0b154b0>] ? kvm_set_ioapic+0x130/0x130 [kvm]
úno 13 18:10:27 argus kernel:  [<ffffffffc0aeb9c1>] ? kvm_set_memory_region+0x21/0x40 [kvm]
úno 13 18:10:27 argus kernel:  [<ffffffffc0aebe1f>] ? kvm_vm_ioctl+0x43f/0x750 [kvm]
úno 13 18:10:27 argus kernel:  [<ffffffff9d2ef4eb>] ? blk_finish_plug+0xb/0x40
úno 13 18:10:27 argus kernel:  [<ffffffff9d10ae75>] ? SyS_madvise+0x3c5/0x800
úno 13 18:10:27 argus kernel:  [<ffffffff9d07ca71>] ? cpuacct_account_field+0x11/0x60
úno 13 18:10:27 argus kernel:  [<ffffffff9d147748>] ? do_vfs_ioctl+0x308/0x510
úno 13 18:10:27 argus kernel:  [<ffffffff9d06ce3f>] ? vtime_account_user+0x3f/0x60
úno 13 18:10:27 argus kernel:  [<ffffffff9d151423>] ? __fget+0x63/0xa0
úno 13 18:10:27 argus kernel:  [<ffffffff9d147986>] ? SyS_ioctl+0x36/0x80
úno 13 18:10:27 argus kernel:  [<ffffffff9d5d453d>] ? int_check_syscall_exit_work+0x34/0x3d
úno 13 18:10:27 argus kernel:  [<ffffffff9d5d4312>] ? system_call_fastpath+0x12/0x17
úno 13 18:10:27 argus kernel: Mem-Info:
úno 13 18:10:27 argus kernel: DMA per-cpu:
úno 13 18:10:27 argus kernel: CPU    0: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    1: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    2: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    3: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    4: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    5: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    6: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    7: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: DMA32 per-cpu:
úno 13 18:10:27 argus kernel: CPU    0: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    1: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    2: hi:  186, btch:  31 usd:  22
úno 13 18:10:27 argus kernel: CPU    3: hi:  186, btch:  31 usd: 170
úno 13 18:10:27 argus kernel: CPU    4: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    5: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    6: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    7: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: Normal per-cpu:
úno 13 18:10:27 argus kernel: CPU    0: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    1: hi:  186, btch:  31 usd:  30
úno 13 18:10:27 argus kernel: CPU    2: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    3: hi:  186, btch:  31 usd: 161
úno 13 18:10:27 argus kernel: CPU    4: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    5: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    6: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    7: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: active_anon:2109969 inactive_anon:930082 isolated_anon:0
                                active_file:318968 inactive_file:466719 isolated_file:0
                                unevictable:0 dirty:134084 writeback:3211 unstable:0
                                free:47211 slab_reclaimable:45577 slab_unreclaimable:74482
                                mapped:47028 shmem:382256 pagetables:23493 bounce:0
                                free_cma:43
úno 13 18:10:27 argus kernel: DMA free:15884kB min:64kB low:80kB high:96kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15984kB managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:16kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 3541 16027 16027
úno 13 18:10:27 argus kernel: DMA32 free:91084kB min:14916kB low:18644kB high:22372kB active_anon:1060260kB inactive_anon:907560kB active_file:510928kB inactive_file:846884kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3636052kB managed:3627220kB mlocked:0kB dirty:225504kB writeback:7144kB mapped:55956kB shmem:331400kB slab_reclaimable:63684kB slab_unreclaimable:43356kB kernel_stack:6464kB pagetables:14680kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 0 12485 12485
úno 13 18:10:27 argus kernel: Normal free:81876kB min:52596kB low:65744kB high:78892kB active_anon:7379616kB inactive_anon:2812768kB active_file:764944kB inactive_file:1019992kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:13074432kB managed:12785460kB mlocked:0kB dirty:310832kB writeback:5700kB mapped:132156kB shmem:1197624kB slab_reclaimable:118624kB slab_unreclaimable:254556kB kernel_stack:10000kB pagetables:79292kB unstable:0kB bounce:0kB free_cma:172kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 0 0 0
úno 13 18:10:27 argus kernel: DMA: 1*4kB (U) 1*8kB (U) 0*16kB 0*32kB 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (R) 3*4096kB (M) = 15884kB
úno 13 18:10:27 argus kernel: DMA32: 20459*4kB (UEM) 766*8kB (UEM) 44*16kB (UEM) 25*32kB (UEMR) 7*64kB (UR) 3*128kB (UMR) 1*256kB (R) 1*512kB (R) 1*1024kB (R) 0*2048kB 0*4096kB = 92092kB
úno 13 18:10:27 argus kernel: Normal: 18555*4kB (UEMC) 145*8kB (UMC) 92*16kB (UM) 54*32kB (UM) 40*64kB (UM) 9*128kB (UM) 2*256kB (U) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 82804kBúno 13 18:10:22 argus kernel: qemu-system-x86: page allocation failure: order:4, mode:0x40d0
úno 13 18:10:23 argus kernel: CPU: 2 PID: 2731 Comm: qemu-system-x86 Not tainted 3.19.0-gentoo #2
úno 13 18:10:27 argus kernel: Hardware name: Dell Inc. OptiPlex 9010/0M9KCM, BIOS A19 08/18/2014
úno 13 18:10:27 argus kernel:  0000000000000004 00000000a9baffad 0000000000000000 ffffffff9d5cdf0c
úno 13 18:10:27 argus kernel:  00000000000040d0 ffffffff9d0d5f1e 0000000000000040 0000000000000000
úno 13 18:10:27 argus kernel:  ffffffff9d807080 ffffffff9d0d8dda ffffffff9d806180 00000000a9baffad
úno 13 18:10:27 argus kernel: Call Trace:
úno 13 18:10:27 argus kernel:  [<ffffffff9d5cdf0c>] ? dump_stack+0x47/0x67
úno 13 18:10:27 argus kernel:  [<ffffffff9d0d5f1e>] ? warn_alloc_failed+0xee/0x150
úno 13 18:10:27 argus kernel:  [<ffffffff9d0d8dda>] ? __alloc_pages_direct_compact+0x14a/0x150
úno 13 18:10:27 argus kernel:  [<ffffffff9d0d9556>] ? __alloc_pages_nodemask+0x776/0xb80
úno 13 18:10:27 argus kernel:  [<ffffffff9d0d9a3a>] ? alloc_kmem_pages+0x3a/0x110
úno 13 18:10:27 argus kernel:  [<ffffffff9d0ee4e3>] ? kmalloc_order+0x13/0x50
úno 13 18:10:27 argus kernel:  [<ffffffff9d0e954b>] ? kmemdup+0x1b/0x40
úno 13 18:10:27 argus kernel:  [<ffffffffc0aeb1fa>] ? __kvm_set_memory_region+0x24a/0x9f0 [kvm]
úno 13 18:10:27 argus kernel:  [<ffffffffc0b154b0>] ? kvm_set_ioapic+0x130/0x130 [kvm]
úno 13 18:10:27 argus kernel:  [<ffffffffc0aeb9c1>] ? kvm_set_memory_region+0x21/0x40 [kvm]
úno 13 18:10:27 argus kernel:  [<ffffffffc0aebe1f>] ? kvm_vm_ioctl+0x43f/0x750 [kvm]
úno 13 18:10:27 argus kernel:  [<ffffffff9d2ef4eb>] ? blk_finish_plug+0xb/0x40
úno 13 18:10:27 argus kernel:  [<ffffffff9d10ae75>] ? SyS_madvise+0x3c5/0x800
úno 13 18:10:27 argus kernel:  [<ffffffff9d07ca71>] ? cpuacct_account_field+0x11/0x60
úno 13 18:10:27 argus kernel:  [<ffffffff9d147748>] ? do_vfs_ioctl+0x308/0x510
úno 13 18:10:27 argus kernel:  [<ffffffff9d06ce3f>] ? vtime_account_user+0x3f/0x60
úno 13 18:10:27 argus kernel:  [<ffffffff9d151423>] ? __fget+0x63/0xa0
úno 13 18:10:27 argus kernel:  [<ffffffff9d147986>] ? SyS_ioctl+0x36/0x80
úno 13 18:10:27 argus kernel:  [<ffffffff9d5d453d>] ? int_check_syscall_exit_work+0x34/0x3d
úno 13 18:10:27 argus kernel:  [<ffffffff9d5d4312>] ? system_call_fastpath+0x12/0x17
úno 13 18:10:27 argus kernel: Mem-Info:
úno 13 18:10:27 argus kernel: DMA per-cpu:
úno 13 18:10:27 argus kernel: CPU    0: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    1: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    2: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    3: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    4: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    5: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    6: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: CPU    7: hi:    0, btch:   1 usd:   0
úno 13 18:10:27 argus kernel: DMA32 per-cpu:
úno 13 18:10:27 argus kernel: CPU    0: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    1: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    2: hi:  186, btch:  31 usd:  22
úno 13 18:10:27 argus kernel: CPU    3: hi:  186, btch:  31 usd: 170
úno 13 18:10:27 argus kernel: CPU    4: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    5: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    6: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    7: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: Normal per-cpu:
úno 13 18:10:27 argus kernel: CPU    0: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    1: hi:  186, btch:  31 usd:  30
úno 13 18:10:27 argus kernel: CPU    2: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    3: hi:  186, btch:  31 usd: 161
úno 13 18:10:27 argus kernel: CPU    4: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    5: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    6: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: CPU    7: hi:  186, btch:  31 usd:   0
úno 13 18:10:27 argus kernel: active_anon:2109969 inactive_anon:930082 isolated_anon:0
                                active_file:318968 inactive_file:466719 isolated_file:0
                                unevictable:0 dirty:134084 writeback:3211 unstable:0
                                free:47211 slab_reclaimable:45577 slab_unreclaimable:74482
                                mapped:47028 shmem:382256 pagetables:23493 bounce:0
                                free_cma:43
úno 13 18:10:27 argus kernel: DMA free:15884kB min:64kB low:80kB high:96kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15984kB managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:16kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 3541 16027 16027
úno 13 18:10:27 argus kernel: DMA32 free:91084kB min:14916kB low:18644kB high:22372kB active_anon:1060260kB inactive_anon:907560kB active_file:510928kB inactive_file:846884kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3636052kB managed:3627220kB mlocked:0kB dirty:225504kB writeback:7144kB mapped:55956kB shmem:331400kB slab_reclaimable:63684kB slab_unreclaimable:43356kB kernel_stack:6464kB pagetables:14680kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 0 12485 12485
úno 13 18:10:27 argus kernel: Normal free:81876kB min:52596kB low:65744kB high:78892kB active_anon:7379616kB inactive_anon:2812768kB active_file:764944kB inactive_file:1019992kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:13074432kB managed:12785460kB mlocked:0kB dirty:310832kB writeback:5700kB mapped:132156kB shmem:1197624kB slab_reclaimable:118624kB slab_unreclaimable:254556kB kernel_stack:10000kB pagetables:79292kB unstable:0kB bounce:0kB free_cma:172kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 0 0 0
úno 13 18:10:27 argus kernel: DMA: 1*4kB (U) 1*8kB (U) 0*16kB 0*32kB 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (R) 3*4096kB (M) = 15884kB
úno 13 18:10:27 argus kernel: DMA32: 20459*4kB (UEM) 766*8kB (UEM) 44*16kB (UEM) 25*32kB (UEMR) 7*64kB (UR) 3*128kB (UMR) 1*256kB (R) 1*512kB (R) 1*1024kB (R) 0*2048kB 0*4096kB = 92092kB
úno 13 18:10:27 argus kernel: Normal: 18555*4kB (UEMC) 145*8kB (UMC) 92*16kB (UM) 54*32kB (UM) 40*64kB (UM) 9*128kB (UM) 2*256kB (U) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 82804kB
úno 13 18:10:27 argus kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
úno 13 18:10:27 argus kernel: 1170782 total pagecache pages
úno 13 18:10:27 argus kernel: 2872 pages in swap cache
úno 13 18:10:27 argus kernel: Swap cache stats: add 111188, delete 108316, find 46841/51516
úno 13 18:10:27 argus kernel: Free swap  = 15734048kB
úno 13 18:10:27 argus kernel: Total swap = 16000736kB
úno 13 18:10:27 argus kernel: 4181617 pages RAM
úno 13 18:10:27 argus kernel: 0 pages HighMem/MovableOnly
úno 13 18:10:27 argus kernel: 18446744073709207272 pages reserved
úno 13 18:10:27 argus kernel: 418816 pages cma reserved
úno 13 18:10:27 argus kernel: 0 pages hwpoisoned
úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled rdmsr: 0x345
úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x40 data 0
úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x60 data 0
úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x41 data 0

úno 13 18:10:27 argus kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
úno 13 18:10:27 argus kernel: 1170782 total pagecache pages
úno 13 18:10:27 argus kernel: 2872 pages in swap cache
úno 13 18:10:27 argus kernel: Swap cache stats: add 111188, delete 108316, find 46841/51516
úno 13 18:10:27 argus kernel: Free swap  = 15734048kB
úno 13 18:10:27 argus kernel: Total swap = 16000736kB
úno 13 18:10:27 argus kernel: 4181617 pages RAM
úno 13 18:10:27 argus kernel: 0 pages HighMem/MovableOnly
úno 13 18:10:27 argus kernel: 18446744073709207272 pages reserved
úno 13 18:10:27 argus kernel: 418816 pages cma reserved
úno 13 18:10:27 argus kernel: 0 pages hwpoisoned
úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled rdmsr: 0x345
úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x40 data 0
úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x60 data 0
úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x41 data 0


and this :

úno 13 18:28:00 argus kernel: ------------[ cut here ]------------
úno 13 18:28:00 argus kernel: WARNING: CPU: 0 PID: 8969 at arch/x86/kernel/cpu/perf_event_intel_ds.c:315 reserve_ds_buffers+0x394/0x3d0()
úno 13 18:28:00 argus kernel: alloc_bts_buffer: BTS buffer allocation failure
úno 13 18:28:00 argus kernel: Modules linked in: 8021q garp mrp vhost_net vhost macvtap macvlan xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp tun bridge stp llc dm_mod ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ip_tables x_tables x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd radeon i2c_algo_bit drm_kms_helper ttm drm snd_hda_codec_realtek snd_hda_codec_generic snd_hda_codec_hdmi iTCO_wdt dcdbas iTCO_vendor_support snd_hda_intel snd_hda_controller ehci_pci ehci_hcd snd_hda_codec thermal tpm_tis video backlight
úno 13 18:28:00 argus kernel:  xhci_pci xhci_hcd microcode tpm snd_hwdep processor thermal_sys snd_pcm i2c_i801 i2c_core lpc_ich snd_timer mfd_core button snd pcspkr sch_fq_codel ipv6
úno 13 18:28:00 argus kernel: CPU: 0 PID: 8969 Comm: qemu-system-x86 Not tainted 3.19.0-gentoo #2
úno 13 18:28:00 argus kernel: Hardware name: Dell Inc. OptiPlex 9010/0M9KCM, BIOS A19 08/18/2014
úno 13 18:28:00 argus kernel:  ffffffff9d6ed918 000000009cac10c2 ffffffff9d6ed918 ffffffff9d5cdf0c
úno 13 18:28:00 argus kernel:  ffff880153ab7aa0 ffffffff9d045fd7 0000000000000000 0000000000000000
úno 13 18:28:00 argus kernel:  ffffffff9d80b7e0 0000000000000000 000000000000abc0 ffffffff9d046068
úno 13 18:28:00 argus kernel: Call Trace:
úno 13 18:28:00 argus kernel:  [<ffffffff9d5cdf0c>] ? dump_stack+0x47/0x67
úno 13 18:28:00 argus kernel:  [<ffffffff9d045fd7>] ? warn_slowpath_common+0x77/0xb0
úno 13 18:28:00 argus kernel:  [<ffffffff9d046068>] ? warn_slowpath_fmt+0x58/0x80
úno 13 18:28:00 argus kernel:  [<ffffffff9d01b904>] ? reserve_ds_buffers+0x394/0x3d0
úno 13 18:28:00 argus kernel:  [<ffffffff9d01625f>] ? x86_pmu_event_init+0x40f/0x420
úno 13 18:28:00 argus kernel:  [<ffffffff9d0cb862>] ? perf_init_event+0xf2/0x160
úno 13 18:28:00 argus kernel:  [<ffffffff9d0cbc38>] ? perf_event_alloc+0x368/0x420
úno 13 18:28:00 argus kernel:  [<ffffffffc0b175c0>] ? kvm_perf_overflow+0x30/0x30 [kvm]
úno 13 18:28:00 argus kernel:  [<ffffffff9d0cc921>] ? perf_event_create_kernel_counter+0x21/0x110
úno 13 18:28:00 argus kernel:  [<ffffffffc0b1727a>] ? reprogram_counter+0xda/0x140 [kvm]
úno 13 18:28:00 argus kernel:  [<ffffffffc0b1736b>] ? reprogram_fixed_counter+0x8b/0xa0 [kvm]
úno 13 18:28:01 argus kernel:  [<ffffffffc0b17f99>] ? kvm_handle_pmu_event+0x59/0xc0 [kvm]
úno 13 18:28:01 argus kernel:  [<ffffffffc0af4c77>] ? vcpu_enter_guest+0x2f7/0xc60 [kvm]
úno 13 18:28:01 argus kernel:  [<ffffffff9d5d4fd0>] ? retint_kernel+0x20/0x30
úno 13 18:28:01 argus kernel:  [<ffffffffc0de23e0>] ? vmx_set_tsc_khz+0x50/0x50 [kvm_intel]
úno 13 18:28:01 argus kernel:  [<ffffffffc0af9458>] ? kvm_arch_vcpu_ioctl_run+0x1f8/0x490 [kvm]
úno 13 18:28:01 argus kernel:  [<ffffffffc0aea1e8>] ? kvm_vcpu_ioctl+0x338/0x5a0 [kvm]
úno 13 18:28:01 argus kernel:  [<ffffffff9d07ca71>] ? cpuacct_account_field+0x11/0x60
úno 13 18:28:01 argus kernel:  [<ffffffff9d147748>] ? do_vfs_ioctl+0x308/0x510
úno 13 18:28:01 argus kernel:  [<ffffffff9d06ce3f>] ? vtime_account_user+0x3f/0x60
úno 13 18:28:01 argus kernel:  [<ffffffff9d151423>] ? __fget+0x63/0xa0
úno 13 18:28:01 argus kernel:  [<ffffffff9d147986>] ? SyS_ioctl+0x36/0x80
úno 13 18:28:01 argus kernel:  [<ffffffff9d5d4558>] ? int_signal+0x12/0x17
úno 13 18:28:01 argus kernel:  [<ffffffff9d5d4312>] ? system_call_fastpath+0x12/0x17
úno 13 18:28:01 argus kernel: ---[ end trace 57619b624d89e2e8 ]---
Comment 2 Marcelo Tosatti 2015-02-25 22:49:47 UTC
(In reply to Ondřej Súkup from comment #1)
> I run about 7 nodes, an simulate build of openstack cloud in qemu-kvm env ..
> 
> nodes randomly after reboot stop working, or hangs in few sec after reboot 
> 
> 
> from journalctl:
> 
> úno 13 18:10:22 argus kernel: qemu-system-x86: page allocation failure:
> order:4, mode:0x40d0
> úno 13 18:10:23 argus kernel: CPU: 2 PID: 2731 Comm: qemu-system-x86 Not
> tainted 3.19.0-gentoo #2
> úno 13 18:10:27 argus kernel: Hardware name: Dell Inc. OptiPlex 9010/0M9KCM,
> BIOS A19 08/18/2014
> úno 13 18:10:27 argus kernel:  0000000000000004 00000000a9baffad
> 0000000000000000 ffffffff9d5cdf0c
> úno 13 18:10:27 argus kernel:  00000000000040d0 ffffffff9d0d5f1e
> 0000000000000040 0000000000000000
> úno 13 18:10:27 argus kernel:  ffffffff9d807080 ffffffff9d0d8dda
> ffffffff9d806180 00000000a9baffad
> úno 13 18:10:27 argus kernel: Call Trace:
> úno 13 18:10:27 argus kernel:  [<ffffffff9d5cdf0c>] ? dump_stack+0x47/0x67
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0d5f1e>] ?
> warn_alloc_failed+0xee/0x150
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0d8dda>] ?
> __alloc_pages_direct_compact+0x14a/0x150
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0d9556>] ?
> __alloc_pages_nodemask+0x776/0xb80
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0d9a3a>] ?
> alloc_kmem_pages+0x3a/0x110
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0ee4e3>] ? kmalloc_order+0x13/0x50
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0e954b>] ? kmemdup+0x1b/0x40
> úno 13 18:10:27 argus kernel:  [<ffffffffc0aeb1fa>] ?
> __kvm_set_memory_region+0x24a/0x9f0 [kvm]
> úno 13 18:10:27 argus kernel:  [<ffffffffc0b154b0>] ?
> kvm_set_ioapic+0x130/0x130 [kvm]
> úno 13 18:10:27 argus kernel:  [<ffffffffc0aeb9c1>] ?
> kvm_set_memory_region+0x21/0x40 [kvm]
> úno 13 18:10:27 argus kernel:  [<ffffffffc0aebe1f>] ?
> kvm_vm_ioctl+0x43f/0x750 [kvm]
> úno 13 18:10:27 argus kernel:  [<ffffffff9d2ef4eb>] ?
> blk_finish_plug+0xb/0x40
> úno 13 18:10:27 argus kernel:  [<ffffffff9d10ae75>] ? SyS_madvise+0x3c5/0x800
> úno 13 18:10:27 argus kernel:  [<ffffffff9d07ca71>] ?
> cpuacct_account_field+0x11/0x60
> úno 13 18:10:27 argus kernel:  [<ffffffff9d147748>] ?
> do_vfs_ioctl+0x308/0x510
> úno 13 18:10:27 argus kernel:  [<ffffffff9d06ce3f>] ?
> vtime_account_user+0x3f/0x60
> úno 13 18:10:27 argus kernel:  [<ffffffff9d151423>] ? __fget+0x63/0xa0
> úno 13 18:10:27 argus kernel:  [<ffffffff9d147986>] ? SyS_ioctl+0x36/0x80
> úno 13 18:10:27 argus kernel:  [<ffffffff9d5d453d>] ?
> int_check_syscall_exit_work+0x34/0x3d
> úno 13 18:10:27 argus kernel:  [<ffffffff9d5d4312>] ?
> system_call_fastpath+0x12/0x17
> úno 13 18:10:27 argus kernel: Mem-Info:
> úno 13 18:10:27 argus kernel: DMA per-cpu:
> úno 13 18:10:27 argus kernel: CPU    0: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    1: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    2: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    3: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    4: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    5: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    6: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    7: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: DMA32 per-cpu:
> úno 13 18:10:27 argus kernel: CPU    0: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    1: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    2: hi:  186, btch:  31 usd:  22
> úno 13 18:10:27 argus kernel: CPU    3: hi:  186, btch:  31 usd: 170
> úno 13 18:10:27 argus kernel: CPU    4: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    5: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    6: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    7: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: Normal per-cpu:
> úno 13 18:10:27 argus kernel: CPU    0: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    1: hi:  186, btch:  31 usd:  30
> úno 13 18:10:27 argus kernel: CPU    2: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    3: hi:  186, btch:  31 usd: 161
> úno 13 18:10:27 argus kernel: CPU    4: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    5: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    6: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    7: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: active_anon:2109969 inactive_anon:930082
> isolated_anon:0
>                                 active_file:318968 inactive_file:466719
> isolated_file:0
>                                 unevictable:0 dirty:134084 writeback:3211
> unstable:0
>                                 free:47211 slab_reclaimable:45577
> slab_unreclaimable:74482
>                                 mapped:47028 shmem:382256 pagetables:23493
> bounce:0
>                                 free_cma:43
> úno 13 18:10:27 argus kernel: DMA free:15884kB min:64kB low:80kB high:96kB
> active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB
> unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15984kB
> managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB
> slab_reclaimable:0kB slab_unreclaimable:16kB kernel_stack:0kB pagetables:0kB
> unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0
> all_unreclaimable? yes
> úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 3541 16027 16027
> úno 13 18:10:27 argus kernel: DMA32 free:91084kB min:14916kB low:18644kB
> high:22372kB active_anon:1060260kB inactive_anon:907560kB
> active_file:510928kB inactive_file:846884kB unevictable:0kB
> isolated(anon):0kB isolated(file):0kB present:3636052kB managed:3627220kB
> mlocked:0kB dirty:225504kB writeback:7144kB mapped:55956kB shmem:331400kB
> slab_reclaimable:63684kB slab_unreclaimable:43356kB kernel_stack:6464kB
> pagetables:14680kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB
> pages_scanned:0 all_unreclaimable? no
> úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 0 12485 12485
> úno 13 18:10:27 argus kernel: Normal free:81876kB min:52596kB low:65744kB
> high:78892kB active_anon:7379616kB inactive_anon:2812768kB
> active_file:764944kB inactive_file:1019992kB unevictable:0kB
> isolated(anon):0kB isolated(file):0kB present:13074432kB managed:12785460kB
> mlocked:0kB dirty:310832kB writeback:5700kB mapped:132156kB shmem:1197624kB
> slab_reclaimable:118624kB slab_unreclaimable:254556kB kernel_stack:10000kB
> pagetables:79292kB unstable:0kB bounce:0kB free_cma:172kB writeback_tmp:0kB
> pages_scanned:0 all_unreclaimable? no
> úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 0 0 0
> úno 13 18:10:27 argus kernel: DMA: 1*4kB (U) 1*8kB (U) 0*16kB 0*32kB 2*64kB
> (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (R) 3*4096kB (M) =
> 15884kB
> úno 13 18:10:27 argus kernel: DMA32: 20459*4kB (UEM) 766*8kB (UEM) 44*16kB
> (UEM) 25*32kB (UEMR) 7*64kB (UR) 3*128kB (UMR) 1*256kB (R) 1*512kB (R)
> 1*1024kB (R) 0*2048kB 0*4096kB = 92092kB
> úno 13 18:10:27 argus kernel: Normal: 18555*4kB (UEMC) 145*8kB (UMC) 92*16kB
> (UM) 54*32kB (UM) 40*64kB (UM) 9*128kB (UM) 2*256kB (U) 0*512kB 0*1024kB
> 0*2048kB 0*4096kB = 82804kBúno 13 18:10:22 argus kernel: qemu-system-x86:
> page allocation failure: order:4, mode:0x40d0
> úno 13 18:10:23 argus kernel: CPU: 2 PID: 2731 Comm: qemu-system-x86 Not
> tainted 3.19.0-gentoo #2
> úno 13 18:10:27 argus kernel: Hardware name: Dell Inc. OptiPlex 9010/0M9KCM,
> BIOS A19 08/18/2014
> úno 13 18:10:27 argus kernel:  0000000000000004 00000000a9baffad
> 0000000000000000 ffffffff9d5cdf0c
> úno 13 18:10:27 argus kernel:  00000000000040d0 ffffffff9d0d5f1e
> 0000000000000040 0000000000000000
> úno 13 18:10:27 argus kernel:  ffffffff9d807080 ffffffff9d0d8dda
> ffffffff9d806180 00000000a9baffad
> úno 13 18:10:27 argus kernel: Call Trace:
> úno 13 18:10:27 argus kernel:  [<ffffffff9d5cdf0c>] ? dump_stack+0x47/0x67
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0d5f1e>] ?
> warn_alloc_failed+0xee/0x150
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0d8dda>] ?
> __alloc_pages_direct_compact+0x14a/0x150
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0d9556>] ?
> __alloc_pages_nodemask+0x776/0xb80
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0d9a3a>] ?
> alloc_kmem_pages+0x3a/0x110
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0ee4e3>] ? kmalloc_order+0x13/0x50
> úno 13 18:10:27 argus kernel:  [<ffffffff9d0e954b>] ? kmemdup+0x1b/0x40
> úno 13 18:10:27 argus kernel:  [<ffffffffc0aeb1fa>] ?
> __kvm_set_memory_region+0x24a/0x9f0 [kvm]
> úno 13 18:10:27 argus kernel:  [<ffffffffc0b154b0>] ?
> kvm_set_ioapic+0x130/0x130 [kvm]
> úno 13 18:10:27 argus kernel:  [<ffffffffc0aeb9c1>] ?
> kvm_set_memory_region+0x21/0x40 [kvm]
> úno 13 18:10:27 argus kernel:  [<ffffffffc0aebe1f>] ?
> kvm_vm_ioctl+0x43f/0x750 [kvm]
> úno 13 18:10:27 argus kernel:  [<ffffffff9d2ef4eb>] ?
> blk_finish_plug+0xb/0x40
> úno 13 18:10:27 argus kernel:  [<ffffffff9d10ae75>] ? SyS_madvise+0x3c5/0x800
> úno 13 18:10:27 argus kernel:  [<ffffffff9d07ca71>] ?
> cpuacct_account_field+0x11/0x60
> úno 13 18:10:27 argus kernel:  [<ffffffff9d147748>] ?
> do_vfs_ioctl+0x308/0x510
> úno 13 18:10:27 argus kernel:  [<ffffffff9d06ce3f>] ?
> vtime_account_user+0x3f/0x60
> úno 13 18:10:27 argus kernel:  [<ffffffff9d151423>] ? __fget+0x63/0xa0
> úno 13 18:10:27 argus kernel:  [<ffffffff9d147986>] ? SyS_ioctl+0x36/0x80
> úno 13 18:10:27 argus kernel:  [<ffffffff9d5d453d>] ?
> int_check_syscall_exit_work+0x34/0x3d
> úno 13 18:10:27 argus kernel:  [<ffffffff9d5d4312>] ?
> system_call_fastpath+0x12/0x17
> úno 13 18:10:27 argus kernel: Mem-Info:
> úno 13 18:10:27 argus kernel: DMA per-cpu:
> úno 13 18:10:27 argus kernel: CPU    0: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    1: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    2: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    3: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    4: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    5: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    6: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: CPU    7: hi:    0, btch:   1 usd:   0
> úno 13 18:10:27 argus kernel: DMA32 per-cpu:
> úno 13 18:10:27 argus kernel: CPU    0: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    1: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    2: hi:  186, btch:  31 usd:  22
> úno 13 18:10:27 argus kernel: CPU    3: hi:  186, btch:  31 usd: 170
> úno 13 18:10:27 argus kernel: CPU    4: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    5: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    6: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    7: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: Normal per-cpu:
> úno 13 18:10:27 argus kernel: CPU    0: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    1: hi:  186, btch:  31 usd:  30
> úno 13 18:10:27 argus kernel: CPU    2: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    3: hi:  186, btch:  31 usd: 161
> úno 13 18:10:27 argus kernel: CPU    4: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    5: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    6: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: CPU    7: hi:  186, btch:  31 usd:   0
> úno 13 18:10:27 argus kernel: active_anon:2109969 inactive_anon:930082
> isolated_anon:0
>                                 active_file:318968 inactive_file:466719
> isolated_file:0
>                                 unevictable:0 dirty:134084 writeback:3211
> unstable:0
>                                 free:47211 slab_reclaimable:45577
> slab_unreclaimable:74482
>                                 mapped:47028 shmem:382256 pagetables:23493
> bounce:0
>                                 free_cma:43
> úno 13 18:10:27 argus kernel: DMA free:15884kB min:64kB low:80kB high:96kB
> active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB
> unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15984kB
> managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB
> slab_reclaimable:0kB slab_unreclaimable:16kB kernel_stack:0kB pagetables:0kB
> unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0
> all_unreclaimable? yes
> úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 3541 16027 16027
> úno 13 18:10:27 argus kernel: DMA32 free:91084kB min:14916kB low:18644kB
> high:22372kB active_anon:1060260kB inactive_anon:907560kB
> active_file:510928kB inactive_file:846884kB unevictable:0kB
> isolated(anon):0kB isolated(file):0kB present:3636052kB managed:3627220kB
> mlocked:0kB dirty:225504kB writeback:7144kB mapped:55956kB shmem:331400kB
> slab_reclaimable:63684kB slab_unreclaimable:43356kB kernel_stack:6464kB
> pagetables:14680kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB
> pages_scanned:0 all_unreclaimable? no
> úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 0 12485 12485
> úno 13 18:10:27 argus kernel: Normal free:81876kB min:52596kB low:65744kB
> high:78892kB active_anon:7379616kB inactive_anon:2812768kB
> active_file:764944kB inactive_file:1019992kB unevictable:0kB
> isolated(anon):0kB isolated(file):0kB present:13074432kB managed:12785460kB
> mlocked:0kB dirty:310832kB writeback:5700kB mapped:132156kB shmem:1197624kB
> slab_reclaimable:118624kB slab_unreclaimable:254556kB kernel_stack:10000kB
> pagetables:79292kB unstable:0kB bounce:0kB free_cma:172kB writeback_tmp:0kB
> pages_scanned:0 all_unreclaimable? no
> úno 13 18:10:27 argus kernel: lowmem_reserve[]: 0 0 0 0
> úno 13 18:10:27 argus kernel: DMA: 1*4kB (U) 1*8kB (U) 0*16kB 0*32kB 2*64kB
> (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (R) 3*4096kB (M) =
> 15884kB
> úno 13 18:10:27 argus kernel: DMA32: 20459*4kB (UEM) 766*8kB (UEM) 44*16kB
> (UEM) 25*32kB (UEMR) 7*64kB (UR) 3*128kB (UMR) 1*256kB (R) 1*512kB (R)
> 1*1024kB (R) 0*2048kB 0*4096kB = 92092kB
> úno 13 18:10:27 argus kernel: Normal: 18555*4kB (UEMC) 145*8kB (UMC) 92*16kB
> (UM) 54*32kB (UM) 40*64kB (UM) 9*128kB (UM) 2*256kB (U) 0*512kB 0*1024kB
> 0*2048kB 0*4096kB = 82804kB
> úno 13 18:10:27 argus kernel: Node 0 hugepages_total=0 hugepages_free=0
> hugepages_surp=0 hugepages_size=2048kB
> úno 13 18:10:27 argus kernel: 1170782 total pagecache pages
> úno 13 18:10:27 argus kernel: 2872 pages in swap cache
> úno 13 18:10:27 argus kernel: Swap cache stats: add 111188, delete 108316,
> find 46841/51516
> úno 13 18:10:27 argus kernel: Free swap  = 15734048kB
> úno 13 18:10:27 argus kernel: Total swap = 16000736kB
> úno 13 18:10:27 argus kernel: 4181617 pages RAM
> úno 13 18:10:27 argus kernel: 0 pages HighMem/MovableOnly
> úno 13 18:10:27 argus kernel: 18446744073709207272 pages reserved
> úno 13 18:10:27 argus kernel: 418816 pages cma reserved
> úno 13 18:10:27 argus kernel: 0 pages hwpoisoned
> úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled rdmsr: 0x345
> úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x40 data 0
> úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x60 data 0
> úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x41 data 0
> 
> úno 13 18:10:27 argus kernel: Node 0 hugepages_total=0 hugepages_free=0
> hugepages_surp=0 hugepages_size=2048kB
> úno 13 18:10:27 argus kernel: 1170782 total pagecache pages
> úno 13 18:10:27 argus kernel: 2872 pages in swap cache
> úno 13 18:10:27 argus kernel: Swap cache stats: add 111188, delete 108316,
> find 46841/51516
> úno 13 18:10:27 argus kernel: Free swap  = 15734048kB
> úno 13 18:10:27 argus kernel: Total swap = 16000736kB
> úno 13 18:10:27 argus kernel: 4181617 pages RAM
> úno 13 18:10:27 argus kernel: 0 pages HighMem/MovableOnly
> úno 13 18:10:27 argus kernel: 18446744073709207272 pages reserved
> úno 13 18:10:27 argus kernel: 418816 pages cma reserved
> úno 13 18:10:27 argus kernel: 0 pages hwpoisoned
> úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled rdmsr: 0x345
> úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x40 data 0
> úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x60 data 0
> úno 13 18:10:27 argus kernel: kvm [2656]: vcpu0 unhandled wrmsr: 0x41 data 0
> 
> 
> and this :
> 
> úno 13 18:28:00 argus kernel: ------------[ cut here ]------------
> úno 13 18:28:00 argus kernel: WARNING: CPU: 0 PID: 8969 at
> arch/x86/kernel/cpu/perf_event_intel_ds.c:315
> reserve_ds_buffers+0x394/0x3d0()
> úno 13 18:28:00 argus kernel: alloc_bts_buffer: BTS buffer allocation failure
> úno 13 18:28:00 argus kernel: Modules linked in: 8021q garp mrp vhost_net
> vhost macvtap macvlan xt_CHECKSUM iptable_mangle ipt_MASQUERADE
> nf_nat_masquerade_ipv4 iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4
> nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp
> tun bridge stp llc dm_mod ebtable_filter ebtables ip6table_filter ip6_tables
> iptable_filter ip_tables x_tables x86_pkg_temp_thermal intel_powerclamp
> coretemp kvm_intel kvm crct10dif_pclmul crc32_pclmul crc32c_intel
> ghash_clmulni_intel aesni_intel aes_x86_64 lrw gf128mul glue_helper
> ablk_helper cryptd radeon i2c_algo_bit drm_kms_helper ttm drm
> snd_hda_codec_realtek snd_hda_codec_generic snd_hda_codec_hdmi iTCO_wdt
> dcdbas iTCO_vendor_support snd_hda_intel snd_hda_controller ehci_pci
> ehci_hcd snd_hda_codec thermal tpm_tis video backlight
> úno 13 18:28:00 argus kernel:  xhci_pci xhci_hcd microcode tpm snd_hwdep
> processor thermal_sys snd_pcm i2c_i801 i2c_core lpc_ich snd_timer mfd_core
> button snd pcspkr sch_fq_codel ipv6
> úno 13 18:28:00 argus kernel: CPU: 0 PID: 8969 Comm: qemu-system-x86 Not
> tainted 3.19.0-gentoo #2
> úno 13 18:28:00 argus kernel: Hardware name: Dell Inc. OptiPlex 9010/0M9KCM,
> BIOS A19 08/18/2014
> úno 13 18:28:00 argus kernel:  ffffffff9d6ed918 000000009cac10c2
> ffffffff9d6ed918 ffffffff9d5cdf0c
> úno 13 18:28:00 argus kernel:  ffff880153ab7aa0 ffffffff9d045fd7
> 0000000000000000 0000000000000000
> úno 13 18:28:00 argus kernel:  ffffffff9d80b7e0 0000000000000000
> 000000000000abc0 ffffffff9d046068
> úno 13 18:28:00 argus kernel: Call Trace:
> úno 13 18:28:00 argus kernel:  [<ffffffff9d5cdf0c>] ? dump_stack+0x47/0x67
> úno 13 18:28:00 argus kernel:  [<ffffffff9d045fd7>] ?
> warn_slowpath_common+0x77/0xb0
> úno 13 18:28:00 argus kernel:  [<ffffffff9d046068>] ?
> warn_slowpath_fmt+0x58/0x80
> úno 13 18:28:00 argus kernel:  [<ffffffff9d01b904>] ?
> reserve_ds_buffers+0x394/0x3d0
> úno 13 18:28:00 argus kernel:  [<ffffffff9d01625f>] ?
> x86_pmu_event_init+0x40f/0x420
> úno 13 18:28:00 argus kernel:  [<ffffffff9d0cb862>] ?
> perf_init_event+0xf2/0x160
> úno 13 18:28:00 argus kernel:  [<ffffffff9d0cbc38>] ?
> perf_event_alloc+0x368/0x420
> úno 13 18:28:00 argus kernel:  [<ffffffffc0b175c0>] ?
> kvm_perf_overflow+0x30/0x30 [kvm]
> úno 13 18:28:00 argus kernel:  [<ffffffff9d0cc921>] ?
> perf_event_create_kernel_counter+0x21/0x110
> úno 13 18:28:00 argus kernel:  [<ffffffffc0b1727a>] ?
> reprogram_counter+0xda/0x140 [kvm]
> úno 13 18:28:00 argus kernel:  [<ffffffffc0b1736b>] ?
> reprogram_fixed_counter+0x8b/0xa0 [kvm]
> úno 13 18:28:01 argus kernel:  [<ffffffffc0b17f99>] ?
> kvm_handle_pmu_event+0x59/0xc0 [kvm]
> úno 13 18:28:01 argus kernel:  [<ffffffffc0af4c77>] ?
> vcpu_enter_guest+0x2f7/0xc60 [kvm]
> úno 13 18:28:01 argus kernel:  [<ffffffff9d5d4fd0>] ? retint_kernel+0x20/0x30
> úno 13 18:28:01 argus kernel:  [<ffffffffc0de23e0>] ?
> vmx_set_tsc_khz+0x50/0x50 [kvm_intel]
> úno 13 18:28:01 argus kernel:  [<ffffffffc0af9458>] ?
> kvm_arch_vcpu_ioctl_run+0x1f8/0x490 [kvm]
> úno 13 18:28:01 argus kernel:  [<ffffffffc0aea1e8>] ?
> kvm_vcpu_ioctl+0x338/0x5a0 [kvm]
> úno 13 18:28:01 argus kernel:  [<ffffffff9d07ca71>] ?
> cpuacct_account_field+0x11/0x60
> úno 13 18:28:01 argus kernel:  [<ffffffff9d147748>] ?
> do_vfs_ioctl+0x308/0x510
> úno 13 18:28:01 argus kernel:  [<ffffffff9d06ce3f>] ?
> vtime_account_user+0x3f/0x60
> úno 13 18:28:01 argus kernel:  [<ffffffff9d151423>] ? __fget+0x63/0xa0
> úno 13 18:28:01 argus kernel:  [<ffffffff9d147986>] ? SyS_ioctl+0x36/0x80
> úno 13 18:28:01 argus kernel:  [<ffffffff9d5d4558>] ? int_signal+0x12/0x17
> úno 13 18:28:01 argus kernel:  [<ffffffff9d5d4312>] ?
> system_call_fastpath+0x12/0x17
> úno 13 18:28:01 argus kernel: ---[ end trace 57619b624d89e2e8 ]---

Ondrej,

Can you please revert the following commit and confirm whether the problem is 
still visible:

commit 1d4e7e3c0bca747d0fc54069a6ab8393349431c0
Author: Igor Mammedov <imammedo@redhat.com>
Date:   Thu Nov 6 15:52:47 2014 +0000

    kvm: x86: increase user memory slots to 509
Comment 3 Thomas Stein 2015-03-19 20:01:11 UTC
Hello.

I have the very same error on my kvm machines.

Mar 19 20:35:07 hn kernel: qemu-system-x86: page allocation failure: order:4, mode:0x40d0
Mar 19 20:35:07 hn kernel: CPU: 0 PID: 7029 Comm: qemu-system-x86 Not tainted 3.19.2 #1
Mar 19 20:35:07 hn kernel: Hardware name: System manufacturer System Product Name/P8B WS, BIOS 0802 08/29/
2011
Mar 19 20:35:07 hn kernel:  0000000000000000 ffff88038857f9d8 ffffffff81711fce 0000000000000001
Mar 19 20:35:07 hn kernel:  00000000000040d0 ffff88038857fa68 ffffffff81108d4e ffff88042fded838
Mar 19 20:35:07 hn kernel:  0000000000000380 00000000000003c0 0000000000000286 fffffff00000000f
Mar 19 20:35:07 hn kernel: Call Trace:
Mar 19 20:35:07 hn kernel:  [<ffffffff81711fce>] dump_stack+0x45/0x57
Mar 19 20:35:07 hn kernel:  [<ffffffff81108d4e>] warn_alloc_failed+0xce/0x120
Mar 19 20:35:07 hn kernel:  [<ffffffff8110bc24>] __alloc_pages_nodemask+0x614/0x850
Mar 19 20:35:07 hn kernel:  [<ffffffff8140da5f>] ? megasas_fire_cmd_gen2+0x3f/0x50
Mar 19 20:35:07 hn kernel:  [<ffffffff8114783c>] alloc_pages_current+0x8c/0x100
Mar 19 20:35:07 hn kernel:  [<ffffffff81108eac>] alloc_kmem_pages+0x2c/0xd0
Mar 19 20:35:07 hn kernel:  [<ffffffff811227f3>] kmalloc_order+0x13/0x50
Mar 19 20:35:07 hn kernel:  [<ffffffff8112284f>] kmalloc_order_trace+0x1f/0x90
Mar 19 20:35:07 hn kernel:  [<ffffffff811511b9>] __kmalloc_track_caller+0x159/0x250
Mar 19 20:35:07 hn kernel:  [<ffffffff8111ce1b>] kmemdup+0x1b/0x40
Mar 19 20:35:07 hn kernel:  [<ffffffffa0004aab>] __kvm_set_memory_region+0x1eb/0x950 [kvm]
Mar 19 20:35:07 hn kernel:  [<ffffffff8115aca0>] ? mem_cgroup_uncharge_swap+0x20/0xa0
Mar 19 20:35:07 hn kernel:  [<ffffffff8113e3a8>] ? swap_entry_free+0x198/0x310
Mar 19 20:35:07 hn kernel:  [<ffffffffa000523a>] kvm_set_memory_region+0x2a/0x50 [kvm]
Mar 19 20:35:07 hn kernel:  [<ffffffffa000577f>] kvm_vm_ioctl+0x51f/0x760 [kvm]
Mar 19 20:35:07 hn kernel:  [<ffffffff81170d30>] do_vfs_ioctl+0x2e0/0x4e0
Mar 19 20:35:07 hn kernel:  [<ffffffff8107666f>] ? vtime_account_user+0x3f/0x60
Mar 19 20:35:07 hn kernel:  [<ffffffff81170fb1>] SyS_ioctl+0x81/0xa0
Mar 19 20:35:07 hn kernel:  [<ffffffff81719ff2>] system_call_fastpath+0x12/0x17

Is anyone working on this?

thanks and best regards
t.
Comment 4 Bandan Das 2015-03-19 21:31:19 UTC
Doe(In reply to Thomas Stein from comment #3)
...
> Is anyone working on this?
> 
> thanks and best regards
> t.

Does reverting the commit suggested in comment 2 work for you ?
Comment 5 Thomas Stein 2015-03-19 22:25:14 UTC
Hi.

Reverted the commit right now. I have to boot with this kernel. More tomorrow.

Thanks and cheers
t.
Comment 6 Igor Mammedov 2015-03-20 09:16:25 UTC
Since commit 1d4e7e3c increased "struct kvm_memslots" size from order 2 to order 4, like-hood of above failure grew in ~2x times (there where 90 order 2 free pages)

Looking at log from comment 1
allocation failure shouldn't happened since there are still 40 Order 4 free pages:

> úno 13 18:10:27 argus kernel: Normal: 18555*4kB (UEMC) 145*8kB (UMC) 92*16kB
> (UM) 54*32kB (UM) 40*64kB (UM) 9*128kB (UM) 2*256kB (U) 0*512kB 0*1024kB
> 0*2048kB 0*4096kB = 82804kB

Anyway I'll post patch that changes allocation vmalloc-ed memory as quick fix
and look for possibility of allocating actual amount of slots instead of possible maximum like it's done now.
Comment 7 Thomas Stein 2015-03-20 09:28:05 UTC
Hello.

After reverting commit 1d4e7e3c0bca747d0fc54069a6ab8393349431c0 i had no problem any more. But we have to keep in mind this error only happend now and then. Especially creating snapshots of running vm's triggered the error but this runs without crashing the vm now. I tested it a few times.

cheers
t.
Comment 8 Igor Mammedov 2015-03-20 10:04:05 UTC
(In reply to Thomas Stein from comment #7)
> Hello.
> 
> After reverting commit 1d4e7e3c0bca747d0fc54069a6ab8393349431c0 i had no
> problem any more. But we have to keep in mind this error only happend now
> and then. Especially creating snapshots of running vm's triggered the error
> but this runs without crashing the vm now. I tested it a few times.
> 
> cheers
> t.

Could you try following patch without reverting 1d4e7e3c0bca ?
http://article.gmane.org/gmane.comp.emulators.kvm.devel/134191
Comment 9 Thomas Stein 2015-03-20 10:30:28 UTC
Hello.

I applied the patch to vanilla 3.19.2. No problems so far. Did a few snapshots and vm restarts.

cheers
t.
Comment 10 Thomas Stein 2015-03-26 14:51:14 UTC
Hello.

I suppose this patch is not included in 3.19.3?

thanks and cheers
t.
Comment 11 Igor Mammedov 2015-03-26 15:13:49 UTC
(In reply to Thomas Stein from comment #10)
> Hello.
> 
> I suppose this patch is not included in 3.19.3?
Nope,

I've posted v2 of the patch fixing problems Marcelo pointed out:
https://www.marc.info/?l=kvm&m=142685412907951&w=3
so it' needs to be reviewed/tested.
Comment 12 Thomas Stein 2015-03-27 10:00:01 UTC
Hello Igor.

Is this bug in 3.18 also present? I'm asking because i consider a downgrade.

thanks and cheers
t.
Comment 13 Igor Mammedov 2015-03-27 15:08:42 UTC
Nope, it's only since 3.19.

Could you test patch in comment 11?
Comment 14 Thomas Stein 2015-03-27 15:25:53 UTC
I have patch from comment 11 already running on two machines. No problems so far.
Comment 15 Igor Mammedov 2015-04-14 13:57:03 UTC
Fixed in v4.0
commit 744961341d472db6272ed9b42319a90f5a2aa7c4
    kvm: avoid page allocation failure in kvm_set_memory_region()