Bug 521800

Summary: kernel backtrace: possible recursive locking detected on Xen domU
Product: [Fedora] Fedora Reporter: Pasi Karkkainen <pasik>
Component: kernelAssignee: Justin M. Forbes <jforbes>
Status: CLOSED CURRENTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: rawhideCC: atodorov, clalance, drjones, itamar, jeremy, jforbes, kernel-maint, markmc, virt-maint
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: 2.6.31.5-127.fc12.i686.PAE Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 523121 (view as bug list) Environment:
Last Closed: 2009-11-19 05:49:43 EST Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Bug Depends On:    
Bug Blocks: 498969, 523121    

Description Pasi Karkkainen 2009-09-08 07:40:13 EDT
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  

-------
Comment 1 Jeremy Fitzhardinge 2009-09-11 13:03:14 EDT
Does this happen on native?  At first glance, I don't see anything Xen-specific there.
Comment 2 Jeremy Fitzhardinge 2009-09-11 13:04:07 EDT
Does this kernel have CONFIG_PARAVIRT_SPINLOCKS enabled?
Comment 3 Justin M. Forbes 2009-09-11 17:01:38 EDT
No, CONFIG_PARAVIRT_SPINLOCKS is not set.
Comment 4 Pasi Karkkainen 2009-09-13 07:10:46 EDT
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
Comment 5 Pasi Karkkainen 2009-09-13 11:07:27 EDT
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.
Comment 6 Jeremy Fitzhardinge 2009-09-15 18:43:53 EDT
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.
Comment 7 Justin M. Forbes 2009-10-06 17:06:58 EDT
Is this still a problem with the 2.6.31.1-56.fc12 kernels?
Comment 8 Pasi Karkkainen 2009-10-08 05:33:51 EDT
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@x86-4.fedora.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@redhat.com
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@aivazian.fsnet.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@monad.swb.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
Comment 9 Pasi Karkkainen 2009-10-09 03:29:07 EDT
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.
Comment 10 Jeremy Fitzhardinge 2009-10-15 14:13:53 EDT
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?
Comment 11 Pasi Karkkainen 2009-10-15 14:40:43 EDT
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@x86-4.fedora.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@redhat.com
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@aivazian.fsnet.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@monad.swb.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
Comment 12 Pasi Karkkainen 2009-11-15 10:52:58 EST
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.
Comment 13 Jeremy Fitzhardinge 2009-11-16 13:54:38 EST
Thanks for the update.  I could never get to the bottom of it; it really didn't look like a Xen problem.
Comment 14 Mark McLoughlin 2009-11-19 05:49:43 EST
Thanks Pasi! Closing out this bug