[redhat-lspp] dmesg from lspp.72.el5 with inconsistent lock state

Joe Nall joe at nall.com
Sun Apr 1 23:13:29 UTC 2007


This is a dmesg from an lspp.72 kernel with current fc6 userland.  
lspp.70 was generating the same errors. It is running within a  
Parallels VM on my laptop.

Linux version 2.6.18-8.1.1.lspp.72.el5 (brewbuilder at hs20- 
bc1-6.build.redhat.com) (gcc version 4.1.1 20070105 (Red Hat  
4.1.1-52)) #1 SMP Wed Mar 28 16:10:51 EDT 2007
BIOS-provided physical RAM map:
BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
BIOS-e820: 0000000000100000 - 0000000014000000 (usable)
0MB HIGHMEM available.
320MB LOWMEM available.
Using x86 segment limits to approximate NX protection
On node 0 totalpages: 81920
   DMA zone: 4096 pages, LIFO batch:0
   Normal zone: 77824 pages, LIFO batch:15
DMI not present or invalid.
Using APIC driver default
ACPI: Unable to locate RSDP
Allocating PCI resources starting at 20000000 (gap: 14000000:ec000000)
Detected 2214.945 MHz processor.
Built 1 zonelists.  Total pages: 81920
Kernel command line: ro root=/dev/VolGroup00/LogVol00 quiet
Local APIC disabled by BIOS -- you can enable it with "lapic"
mapped APIC to ffffd000 (0128d000)
Enabling fast FPU save and restore... done.
Enabling unmasked SIMD FPU exception support... done.
Initializing CPU#0
CPU 0 irqstacks, hard=c0794000 soft=c0774000
PID hash table entries: 2048 (order: 11, 8192 bytes)
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: 904 kB
per task-struct memory footprint: 1200 bytes
Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
Memory: 315572k/327680k available (2138k kernel code, 11440k  
reserved, 1123k data, 236k init, 0k highmem)
Checking if this processor honours the WP bit even in supervisor  
mode... Ok.
Calibrating delay using timer specific routine.. 17301.52 BogoMIPS  
(lpj=8650764)
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: 512
CPU: After generic identify, caps: 0f80b9b9 00000000 00000000  
00000000 00000001 00000000 00000000
CPU: After vendor identify, caps: 0f80b9b9 00000000 00000000 00000000  
00000001 00000000 00000000
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 2048K
CPU: After all inits, caps: 0f80b1b9 00000000 00000000 00000140  
00000001 00000000 00000000
Checking 'hlt' instruction... OK.
SMP alternatives: switching to UP code
Freeing SMP alternatives: 12k freed
CPU0: Intel Genuine Intel(R) CPU           T2600  @ 2.16GHz stepping 08
SMP motherboard not detected.
Local APIC not detected. Using dummy APIC emulation.
Brought up 1 CPUs
sizeof(vma)=84 bytes
sizeof(page)=32 bytes
sizeof(inode)=568 bytes
sizeof(dentry)=160 bytes
sizeof(ext3inode)=804 bytes
sizeof(buffer_head)=52 bytes
sizeof(skbuff)=172 bytes
checking if image is initramfs... it is
Freeing initrd memory: 2138k freed
NET: Registered protocol family 16
ACPI Exception (utmutex-0262): AE_BAD_PARAMETER, Thread C132D530  
could not acquire Mutex [2] [20060707]
PCI: PCI BIOS revision 2.10 entry at 0xf81a4, last bus=1
PCI: Using configuration type 1
Setting up standard PCI resources
ACPI: Interpreter disabled.
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI: disabled
usbcore: registered new driver usbfs
usbcore: registered new driver hub
PCI: Probing PCI hardware
PCI: Probing PCI hardware (bus 00)
Boot video device is 0000:00:02.0
PCI quirk: region 1000-107f claimed by ICH4 ACPI/GPIO/TCO
PCI: Device 0000:00:1d.7 not found by BIOS
PCI: Device 0000:00:1f.5 not found by BIOS
NetLabel: Initializing
NetLabel:  domain hash size = 128
NetLabel:  protocols = UNLABELED CIPSOv4
NetLabel:  unlabeled traffic allowed by default
NET: Registered protocol family 2
IP route cache hash table entries: 4096 (order: 2, 16384 bytes)
TCP established hash table entries: 16384 (order: 7, 524288 bytes)
TCP bind hash table entries: 8192 (order: 6, 262144 bytes)
TCP: Hash tables configured (established 16384 bind 8192)
TCP reno registered
apm: BIOS not found.
audit: initializing netlink socket (disabled)
audit(1175447891.613:1): initialized
Total HugeTLB memory allocated, 0
VFS: Disk quotas dquot_6.5.1
Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
SELinux:  Registering netfilter hooks
Initializing Cryptographic API
ksign: Installing public key data
Loading keyring
- Added public key B58771416977B91B
- User ID: Red Hat, Inc. (Kernel Module GPG key)
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
Real Time Clock Driver v1.12ac
Non-volatile memory driver v1.2
Linux agpgart interface v0.101 (c) Dave Jones
agpgart: Detected an Intel i815 Chipset.
agpgart: AGP aperture is 64M @ 0xe0000000
Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
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
ICH2: IDE controller at PCI slot 0000:00:1f.1
ICH2: chipset revision 0
ICH2: not 100% native mode: will probe irqs later
     ide0: BM-DMA at 0x6c00-0x6c07, BIOS settings: hda:DMA, hdb:DMA
Probing IDE interface ide0...
hda: Virtual HDD [0], ATA DISK drive
hdb: PRL CD-ROM [1], ATAPI CD/DVD-ROM drive
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
Probing IDE interface ide1...
hda: max request size: 512KiB
hda: 21504672 sectors (11010 MB) w/2048KiB Cache, CHS=16383/255/63,  
UDMA(100)
hda: cache flushes supported
hda: hda1 hda2
ide-floppy driver 0.99.newide
usbcore: registered new driver hiddev
usbcore: registered new driver usbhid
drivers/usb/input/hid-core.c: v2.6:USB HID core driver
PNP: No PS/2 controller found. Probing ports directly.
serio: i8042 AUX port at 0x60,0x64 irq 12
serio: i8042 KBD port at 0x60,0x64 irq 1
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
Using IPI No-Shortcut mode
Freeing unused kernel memory: 236k freed
Time: tsc clocksource has been installed.
Write protecting the kernel read-only data: 400k
input: AT Translated Set 2 keyboard as /class/input/input0
input: ImExPS/2 Generic Explorer Mouse as /class/input/input1
USB Universal Host Controller Interface driver v3.0
PCI: Setting latency timer of device 0000:00:1d.0 to 64
uhci_hcd 0000:00:1d.0: UHCI Host Controller
uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 1
uhci_hcd 0000:00:1d.0: irq 11, io base 0x00005000
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
ohci_hcd: 2005 April 22 USB 1.1 'Open' Host Controller (OHCI) Driver  
(PCI)
PCI: Setting latency timer of device 0000:00:1d.7 to 64
ehci_hcd 0000:00:1d.7: EHCI Host Controller
ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 2
PCI: cache line size of 32 is not supported by device 0000:00:1d.7
ehci_hcd 0000:00:1d.7: irq 9, io mem 0xc1000000
ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 8 ports detected
device-mapper: ioctl: 4.11.0-ioctl (2006-09-14) initialised: dm- 
devel at redhat.com
EXT3-fs: INFO: recovery required on readonly filesystem.
EXT3-fs: write access will be enabled during recovery.
kjournald starting.  Commit interval 5 seconds
EXT3-fs: recovery complete.
EXT3-fs: mounted filesystem with ordered data mode.
security:  5 users, 7 roles, 2082 types, 89 bools, 16 sens, 1024 cats
security:  59 classes, 142541 rules
SELinux:  Completing initialization.
SELinux:  Setting up existing superblocks.
SELinux: initialized (dev dm-0, type ext3), uses xattr
SELinux: initialized (dev usbfs, type usbfs), uses genfs_contexts
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(1175447907.119:2): policy loaded auid=4294967295
TSC appears to be running slowly. Marking it as unstable
Time: pit clocksource has been installed.
audit(1175447925.086:3): avc:  denied  { execute_no_trans } for   
pid=596 comm="udevd" name="dmsetup" dev=dm-0 ino=1731818  
scontext=system_u:system_r:udev_t:s0-s15:c0.c1023  
tcontext=system_u:object_r:lvm_exec_t:s0 tclass=file
audit(1175447925.086:4): avc:  denied  { read } for  pid=596  
comm="udevd" name="dmsetup" dev=dm-0 ino=1731818  
scontext=system_u:system_r:udev_t:s0-s15:c0.c1023  
tcontext=system_u:object_r:lvm_exec_t:s0 tclass=file
input: PC Speaker as /class/input/input2
intel_rng: FWH not detected
ne2k-pci.c:v1.03 9/22/2003 D. Becker/P. Gortmaker
   http://www.scyld.com/network/ne2k-pci.html
eth0: RealTek RTL-8029 found at 0x4c00, IRQ 10, 00:69:2A:37:D7:46.
Floppy drive(s): fd0 is 1.44M
FDC 0 is an 8272A
hdb: ATAPI 24X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(25)
Uniform CD-ROM driver Revision: 3.20
PCI: Setting latency timer of device 0000:00:1f.5 to 64
intel8x0_measure_ac97_clock: measured 54809 usecs
intel8x0: measured clock 149464 rejected
intel8x0: clocking to 48000
lp: driver loaded but no devices found
sonypi: Sony Programmable I/O Controller Driver v1.26.
audit(1175447949.980:5): avc:  denied  { read write } for  pid=995  
comm="loadkeys" name="tty0" dev=tmpfs ino=634  
scontext=system_u:system_r:loadkeys_t:s0-s15:c0.c1023  
tcontext=system_u:object_r:tty_device_t:s0 tclass=chr_file
md: Autodetecting RAID arrays.
md: autorun ...
md: ... autorun DONE.
device-mapper: multipath: version 1.0.5 loaded
audit(1175447968.794:6): avc:  denied  { write } for  pid=1021  
comm="multipath.stati" name="control" dev=tmpfs ino=736  
scontext=system_u:system_r:initrc_t:s0-s15:c0.c1023  
tcontext=system_u:object_r:lvm_control_t:s0 tclass=chr_file
hdb: packet command error: status=0x51 { DriveReady SeekComplete Error }
hdb: packet command error: error=0x50 { LastFailedSense=0x05 }
ide: failed opcode was: unknown
hdb: packet command error: status=0x51 { DriveReady SeekComplete Error }
hdb: packet command error: error=0x50 { LastFailedSense=0x05 }
ide: failed opcode was: unknown
EXT3 FS on dm-0, internal journal
kjournald starting.  Commit interval 5 seconds
EXT3 FS on hda1, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
SELinux: initialized (dev hda1, type ext3), uses xattr
SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
Adding 655352k swap on /dev/VolGroup00/LogVol01.  Priority:-1 extents: 
1 across:655352k
SELinux: initialized (dev binfmt_misc, type binfmt_misc), uses  
genfs_contexts
NET: Registered protocol family 10
lo: Disabled Privacy Extensions
IPv6 over IPv4 tunneling driver
ip6_tables: (C) 2000-2006 Netfilter Core Team
ip_tables: (C) 2000-2006 Netfilter Core Team
Netfilter messages via NETLINK v0.30.
ip_conntrack version 2.4 (2560 buckets, 20480 max) - 228 bytes per  
conntrack
process `sysctl' is using deprecated sysctl (syscall)  
net.ipv6.neigh.lo.retrans_time; Use net.ipv6.neigh.lo.retrans_time_ms  
instead.

=================================
[ INFO: inconsistent lock state ]
2.6.18-8.1.1.lspp.72.el5 #1
---------------------------------
inconsistent {hardirq-on-W} -> {in-hardirq-W} usage.
ifup-eth/1510 [HC1[1]:SC1[2]:HE0:SE0] takes:
(&ei_local->page_lock){++..}, at: [<d488276d>] ei_interrupt 
+0x46/0x2c3 [8390]
{hardirq-on-W} state was registered at:
   [<c043b907>] __lock_acquire+0x3a4/0x90d
   [<c043c3e1>] lock_acquire+0x4b/0x6a
   [<c0613e73>] _spin_lock+0x19/0x28
   [<d4882d57>] ei_start_xmit+0xa6/0x243 [8390]
   [<c05b8096>] dev_hard_start_xmit+0x1a5/0x202
   [<c05c6897>] __qdisc_run+0xdf/0x19d
   [<c05b99f9>] dev_queue_xmit+0x147/0x25a
   [<d4a481f2>] mld_sendpack+0x1ad/0x27d [ipv6]
   [<d4a48d7e>] mld_ifc_timer_expire+0x18e/0x1b6 [ipv6]
   [<c042dccb>] run_timer_softirq+0x108/0x167
   [<c04290f7>] __do_softirq+0x78/0xf2
   [<c04065f3>] do_softirq+0x5a/0xbe
   [<ffffffff>] 0xffffffff
irq event stamp: 87
hardirqs last  enabled at (86): [<c061413b>] _spin_unlock_irqrestore 
+0x36/0x3c
hardirqs last disabled at (87): [<c0404a67>] common_interrupt+0x1b/0x2c
softirqs last  enabled at (0): [<c0422403>] copy_process+0x330/0x1327
softirqs last disabled at (47): [<c04065f3>] do_softirq+0x5a/0xbe

other info that might help us debug this:
3 locks held by ifup-eth/1510:
#0:  (&mm->mmap_sem){----}, at: [<c0615150>] do_page_fault+0x14f/0x4a4
#1:  (&mm->page_table_lock){--..}, at: [<c046071d>] do_wp_page 
+0x296/0x3d7
#2:  (&dev->_xmit_lock){-...}, at: [<c05c6818>] __qdisc_run+0x60/0x19d

stack backtrace:
[<c04051ff>] show_trace_log_lvl+0x12/0x25
[<c040570d>] show_trace+0xd/0x10
[<c0405826>] dump_stack+0x19/0x1b
[<c043a8cd>] print_usage_bug+0x1cf/0x1dc
[<c043ac18>] mark_lock+0x96/0x353
[<c043b888>] __lock_acquire+0x325/0x90d
[<c043c3e1>] lock_acquire+0x4b/0x6a
[<c0613e73>] _spin_lock+0x19/0x28
[<d488276d>] ei_interrupt+0x46/0x2c3 [8390]
[<c0450559>] handle_IRQ_event+0x20/0x4d
[<c045061a>] __do_IRQ+0x94/0xef
[<c04066f5>] do_IRQ+0x9e/0xbd
[<c0404a71>] common_interrupt+0x25/0x2c
[<c0450d33>] enable_irq+0x8b/0x94
[<d4882edc>] ei_start_xmit+0x22b/0x243 [8390]
[<c05b8096>] dev_hard_start_xmit+0x1a5/0x202
[<c05c6897>] __qdisc_run+0xdf/0x19d
[<c05b99f9>] dev_queue_xmit+0x147/0x25a
[<d4a481f2>] mld_sendpack+0x1ad/0x27d [ipv6]
[<d4a48d7e>] mld_ifc_timer_expire+0x18e/0x1b6 [ipv6]
[<c042dccb>] run_timer_softirq+0x108/0x167
[<c04290f7>] __do_softirq+0x78/0xf2
[<c04065f3>] do_softirq+0x5a/0xbe
[<c0428fa0>] irq_exit+0x3d/0x3f
[<c0406707>] do_IRQ+0xb0/0xbd
[<c0404a71>] common_interrupt+0x25/0x2c
[<c0461b49>] __handle_mm_fault+0x7cb/0x841
[<c0615202>] do_page_fault+0x201/0x4a4
[<c0404c09>] error_code+0x39/0x40
=======================
SELinux: initialized (dev rpc_pipefs, type rpc_pipefs), uses  
genfs_contexts
NET: Registered protocol family 15
Bluetooth: Core ver 2.10
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
SELinux: initialized (dev autofs, type autofs), uses genfs_contexts
SELinux: initialized (dev autofs, type autofs), uses genfs_contexts
SELinux: initialized (dev autofs, type autofs), uses genfs_contexts
eth0: no IPv6 routers present
mtrr: your processor doesn't support write-combining




More information about the redhat-lspp mailing list