cpuspeed lock dependency problem FC6 test1

Andrew Gray andrewg at linnetsol.co.uk
Thu Jul 20 10:44:57 UTC 2006


AMD Athlon 64 Moblie 3400+ 
powernow-k8: Found 1 AMD Athlon(tm) 64 Processor 3400+ processors
(version 2.00.00)
powernow-k8:    0 : fid 0xc (2000 MHz), vid 0x6
powernow-k8:    1 : fid 0xa (1800 MHz), vid 0xa
powernow-k8:    2 : fid 0x0 (800 MHz), vid 0x1

Kernel 2.6.17-1.2416.FC6.x86_64 SMP
cupspeed-1.2.1-1.36.fc6.1 

On booting and in dmesg the following lock dependency is reported:-

=======================================================
[ INFO: possible circular locking dependency detected ]
-------------------------------------------------------
cpuspeed/1506 is trying to acquire lock:
 (&policy->lock){--..}, at: [<ffffffff80265ddf>] mutex_lock+0x2a/0x2e

but task is already holding lock:
 (cpucontrol){--..}, at: [<ffffffff80265ddf>] mutex_lock+0x2a/0x2e

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (cpucontrol){--..}:
       [<ffffffff802a8302>] lock_acquire+0x4a/0x69
       [<ffffffff80265c38>] __mutex_lock_slowpath+0xe4/0x261
       [<ffffffff80265dde>] mutex_lock+0x29/0x2e
       [<ffffffff802ab5bb>] __lock_cpu_hotplug+0x3c/0x5f
       [<ffffffff802ab5f8>] lock_cpu_hotplug+0xa/0xd
       [<ffffffff8040e88f>] __cpufreq_driver_target+0x1a/0x82
       [<ffffffff8040fb51>] cpufreq_governor_userspace+0x1e9/0x22c
       [<ffffffff8040e248>] __cpufreq_governor+0x74/0x107
       [<ffffffff8040e4b0>] __cpufreq_set_policy+0x1d5/0x1e7
       [<ffffffff8040e4fd>] cpufreq_set_policy+0x3b/0x96
       [<ffffffff8040f0d9>] cpufreq_add_dev+0x3ac/0x57b
       [<ffffffff803b2cd4>] sysdev_driver_register+0x7b/0xdc
       [<ffffffff8040e0f4>] cpufreq_register_driver+0xc1/0x1a1
       [<ffffffff8027d765>] powernowk8_init+0x7e/0x88
       [<ffffffff8026d2ac>] init+0x1fc/0x3cd
       [<ffffffff80260e9d>] child_rip+0x7/0x12

-> #1 (userspace_mutex){--..}:
       [<ffffffff802a8302>] lock_acquire+0x4a/0x69
       [<ffffffff80265c38>] __mutex_lock_slowpath+0xe4/0x261
       [<ffffffff80265dde>] mutex_lock+0x29/0x2e
       [<ffffffff8040f9cd>] cpufreq_governor_userspace+0x65/0x22c
       [<ffffffff8040e248>] __cpufreq_governor+0x74/0x107
       [<ffffffff8040e44f>] __cpufreq_set_policy+0x174/0x1e7
       [<ffffffff8040e4fd>] cpufreq_set_policy+0x3b/0x96
       [<ffffffff8040f0d9>] cpufreq_add_dev+0x3ac/0x57b
       [<ffffffff803b2cd4>] sysdev_driver_register+0x7b/0xdc
       [<ffffffff8040e0f4>] cpufreq_register_driver+0xc1/0x1a1
       [<ffffffff8027d765>] powernowk8_init+0x7e/0x88
       [<ffffffff8026d2ac>] init+0x1fc/0x3cd
       [<ffffffff80260e9d>] child_rip+0x7/0x12

-> #0 (&policy->lock){--..}:
       [<ffffffff802a8302>] lock_acquire+0x4a/0x69
       [<ffffffff80265c38>] __mutex_lock_slowpath+0xe4/0x261
       [<ffffffff80265dde>] mutex_lock+0x29/0x2e
       [<ffffffff8040e6a6>] store_scaling_governor+0x14e/0x19c
       [<ffffffff80274fb3>] store+0x4b/0x66
       [<ffffffff80309b18>] sysfs_write_file+0xd0/0x103
       [<ffffffff80217147>] vfs_write+0xce/0x175
       [<ffffffff80217a2f>] sys_write+0x46/0x70
       [<ffffffff8025ff4d>] system_call+0x7d/0x83

other info that might help us debug this:

1 lock held by cpuspeed/1506:
 #0:  (cpucontrol){--..}, at: [<ffffffff80265ddf>] mutex_lock+0x2a/0x2e

stack backtrace:

Call Trace:
 [<ffffffff8026e2a9>] show_trace+0xaa/0x23d
 [<ffffffff8026e451>] dump_stack+0x15/0x17
 [<ffffffff802a655c>] print_circular_bug_tail+0x6c/0x77
 [<ffffffff802a7b61>] __lock_acquire+0x853/0xa54
 [<ffffffff802a8303>] lock_acquire+0x4b/0x69
 [<ffffffff80265c39>] __mutex_lock_slowpath+0xe5/0x261
 [<ffffffff80265ddf>] mutex_lock+0x2a/0x2e
 [<ffffffff8040e6a7>] store_scaling_governor+0x14f/0x19c
 [<ffffffff80274fb4>] store+0x4c/0x66
 [<ffffffff80309b19>] sysfs_write_file+0xd1/0x103
 [<ffffffff80217148>] vfs_write+0xcf/0x175
 [<ffffffff80217a30>] sys_write+0x47/0x70
 [<ffffffff8025ff4e>] system_call+0x7e/0x83


Otherwise once booted cpuspeed seen to work and dynamically control the
Athlon 64 M 3400+ 

The full dmesg output is also attached.


Hope this helps in debugging.

Keep up the good work. 

--Andrew Gray
-------------- next part --------------
Bootdata ok (command line is ro root=/dev/VolGroup00/LogVol00 rhgb 3)
Linux version 2.6.17-1.2416.fc6 (brewbuilder at hs20-bc2-3.build.redhat.com) (gcc version 4.1.1 20060711 (Red Hat 4.1.1-8)) #1 SMP Tue Jul 18 17:25:28 EDT 2006
BIOS-provided physical RAM map:
 BIOS-e820: 0000000000000000 - 000000000009f800 (usable)
 BIOS-e820: 000000000009f800 - 00000000000a0000 (reserved)
 BIOS-e820: 00000000000d8000 - 0000000000100000 (reserved)
 BIOS-e820: 0000000000100000 - 000000003bf70000 (usable)
 BIOS-e820: 000000003bf70000 - 000000003bf7a000 (ACPI data)
 BIOS-e820: 000000003bf7a000 - 000000003bf80000 (ACPI NVS)
 BIOS-e820: 000000003bf80000 - 0000000040000000 (reserved)
 BIOS-e820: 00000000fffe0000 - 0000000100000000 (reserved)
DMI present.
ACPI: RSDP (v000 PTLTD                                 ) @ 0x00000000000f68d0
ACPI: RSDT (v001 PTLTD    RSDT   0x06040000  LTP 0x00000000) @ 0x000000003bf75fea
ACPI: FADT (v001 AMDK8  PTLTW    0x06040000 PTL_ 0x000f4240) @ 0x000000003bf79e66
ACPI: SSDT (v001 PTLTD  POWERNOW 0x06040000  LTP 0x00000001) @ 0x000000003bf79eda
ACPI: MADT (v001 PTLTD  	 APIC   0x06040000  LTP 0x00000000) @ 0x000000003bf79fb0
ACPI: DSDT (v001  VIA   PTL_ACPI 0x06040000 MSFT 0x0100000e) @ 0x0000000000000000
Scanning NUMA topology in Northbridge 24
Number of nodes 1
Node 0 MemBase 0000000000000000 Limit 000000003bf70000
NUMA: Using 63 for the hash shift.
Using node hash shift of 63
Bootmem setup node 0 0000000000000000-000000003bf70000
On node 0 totalpages: 238028
  DMA zone: 1696 pages, LIFO batch:0
  DMA32 zone: 236332 pages, LIFO batch:31
ACPI: PM-Timer IO Port: 0x4008
ACPI: Local APIC address 0xfee00000
ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
Processor #0 15:4 APIC version 16
ACPI: LAPIC_NMI (acpi_id[0x00] high edge lint[0x1])
ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
IOAPIC[0]: apic_id 1, version 3, address 0xfec00000, GSI 0-23
ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 high edge)
ACPI: IRQ0 used by override.
ACPI: IRQ2 used by override.
ACPI: IRQ10 used by override.
Setting APIC routing to physical flat
Using ACPI (MADT) for SMP configuration information
Allocating PCI resources starting at 50000000 (gap: 40000000:bffe0000)
SMP: Allowing 1 CPUs, 0 hotplug CPUs
Built 1 zonelists.  Total pages: 238028
Kernel command line: ro root=/dev/VolGroup00/LogVol00 rhgb 3
Initializing CPU#0
PID hash table entries: 4096 (order: 12, 32768 bytes)
time.c: Using 3.579545 MHz WALL PM GTOD PIT/TSC timer.
time.c: Detected 2004.613 MHz processor.
Console: colour VGA+ 80x25
Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
... MAX_LOCKDEP_SUBCLASSES:    8
... MAX_LOCK_DEPTH:          30
... MAX_LOCKDEP_KEYS:        2048
... CLASSHASH_SIZE:           1024
... MAX_LOCKDEP_ENTRIES:     8192
... MAX_LOCKDEP_CHAINS:      8192
... CHAINHASH_SIZE:          4096
 memory used by lock dependency info: 1120 kB
 per task-struct memory footprint: 1680 bytes
Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes)
Inode-cache hash table entries: 65536 (order: 7, 524288 bytes)
Checking aperture...
CPU 0: aperture @ e0000000 size 256 MB
Memory: 946880k/982464k available (2472k kernel code, 35196k reserved, 2043k data, 208k init)
Calibrating delay using timer specific routine.. 4014.51 BogoMIPS (lpj=8029026)
Security Framework v1.0.0 initialized
SELinux:  Initializing.
SELinux:  Starting in permissive mode
selinux_register_security:  Registering secondary module capability
Capability LSM initialized as secondary
Mount-cache hash table entries: 256
CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line)
CPU: L2 Cache: 1024K (64 bytes/line)
CPU 0/0 -> Node 0
SMP alternatives: switching to UP code
Freeing SMP alternatives: 28k freed
ACPI: Core revision 20060707
Using local APIC timer interrupts.
result 12528848
Detected 12.528 MHz APIC timer.
Brought up 1 CPUs
testing NMI watchdog ... OK.
sizeof(vma)=176 bytes
sizeof(page)=88 bytes
sizeof(inode)=1008 bytes
sizeof(dentry)=256 bytes
sizeof(ext3inode)=1376 bytes
sizeof(buffer_head)=96 bytes
sizeof(skbuff)=240 bytes
checking if image is initramfs... it is
Freeing initrd memory: 2032k freed
PM: Adding info for No Bus:platform
NET: Registered protocol family 16
ACPI: bus type pci registered
PCI: Using configuration type 1
ACPI: Interpreter enabled
ACPI: Using IOAPIC for interrupt routing
PM: Adding info for acpi:acpi
ACPI: PCI Root Bridge [PCI0] (0000:00)
PCI: Probing PCI hardware (bus 00)
PM: Adding info for No Bus:pci0000:00
PCI quirk: region 4000-407f claimed by vt8235 PM
PCI quirk: region 8100-810f claimed by vt8235 SMB
Boot video device is 0000:01:00.0
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
PM: Adding info for pci:0000:00:00.0
PM: Adding info for pci:0000:00:00.1
PM: Adding info for pci:0000:00:00.2
PM: Adding info for pci:0000:00:00.3
PM: Adding info for pci:0000:00:00.4
PM: Adding info for pci:0000:00:00.7
PM: Adding info for pci:0000:00:01.0
PM: Adding info for pci:0000:00:05.0
PM: Adding info for pci:0000:00:08.0
PM: Adding info for pci:0000:00:0c.0
PM: Adding info for pci:0000:00:0e.0
PM: Adding info for pci:0000:00:0e.1
PM: Adding info for pci:0000:00:10.0
PM: Adding info for pci:0000:00:10.1
PM: Adding info for pci:0000:00:10.2
PM: Adding info for pci:0000:00:10.3
PM: Adding info for pci:0000:00:11.0
PM: Adding info for pci:0000:00:11.1
PM: Adding info for pci:0000:00:11.5
PM: Adding info for pci:0000:00:11.6
PM: Adding info for pci:0000:00:18.0
PM: Adding info for pci:0000:00:18.1
PM: Adding info for pci:0000:00:18.2
PM: Adding info for pci:0000:00:18.3
PM: Adding info for pci:0000:01:00.0
ACPI: PCI Interrupt Link [ALKA] (IRQs 16 17 18 19 20 21 22 23) *9, disabled.
ACPI: PCI Interrupt Link [ALKB] (IRQs 16 17 18 19 20 21 22 23) *11, disabled.
ACPI: PCI Interrupt Link [ALKC] (IRQs 22) *10, disabled.
ACPI: PCI Interrupt Link [ALKD] (IRQs 21) *5, disabled.
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 7 *9 12 14 15)
ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 7 10 12 14 15) *11
ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 7 11 12 14 15) *10
ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 *5 7 9 10 11 12 14 15)
ACPI: Embedded Controller [EC] (gpe 11) interrupt mode.
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI init
PM: Adding info for No Bus:pnp0
PM: Adding info for pnp:00:00
PM: Adding info for pnp:00:01
PM: Adding info for pnp:00:02
PM: Adding info for pnp:00:03
PM: Adding info for pnp:00:04
PM: Adding info for pnp:00:05
PM: Adding info for pnp:00:06
PM: Adding info for pnp:00:07
PM: Adding info for pnp:00:08
PM: Adding info for pnp:00:09
PM: Adding info for pnp:00:0a
pnp: PnP ACPI: found 11 devices
usbcore: registered new driver usbfs
usbcore: registered new driver hub
PCI: Using ACPI for IRQ routing
PCI: If a device doesn't work, try "pci=routeirq".  If it helps, post a report
agpgart: Detected AGP bridge 0
agpgart: AGP aperture is 256M @ 0xe0000000
PCI-DMA: Disabling IOMMU.
pnp: 00:06: ioport range 0x4d0-0x4d1 has been reserved
pnp: 00:06: ioport range 0xfe10-0xfe11 could not be reserved
pnp: 00:06: ioport range 0xfe00-0xfe00 has been reserved
pnp: 00:06: ioport range 0x4000-0x407f could not be reserved
pnp: 00:06: ioport range 0x8100-0x811f could not be reserved
PCI: Failed to allocate mem resource #6:10000 at f4000000 for 0000:01:00.0
PCI: Bridge: 0000:00:01.0
  IO window: disabled.
  MEM window: d1000000-d1ffffff
  PREFETCH window: f0000000-f3ffffff
PCI: Bus 2, cardbus bridge: 0000:00:0c.0
  IO window: 00002000-000020ff
  IO window: 00002400-000024ff
  PREFETCH window: 50000000-51ffffff
  MEM window: 52000000-53ffffff
PCI: Setting latency timer of device 0000:00:01.0 to 64
PCI: Enabling device 0000:00:0c.0 (0000 -> 0003)
GSI 16 sharing vector 0xA9 and IRQ 16
ACPI: PCI Interrupt 0000:00:0c.0[A] -> GSI 16 (level, low) -> IRQ 169
PCI: Setting latency timer of device 0000:00:0c.0 to 64
NET: Registered protocol family 2
IP route cache hash table entries: 32768 (order: 6, 262144 bytes)
TCP established hash table entries: 65536 (order: 9, 3670016 bytes)
TCP bind hash table entries: 32768 (order: 8, 1835008 bytes)
TCP: Hash tables configured (established 65536 bind 32768)
TCP reno registered
PM: Adding info for platform:pcspkr
audit: initializing netlink socket (disabled)
audit(1153394587.692:1): initialized
Total HugeTLB memory allocated, 0
VFS: Disk quotas dquot_6.5.1
Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
SELinux:  Registering netfilter hooks
Initializing Cryptographic API
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
PM: Adding info for platform:vesafb.0
ACPI: CPU0 (power states: C1[C1] C2[C2])
ACPI Exception (acpi_thermal-0412): AE_NOT_FOUND, Invalid active threshold [0] [20060707]
ACPI: Thermal Zone [THRM] (53 C)
Real Time Clock Driver v1.12ac
Non-volatile memory driver v1.2
Linux agpgart interface v0.101 (c) Dave Jones
Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
PM: Adding info for platform:serial8250
serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
00:09: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
RAMDISK driver initialized: 16 RAM disks of 16384K size 4096 blocksize
Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
VP_IDE: IDE controller at PCI slot 0000:00:11.1
ACPI: PCI Interrupt Link [ALKA] disabled and referenced, BIOS bug
ACPI: PCI Interrupt Link [ALKA] BIOS reported IRQ 0, using IRQ 23
ACPI: PCI Interrupt Link [ALKA] enabled at IRQ 23
GSI 17 sharing vector 0xB1 and IRQ 17
ACPI: PCI Interrupt 0000:00:11.1[A] -> Link [ALKA] -> GSI 23 (level, low) -> IRQ 177
PCI: VIA IRQ fixup for 0000:00:11.1, from 0 to 1
VP_IDE: chipset revision 6
VP_IDE: not 100% native mode: will probe irqs later
VP_IDE: VIA vt8235 (rev 00) IDE UDMA133 controller on pci0000:00:11.1
    ide0: BM-DMA at 0x1c60-0x1c67, BIOS settings: hda:DMA, hdb:pio
    ide1: BM-DMA at 0x1c68-0x1c6f, BIOS settings: hdc:DMA, hdd:pio
Probing IDE interface ide0...
hda: HTS541080G9AT00, ATA DISK drive
PM: Adding info for No Bus:ide0
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
PM: Adding info for ide:0.0
Probing IDE interface ide1...
hdc: SONY DVD RW DW-D56A, ATAPI CD/DVD-ROM drive
PM: Adding info for No Bus:ide1
ide1 at 0x170-0x177,0x376 on irq 15
PM: Adding info for ide:1.0
hda: max request size: 512KiB
hda: 156301488 sectors (80026 MB) w/7539KiB Cache, CHS=16383/255/63, UDMA(100)
hda: cache flushes supported
 hda: hda1 hda2 hda3
ide-floppy driver 0.99.newide
Yenta: CardBus bridge found at 0000:00:0c.0 [1558:4702]
Yenta: Using CSCINT to route CSC interrupts to PCI
Yenta: Routing CardBus interrupts to PCI
Yenta TI: socket 0000:00:0c.0, mfunc 0x00001002, devctl 0x44
Yenta: ISA IRQ mask 0x0a40, PCI irq 169
Socket status: 30000006
usbcore: registered new driver libusual
usbcore: registered new driver hiddev
usbcore: registered new driver usbhid
drivers/usb/input/hid-core.c: v2.6:USB HID core driver
PNP: PS/2 Controller [PNP0303:PS2K,PNP0f13:PS2M] at 0x60,0x64 irq 1,12
PM: Adding info for platform:i8042
i8042.c: Detected active multiplexing controller, rev 1.1.
serio: i8042 AUX0 port at 0x60,0x64 irq 12
serio: i8042 AUX1 port at 0x60,0x64 irq 12
serio: i8042 AUX2 port at 0x60,0x64 irq 12
serio: i8042 AUX3 port at 0x60,0x64 irq 12
serio: i8042 KBD port at 0x60,0x64 irq 1
PM: Adding info for serio:serio0
mice: PS/2 mouse device common for all mice
md: md driver 0.90.3 MAX_MD_DEVS=256, MD_SB_DISKS=27
md: bitmap version 4.39
TCP bic registered
Initializing IPsec netlink socket
NET: Registered protocol family 1
NET: Registered protocol family 17
PM: Adding info for serio:serio1
powernow-k8: Found 1 AMD Athlon(tm) 64 Processor 3400+ processors (version 2.00.00)
powernow-k8:    0 : fid 0xc (2000 MHz), vid 0x6
powernow-k8:    1 : fid 0xa (1800 MHz), vid 0xa
powernow-k8:    2 : fid 0x0 (800 MHz), vid 0x12
PM: Adding info for serio:serio2
PM: Adding info for serio:serio3
ACPI: (supports S0 S3 S4 S5)
Freeing unused kernel memory: 208k freed
Write protecting the kernel read-only data: 469k
PM: Adding info for serio:serio4
input: AT Translated Set 2 keyboard as /class/input/input0
device-mapper: ioctl: 4.7.0-ioctl (2006-06-24) initialised: dm-devel at redhat.com
input: PS/2 Mouse as /class/input/input1
input: AlpsPS/2 ALPS GlidePoint as /class/input/input2
kjournald starting.  Commit interval 5 seconds
EXT3-fs: mounted filesystem with ordered data mode.
security:  3 users, 6 roles, 1467 types, 157 bools, 1 sens, 256 cats
security:  58 classes, 43317 rules
SELinux:  Completing initialization.
SELinux:  Setting up existing superblocks.
SELinux: initialized (dev dm-0, type ext3), uses xattr
SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
SELinux: initialized (dev debugfs, type debugfs), 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 genfs_contexts
SELinux: initialized (dev devpts, type devpts), uses transition SIDs
SELinux: initialized (dev eventpollfs, type eventpollfs), uses task SIDs
SELinux: initialized (dev inotifyfs, type inotifyfs), uses genfs_contexts
SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
SELinux: initialized (dev futexfs, type futexfs), uses genfs_contexts
SELinux: initialized (dev pipefs, type pipefs), uses task SIDs
SELinux: initialized (dev sockfs, type sockfs), uses task SIDs
SELinux: initialized (dev cpuset, type cpuset), not configured for labeling
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
audit(1153394593.292:2): policy loaded auid=4294967295
audit(1153394593.292:3): avc:  granted  { load_policy } for  pid=1 comm="init" scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:security_t:s0 tclass=security
SELinux: initialized (dev usbfs, type usbfs), uses genfs_contexts
ieee80211_crypt: registered algorithm 'NULL'
ieee80211: 802.11 data/management/control stack, git-1.1.13
ieee80211: Copyright (C) 2004-2005 Intel Corporation <jketreno at linux.intel.com>
ipw2200: Intel(R) PRO/Wireless 2200/2915 Network Driver, 1.1.2kmprq
ipw2200: Copyright(c) 2003-2006 Intel Corporation
PCI: Enabling device 0000:00:05.0 (0000 -> 0002)
ACPI: PCI Interrupt 0000:00:05.0[A] -> GSI 16 (level, low) -> IRQ 169
PCI: Setting latency timer of device 0000:00:05.0 to 64
ipw2200: Detected Intel PRO/Wireless 2200BG Network Connection
input: PC Speaker as /class/input/input3
hdc: ATAPI 24X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(33)
Uniform CD-ROM driver Revision: 3.20
8139too Fast Ethernet driver 0.9.27
NET: Registered protocol family 23
USB Universal Host Controller Interface driver v3.0
ipw2200: ipw2200-bss.fw request_firmware failed: Reason -2
ipw2200: Unable to load firmware: -2
ipw2200: failed to register network device
ACPI: PCI interrupt for device 0000:00:05.0 disabled
ipw2200: probe of 0000:00:05.0 failed with error -5
ACPI: PCI Interrupt Link [ALKD] disabled and referenced, BIOS bug
ACPI: PCI Interrupt Link [ALKD] BIOS reported IRQ 0, using IRQ 21
ACPI: PCI Interrupt Link [ALKD] enabled at IRQ 21
GSI 18 sharing vector 0xB9 and IRQ 18
ACPI: PCI Interrupt 0000:00:10.3[D] -> Link [ALKD] -> GSI 21 (level, low) -> IRQ 185
ehci_hcd 0000:00:10.3: EHCI Host Controller
ehci_hcd 0000:00:10.3: new USB bus registered, assigned bus number 1
ehci_hcd 0000:00:10.3: irq 185, io mem 0xd0004400
ehci_hcd 0000:00:10.3: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
PM: Adding info for usb:usb1
PM: Adding info for No Bus:usbdev1.1_ep00
usb usb1: configuration #1 chosen from 1 choice
PM: Adding info for usb:1-0:1.0
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 6 ports detected
PM: Adding info for No Bus:usbdev1.1_ep81
PM: Adding info for No Bus:usbdev1.1
GSI 19 sharing vector 0xC1 and IRQ 19
ACPI: PCI Interrupt 0000:00:08.0[A] -> GSI 19 (level, low) -> IRQ 193
eth0: RealTek RTL8139 at 0xffffc20000020000, 00:90:f5:3e:41:f0, IRQ 193
eth0:  Identified 8139 chip type 'RTL-8100B/8139D'
ACPI: PCI Interrupt Link [ALKC] disabled and referenced, BIOS bug
ACPI: PCI Interrupt Link [ALKC] BIOS reported IRQ 0, using IRQ 22
ACPI: PCI Interrupt Link [ALKC] enabled at IRQ 22
GSI 20 sharing vector 0xC9 and IRQ 20
ACPI: PCI Interrupt 0000:00:11.5[C] -> Link [ALKC] -> GSI 22 (level, low) -> IRQ 201
PCI: Setting latency timer of device 0000:00:11.5 to 64
8139cp: 10/100 PCI Ethernet driver v1.2 (Mar 22, 2004)
PM: Adding info for ac97:0-0:ALC202
ACPI: PCI Interrupt 0000:00:10.0[A] -> Link [ALKD] -> GSI 21 (level, low) -> IRQ 185
PCI: VIA IRQ fixup for 0000:00:10.0, from 0 to 9
uhci_hcd 0000:00:10.0: UHCI Host Controller
uhci_hcd 0000:00:10.0: new USB bus registered, assigned bus number 2
uhci_hcd 0000:00:10.0: irq 185, io base 0x00001c00
PM: Adding info for usb:usb2
PM: Adding info for No Bus:usbdev2.1_ep00
usb usb2: configuration #1 chosen from 1 choice
PM: Adding info for usb:2-0:1.0
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
PM: Adding info for No Bus:usbdev2.1_ep81
PM: Adding info for No Bus:usbdev2.1
ACPI: PCI Interrupt 0000:00:10.1[B] -> Link [ALKD] -> GSI 21 (level, low) -> IRQ 185
PCI: VIA IRQ fixup for 0000:00:10.1, from 0 to 9
uhci_hcd 0000:00:10.1: UHCI Host Controller
uhci_hcd 0000:00:10.1: new USB bus registered, assigned bus number 3
uhci_hcd 0000:00:10.1: irq 185, io base 0x00001c20
PM: Adding info for usb:usb3
PM: Adding info for No Bus:usbdev3.1_ep00
usb usb3: configuration #1 chosen from 1 choice
PM: Adding info for usb:3-0:1.0
hub 3-0:1.0: USB hub found
hub 3-0:1.0: 2 ports detected
PM: Adding info for No Bus:usbdev3.1_ep81
PM: Adding info for No Bus:usbdev3.1
ACPI: PCI Interrupt 0000:00:10.2[C] -> Link [ALKD] -> GSI 21 (level, low) -> IRQ 185
PCI: VIA IRQ fixup for 0000:00:10.2, from 0 to 9
uhci_hcd 0000:00:10.2: UHCI Host Controller
uhci_hcd 0000:00:10.2: new USB bus registered, assigned bus number 4
uhci_hcd 0000:00:10.2: irq 185, io base 0x00001c40
PM: Adding info for usb:usb4
PM: Adding info for No Bus:usbdev4.1_ep00
usb usb4: configuration #1 chosen from 1 choice
PM: Adding info for usb:4-0:1.0
hub 4-0:1.0: USB hub found
hub 4-0:1.0: 2 ports detected
PM: Adding info for No Bus:usbdev4.1_ep81
PM: Adding info for No Bus:usbdev4.1
PM: Adding info for No Bus:i2c-0
ACPI: PCI Interrupt 0000:00:11.6[C] -> Link [ALKC] -> GSI 22 (level, low) -> IRQ 201
PCI: Setting latency timer of device 0000:00:11.6 to 64
usb 2-2: new low speed USB device using uhci_hcd and address 2
PM: Adding info for usb:2-2
PM: Adding info for No Bus:usbdev2.2_ep00
usb 2-2: configuration #1 chosen from 1 choice
PM: Adding info for usb:2-2:1.0
input: Dell Dell USB Mouse as /class/input/input4
input: USB HID v1.10 Mouse [Dell Dell USB Mouse] on usb-0000:00:10.0-2
PM: Adding info for No Bus:usbdev2.2_ep81
PM: Adding info for No Bus:usbdev2.2
PM: Adding info for ac97:1-1:Si3036,8
usb 4-1: new full speed USB device using uhci_hcd and address 2
PM: Adding info for usb:4-1
PM: Adding info for No Bus:usbdev4.2_ep00
usb 4-1: configuration #1 chosen from 1 choice
PM: Adding info for usb:4-1:1.0
PM: Adding info for No Bus:usbdev4.2_ep81
PM: Adding info for No Bus:usbdev4.2_ep82
PM: Adding info for No Bus:usbdev4.2
Linux video capture interface: v2.00
zc0301: V4L2 driver for ZC0301[P] Image Processor and Control Chip v1:1.05
usb 4-1: ZC0301[P] Image Processor and Control Chip detected (vid/pid 0x0AC8/0x301B)
usb 4-1: No supported image sensor detected
usbcore: registered new driver zc0301
floppy0: no floppy controllers found
parport: PnPBIOS parport detected.
parport0: PC-style at 0x378 (0x778), irq 7 [PCSPP,TRISTATE]
lp0: using parport0 (interrupt-driven).
lp0: console ready
ACPI: AC Adapter [AC] (on-line)
ACPI: Battery Slot [BAT0] (battery present)
ACPI: Power Button (FF) [PWRF]
ACPI: Power Button (CM) [PWB]
ACPI: Sleep Button (CM) [SLPB]
ACPI: Lid Switch [LID]
ibm_acpi: ec object not found
ACPI: Video Device [VGA] (multi-head: yes  rom: no  post: no)
md: Autodetecting RAID arrays.
md: autorun ...
md: ... autorun DONE.
EXT3 FS on dm-0, internal journal
kjournald starting.  Commit interval 5 seconds
EXT3 FS on hda2, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
SELinux: initialized (dev hda2, type ext3), uses xattr
SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
Adding 1933304k swap on /dev/mapper/VolGroup00-LogVol01.  Priority:-1 extents:1 across:1933304k
SELinux: initialized (dev binfmt_misc, type binfmt_misc), uses genfs_contexts

=======================================================
[ INFO: possible circular locking dependency detected ]
-------------------------------------------------------
cpuspeed/1506 is trying to acquire lock:
 (&policy->lock){--..}, at: [<ffffffff80265ddf>] mutex_lock+0x2a/0x2e

but task is already holding lock:
 (cpucontrol){--..}, at: [<ffffffff80265ddf>] mutex_lock+0x2a/0x2e

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (cpucontrol){--..}:
       [<ffffffff802a8302>] lock_acquire+0x4a/0x69
       [<ffffffff80265c38>] __mutex_lock_slowpath+0xe4/0x261
       [<ffffffff80265dde>] mutex_lock+0x29/0x2e
       [<ffffffff802ab5bb>] __lock_cpu_hotplug+0x3c/0x5f
       [<ffffffff802ab5f8>] lock_cpu_hotplug+0xa/0xd
       [<ffffffff8040e88f>] __cpufreq_driver_target+0x1a/0x82
       [<ffffffff8040fb51>] cpufreq_governor_userspace+0x1e9/0x22c
       [<ffffffff8040e248>] __cpufreq_governor+0x74/0x107
       [<ffffffff8040e4b0>] __cpufreq_set_policy+0x1d5/0x1e7
       [<ffffffff8040e4fd>] cpufreq_set_policy+0x3b/0x96
       [<ffffffff8040f0d9>] cpufreq_add_dev+0x3ac/0x57b
       [<ffffffff803b2cd4>] sysdev_driver_register+0x7b/0xdc
       [<ffffffff8040e0f4>] cpufreq_register_driver+0xc1/0x1a1
       [<ffffffff8027d765>] powernowk8_init+0x7e/0x88
       [<ffffffff8026d2ac>] init+0x1fc/0x3cd
       [<ffffffff80260e9d>] child_rip+0x7/0x12

-> #1 (userspace_mutex){--..}:
       [<ffffffff802a8302>] lock_acquire+0x4a/0x69
       [<ffffffff80265c38>] __mutex_lock_slowpath+0xe4/0x261
       [<ffffffff80265dde>] mutex_lock+0x29/0x2e
       [<ffffffff8040f9cd>] cpufreq_governor_userspace+0x65/0x22c
       [<ffffffff8040e248>] __cpufreq_governor+0x74/0x107
       [<ffffffff8040e44f>] __cpufreq_set_policy+0x174/0x1e7
       [<ffffffff8040e4fd>] cpufreq_set_policy+0x3b/0x96
       [<ffffffff8040f0d9>] cpufreq_add_dev+0x3ac/0x57b
       [<ffffffff803b2cd4>] sysdev_driver_register+0x7b/0xdc
       [<ffffffff8040e0f4>] cpufreq_register_driver+0xc1/0x1a1
       [<ffffffff8027d765>] powernowk8_init+0x7e/0x88
       [<ffffffff8026d2ac>] init+0x1fc/0x3cd
       [<ffffffff80260e9d>] child_rip+0x7/0x12

-> #0 (&policy->lock){--..}:
       [<ffffffff802a8302>] lock_acquire+0x4a/0x69
       [<ffffffff80265c38>] __mutex_lock_slowpath+0xe4/0x261
       [<ffffffff80265dde>] mutex_lock+0x29/0x2e
       [<ffffffff8040e6a6>] store_scaling_governor+0x14e/0x19c
       [<ffffffff80274fb3>] store+0x4b/0x66
       [<ffffffff80309b18>] sysfs_write_file+0xd0/0x103
       [<ffffffff80217147>] vfs_write+0xce/0x175
       [<ffffffff80217a2f>] sys_write+0x46/0x70
       [<ffffffff8025ff4d>] system_call+0x7d/0x83

other info that might help us debug this:

1 lock held by cpuspeed/1506:
 #0:  (cpucontrol){--..}, at: [<ffffffff80265ddf>] mutex_lock+0x2a/0x2e

stack backtrace:

Call Trace:
 [<ffffffff8026e2a9>] show_trace+0xaa/0x23d
 [<ffffffff8026e451>] dump_stack+0x15/0x17
 [<ffffffff802a655c>] print_circular_bug_tail+0x6c/0x77
 [<ffffffff802a7b61>] __lock_acquire+0x853/0xa54
 [<ffffffff802a8303>] lock_acquire+0x4b/0x69
 [<ffffffff80265c39>] __mutex_lock_slowpath+0xe5/0x261
 [<ffffffff80265ddf>] mutex_lock+0x2a/0x2e
 [<ffffffff8040e6a7>] store_scaling_governor+0x14f/0x19c
 [<ffffffff80274fb4>] store+0x4c/0x66
 [<ffffffff80309b19>] sysfs_write_file+0xd1/0x103
 [<ffffffff80217148>] vfs_write+0xcf/0x175
 [<ffffffff80217a30>] sys_write+0x47/0x70
 [<ffffffff8025ff4e>] system_call+0x7e/0x83
NET: Registered protocol family 10
lo: Disabled Privacy Extensions
IPv6 over IPv4 tunneling driver
ip6_tables: (C) 2000-2006 Netfilter Core Team
Netfilter messages via NETLINK v0.30.
ip_conntrack version 2.4 (3837 buckets, 30696 max) - 304 bytes per conntrack
ip_tables: (C) 2000-2006 Netfilter Core Team
eth0: link up, 100Mbps, full-duplex, lpa 0x41E1
audit(1153391026.069:4): audit_pid=1839 old=0 by auid=4294967295 subj=system_u:system_r:auditd_t:s0
eth0: no IPv6 routers present
SELinux: initialized (dev rpc_pipefs, type rpc_pipefs), uses genfs_contexts
Bluetooth: Core ver 2.10
PM: Adding info for platform:bluetooth
NET: Registered protocol family 31
Bluetooth: HCI device and connection manager initialized
Bluetooth: HCI socket layer initialized
Bluetooth: L2CAP ver 2.8
Bluetooth: L2CAP socket layer initialized
Bluetooth: RFCOMM socket layer initialized
Bluetooth: RFCOMM TTY layer initialized
Bluetooth: RFCOMM ver 1.8
Bluetooth: HIDP (Human Interface Emulation) ver 1.1
i2c /dev entries driver
PM: Adding info for i2c:0-0050
PM: Adding info for i2c:0-0051
SELinux: initialized (dev autofs, type autofs), uses genfs_contexts
SELinux: initialized (dev autofs, type autofs), uses genfs_contexts
ACPI Exception (acpi_thermal-0412): AE_NOT_FOUND, Invalid active threshold [0] [20060707]
ACPI Exception (acpi_thermal-0412): AE_NOT_FOUND, Invalid active threshold [0] [20060707]


More information about the fedora-test-list mailing list