|
| From: | Richard Davies |
| Subject: | Re: [Qemu-devel] Windows slow boot: contractor wanted |
| Date: | Sun, 26 Aug 2012 11:58:03 +0100 |
| User-agent: | Mutt/1.5.20 (2009-06-14) |
Rik van Riel wrote:
> Can you get a backtrace to that _raw_spin_lock_irqsave, to see
> from where it is running into lock contention?
>
> It would be good to know whether it is isolate_freepages_block,
> yield_to, kvm_vcpu_on_spin or something else...
Hi Rik,
I got into a slow boot situation on 3.6.0-rc3, ran "perf record -g -a" for a
while, then ran perf report with the output below.
This trace looks more like the second perf top trace that I sent on Saturday
(there were two in my email and they were different from each other as well
as different from on 3.5.2).
The symptoms were a bit different too - the VM boots appeared to be
completely locked up rather than just slow, and I couldn't quit qemu-kvm at
the monitor - I had to restart the host.
So perhaps this one is actually a deadlock rather than just slow?
Cheers,
Richard.
# ========
# captured on: Sun Aug 26 10:08:28 2012
# os release : 3.6.0-rc3-elastic
# perf version : 3.5.2
# arch : x86_64
# nrcpus online : 16
# nrcpus avail : 16
# cpudesc : AMD Opteron(tm) Processor 6128
# cpuid : AuthenticAMD,16,9,1
# total memory : 131971760 kB
# cmdline : /home/root/bin/perf record -g -a
# event : name = cycles, type = 0, config = 0x0, config1 = 0x0, config2 = 0x0,
excl_usr = 0, excl_kern = 0, id = { 49, 50, 51, 52, 53, 54, 55, 56, 57, 58, 59,
60, 61, 62, 63, 64 }
# HEADER_CPU_TOPOLOGY info available, use -I to display
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# ========
#
# Samples: 2M of event 'cycles'
# Event count (approx.): 1040676441385
#
# Overhead Command Shared Object
Symbol
# ........ ............... ....................
..............................................
#
90.01% qemu-kvm [kernel.kallsyms] [k] _raw_spin_lock_irqsave
|
--- _raw_spin_lock_irqsave
|
|--99.99%-- isolate_migratepages_range
| compact_zone
| compact_zone_order
| try_to_compact_pages
| __alloc_pages_direct_compact
| __alloc_pages_nodemask
| alloc_pages_vma
| do_huge_pmd_anonymous_page
| handle_mm_fault
| __get_user_pages
| get_user_page_nowait
| hva_to_pfn.isra.33
| __gfn_to_pfn
| gfn_to_pfn_async
| try_async_pf
| tdp_page_fault
| kvm_mmu_page_fault
| pf_interception
| handle_exit
| kvm_arch_vcpu_ioctl_run
| kvm_vcpu_ioctl
| do_vfs_ioctl
| sys_ioctl
| system_call_fastpath
| ioctl
| |
| |--54.91%-- 0x10100000002
| |
| --45.09%-- 0x10100000006
--0.01%-- [...]
4.66% qemu-kvm [kernel.kallsyms] [k] sub_preempt_count
|
--- sub_preempt_count
|
|--99.77%-- _raw_spin_unlock_irqrestore
| |
| |--99.99%-- compact_checklock_irqsave
| | isolate_migratepages_range
| | compact_zone
| | compact_zone_order
| | try_to_compact_pages
| | __alloc_pages_direct_compact
| | __alloc_pages_nodemask
| | alloc_pages_vma
| | do_huge_pmd_anonymous_page
| | handle_mm_fault
| | __get_user_pages
| | get_user_page_nowait
| | hva_to_pfn.isra.33
| | __gfn_to_pfn
| | gfn_to_pfn_async
| | try_async_pf
| | tdp_page_fault
| | kvm_mmu_page_fault
| | pf_interception
| | handle_exit
| | kvm_arch_vcpu_ioctl_run
| | kvm_vcpu_ioctl
| | do_vfs_ioctl
| | sys_ioctl
| | system_call_fastpath
| | ioctl
| | |
| | |--51.94%-- 0x10100000002
| | |
| | --48.06%-- 0x10100000006
| --0.01%-- [...]
--0.23%-- [...]
1.23% ksmd [kernel.kallsyms] [k] memcmp
|
--- memcmp
|
|--99.83%-- memcmp_pages
| |
| |--78.46%-- ksm_scan_thread
| | kthread
| | kernel_thread_helper
| |
| --21.54%-- try_to_merge_with_ksm_page
| ksm_scan_thread
| kthread
| kernel_thread_helper
--0.17%-- [...]
0.91% ksmd [kernel.kallsyms] [k] smp_call_function_many
|
--- smp_call_function_many
|
|--99.98%-- native_flush_tlb_others
| |
| |--99.86%-- flush_tlb_page
| | ptep_clear_flush
| | try_to_merge_with_ksm_page
| | ksm_scan_thread
| | kthread
| | kernel_thread_helper
| --0.14%-- [...]
--0.02%-- [...]
0.34% qemu-kvm [kernel.kallsyms] [k]
_raw_spin_unlock_irqrestore
|
--- _raw_spin_unlock_irqrestore
|
|--96.08%-- compact_checklock_irqsave
| isolate_migratepages_range
| compact_zone
| compact_zone_order
| try_to_compact_pages
| __alloc_pages_direct_compact
| __alloc_pages_nodemask
| alloc_pages_vma
| do_huge_pmd_anonymous_page
| handle_mm_fault
| __get_user_pages
| get_user_page_nowait
| hva_to_pfn.isra.33
| __gfn_to_pfn
| gfn_to_pfn_async
| try_async_pf
| tdp_page_fault
| kvm_mmu_page_fault
| pf_interception
| handle_exit
| kvm_arch_vcpu_ioctl_run
| kvm_vcpu_ioctl
| do_vfs_ioctl
| sys_ioctl
| system_call_fastpath
| ioctl
| |
| |--65.19%-- 0x10100000006
| |
| --34.81%-- 0x10100000002
|
|--2.68%-- isolate_migratepages_range
| compact_zone
| compact_zone_order
| try_to_compact_pages
| __alloc_pages_direct_compact
| __alloc_pages_nodemask
| alloc_pages_vma
| do_huge_pmd_anonymous_page
| handle_mm_fault
| __get_user_pages
| get_user_page_nowait
| hva_to_pfn.isra.33
| __gfn_to_pfn
| gfn_to_pfn_async
| try_async_pf
| tdp_page_fault
| kvm_mmu_page_fault
| pf_interception
| handle_exit
| kvm_arch_vcpu_ioctl_run
| kvm_vcpu_ioctl
| do_vfs_ioctl
| sys_ioctl
| system_call_fastpath
| ioctl
| |
| |--52.08%-- 0x10100000002
| |
| --47.92%-- 0x10100000006
|
|--0.56%-- ntp_tick_length
| do_timer
| tick_do_update_jiffies64
| tick_sched_timer
| __run_hrtimer
| hrtimer_interrupt
| smp_apic_timer_interrupt
| apic_timer_interrupt
| compact_checklock_irqsave
| isolate_migratepages_range
| compact_zone
| compact_zone_order
| try_to_compact_pages
| __alloc_pages_direct_compact
| __alloc_pages_nodemask
| alloc_pages_vma
| do_huge_pmd_anonymous_page
| handle_mm_fault
| __get_user_pages
| get_user_page_nowait
| hva_to_pfn.isra.33
| __gfn_to_pfn
| gfn_to_pfn_async
| try_async_pf
| tdp_page_fault
| kvm_mmu_page_fault
| pf_interception
| handle_exit
| kvm_arch_vcpu_ioctl_run
| kvm_vcpu_ioctl
| do_vfs_ioctl
| sys_ioctl
| system_call_fastpath
| ioctl
| 0x10100000002
--0.68%-- [...]
0.30% swapper [kernel.kallsyms] [k] default_idle
|
--- default_idle
|
|--99.95%-- cpu_idle
| start_secondary
--0.05%-- [...]
0.15% qemu-kvm [kernel.kallsyms] [k]
isolate_migratepages_range
|
--- isolate_migratepages_range
|
|--97.41%-- compact_zone
| compact_zone_order
| try_to_compact_pages
| __alloc_pages_direct_compact
| __alloc_pages_nodemask
| alloc_pages_vma
| do_huge_pmd_anonymous_page
| handle_mm_fault
| __get_user_pages
| get_user_page_nowait
| hva_to_pfn.isra.33
| __gfn_to_pfn
| gfn_to_pfn_async
| try_async_pf
| tdp_page_fault
| kvm_mmu_page_fault
| pf_interception
| handle_exit
| kvm_arch_vcpu_ioctl_run
| kvm_vcpu_ioctl
| do_vfs_ioctl
| sys_ioctl
| system_call_fastpath
| ioctl
| |
| |--54.02%-- 0x10100000002
| |
| --45.98%-- 0x10100000006
|
--2.59%-- compact_zone_order
try_to_compact_pages
__alloc_pages_direct_compact
__alloc_pages_nodemask
alloc_pages_vma
do_huge_pmd_anonymous_page
handle_mm_fault
__get_user_pages
get_user_page_nowait
hva_to_pfn.isra.33
__gfn_to_pfn
gfn_to_pfn_async
try_async_pf
tdp_page_fault
kvm_mmu_page_fault
pf_interception
handle_exit
kvm_arch_vcpu_ioctl_run
kvm_vcpu_ioctl
do_vfs_ioctl
sys_ioctl
system_call_fastpath
ioctl
|
|--56.10%-- 0x10100000002
|
--43.90%-- 0x10100000006
0.12% qemu-kvm [kernel.kallsyms] [k] compact_zone
|
--- compact_zone
compact_zone_order
try_to_compact_pages
__alloc_pages_direct_compact
__alloc_pages_nodemask
alloc_pages_vma
do_huge_pmd_anonymous_page
handle_mm_fault
__get_user_pages
get_user_page_nowait
hva_to_pfn.isra.33
__gfn_to_pfn
gfn_to_pfn_async
try_async_pf
tdp_page_fault
kvm_mmu_page_fault
pf_interception
handle_exit
kvm_arch_vcpu_ioctl_run
kvm_vcpu_ioctl
do_vfs_ioctl
sys_ioctl
system_call_fastpath
ioctl
|
|--52.09%-- 0x10100000002
|
--47.91%-- 0x10100000006
0.11% qemu-kvm [kernel.kallsyms] [k] flush_tlb_func
|
--- flush_tlb_func
|
|--99.58%-- generic_smp_call_function_interrupt
| smp_call_function_interrupt
| call_function_interrupt
| |
| |--94.65%-- compact_checklock_irqsave
| | isolate_migratepages_range
| | compact_zone
| | compact_zone_order
| | try_to_compact_pages
| | __alloc_pages_direct_compact
| | __alloc_pages_nodemask
| | alloc_pages_vma
| | do_huge_pmd_anonymous_page
| | handle_mm_fault
| | __get_user_pages
| | get_user_page_nowait
| | hva_to_pfn.isra.33
| | __gfn_to_pfn
| | gfn_to_pfn_async
| | try_async_pf
| | tdp_page_fault
| | kvm_mmu_page_fault
| | pf_interception
| | handle_exit
| | kvm_arch_vcpu_ioctl_run
| | kvm_vcpu_ioctl
| | do_vfs_ioctl
| | sys_ioctl
| | system_call_fastpath
| | ioctl
| | |
| | |--78.04%-- 0x10100000006
| | |
| | --21.96%-- 0x10100000002
| |
| |--4.67%-- sub_preempt_count
| | _raw_spin_unlock_irqrestore
| | compact_checklock_irqsave
| | isolate_migratepages_range
| | compact_zone
| | compact_zone_order
| | try_to_compact_pages
| | __alloc_pages_direct_compact
| | __alloc_pages_nodemask
| | alloc_pages_vma
| | do_huge_pmd_anonymous_page
| | handle_mm_fault
| | __get_user_pages
| | get_user_page_nowait
| | hva_to_pfn.isra.33
| | __gfn_to_pfn
| | gfn_to_pfn_async
| | try_async_pf
| | tdp_page_fault
| | kvm_mmu_page_fault
| | pf_interception
| | handle_exit
| | kvm_arch_vcpu_ioctl_run
| | kvm_vcpu_ioctl
| | do_vfs_ioctl
| | sys_ioctl
| | system_call_fastpath
| | ioctl
| | |
| | |--78.18%-- 0x10100000006
| | |
| | --21.82%-- 0x10100000002
| --0.68%-- [...]
--0.42%-- [...]
0.09% qemu-kvm [kernel.kallsyms] [k] mod_zone_page_state
|
--- mod_zone_page_state
|
|--80.84%-- isolate_migratepages_range
| compact_zone
| compact_zone_order
| try_to_compact_pages
| __alloc_pages_direct_compact
| __alloc_pages_nodemask
| alloc_pages_vma
| do_huge_pmd_anonymous_page
| handle_mm_fault
| __get_user_pages
| get_user_page_nowait
| hva_to_pfn.isra.33
| __gfn_to_pfn
| gfn_to_pfn_async
| try_async_pf
| tdp_page_fault
| kvm_mmu_page_fault
| pf_interception
| handle_exit
| kvm_arch_vcpu_ioctl_run
| kvm_vcpu_ioctl
| do_vfs_ioctl
| sys_ioctl
| system_call_fastpath
| ioctl
| |
| |--53.90%-- 0x10100000002
| |
| --46.10%-- 0x10100000006
|
--19.16%-- compact_zone
compact_zone_order
try_to_compact_pages
__alloc_pages_direct_compact
__alloc_pages_nodemask
alloc_pages_vma
do_huge_pmd_anonymous_page
handle_mm_fault
__get_user_pages
get_user_page_nowait
hva_to_pfn.isra.33
__gfn_to_pfn
gfn_to_pfn_async
try_async_pf
tdp_page_fault
kvm_mmu_page_fault
pf_interception
handle_exit
kvm_arch_vcpu_ioctl_run
kvm_vcpu_ioctl
do_vfs_ioctl
sys_ioctl
system_call_fastpath
ioctl
|
|--55.04%-- 0x10100000002
|
--44.96%-- 0x10100000006
0.09% qemu-kvm [kernel.kallsyms] [k] migrate_pages
|
--- migrate_pages
|
|--96.21%-- compact_zone
| compact_zone_order
| try_to_compact_pages
| __alloc_pages_direct_compact
| __alloc_pages_nodemask
| alloc_pages_vma
| do_huge_pmd_anonymous_page
| handle_mm_fault
| __get_user_pages
| get_user_page_nowait
| hva_to_pfn.isra.33
| __gfn_to_pfn
| gfn_to_pfn_async
| try_async_pf
| tdp_page_fault
| kvm_mmu_page_fault
| pf_interception
| handle_exit
| kvm_arch_vcpu_ioctl_run
| kvm_vcpu_ioctl
| do_vfs_ioctl
| sys_ioctl
| system_call_fastpath
| ioctl
| |
| |--52.94%-- 0x10100000002
| |
| --47.06%-- 0x10100000006
|
--3.79%-- compact_zone_order
try_to_compact_pages
__alloc_pages_direct_compact
__alloc_pages_nodemask
alloc_pages_vma
do_huge_pmd_anonymous_page
handle_mm_fault
__get_user_pages
get_user_page_nowait
hva_to_pfn.isra.33
__gfn_to_pfn
gfn_to_pfn_async
try_async_pf
tdp_page_fault
kvm_mmu_page_fault
pf_interception
handle_exit
kvm_arch_vcpu_ioctl_run
kvm_vcpu_ioctl
do_vfs_ioctl
sys_ioctl
system_call_fastpath
ioctl
|
|--50.72%-- 0x10100000002
|
--49.28%-- 0x10100000006
0.09% qemu-kvm [kernel.kallsyms] [k] __zone_watermark_ok
|
--- __zone_watermark_ok
|
|--95.81%-- zone_watermark_ok
| compact_zone
| compact_zone_order
| try_to_compact_pages
| __alloc_pages_direct_compact
| __alloc_pages_nodemask
| alloc_pages_vma
| do_huge_pmd_anonymous_page
| handle_mm_fault
| __get_user_pages
| get_user_page_nowait
| hva_to_pfn.isra.33
| __gfn_to_pfn
| gfn_to_pfn_async
| try_async_pf
| tdp_page_fault
| kvm_mmu_page_fault
| pf_interception
| handle_exit
| kvm_arch_vcpu_ioctl_run
| kvm_vcpu_ioctl
| do_vfs_ioctl
| sys_ioctl
| system_call_fastpath
| ioctl
| |
| |--51.21%-- 0x10100000002
| |
| --48.79%-- 0x10100000006
|
--4.19%-- compact_zone
compact_zone_order
try_to_compact_pages
__alloc_pages_direct_compact
__alloc_pages_nodemask
alloc_pages_vma
do_huge_pmd_anonymous_page
handle_mm_fault
__get_user_pages
get_user_page_nowait
hva_to_pfn.isra.33
__gfn_to_pfn
gfn_to_pfn_async
try_async_pf
tdp_page_fault
kvm_mmu_page_fault
pf_interception
handle_exit
kvm_arch_vcpu_ioctl_run
kvm_vcpu_ioctl
do_vfs_ioctl
sys_ioctl
system_call_fastpath
ioctl
|
|--50.00%-- 0x10100000006
|
--50.00%-- 0x10100000002
0.06% perf [kernel.kallsyms] [k] copy_user_generic_string
|
--- copy_user_generic_string
generic_file_buffered_write
__generic_file_aio_write
generic_file_aio_write
ext4_file_write
do_sync_write
vfs_write
sys_write
system_call_fastpath
write
run_builtin
main
__libc_start_main
| [Prev in Thread] | Current Thread | [Next in Thread] |