From: Richard Davies <richard.davies@elastichosts.com>
To: Rik van Riel <riel@redhat.com>
Cc: Avi Kivity <avi@redhat.com>, kvm@vger.kernel.org, qemu-devel@nongnu.org
Subject: Re: [Qemu-devel] Windows slow boot: contractor wanted
Date: Thu, 6 Sep 2012 10:20:39 +0100 [thread overview]
Message-ID: <20120906092039.GA19234@alpha.arachsys.com> (raw)
In-Reply-To: <20120826105803.GA377@alpha.arachsys.com>
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
next prev parent reply other threads:[~2012-09-06 9:21 UTC|newest] Thread overview: 46+ messages / expand[flat|nested] mbox.gz Atom feed top 2012-08-16 10:47 [Qemu-devel] Windows slow boot: contractor wanted Richard Davies 2012-08-16 11:39 ` Avi Kivity 2012-08-17 12:36 ` Richard Davies 2012-08-17 13:02 ` Robert Vineyard 2012-08-18 14:44 ` Richard Davies 2012-08-19 5:02 ` Brian Jackson 2012-08-20 8:16 ` Richard Davies 2012-08-19 8:40 ` Avi Kivity 2012-08-19 8:51 ` Richard Davies 2012-08-19 14:04 ` Avi Kivity 2012-08-20 13:56 ` Richard Davies 2012-08-21 9:00 ` Avi Kivity 2012-08-21 15:21 ` Richard Davies 2012-08-21 15:39 ` Troy Benjegerdes 2012-08-22 9:08 ` Avi Kivity 2012-08-22 12:40 ` Richard Davies 2012-08-22 12:44 ` Avi Kivity 2012-08-22 14:41 ` Richard Davies 2012-08-22 14:53 ` Avi Kivity 2012-08-22 15:26 ` Richard Davies 2012-08-22 17:22 ` Troy Benjegerdes 2012-08-25 17:51 ` Richard Davies 2012-08-22 15:21 ` Rik van Riel 2012-08-22 15:34 ` Richard Davies 2012-08-25 17:45 ` Richard Davies 2012-08-25 18:11 ` Rik van Riel 2012-08-26 10:58 ` Richard Davies 2012-09-06 9:20 ` Richard Davies [this message] 2012-09-12 10:56 ` [Qemu-devel] Windows VM slow boot Richard Davies 2012-09-12 12:25 ` Mel Gorman 2012-09-12 16:46 ` Richard Davies 2012-09-13 9:50 ` Mel Gorman 2012-09-13 19:47 ` [Qemu-devel] [PATCH 1/2] Revert "mm: have order > 0 compaction start near a pageblock with free pages" Rik van Riel 2012-09-13 19:48 ` [Qemu-devel] [PATCH 2/2] make the compaction "skip ahead" logic robust Rik van Riel 2012-09-13 19:54 ` [Qemu-devel] [PATCH -v2 " Rik van Riel 2012-09-15 15:55 ` Richard Davies 2012-09-16 19:12 ` Richard Davies 2012-09-17 12:26 ` Mel Gorman 2012-09-18 8:14 ` Richard Davies 2012-09-18 11:21 ` Mel Gorman 2012-09-18 17:58 ` Richard Davies 2012-09-17 13:50 ` Rik van Riel 2012-09-17 14:07 ` Mel Gorman 2012-08-16 14:10 ` [Qemu-devel] Windows slow boot: contractor wanted Benoît Canet 2012-08-16 15:53 ` Troy Benjegerdes 2012-09-18 15:12 ` [Qemu-devel] Windows slow boot Michael Tokarev
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20120906092039.GA19234@alpha.arachsys.com \
--to=richard.davies@elastichosts.com \
--cc=avi@redhat.com \
--cc=kvm@vger.kernel.org \
--cc=qemu-devel@nongnu.org \
--cc=riel@redhat.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).