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 -- To unsubscribe from this list: send the line "unsubscribe kvm" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html