Description of problem: During Xen domU bootup there's a backtrace related to recursive locking. I copy & pasted it here from domU dmesg. Version-Release number of selected component (if applicable): 2.6.31-0.203.rc8.git2.fc12.i686.PAE How reproducible: Always. Steps to Reproduce: 1. Boot rawhide kernel as Xen domU 2. domU seems to work, but you get the backtrace Actual results: recursive locking related backtrace during kernel startup Expected results: No backtrace / locking errors. Additional info: This happens on Fedora 11 Xen dom0, using xen-3.4.1-3 (rebuilt for F11), pv_ops dom0 kernel, and libvirt from F11 testing-updates. paste from domU dmesg: Write protecting the kernel text: 4352k Write protecting the kernel read-only data: 1800k ============================================= [ INFO: possible recursive locking detected ] 2.6.31-0.203.rc8.git2.fc12.i686.PAE #1 --------------------------------------------- init/1 is trying to acquire lock: (&input_pool.lock){+.+...}, at: [<c043b30e>] __wake_up+0x2b/0x61 but task is already holding lock: (&input_pool.lock){+.+...}, at: [<c068e21b>] account+0x30/0xf0 other info that might help us debug this: 2 locks held by init/1: #0: (&p->cred_guard_mutex){+.+.+.}, at: [<c0508756>] do_execve+0xa4/0x2ee #1: (&input_pool.lock){+.+...}, at: [<c068e21b>] account+0x30/0xf0 stack backtrace: Pid: 1, comm: init Not tainted 2.6.31-0.203.rc8.git2.fc12.i686.PAE #1 Call Trace: [<c08387c0>] ? printk+0x22/0x3a [<c0478b59>] __lock_acquire+0x7e9/0xb25 [<c0478f4c>] lock_acquire+0xb7/0xeb [<c043b30e>] ? __wake_up+0x2b/0x61 [<c043b30e>] ? __wake_up+0x2b/0x61 [<c083b4f7>] _spin_lock_irqsave+0x45/0x89 [<c043b30e>] ? __wake_up+0x2b/0x61 [<c043b30e>] __wake_up+0x2b/0x61 [<c068e2a0>] account+0xb5/0xf0 [<c068e3ef>] extract_entropy+0x3e/0xac [<c0406b0b>] ? xen_restore_fl_direct_end+0x0/0x1 [<c04799d7>] ? lock_release+0x186/0x19f [<c068e56e>] get_random_bytes+0x29/0x3e [<c053bbd1>] load_elf_binary+0xab9/0x106c [<c050732d>] search_binary_handler+0xd7/0x27b [<c053b118>] ? load_elf_binary+0x0/0x106c [<c0539c76>] load_script+0x1a6/0x1c8 [<c0507323>] ? search_binary_handler+0xcd/0x27b [<c0406199>] ? xen_force_evtchn_callback+0x1d/0x34 [<c0507323>] ? search_binary_handler+0xcd/0x27b [<c0406b14>] ? check_events+0x8/0xc [<c0406b0b>] ? xen_restore_fl_direct_end+0x0/0x1 [<c04799d7>] ? lock_release+0x186/0x19f [<c050732d>] search_binary_handler+0xd7/0x27b [<c0539ad0>] ? load_script+0x0/0x1c8 [<c050888b>] do_execve+0x1d9/0x2ee [<c0408359>] sys_execve+0x39/0x6e [<c0409ad0>] syscall_call+0x7/0xb [<c04f00d8>] ? sys_swapon+0x348/0xa98 [<c040d76b>] ? kernel_execve+0x27/0x3e [<c04031e0>] ? run_init_process+0x2b/0x3e [<c0403275>] ? init_post+0x82/0xe9 [<c0a9b566>] ? kernel_init+0x1f6/0x211 [<c0a9b370>] ? kernel_init+0x0/0x211 [<c040a6bf>] ? kernel_thread_helper+0x7/0x10 -------
Does this happen on native? At first glance, I don't see anything Xen-specific there.
Does this kernel have CONFIG_PARAVIRT_SPINLOCKS enabled?
No, CONFIG_PARAVIRT_SPINLOCKS is not set.
I just tried updating the rawhide domU to the latest packages.. here's the backtrace from 2.6.31-2.fc12.i686.PAE: I'll try to upgrade the dom0 to rawhide, to check if this happens also on baremetal. dracut: dracut-001-9.git6f0e469d.fc12 udev: starting version 145 udevadm used greatest stack depth: 6072 bytes left ============================================= [ INFO: possible recursive locking detected ] 2.6.31-2.fc12.i686.PAE #1 --------------------------------------------- udevd/68 is trying to acquire lock: (&input_pool.lock){+.+...}, at: [<c043b31e>] __wake_up+0x2b/0x61 but task is already holding lock: (&input_pool.lock){+.+...}, at: [<c068e3e7>] account+0x30/0xf0 other info that might help us debug this: 2 locks held by udevd/68: #0: (nl_table_lock){.+.+..}, at: [<c07b4f8e>] netlink_table_grab+0x21/0xb8 #1: (&input_pool.lock){+.+...}, at: [<c068e3e7>] account+0x30/0xf0 stack backtrace: Pid: 68, comm: udevd Not tainted 2.6.31-2.fc12.i686.PAE #1 Call Trace: [<c0838c08>] ? printk+0x22/0x3a [<c0478b69>] __lock_acquire+0x7e9/0xb25 [<c0478f5c>] lock_acquire+0xb7/0xeb [<c043b31e>] ? __wake_up+0x2b/0x61 [<c043b31e>] ? __wake_up+0x2b/0x61 [<c083b93f>] _spin_lock_irqsave+0x45/0x89 [<c043b31e>] ? __wake_up+0x2b/0x61 [<c043b31e>] __wake_up+0x2b/0x61 [<c068e46c>] account+0xb5/0xf0 [<c068e5bb>] extract_entropy+0x3e/0xac [<c07b578c>] ? nl_pid_hash_zalloc+0x27/0x52 [<c068e73a>] get_random_bytes+0x29/0x3e [<c07b5987>] nl_pid_hash_rehash+0x71/0xed [<c07b5a9f>] netlink_insert+0x9c/0x123 [<c07b5bd0>] netlink_autobind+0xaa/0xce [<c07b5d34>] netlink_bind+0x8d/0x164 [<c078bed6>] sys_bind+0x7e/0xb4 [<c0476219>] ? lock_release_holdtime+0x39/0x143 [<c0479762>] ? lock_release_non_nested+0xb6/0x1b5 [<c0406b0b>] ? xen_restore_fl_direct_end+0x0/0x1 [<c0478f74>] ? lock_acquire+0xcf/0xeb [<c0406199>] ? xen_force_evtchn_callback+0x1d/0x34 [<c04df3c0>] ? might_fault+0x56/0xa4 [<c0406b14>] ? check_events+0x8/0xc [<c0406b0b>] ? xen_restore_fl_direct_end+0x0/0x1 [<c04799e7>] ? lock_release+0x186/0x19f [<c04df3fb>] ? might_fault+0x91/0xa4 [<c078c713>] sys_socketcall+0x8f/0x1a6 [<c0409ad0>] syscall_call+0x7/0xb dracut: Starting plymouth daemon blkfront: xvda: barriers enabled xvda: xvda1 xvda2 blkid used greatest stack depth: 5968 bytes left
I just upgraded the host to rawhide/f12, and booted 2.6.31-2.fc12.i686.PAE on baremetal. No backtrace on baremetal, so it only happens on Xen domU.
This is very confusing. It appears to be claiming that wait_queue_head_t->lock and entropy_store->lock are the same class, or that the __wake_up is trying to take the entropy_store lock. If this were really happening the kernel would lock up, so it appears the lock debug machinery is getting confused somehow. I don't understand why it would only get confused under Xen... I think its probably pulling in some of the lock debug people into this one.
Is this still a problem with the 2.6.31.1-56.fc12 kernels?
I just tried, and yes, it still happens with 2.6.31.1-56.fc12.i686.PAE: Reserving virtual address space above 0xf5800000 Initializing cgroup subsys cpuset Initializing cgroup subsys cpu Linux version 2.6.31.1-56.fc12.i686.PAE (mockbuild.phx.redhat.com) (gcc version 4.4.1 20090925 (Red Hat 4.4.1-17) (GCC) ) #1 SMP Tue Sep 29 16:16:16 EDT 2009 KERNEL supported cpus: Intel GenuineIntel AMD AuthenticAMD NSC Geode by NSC Cyrix CyrixInstead Centaur CentaurHauls Transmeta GenuineTMx86 Transmeta TransmetaCPU UMC UMC UMC UMC ACPI in unprivileged domain disabled BIOS-provided physical RAM map: Xen: 0000000000000000 - 00000000000a0000 (usable) Xen: 00000000000a0000 - 0000000000100000 (reserved) Xen: 0000000000100000 - 0000000020000000 (usable) DMI not present or invalid. last_pfn = 0x20000 max_arch_pfn = 0x1000000 initial memory mapped : 0 - 037ff000 init_memory_mapping: 0000000000000000-0000000020000000 Using x86 segment limits to approximate NX protection 0000000000 - 0020000000 page 4k kernel direct mapping tables up to 20000000 @ 100000-206000 RAMDISK: 0140d000 - 02dc7000 0MB HIGHMEM available. 512MB LOWMEM available. mapped low ram: 0 - 20000000 low ram: 0 - 20000000 node 0 low ram: 00000000 - 20000000 node 0 bootmap 00002000 - 00006000 (9 early reservations) ==> bootmem [0000000000 - 0020000000] #0 [0000000000 - 0000001000] BIOS data page ==> [0000000000 - 0000001000] #1 [0002e4a000 - 0002e64000] XEN PAGETABLES ==> [0002e4a000 - 0002e64000] #2 [0000001000 - 0000002000] EX TRAMPOLINE ==> [0000001000 - 0000002000] #3 [0000006000 - 0000007000] TRAMPOLINE ==> [0000006000 - 0000007000] #4 [0000400000 - 00012e7f4c] TEXT DATA BSS ==> [0000400000 - 00012e7f4c] #5 [000140d000 - 0002dc7000] RAMDISK ==> [000140d000 - 0002dc7000] #6 [0002dc7000 - 0002e4a000] XEN START INFO ==> [0002dc7000 - 0002e4a000] #7 [0000100000 - 00001e7000] PGTABLE ==> [0000100000 - 00001e7000] #8 [0000002000 - 0000006000] BOOTMAP ==> [0000002000 - 0000006000] Zone PFN ranges: DMA 0x00000000 -> 0x00001000 Normal 0x00001000 -> 0x00020000 HighMem 0x00020000 -> 0x00020000 Movable zone start PFN for each node early_node_map[2] active PFN ranges 0: 0x00000000 -> 0x000000a0 0: 0x00000100 -> 0x00020000 On node 0 totalpages: 130976 free_area_init_node: node 0, pgdat c0a8c120, node_mem_map c2e64000 DMA zone: 60 pages used for memmap DMA zone: 0 pages reserved DMA zone: 3940 pages, LIFO batch:0 Normal zone: 1860 pages used for memmap Normal zone: 125116 pages, LIFO batch:31 Using APIC driver default SMP: Allowing 1 CPUs, 0 hotplug CPUs Local APIC disabled by BIOS -- you can enable it with "lapic" APIC: disable apic facility nr_irqs_gsi: 16 PM: Registered nosave memory: 00000000000a0000 - 0000000000100000 Allocating PCI resources starting at 20000000 (gap: 20000000:e0000000) NR_CPUS:32 nr_cpumask_bits:32 nr_cpu_ids:1 nr_node_ids:1 PERCPU: Allocated 330 4k pages, static data 1349148 bytes trying to map vcpu_info 0 at e0801010, mfn 7e57c, offset 16 cpu 0 using vcpu_info at e0801010 Xen: using vcpu_info placement Built 1 zonelists in Zone order, mobility grouping on. Total pages: 129056 Kernel command line: ro root=/dev/mapper/vg_f12-lv_root rhgb quietLANG=en_US.UTF-8SYSFONT=latarcyrheb-sun16 KEYBOARDTYPE=pc KEYTABLE=fi SYSFONT=latarcyrheb-sun16 LANG=en_US.UTF-8 PID hash table entries: 2048 (order: 11, 8192 bytes) Dentry cache hash table entries: 65536 (order: 6, 262144 bytes) Inode-cache hash table entries: 32768 (order: 5, 131072 bytes) Enabling fast FPU save and restore... done. Enabling unmasked SIMD FPU exception support... done. Initializing CPU#0 allocated 2621440 bytes of page_cgroup please try 'cgroup_disable=memory' option if you don't want memory cgroups Initializing HighMem for node 0 (00000000:00000000) Memory: 468420k/524288k available (4356k kernel code, 55176k reserved, 2416k data, 1784k init, 0k highmem) virtual kernel memory layout: fixmap : 0xf52d5000 - 0xf57ff000 (5288 kB) pkmap : 0xf4e00000 - 0xf5000000 (2048 kB) vmalloc : 0xe0800000 - 0xf4dfe000 ( 325 MB) lowmem : 0xc0000000 - 0xe0000000 ( 512 MB) .init : 0xc0a9d000 - 0xc0c5b000 (1784 kB) .data : 0xc0841000 - 0xc0a9d000 (2416 kB) .text : 0xc0400000 - 0xc0841000 (4356 kB) SLUB: Genslabs=13, HWalign=128, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 Hierarchical RCU implementation. NR_IRQS:1280 Detected 3000.106 MHz processor. Console: colour dummy device 80x25 console [tty0] enabled console [hvc0] enabled Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar ... MAX_LOCKDEP_SUBCLASSES: 8 ... MAX_LOCK_DEPTH: 48 ... MAX_LOCKDEP_KEYS: 8191 ... CLASSHASH_SIZE: 4096 ... MAX_LOCKDEP_ENTRIES: 16384 ... MAX_LOCKDEP_CHAINS: 32768 ... CHAINHASH_SIZE: 16384 memory used by lock dependency info: 3743 kB per task-struct memory footprint: 1920 bytes ODEBUG: 9 of 9 active objects replaced Xen: using vcpuop timer interface installing Xen timer for CPU 0 Calibrating delay loop (skipped), value calculated using timer frequency.. 6000.21 BogoMIPS (lpj=3000106) Security Framework initialized SELinux: Initializing. SELinux: Starting in permissive mode Mount-cache hash table entries: 512 Initializing cgroup subsys ns Initializing cgroup subsys cpuacct Initializing cgroup subsys memory Initializing cgroup subsys devices Initializing cgroup subsys freezer Initializing cgroup subsys net_cls CPU: Trace cache: 12K uops, L1 D cache: 16K CPU: L2 cache: 1024K CPU: Unsupported number of siblings 2 Performance Counters: no PMU driver, software counters only. SMP alternatives: switching to UP code Freeing SMP alternatives: 14k freed ftrace: converting mcount calls to 0f 1f 44 00 00 ftrace: allocating 20799 entries in 41 pages Brought up 1 CPUs sizeof(vma)=88 bytes sizeof(page)=60 bytes sizeof(inode)=652 bytes sizeof(dentry)=164 bytes sizeof(ext3inode)=912 bytes sizeof(buffer_head)=56 bytes sizeof(skbuff)=192 bytes sizeof(task_struct)=5512 bytes CPU0 attaching NULL sched-domain. Booting paravirtualized kernel on Xen Xen version: 3.4.1 (preserve-AD) Grant table initialized regulator: core version 0.5 Time: 165:165:165 Date: 165/165/65 NET: Registered protocol family 16 PCI: Fatal: No config space access function found bio: create slab <bio-0> at 0 ACPI: Interpreter disabled. xen_balloon: Initialising balloon driver. vgaarb: loaded SCSI subsystem initialized libata version 3.00 loaded. usbcore: registered new interface driver usbfs usbcore: registered new interface driver hub usbcore: registered new device driver usb PCI: System does not support PCI PCI: System does not support PCI NetLabel: Initializing NetLabel: domain hash size = 128 NetLabel: protocols = UNLABELED CIPSOv4 NetLabel: unlabeled traffic allowed by default DMA-API: preallocated 32768 debug entries DMA-API: debugging enabled by kernel config Switched to high resolution mode on CPU 0 pnp: PnP ACPI: disabled NET: Registered protocol family 2 IP route cache hash table entries: 16384 (order: 4, 65536 bytes) TCP established hash table entries: 65536 (order: 7, 524288 bytes) TCP bind hash table entries: 65536 (order: 9, 2621440 bytes) TCP: Hash tables configured (established 65536 bind 65536) TCP reno registered NET: Registered protocol family 1 Trying to unpack rootfs image as initramfs... Freeing initrd memory: 26344k freed platform rtc_cmos: registered platform RTC device (no PNP device found) apm: BIOS not found. audit: initializing netlink socket (disabled) type=2000 audit(1255005238.043:1): initialized HugeTLB registered 2 MB page size, pre-allocated 0 pages VFS: Disk quotas dquot_6.5.2 Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) msgmni has been set to 1075 SELinux: Registering netfilter hooks cryptomgr_test used greatest stack depth: 6936 bytes left cryptomgr_test used greatest stack depth: 6920 bytes left cryptomgr_test used greatest stack depth: 6884 bytes left alg: No test for stdrng (krng) Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252) io scheduler noop registered io scheduler anticipatory registered io scheduler deadline registered io scheduler cfq registered (default) pci_hotplug: PCI Hot Plug PCI Core version: 0.5 pciehp: PCI Express Hot Plug Controller Driver version: 0.4 acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 Console: switching to colour frame buffer device 100x37 console [tty0] enabled isapnp: Write Data Register 0xa79 already used Non-volatile memory driver v1.3 Linux agpgart interface v0.103 Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled brd: module loaded loop: module loaded input: Macintosh mouse button emulation as /devices/virtual/input/input0 Fixed MDIO Bus: probed ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver uhci_hcd: USB Universal Host Controller Interface driver PNP: No PS/2 controller found. Probing ports directly. mice: PS/2 mouse device common for all mice input: Xen Virtual Keyboard as /devices/virtual/input/input1 input: Xen Virtual Pointer as /devices/virtual/input/input2 rtc_cmos: probe of rtc_cmos failed with error -16 device-mapper: uevent: version 1.0.3 device-mapper: ioctl: 4.15.0-ioctl (2009-04-01) initialised: dm-devel cpuidle: using governor ladder cpuidle: using governor menu usbcore: registered new interface driver hiddev usbcore: registered new interface driver usbhid usbhid: v2.6:USB HID core driver nf_conntrack version 0.5.0 (8192 buckets, 32768 max) CONFIG_NF_CT_ACCT is deprecated and will be removed soon. Please use nf_conntrack.acct=1 kernel parameter, acct=1 nf_conntrack module option or sysctl net.netfilter.nf_conntrack_acct=1 to enable it. ip_tables: (C) 2000-2006 Netfilter Core Team TCP cubic registered Initializing XFRM netlink socket NET: Registered protocol family 17 Using IPI No-Shortcut mode PM: Resume from disk failed. registered taskstats version 1 No TPM chip found, activating TPM-bypass! XENBUS: Device with no driver: device/console/0 XENBUS: Device with no driver: device/vbd/51712 XENBUS: Device with no driver: device/vif/0 Magic number: 1:252:3141 drivers/rtc/hctosys.c: unable to open rtc device (rtc0) Initalizing network drop monitor service Freeing unused kernel memory: 1784k freed NX-protecting the kernel data: c0841000, 3020 pages Write protecting the kernel text: 4356k Write protecting the kernel read-only data: 1800k mknod used greatest stack depth: 6472 bytes left mount used greatest stack depth: 6420 bytes left mount used greatest stack depth: 6212 bytes left mkdir used greatest stack depth: 6140 bytes left dracut: dracut-002-12.git8f397a9b.fc12 udev: starting version 145 ============================================= [ INFO: possible recursive locking detected ] 2.6.31.1-56.fc12.i686.PAE #1 --------------------------------------------- udevd/69 is trying to acquire lock: (&input_pool.lock){+.+...}, at: [<c043b3b0>] __wake_up+0x2b/0x61 but task is already holding lock: (&input_pool.lock){+.+...}, at: [<c068e66b>] account+0x30/0xf0 other info that might help us debug this: 2 locks held by udevd/69: #0: (nl_table_lock){.+.+..}, at: [<c07b54be>] netlink_table_grab+0x21/0xb8 #1: (&input_pool.lock){+.+...}, at: [<c068e66b>] account+0x30/0xf0 stack backtrace: Pid: 69, comm: udevd Not tainted 2.6.31.1-56.fc12.i686.PAE #1 Call Trace: [<c0839114>] ? printk+0x22/0x36 [<c0478c0d>] __lock_acquire+0x7e9/0xb25 [<c0479000>] lock_acquire+0xb7/0xeb [<c043b3b0>] ? __wake_up+0x2b/0x61 [<c043b3b0>] ? __wake_up+0x2b/0x61 [<c083be47>] _spin_lock_irqsave+0x45/0x89 [<c043b3b0>] ? __wake_up+0x2b/0x61 [<c043b3b0>] __wake_up+0x2b/0x61 [<c068e6f0>] account+0xb5/0xf0 [<c068e83f>] extract_entropy+0x3e/0xac [<c07b5cbc>] ? nl_pid_hash_zalloc+0x27/0x52 [<c068e9be>] get_random_bytes+0x29/0x3e [<c07b5eb7>] nl_pid_hash_rehash+0x71/0xed [<c07b5fcf>] netlink_insert+0x9c/0x123 [<c07b6100>] netlink_autobind+0xaa/0xce [<c07b6264>] netlink_bind+0x8d/0x164 [<c078c406>] sys_bind+0x7e/0xb4 [<c04762bd>] ? lock_release_holdtime+0x39/0x143 [<c0479806>] ? lock_release_non_nested+0xb6/0x1b5 [<c0406b0b>] ? xen_restore_fl_direct_end+0x0/0x1 [<c0479018>] ? lock_acquire+0xcf/0xeb [<c0406199>] ? xen_force_evtchn_callback+0x1d/0x34 [<c04df4d0>] ? might_fault+0x56/0xa4 [<c0406b14>] ? check_events+0x8/0xc [<c0406b0b>] ? xen_restore_fl_direct_end+0x0/0x1 [<c0479a8b>] ? lock_release+0x186/0x19f [<c04df50b>] ? might_fault+0x91/0xa4 [<c078cc43>] sys_socketcall+0x8f/0x1a6 [<c0409ad0>] syscall_call+0x7/0xb setfont used greatest stack depth: 6116 bytes left dracut: Starting plymouth daemon udevd used greatest stack depth: 5908 bytes left blkfront: xvda: barriers enabled xvda: xvda1 xvda2 dracut: Scanning devices xvda2 for LVM volume groups dracut: Reading all physical volumes. This may take a while... dracut: Found volume group "vg_f12" using metadata type lvm2 dracut: 2 logical volume(s) in volume group "vg_f12" now active EXT4-fs (dm-0): barriers enabled kjournald2 starting: pid 210, dev dm-0:8, commit interval 5 seconds EXT4-fs (dm-0): delayed allocation enabled EXT4-fs: file extents enabled EXT4-fs: mballoc enabled EXT4-fs (dm-0): mounted filesystem with ordered data mode dracut: Mounted root filesystem /dev/mapper/vg_f12-lv_root dracut: Loading SELinux policy type=1404 audit(1255005243.107:2): enforcing=1 old_enforcing=0 auid=4294967295 ses=4294967295 SELinux: 8192 avtab hash slots, 138606 rules. SELinux: 8192 avtab hash slots, 138606 rules. SELinux: 8 users, 12 roles, 2873 types, 129 bools, 1 sens, 1024 cats SELinux: 75 classes, 138606 rules SELinux: Completing initialization. SELinux: Setting up existing superblocks. SELinux: initialized (dev dm-0, type ext4), uses xattr SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs SELinux: initialized (dev securityfs, type securityfs), uses genfs_contexts SELinux: initialized (dev selinuxfs, type selinuxfs), uses genfs_contexts SELinux: initialized (dev mqueue, type mqueue), uses transition SIDs SELinux: initialized (dev hugetlbfs, type hugetlbfs), uses transition SIDs SELinux: initialized (dev devpts, type devpts), uses transition SIDs SELinux: initialized (dev inotifyfs, type inotifyfs), uses genfs_contexts SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs SELinux: initialized (dev anon_inodefs, type anon_inodefs), uses genfs_contexts SELinux: initialized (dev pipefs, type pipefs), uses task SIDs SELinux: initialized (dev debugfs, type debugfs), uses genfs_contexts SELinux: initialized (dev sockfs, type sockfs), uses task SIDs SELinux: initialized (dev proc, type proc), uses genfs_contexts SELinux: initialized (dev bdev, type bdev), uses genfs_contexts SELinux: initialized (dev rootfs, type rootfs), uses genfs_contexts SELinux: initialized (dev sysfs, type sysfs), uses genfs_contexts type=1403 audit(1255005244.816:3): policy loaded auid=4294967295 ses=4294967295 load_policy used greatest stack depth: 5488 bytes left dracut: Switching root SELinux: initialized (dev usbfs, type usbfs), uses genfs_contexts udev: starting version 145 Initialising Xen virtual ethernet driver. device-mapper: multipath: version 1.1.0 loaded EXT4-fs (dm-0): internal journal on dm-0:8 EXT4-fs (xvda1): barriers enabled kjournald2 starting: pid 491, dev xvda1:8, commit interval 5 seconds EXT4-fs (xvda1): internal journal on xvda1:8 EXT4-fs (xvda1): delayed allocation enabled EXT4-fs: file extents enabled EXT4-fs: mballoc enabled EXT4-fs (xvda1): mounted filesystem with ordered data mode SELinux: initialized (dev xvda1, type ext4), uses xattr SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs Adding 1179640k swap on /dev/mapper/vg_f12-lv_swap. Priority:-1 extents:1 across:1179640k SELinux: initialized (dev binfmt_misc, type binfmt_misc), uses genfs_contexts microcode: CPU0 sig=0xf34, pf=0x10, revision=0x14 platform microcode: firmware: requesting intel-ucode/0f-03-04 Microcode Update Driver: v2.00 <tigran.co.uk>, Peter Oruba microcode: CPU0 update to revision 0x17 failed Microcode Update Driver: v2.00 removed. vgs used greatest stack depth: 5484 bytes left NET: Registered protocol family 10 lo: Disabled Privacy Extensions RPC: Registered udp transport module. RPC: Registered tcp transport module. SELinux: initialized (dev rpc_pipefs, type rpc_pipefs), uses genfs_contexts Installing knfsd (copyright (C) 1996 okir.de). SELinux: initialized (dev nfsd, type nfsd), uses genfs_contexts NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory NFSD: starting 90-second grace period rpc.nfsd used greatest stack depth: 4928 bytes left eth0: no IPv6 routers present
Jeremy: Additional note.. this domU kernel recursive locking happens on the same old evil P4 with HyperThreading hardware that can very easily trigger the dom0 kernel CONFIG_HIGHPTE=y race.
Hm. The problem in this bug is that the report doesn't actually make sense. The two locks it mentions are quite distinct, so I don't know why its reporting them as a recursive lock attempt (if it were, the kernel would lock up solidly). Do the symptoms change if you disable HT?
domU is single vcpu. I just disabled HT from BIOS, and tried again. Here's dmesg from the domU. Reserving virtual address space above 0xf5800000 Initializing cgroup subsys cpuset Initializing cgroup subsys cpu Linux version 2.6.31.1-56.fc12.i686.PAE (mockbuild.phx.redhat.com) (gcc version 4.4.1 20090925 (Red Hat 4.4.1-17) (GCC) ) #1 SMP Tue Sep 29 16:16:16 EDT 2009 KERNEL supported cpus: Intel GenuineIntel AMD AuthenticAMD NSC Geode by NSC Cyrix CyrixInstead Centaur CentaurHauls Transmeta GenuineTMx86 Transmeta TransmetaCPU UMC UMC UMC UMC ACPI in unprivileged domain disabled BIOS-provided physical RAM map: Xen: 0000000000000000 - 00000000000a0000 (usable) Xen: 00000000000a0000 - 0000000000100000 (reserved) Xen: 0000000000100000 - 0000000020000000 (usable) DMI not present or invalid. last_pfn = 0x20000 max_arch_pfn = 0x1000000 initial memory mapped : 0 - 037ff000 init_memory_mapping: 0000000000000000-0000000020000000 Using x86 segment limits to approximate NX protection 0000000000 - 0020000000 page 4k kernel direct mapping tables up to 20000000 @ 100000-206000 RAMDISK: 0140d000 - 02dc7000 0MB HIGHMEM available. 512MB LOWMEM available. mapped low ram: 0 - 20000000 low ram: 0 - 20000000 node 0 low ram: 00000000 - 20000000 node 0 bootmap 00002000 - 00006000 (9 early reservations) ==> bootmem [0000000000 - 0020000000] #0 [0000000000 - 0000001000] BIOS data page ==> [0000000000 - 0000001000] #1 [0002e4a000 - 0002e64000] XEN PAGETABLES ==> [0002e4a000 - 0002e64000] #2 [0000001000 - 0000002000] EX TRAMPOLINE ==> [0000001000 - 0000002000] #3 [0000006000 - 0000007000] TRAMPOLINE ==> [0000006000 - 0000007000] #4 [0000400000 - 00012e7f4c] TEXT DATA BSS ==> [0000400000 - 00012e7f4c] #5 [000140d000 - 0002dc7000] RAMDISK ==> [000140d000 - 0002dc7000] #6 [0002dc7000 - 0002e4a000] XEN START INFO ==> [0002dc7000 - 0002e4a000] #7 [0000100000 - 00001e7000] PGTABLE ==> [0000100000 - 00001e7000] #8 [0000002000 - 0000006000] BOOTMAP ==> [0000002000 - 0000006000] Zone PFN ranges: DMA 0x00000000 -> 0x00001000 Normal 0x00001000 -> 0x00020000 HighMem 0x00020000 -> 0x00020000 Movable zone start PFN for each node early_node_map[2] active PFN ranges 0: 0x00000000 -> 0x000000a0 0: 0x00000100 -> 0x00020000 On node 0 totalpages: 130976 free_area_init_node: node 0, pgdat c0a8c120, node_mem_map c2e64000 DMA zone: 60 pages used for memmap DMA zone: 0 pages reserved DMA zone: 3940 pages, LIFO batch:0 Normal zone: 1860 pages used for memmap Normal zone: 125116 pages, LIFO batch:31 Using APIC driver default SMP: Allowing 1 CPUs, 0 hotplug CPUs Local APIC disabled by BIOS -- you can enable it with "lapic" APIC: disable apic facility nr_irqs_gsi: 16 PM: Registered nosave memory: 00000000000a0000 - 0000000000100000 Allocating PCI resources starting at 20000000 (gap: 20000000:e0000000) NR_CPUS:32 nr_cpumask_bits:32 nr_cpu_ids:1 nr_node_ids:1 PERCPU: Allocated 330 4k pages, static data 1349148 bytes trying to map vcpu_info 0 at e0801010, mfn 7d331, offset 16 cpu 0 using vcpu_info at e0801010 Xen: using vcpu_info placement Built 1 zonelists in Zone order, mobility grouping on. Total pages: 129056 Kernel command line: ro root=/dev/mapper/vg_f12-lv_root rhgb quietLANG=en_US.UTF-8SYSFONT=latarcyrheb-sun16 KEYBOARDTYPE=pc KEYTABLE=fi SYSFONT=latarcyrheb-sun16 LANG=en_US.UTF-8 PID hash table entries: 2048 (order: 11, 8192 bytes) Dentry cache hash table entries: 65536 (order: 6, 262144 bytes) Inode-cache hash table entries: 32768 (order: 5, 131072 bytes) Enabling fast FPU save and restore... done. Enabling unmasked SIMD FPU exception support... done. Initializing CPU#0 allocated 2621440 bytes of page_cgroup please try 'cgroup_disable=memory' option if you don't want memory cgroups Initializing HighMem for node 0 (00000000:00000000) Memory: 468420k/524288k available (4356k kernel code, 55176k reserved, 2416k data, 1784k init, 0k highmem) virtual kernel memory layout: fixmap : 0xf52d5000 - 0xf57ff000 (5288 kB) pkmap : 0xf4e00000 - 0xf5000000 (2048 kB) vmalloc : 0xe0800000 - 0xf4dfe000 ( 325 MB) lowmem : 0xc0000000 - 0xe0000000 ( 512 MB) .init : 0xc0a9d000 - 0xc0c5b000 (1784 kB) .data : 0xc0841000 - 0xc0a9d000 (2416 kB) .text : 0xc0400000 - 0xc0841000 (4356 kB) SLUB: Genslabs=13, HWalign=128, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 Hierarchical RCU implementation. NR_IRQS:1280 Detected 3000.106 MHz processor. Console: colour dummy device 80x25 console [tty0] enabled console [hvc0] enabled Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar ... MAX_LOCKDEP_SUBCLASSES: 8 ... MAX_LOCK_DEPTH: 48 ... MAX_LOCKDEP_KEYS: 8191 ... CLASSHASH_SIZE: 4096 ... MAX_LOCKDEP_ENTRIES: 16384 ... MAX_LOCKDEP_CHAINS: 32768 ... CHAINHASH_SIZE: 16384 memory used by lock dependency info: 3743 kB per task-struct memory footprint: 1920 bytes ODEBUG: 9 of 9 active objects replaced Xen: using vcpuop timer interface installing Xen timer for CPU 0 Calibrating delay loop (skipped), value calculated using timer frequency.. 6000.21 BogoMIPS (lpj=3000106) Security Framework initialized SELinux: Initializing. SELinux: Starting in permissive mode Mount-cache hash table entries: 512 Initializing cgroup subsys ns Initializing cgroup subsys cpuacct Initializing cgroup subsys memory Initializing cgroup subsys devices Initializing cgroup subsys freezer Initializing cgroup subsys net_cls CPU: Trace cache: 12K uops, L1 D cache: 16K CPU: L2 cache: 1024K CPU: Hyper-Threading is disabled Performance Counters: no PMU driver, software counters only. SMP alternatives: switching to UP code Freeing SMP alternatives: 14k freed ftrace: converting mcount calls to 0f 1f 44 00 00 ftrace: allocating 20799 entries in 41 pages Brought up 1 CPUs sizeof(vma)=88 bytes sizeof(page)=60 bytes sizeof(inode)=652 bytes sizeof(dentry)=164 bytes sizeof(ext3inode)=912 bytes sizeof(buffer_head)=56 bytes sizeof(skbuff)=192 bytes sizeof(task_struct)=5512 bytes CPU0 attaching NULL sched-domain. Booting paravirtualized kernel on Xen Xen version: 3.4.1 (preserve-AD) Grant table initialized regulator: core version 0.5 Time: 165:165:165 Date: 165/165/65 NET: Registered protocol family 16 PCI: Fatal: No config space access function found bio: create slab <bio-0> at 0 ACPI: Interpreter disabled. xen_balloon: Initialising balloon driver. vgaarb: loaded SCSI subsystem initialized libata version 3.00 loaded. usbcore: registered new interface driver usbfs usbcore: registered new interface driver hub usbcore: registered new device driver usb PCI: System does not support PCI PCI: System does not support PCI NetLabel: Initializing NetLabel: domain hash size = 128 NetLabel: protocols = UNLABELED CIPSOv4 NetLabel: unlabeled traffic allowed by default DMA-API: preallocated 32768 debug entries DMA-API: debugging enabled by kernel config Switched to high resolution mode on CPU 0 pnp: PnP ACPI: disabled NET: Registered protocol family 2 IP route cache hash table entries: 16384 (order: 4, 65536 bytes) TCP established hash table entries: 65536 (order: 7, 524288 bytes) TCP bind hash table entries: 65536 (order: 9, 2621440 bytes) TCP: Hash tables configured (established 65536 bind 65536) TCP reno registered NET: Registered protocol family 1 Trying to unpack rootfs image as initramfs... Freeing initrd memory: 26344k freed platform rtc_cmos: registered platform RTC device (no PNP device found) apm: BIOS not found. audit: initializing netlink socket (disabled) type=2000 audit(1255642859.566:1): initialized HugeTLB registered 2 MB page size, pre-allocated 0 pages VFS: Disk quotas dquot_6.5.2 Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) msgmni has been set to 1075 SELinux: Registering netfilter hooks cryptomgr_test used greatest stack depth: 6936 bytes left cryptomgr_test used greatest stack depth: 6920 bytes left cryptomgr_test used greatest stack depth: 6884 bytes left alg: No test for stdrng (krng) Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252) io scheduler noop registered io scheduler anticipatory registered io scheduler deadline registered io scheduler cfq registered (default) pci_hotplug: PCI Hot Plug PCI Core version: 0.5 pciehp: PCI Express Hot Plug Controller Driver version: 0.4 acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 Console: switching to colour frame buffer device 100x37 console [tty0] enabled isapnp: Write Data Register 0xa79 already used Non-volatile memory driver v1.3 Linux agpgart interface v0.103 Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled brd: module loaded loop: module loaded input: Macintosh mouse button emulation as /devices/virtual/input/input0 Fixed MDIO Bus: probed ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver uhci_hcd: USB Universal Host Controller Interface driver PNP: No PS/2 controller found. Probing ports directly. mice: PS/2 mouse device common for all mice input: Xen Virtual Keyboard as /devices/virtual/input/input1 input: Xen Virtual Pointer as /devices/virtual/input/input2 rtc_cmos: probe of rtc_cmos failed with error -16 device-mapper: uevent: version 1.0.3 device-mapper: ioctl: 4.15.0-ioctl (2009-04-01) initialised: dm-devel cpuidle: using governor ladder cpuidle: using governor menu usbcore: registered new interface driver hiddev usbcore: registered new interface driver usbhid usbhid: v2.6:USB HID core driver nf_conntrack version 0.5.0 (8192 buckets, 32768 max) CONFIG_NF_CT_ACCT is deprecated and will be removed soon. Please use nf_conntrack.acct=1 kernel parameter, acct=1 nf_conntrack module option or sysctl net.netfilter.nf_conntrack_acct=1 to enable it. ip_tables: (C) 2000-2006 Netfilter Core Team TCP cubic registered Initializing XFRM netlink socket NET: Registered protocol family 17 Using IPI No-Shortcut mode PM: Resume from disk failed. registered taskstats version 1 No TPM chip found, activating TPM-bypass! XENBUS: Device with no driver: device/vbd/51712 XENBUS: Device with no driver: device/vif/0 XENBUS: Device with no driver: device/console/0 Magic number: 1:252:3141 drivers/rtc/hctosys.c: unable to open rtc device (rtc0) Initalizing network drop monitor service Freeing unused kernel memory: 1784k freed NX-protecting the kernel data: c0841000, 3020 pages Write protecting the kernel text: 4356k Write protecting the kernel read-only data: 1800k mknod used greatest stack depth: 6444 bytes left mount used greatest stack depth: 6416 bytes left modprobe used greatest stack depth: 6396 bytes left mount used greatest stack depth: 6336 bytes left mount used greatest stack depth: 6284 bytes left mknod used greatest stack depth: 6272 bytes left mkdir used greatest stack depth: 6076 bytes left dracut: dracut-002-12.git8f397a9b.fc12 mkdir used greatest stack depth: 6060 bytes left udev: starting version 145 ============================================= [ INFO: possible recursive locking detected ] 2.6.31.1-56.fc12.i686.PAE #1 --------------------------------------------- udevd/69 is trying to acquire lock: (&input_pool.lock){+.+...}, at: [<c043b3b0>] __wake_up+0x2b/0x61 but task is already holding lock: (&input_pool.lock){+.+...}, at: [<c068e66b>] account+0x30/0xf0 other info that might help us debug this: 2 locks held by udevd/69: #0: (nl_table_lock){.+.+..}, at: [<c07b54be>] netlink_table_grab+0x21/0xb8 #1: (&input_pool.lock){+.+...}, at: [<c068e66b>] account+0x30/0xf0 stack backtrace: Pid: 69, comm: udevd Not tainted 2.6.31.1-56.fc12.i686.PAE #1 Call Trace: [<c0839114>] ? printk+0x22/0x36 [<c0478c0d>] __lock_acquire+0x7e9/0xb25 [<c0479000>] lock_acquire+0xb7/0xeb [<c043b3b0>] ? __wake_up+0x2b/0x61 [<c043b3b0>] ? __wake_up+0x2b/0x61 [<c083be47>] _spin_lock_irqsave+0x45/0x89 [<c043b3b0>] ? __wake_up+0x2b/0x61 [<c043b3b0>] __wake_up+0x2b/0x61 [<c068e6f0>] account+0xb5/0xf0 [<c068e83f>] extract_entropy+0x3e/0xac [<c07b5cbc>] ? nl_pid_hash_zalloc+0x27/0x52 [<c068e9be>] get_random_bytes+0x29/0x3e [<c07b5eb7>] nl_pid_hash_rehash+0x71/0xed [<c07b5fcf>] netlink_insert+0x9c/0x123 [<c07b6100>] netlink_autobind+0xaa/0xce [<c07b6264>] netlink_bind+0x8d/0x164 [<c078c406>] sys_bind+0x7e/0xb4 [<c04762bd>] ? lock_release_holdtime+0x39/0x143 [<c0479806>] ? lock_release_non_nested+0xb6/0x1b5 [<c0406b0b>] ? xen_restore_fl_direct_end+0x0/0x1 [<c0479018>] ? lock_acquire+0xcf/0xeb [<c0406199>] ? xen_force_evtchn_callback+0x1d/0x34 [<c04df4d0>] ? might_fault+0x56/0xa4 [<c0406b14>] ? check_events+0x8/0xc [<c0406b0b>] ? xen_restore_fl_direct_end+0x0/0x1 [<c0479a8b>] ? lock_release+0x186/0x19f [<c04df50b>] ? might_fault+0x91/0xa4 [<c078cc43>] sys_socketcall+0x8f/0x1a6 [<c0409ad0>] syscall_call+0x7/0xb dracut: Starting plymouth daemon udevd used greatest stack depth: 5908 bytes left blkfront: xvda: barriers enabled xvda: xvda1 xvda2 dracut: Scanning devices xvda2 for LVM volume groups dracut: Reading all physical volumes. This may take a while... dracut: Found volume group "vg_f12" using metadata type lvm2 dracut: 2 logical volume(s) in volume group "vg_f12" now active EXT4-fs (dm-0): barriers enabled kjournald2 starting: pid 203, dev dm-0:8, commit interval 5 seconds EXT4-fs (dm-0): delayed allocation enabled EXT4-fs: file extents enabled EXT4-fs: mballoc enabled EXT4-fs (dm-0): mounted filesystem with ordered data mode mount used greatest stack depth: 5840 bytes left dracut: Mounted root filesystem /dev/mapper/vg_f12-lv_root dracut: Loading SELinux policy type=1404 audit(1255642864.658:2): enforcing=1 old_enforcing=0 auid=4294967295 ses=4294967295 SELinux: 8192 avtab hash slots, 138606 rules. SELinux: 8192 avtab hash slots, 138606 rules. SELinux: 8 users, 12 roles, 2873 types, 129 bools, 1 sens, 1024 cats SELinux: 75 classes, 138606 rules SELinux: Completing initialization. SELinux: Setting up existing superblocks. SELinux: initialized (dev dm-0, type ext4), uses xattr SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs SELinux: initialized (dev securityfs, type securityfs), uses genfs_contexts SELinux: initialized (dev selinuxfs, type selinuxfs), uses genfs_contexts SELinux: initialized (dev mqueue, type mqueue), uses transition SIDs SELinux: initialized (dev hugetlbfs, type hugetlbfs), uses transition SIDs SELinux: initialized (dev devpts, type devpts), uses transition SIDs SELinux: initialized (dev inotifyfs, type inotifyfs), uses genfs_contexts SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs SELinux: initialized (dev anon_inodefs, type anon_inodefs), uses genfs_contexts SELinux: initialized (dev pipefs, type pipefs), uses task SIDs SELinux: initialized (dev debugfs, type debugfs), uses genfs_contexts SELinux: initialized (dev sockfs, type sockfs), uses task SIDs SELinux: initialized (dev proc, type proc), uses genfs_contexts SELinux: initialized (dev bdev, type bdev), uses genfs_contexts SELinux: initialized (dev rootfs, type rootfs), uses genfs_contexts SELinux: initialized (dev sysfs, type sysfs), uses genfs_contexts type=1403 audit(1255642866.398:3): policy loaded auid=4294967295 ses=4294967295 load_policy used greatest stack depth: 5736 bytes left dracut: Switching root SELinux: initialized (dev usbfs, type usbfs), uses genfs_contexts mount used greatest stack depth: 5552 bytes left udev: starting version 145 Initialising Xen virtual ethernet driver. ip used greatest stack depth: 5528 bytes left device-mapper: multipath: version 1.1.0 loaded EXT4-fs (dm-0): internal journal on dm-0:8 EXT4-fs (xvda1): barriers enabled kjournald2 starting: pid 503, dev xvda1:8, commit interval 5 seconds EXT4-fs (xvda1): internal journal on xvda1:8 EXT4-fs (xvda1): delayed allocation enabled EXT4-fs: file extents enabled EXT4-fs: mballoc enabled EXT4-fs (xvda1): mounted filesystem with ordered data mode SELinux: initialized (dev xvda1, type ext4), uses xattr SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs Adding 1179640k swap on /dev/mapper/vg_f12-lv_swap. Priority:-1 extents:1 across:1179640k SELinux: initialized (dev binfmt_misc, type binfmt_misc), uses genfs_contexts microcode: CPU0 sig=0xf34, pf=0x10, revision=0x14 platform microcode: firmware: requesting intel-ucode/0f-03-04 Microcode Update Driver: v2.00 <tigran.co.uk>, Peter Oruba microcode: CPU0 update to revision 0x17 failed Microcode Update Driver: v2.00 removed. vgs used greatest stack depth: 5408 bytes left NET: Registered protocol family 10 lo: Disabled Privacy Extensions RPC: Registered udp transport module. RPC: Registered tcp transport module. SELinux: initialized (dev rpc_pipefs, type rpc_pipefs), uses genfs_contexts Installing knfsd (copyright (C) 1996 okir.de). SELinux: initialized (dev nfsd, type nfsd), uses genfs_contexts NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory NFSD: starting 90-second grace period rpc.nfsd used greatest stack depth: 4928 bytes left eth0: no IPv6 routers present
I just tried the latest F12 kernel 2.6.31.5-127.fc12.i686.PAE, and it fixes the problem! 2.6.31.1-56.fc12.i686.PAE gives the locking backtrace, but 2.6.31.5-127.fc12.i686.PAE works OK. Not sure which kernel actually fixed the problem, but the latest kernel works for me now.
Thanks for the update. I could never get to the bottom of it; it really didn't look like a Xen problem.
Thanks Pasi! Closing out this bug