[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] Re: [Xen-devel] [PATCH 0/4] enhance lock debugging
On 07/08/2019 15:31, Juergen Gross wrote: > While hunting a locking problem in my core scheduling series I have > added some debugging aids to spinlock handling making it easier to > find the root cause for the problem. > > Making use of the already lock profiling and enhancing it a little > bit produces some really valuable diagnostic data e.g. when a NMI > watchdog is triggering a crash. So I'm not sure where best to report this in the series, so 0/$N will have to do. Here is a sample trace from panic(): (XEN) Xen lock profile info SHOW (now = 49695791886 total = 49695791886) (XEN) Global grant_lock: addr=ffff82d080818640, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global balloon_lock: addr=ffff82d080818630, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global osvw_lock: addr=ffff82d080818610, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global mtrr_mutex: addr=ffff82d0808185f0, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global set_atomicity_lock: addr=ffff82d0808185e0, lockval=80008, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global cmci_discover_lock: addr=ffff82d0808185c0, lockval=80008, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global mce_logout_lock: addr=ffff82d0808185a0, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global processing_lock: addr=ffff82d080818580, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global vpmu_lock: addr=ffff82d080818560, lockval=40004, cpu=4095 (XEN) lock: 4(00000000:0000007D), block: 0(00000000:00000000) (XEN) Global pm_lock: addr=ffff82d080818230, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global rtc_lock: addr=ffff82d080818210, lockval=310031, cpu=4095 (XEN) lock: 48(00000000:0001892E), block: 0(00000000:00000000) (XEN) Global pit_lock: addr=ffff82d080818200, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global platform_timer_lock: addr=ffff82d0808181f0, lockval=6c006c, cpu=4095 (XEN) lock: 92(00000000:00012CAB), block: 0(00000000:00000000) (XEN) Global sync_lock: addr=ffff82d0808181d0, lockval=c188c188, cpu=4095 (XEN) lock: 115080(00000000:0074F130), block: 115079(00000000:0871000E) (XEN) Global lock: addr=ffff82d0808181e0, lockval=10001, cpu=4095 (XEN) lock: 1(00000000:01322165), block: 0(00000000:00000000) (XEN) Global flush_lock: addr=ffff82d0808181c0, lockval=91139111, cpu=3 (XEN) lock: 168195(00000000:159C6F6E), block: 1695(00000000:006B31FD) (XEN) Global xenpf_lock: addr=ffff82d0808181b0, lockval=2f002f, cpu=4095 (XEN) lock: 47(00000000:0001BC02), block: 0(00000000:00000000) (XEN) Global pci_config_lock: addr=ffff82d0808181a0, lockval=374d374d, cpu=4095 (XEN) lock: 5196(00000000:004545AA), block: 0(00000000:00000000) (XEN) Global lapic_nmi_owner_lock: addr=ffff82d080817d70, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global last_lock: addr=ffff82d080817d40, lockval=40034003, cpu=4095 (XEN) lock: 16387(00000000:00047132), block: 0(00000000:00000000) (XEN) Global map_pgdir_lock: addr=ffff82d080817d50, lockval=2c002c, cpu=4095 (XEN) lock: 38(00000000:00000ACF), block: 0(00000000:00000000) (XEN) Global microcode_mutex: addr=ffff82d080817d20, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global microcode_update_lock: addr=ffff82d080817d10, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global microcode_update_lock: addr=ffff82d080817d00, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global vector_lock: addr=ffff82d080817cf0, lockval=440044, cpu=4095 (XEN) lock: 27(00000000:00003B20), block: 0(00000000:00000000) (XEN) Global irq_ratelimit_lock: addr=ffff82d080817ce0, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global lock: addr=ffff82d080817cc0, lockval=100010, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global msix_fixmap_lock: addr=ffff82d080817cb0, lockval=20002, cpu=4095 (XEN) lock: 2(00000000:000000CF), block: 0(00000000:00000000) (XEN) Global ioapic_lock: addr=ffff82d080817c90, lockval=660066, cpu=4095 (XEN) lock: 20(00000000:00026E6C), block: 0(00000000:00000000) (XEN) Global i8259A_lock: addr=ffff82d080817c80, lockval=2d002d, cpu=4095 (XEN) lock: 6(00000000:00001BA0), block: 0(00000000:00000000) (XEN) Global apei_iomaps_lock: addr=ffff82d080817c50, lockval=110011, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global erst_lock: addr=ffff82d080817c40, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global shared_intremap_lock: addr=ffff82d080817bc0, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global iommu_pt_cleanup_lock: addr=ffff82d080817ba0, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global rx_lock: addr=ffff82d080817b70, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global tx_lock: addr=ffff82d080817b60, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global console_lock: addr=ffff82d080817830, lockval=770077, cpu=4095 (XEN) lock: 3447(00000000:07595894), block: 0(00000000:00000000) (XEN) Global ratelimit_lock: addr=ffff82d080817820, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global lock: addr=ffff82d080817800, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global pool_list_lock: addr=ffff82d0808177e0, lockval=10001, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global xenoprof_lock: addr=ffff82d0808177d0, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global pmu_owner_lock: addr=ffff82d0808177c0, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global vm_lock: addr=ffff82d0808177b0, lockval=220022, cpu=4095 (XEN) lock: 17(00000000:00001ED1), block: 0(00000000:00000000) (XEN) Global virtual_region_lock: addr=ffff82d0808177a0, lockval=10001, cpu=4095 (XEN) lock: 1(00000000:00000054), block: 0(00000000:00000000) (XEN) Global lock: addr=ffff82d080817780, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global wc_lock: addr=ffff82d080817770, lockval=c000c, cpu=4095 (XEN) lock: 11(00000000:00000995), block: 0(00000000:00000000) (XEN) Global tasklet_lock: addr=ffff82d080817760, lockval=3f403f4, cpu=4095 (XEN) lock: 426(00000000:00007AFF), block: 0(00000000:00000000) (XEN) Global sysctl_lock: addr=ffff82d080817750, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global symbols_mutex: addr=ffff82d080817740, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global stopmachine_lock: addr=ffff82d080817730, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global call_lock: addr=ffff82d080817710, lockval=4d004d, cpu=4095 (XEN) lock: 67(00000000:00176310), block: 0(00000000:00000000) (XEN) Global heap_lock: addr=ffff82d080817570, lockval=6b286b28, cpu=4095 (XEN) lock: 753071(00000000:018E9B8B), block: 33(00000000:0000916A) (XEN) Global payload_lock: addr=ffff82d080817550, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global crash_notes_lock: addr=ffff82d080817530, lockval=80008, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global lock: addr=ffff82d080817510, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global global_virq_handlers_lock: addr=ffff82d080817500, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global domlist_update_lock: addr=ffff82d0808174e0, lockval=10001, cpu=4095 (XEN) lock: 1(00000000:0000005B), block: 0(00000000:00000000) (XEN) Global domctl_lock: addr=ffff82d0808174d0, lockval=50005, cpu=4095 (XEN) lock: 5(00000000:000008DC), block: 0(00000000:00000000) (XEN) Global cpupool_lock: addr=ffff82d0808174b0, lockval=a000a, cpu=4095 (XEN) lock: 1(00000000:00000176), block: 0(00000000:00000000) (XEN) Global cpu_add_remove_lock: addr=ffff82d0808174a0, lockval=2d002d, cpu=4095 (XEN) lock: 24(00000000:0000175F), block: 0(00000000:00000000) (XEN) Global efi_rs_lock: addr=ffff82d080817030, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Domain 0 event_lock: addr=ffff8308366c50e8, lockval=1d451d45, cpu=4095 (XEN) lock: 7493(00000000:00866052), block: 0(00000000:00000000) (XEN) Domain 0 page_alloc_lock: addr=ffff8308366c5028, lockval=9aa59aa5, cpu=4095 (XEN) lock: 39589(00000000:0055339E), block: 0(00000000:00000000) (XEN) Domain 0 domain_lock: addr=ffff8308366c5018, lockval=150015, cpu=4095 (XEN) lock: 21(00000000:00009D70), block: 0(00000000:00000000) (XEN) Domain 32767 page_alloc_lock: addr=ffff83084ccc5028, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Domain 32767 domain_lock: addr=ffff83084ccc5018, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Domain 32753 page_alloc_lock: addr=ffff83084cccf028, lockval=3ee43ee4, cpu=4095 (XEN) lock: 16100(00000000:0005173F), block: 0(00000000:00000000) (XEN) Domain 32753 domain_lock: addr=ffff83084cccf018, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Domain 32754 page_alloc_lock: addr=ffff83084ccd0028, lockval=64006400, cpu=4095 (XEN) lock: 25600(00000000:000814D9), block: 0(00000000:00000000) (XEN) Domain 32754 domain_lock: addr=ffff83084ccd0018, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) Its not exactly the easiest to dump to follow. First of all - I don't see why the hold/block time are printed like that. It might be a holdover from the 32bit build, pre PRId64 support. They should probably use PRI_stime anyway. The domid rendering is unfortunate. Ideally we'd use %pd but that would involve rearranging the logic to get a struct domain* in hand. Seeing as you're the last person to modify this code, how hard would that be to do? If/when the per-domain locks are rendered more clearly, the "Global " prefix can be dropped. An interesting quirk of ticketlocks is that lockval= is redundant with lock_cnt. Could we perhaps fold the two fields? Distinguishing cpu=4095 as "not locked" would be useful. We have several global locks called lock: (XEN) Global lock: addr=ffff82d0808181e0, lockval=10001, cpu=4095 (XEN) lock: 1(00000000:01322165), block: 0(00000000:00000000) (XEN) Global lock: addr=ffff82d080817cc0, lockval=100010, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global lock: addr=ffff82d080817800, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global lock: addr=ffff82d080817780, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) (XEN) Global lock: addr=ffff82d080817510, lockval=0000, cpu=4095 (XEN) lock: 0(00000000:00000000), block: 0(00000000:00000000) The second one in particular has corrupt data, seeing has it has been taken and released several times without lock_cnt increasing. For sanity sake, we should enforce unique naming of any lock registered for profiling. ~Andrew _______________________________________________ Xen-devel mailing list Xen-devel@xxxxxxxxxxxxxxxxxxxx https://lists.xenproject.org/mailman/listinfo/xen-devel
|
Lists.xenproject.org is hosted with RackSpace, monitoring our |