|
| From: | Richard Davies |
| Subject: | Re: [Qemu-devel] Windows slow boot: contractor wanted |
| Date: | Thu, 6 Sep 2012 10:20:39 +0100 |
| User-agent: | Mutt/1.5.20 (2009-06-14) |
Hi Rik,
Are there any more tests which I can usefully do for you?
I notice that 3.6.0-rc4 is out - are there changes from rc3 which are worth
me retesting?
Cheers,
Richard.
Richard Davies wrote:
> 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] |