Hello Steven, Thanks for your reply > The above sounds more like you need a completion. Funny, I first started with using completion structures, but that did not work either. I get similar OOPses on all these kind of locking mechanisms, as long as I use the _interruptible() type. I tried every work-around I can think of, but none worked :-(( Even if I block on an ordinary rt-mutex in the same routine, wait a _interruptible() type, I get the same problem. > What's used to wake up the caller of down_interruptible? A call to up() is used from inside an interrupt(thread) context, but this is not relevant for the problem, because only blocking on a semaphore with down_interruptible() and waking the thread by CTRL-C is enough to get this Oops. I saw that the code is trying to wake 'other waiters', while there is only 1 thread waiting on the semaphore at most. I feel that the root cause of this problem has to be searched there. I believe that executing any PI code on semaphores is a strange behavior anyway, because a semaphore is never 'owned' by a thread, and it is always another thread that wakes the thread that blocks on a semaphore, and because the waker is unknown, the PI code will always boost the prio of the wrong thread. Strange is also, that I get different behavior on ARM if I use sema_init(&sema, 1) versus sema_init(&sema,0). The latter seems to crash less, it will not crash until the first up(); while the first will crash even without any up(). Attached I have put a sample driver I just hacked together a few minutes ago. It is NOT the driver that has generates the oops in the previous mail, but I have stripped a scull-driver down that much that it will be much easier to talk about, and to keep us focussed on the part of the code that is causing this. Besides: I tested this driver on X86 with 2.6.23.1-rt5 and I get the also OOPSes although slightly different than on ARM. See the attached dummy.txt file. Beware: The up(&sema) is NOT required to get this OOPS, I get it even without any up(&sema) ! I hope you can look at the attached driver source and help me with this... Kind Regards, Remy Bohmer 2007/11/16, Steven Rostedt <[email protected]>: > > > On Fri, 16 Nov 2007, Remy Bohmer wrote: > > > Hello All, > > > > I have a problem with the RT-mutex code and signals. The problem is > > very easily reproducible, but I do not have found the root-cause yet. > > I hope someone can help me on this one. > > > > This is what I am doing: > > * I have a simple character driver with a read call.(called spi_read() > > in the logging below ) > > * The read call blocks on a semaphore until some condition in hardware > > is reached. (in the routine wait_for_io_level(), see logging below) > > * I use a down_interruptible() call on a 'struct semaphore' type > > semaphore, which eventually blocks on a mutex. (the semaphore is, of > > course, initialised with sema_init() ) > > The above sounds more like you need a completion. What's used to wake up > the caller of down_interruptible? > > Can you post some code to see what you are doing. That would make it much > easier to analyze. > > -- Steve > > > > > > What happens is that when a user-space RT-thread is waiting on the > > semaphore through the spi_read() call, and a signal arrives during the > > wait at this thread (like e.g. CTRL-C), the kernel starts oopsing > > until it is as good as brain-dead. > > > > If I do NOT sent a posix-signal the code/mutex/semaphore is working > > properly for days, > > So, it seems to be related by waking up from a blocking situation, > > because of a pending posix-signal. > > > > I tried also the types 'struct compat_semaphore', and mutexes; none of > > them work. > > In fact the real Mutex type, declared with init_MUTEX() has the same problem. > > > > Anyone an idea? > > Below the kernel oops output. (I run on ARM, but I think that should > > not matter for this problem) > > >
Attachment:
dummy.tgz
Description: GNU Zip compressed data
Linux version 2.6.23.1-rt5 (remy@huiskamer) (gcc version 4.1.2 20070925 (Red Hat 4.1.2-33)) #1 SMP PREEMPT RT Fri Nov 16 23:28:18 CET 2007
BIOS-provided physical RAM map:
BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
BIOS-e820: 00000000000e8000 - 0000000000100000 (reserved)
BIOS-e820: 0000000000100000 - 000000003ff30000 (usable)
BIOS-e820: 000000003ff30000 - 000000003ff40000 (ACPI data)
BIOS-e820: 000000003ff40000 - 000000003fff0000 (ACPI NVS)
BIOS-e820: 000000003fff0000 - 0000000040000000 (reserved)
BIOS-e820: 00000000ffb80000 - 0000000100000000 (reserved)
127MB HIGHMEM available.
896MB LOWMEM available.
found SMP MP-table at 000ff780
Entering add_active_range(0, 0, 261936) 0 entries of 256 used
Zone PFN ranges:
DMA 0 -> 4096
Normal 4096 -> 229376
HighMem 229376 -> 261936
Movable zone start PFN for each node
early_node_map[1] active PFN ranges
0: 0 -> 261936
On node 0 totalpages: 261936
DMA zone: 56 pages used for memmap
DMA zone: 0 pages reserved
DMA zone: 4040 pages, LIFO batch:0
Normal zone: 3080 pages used for memmap
Normal zone: 222200 pages, LIFO batch:31
HighMem zone: 445 pages used for memmap
HighMem zone: 32115 pages, LIFO batch:7
Movable zone: 0 pages used for memmap
DMI 2.3 present.
Using APIC driver default
ACPI: RSDP 000F9E30, 0021 (r2 ACPIAM)
ACPI: XSDT 3FF30100, 003C (r1 A M I OEMXSDT 10000414 MSFT 97)
ACPI: FACP 3FF30290, 00F4 (r3 A M I OEMFACP 10000414 MSFT 97)
ACPI: DSDT 3FF303F0, 382D (r1 P4P81 P4P81104 104 INTL 2002026)
ACPI: FACS 3FF40000, 0040
ACPI: APIC 3FF30390, 005C (r1 A M I OEMAPIC 10000414 MSFT 97)
ACPI: OEMB 3FF40040, 003F (r1 A M I OEMBIOS 10000414 MSFT 97)
ACPI: PM-Timer IO Port: 0x808
ACPI: Local APIC address 0xfee00000
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
Processor #0 15:2 APIC version 20
ACPI: LAPIC (acpi_id[0x02] lapic_id[0x01] enabled)
Processor #1 15:2 APIC version 20
ACPI: IOAPIC (id[0x02] address[0xfec00000] gsi_base[0])
IOAPIC[0]: apic_id 2, version 32, address 0xfec00000, GSI 0-23
ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
ACPI: IRQ0 used by override.
ACPI: IRQ2 used by override.
ACPI: IRQ9 used by override.
Enabling APIC mode: Flat. Using 1 I/O APICs
Using ACPI (MADT) for SMP configuration information
Allocating PCI resources starting at 50000000 (gap: 40000000:bfb80000)
swsusp: Registered nosave memory region: 000000000009f000 - 00000000000a0000
swsusp: Registered nosave memory region: 00000000000a0000 - 00000000000e8000
swsusp: Registered nosave memory region: 00000000000e8000 - 0000000000100000
Real-Time Preemption Support (C) 2004-2007 Ingo Molnar
Built 1 zonelists in Zone order. Total pages: 258355
Kernel command line: ro root=/dev/lvmbase/root rhgb quiet
mapped APIC to ffffb000 (fee00000)
mapped IOAPIC to ffffa000 (fec00000)
Enabling fast FPU save and restore... done.
Enabling unmasked SIMD FPU exception support... done.
Initializing CPU#0
WARNING: experimental RCU implementation.
CPU 0 irqstacks, hard=c07b0000 soft=c0790000
PID hash table entries: 4096 (order: 12, 16384 bytes)
Detected 3198.545 MHz processor.
Console: colour VGA+ 80x25
console [tty0] enabled
Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Memory: 1023700k/1047744k available (2182k kernel code, 23336k reserved, 1157k data, 276k init, 130240k highmem)
virtual kernel memory layout:
fixmap : 0xffc53000 - 0xfffff000 (3760 kB)
pkmap : 0xff800000 - 0xffc00000 (4096 kB)
vmalloc : 0xf8800000 - 0xff7fe000 ( 111 MB)
lowmem : 0xc0000000 - 0xf8000000 ( 896 MB)
.init : 0xc0748000 - 0xc078d000 ( 276 kB)
.data : 0xc0621b0c - 0xc0743124 (1157 kB)
.text : 0xc0400000 - 0xc0621b0c (2182 kB)
Checking if this processor honours the WP bit even in supervisor mode... Ok.
Calibrating delay using timer specific routine.. 6399.57 BogoMIPS (lpj=3199788)
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: bfebfbff 00000000 00000000 00000000 00004400 00000000 00000000 00000000
CPU: Trace cache: 12K uops, L1 D cache: 8K
CPU: L2 cache: 512K
CPU: Physical Processor ID: 0
CPU: After all inits, caps: bfebfbff 00000000 00000000 0000b080 00004400 00000000 00000000 00000000
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#0.
CPU0: Intel P4/Xeon Extended MCE MSRs (12) available
CPU0: Thermal monitoring enabled
Compat vDSO mapped to ffffe000.
Checking 'hlt' instruction... OK.
SMP alternatives: switching to UP code
ACPI: Core revision 20070126
CPU0: Intel(R) Pentium(R) 4 CPU 3.20GHz stepping 09
SMP alternatives: switching to SMP code
Booting processor 1/1 eip 3000
CPU 1 irqstacks, hard=c07b1000 soft=c0791000
Initializing CPU#1
Calibrating delay using timer specific routine.. 6395.97 BogoMIPS (lpj=3197987)
CPU: After generic identify, caps: bfebfbff 00000000 00000000 00000000 00004400 00000000 00000000 00000000
CPU: Trace cache: 12K uops, L1 D cache: 8K
CPU: L2 cache: 512K
CPU: Physical Processor ID: 0
CPU: After all inits, caps: bfebfbff 00000000 00000000 0000b080 00004400 00000000 00000000 00000000
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#1.
CPU1: Intel P4/Xeon Extended MCE MSRs (12) available
CPU1: Thermal monitoring enabled
CPU1: Intel(R) Pentium(R) 4 CPU 3.20GHz stepping 09
Total of 2 processors activated (12795.55 BogoMIPS).
ENABLING IO-APIC IRQs
..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1
checking TSC synchronization [CPU#0 -> CPU#1]: passed.
Brought up 2 CPUs
Booting paravirtualized kernel on bare hardware
Time: 23:44:46 Date: 10/16/107
NET: Registered protocol family 16
No dock devices found.
ACPI: bus type pci registered
PCI: PCI BIOS revision 2.10 entry at 0xf0031, last bus=3
PCI: Using configuration type 1
Setting up standard PCI resources
ACPI: EC: Look up EC in DSDT
ACPI: Interpreter enabled
ACPI: (supports S0 S1 S3 S4 S5)
ACPI: Using IOAPIC for interrupt routing
ACPI: PCI Root Bridge [PCI0] (0000:00)
Force enabled HPET at base address 0xfed00000
PCI quirk: region 0800-087f claimed by ICH4 ACPI/GPIO/TCO
PCI quirk: region 0480-04bf claimed by ICH4 GPIO
PCI: Transparent bridge - 0000:00:1e.0
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.P0P4._PRT]
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 *10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 *7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 *5 6 7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKD] (IRQs *3 4 5 6 7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 *5 6 7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 *10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 6 7 *10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 10 *11 12 14 15)
ACPI Warning (tbutils-0217): Incorrect checksum in table [OEMB] - 03, should be FA [20070126]
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI init
ACPI: bus type pnp registered
pnp: PnP ACPI: found 13 devices
ACPI: ACPI bus type pnp unregistered
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
PCI: Using ACPI for IRQ routing
PCI: If a device doesn't work, try "pci=routeirq". If it helps, post a report
PCI: Cannot allocate resource region 0 of device 0000:00:00.0
NetLabel: Initializing
NetLabel: domain hash size = 128
NetLabel: protocols = UNLABELED CIPSOv4
NetLabel: unlabeled traffic allowed by default
hpet clockevent registered
hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
hpet0: 3 64-bit timers, 14318180 Hz
pnp: 00:09: ioport range 0x680-0x6ff has been reserved
pnp: 00:09: ioport range 0x290-0x297 has been reserved
pnp: 00:0a: iomem range 0xfed20000-0xfed8ffff has been reserved
pnp: 00:0a: iomem range 0xffb00000-0xffbfffff could not be reserved
pnp: 00:0b: iomem range 0xfec00000-0xfec00fff has been reserved
pnp: 00:0b: iomem range 0xfee00000-0xfee00fff has been reserved
pnp: 00:0c: iomem range 0x0-0x9ffff could not be reserved
pnp: 00:0c: iomem range 0xc0000-0xdffff could not be reserved
pnp: 00:0c: iomem range 0xe0000-0xfffff could not be reserved
pnp: 00:0c: iomem range 0x100000-0x3ffeffff could not be reserved
PCI: Bridge: 0000:00:01.0
IO window: d000-dfff
MEM window: f6d00000-f6dfffff
PREFETCH window: d0000000-f5ffffff
PCI: Bridge: 0000:02:09.0
IO window: disabled.
MEM window: f6f00000-fbffffff
PREFETCH window: disabled.
PCI: Bridge: 0000:00:1e.0
IO window: e000-efff
MEM window: f6e00000-fbffffff
PREFETCH window: disabled.
PCI: Setting latency timer of device 0000:00:1e.0 to 64
NET: Registered protocol family 2
IP route cache hash table entries: 32768 (order: 5, 131072 bytes)
TCP established hash table entries: 65536 (order: 9, 2883584 bytes)
TCP bind hash table entries: 65536 (order: 9, 2359296 bytes)
TCP: Hash tables configured (established 65536 bind 65536)
TCP reno registered
checking if image is initramfs... it is
Freeing initrd memory: 3581k freed
apm: BIOS version 1.2 Flags 0x03 (Driver version 1.16ac)
apm: disabled - APM is not SMP safe.
audit: initializing netlink socket (disabled)
audit(1195256685.210:1): initialized
highmem bounce pool size: 64 pages
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
Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
io scheduler noop registered
io scheduler anticipatory registered
io scheduler deadline registered
io scheduler cfq registered (default)
Boot video device is 0000:01:00.0
pci_hotplug: PCI Hot Plug PCI Core version: 0.5
isapnp: Scanning for PnP cards...
isapnp: No Plug & Play device found
Real Time Clock Driver v1.12ac
Non-volatile memory driver v1.2
Linux agpgart interface v0.102
agpgart: Detected an Intel 865 Chipset.
agpgart: AGP aperture is 64M @ 0x54000000
Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
00:07: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
RAMDISK driver initialized: 16 RAM disks of 16384K size 4096 blocksize
input: Macintosh mouse button emulation as /class/input/input0
PNP: PS/2 Controller [PNP0303:PS2K,PNP0f03:PS2M] at 0x60,0x64 irq 1,12
serio: i8042 KBD port at 0x60,0x64 irq 1
serio: i8042 AUX port at 0x60,0x64 irq 12
mice: PS/2 mouse device common for all mice
input: AT Translated Set 2 keyboard as /class/input/input1
cpuidle: using governor menu
usbcore: registered new interface driver hiddev
usbcore: registered new interface driver usbhid
drivers/hid/usbhid/hid-core.c: v2.6:USB HID core driver
TCP cubic registered
Initializing XFRM netlink socket
NET: Registered protocol family 1
NET: Registered protocol family 17
Using IPI No-Shortcut mode
Magic number: 15:358:757
Freeing unused kernel memory: 276k freed
Write protecting the kernel read-only data: 856k
logips2pp: Detected unknown logitech mouse model 127
ACPI: PCI Interrupt 0000:00:1d.7[D] -> GSI 23 (level, low) -> IRQ 16
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 1
ehci_hcd 0000:00:1d.7: debug port 1
PCI: cache line size of 128 is not supported by device 0000:00:1d.7
ehci_hcd 0000:00:1d.7: irq 16, io mem 0xf6cffc00
ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 8 ports detected
ohci_hcd: 2006 August 04 USB 1.1 'Open' Host Controller (OHCI) Driver
USB Universal Host Controller Interface driver v3.0
ACPI: PCI Interrupt 0000:00:1d.0[A] -> GSI 16 (level, low) -> IRQ 17
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 2
uhci_hcd 0000:00:1d.0: irq 17, io base 0x0000c480
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
ACPI: PCI Interrupt 0000:00:1d.1[B] -> GSI 19 (level, low) -> IRQ 18
PCI: Setting latency timer of device 0000:00:1d.1 to 64
uhci_hcd 0000:00:1d.1: UHCI Host Controller
uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 3
uhci_hcd 0000:00:1d.1: irq 18, io base 0x0000c800
usb usb3: configuration #1 chosen from 1 choice
hub 3-0:1.0: USB hub found
hub 3-0:1.0: 2 ports detected
ACPI: PCI Interrupt 0000:00:1d.2[C] -> GSI 18 (level, low) -> IRQ 19
PCI: Setting latency timer of device 0000:00:1d.2 to 64
uhci_hcd 0000:00:1d.2: UHCI Host Controller
uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 4
uhci_hcd 0000:00:1d.2: irq 19, io base 0x0000c880
usb usb4: configuration #1 chosen from 1 choice
hub 4-0:1.0: USB hub found
hub 4-0:1.0: 2 ports detected
input: ImExPS/2 Logitech Explorer Mouse as /class/input/input2
ACPI: PCI Interrupt 0000:00:1d.3[A] -> GSI 16 (level, low) -> IRQ 17
PCI: Setting latency timer of device 0000:00:1d.3 to 64
uhci_hcd 0000:00:1d.3: UHCI Host Controller
uhci_hcd 0000:00:1d.3: new USB bus registered, assigned bus number 5
uhci_hcd 0000:00:1d.3: irq 17, io base 0x0000cc00
usb usb5: configuration #1 chosen from 1 choice
hub 5-0:1.0: USB hub found
hub 5-0:1.0: 2 ports detected
usb 2-2: new full speed USB device using uhci_hcd and address 2
SCSI subsystem initialized
libata version 2.21 loaded.
ata_piix 0000:00:1f.1: version 2.12
PCI: Enabling device 0000:00:1f.1 (0005 -> 0007)
ACPI: PCI Interrupt 0000:00:1f.1[A] -> GSI 18 (level, low) -> IRQ 19
PCI: Setting latency timer of device 0000:00:1f.1 to 64
scsi0 : ata_piix
scsi1 : ata_piix
ata1: PATA max UDMA/133 cmd 0x000101f0 ctl 0x000103f6 bmdma 0x0001fc00 irq 14
ata2: PATA max UDMA/133 cmd 0x00010170 ctl 0x00010376 bmdma 0x0001fc08 irq 15
usb 2-2: configuration #1 chosen from 1 choice
hub 2-2:1.0: USB hub found
hub 2-2:1.0: 4 ports detected
ata1.00: ATAPI: SONY DVD RW DRU-500A, 2.1a, max UDMA/33
ata1.00: configured for UDMA/33
ata2.00: ATA-6: WDC WD3200JB-00KFA0, 08.05J08, max UDMA/100
ata2.00: 625142448 sectors, multi 16: LBA48
ata2.01: ATA-7: Maxtor 6E040L0, NAR61590, max UDMA/133
ata2.01: 80293248 sectors, multi 16: LBA
ata2.00: configured for UDMA/100
ata2.01: configured for UDMA/133
scsi 0:0:0:0: CD-ROM SONY DVD RW DRU-500A 2.1a PQ: 0 ANSI: 5
scsi 1:0:0:0: Direct-Access ATA WDC WD3200JB-00K 08.0 PQ: 0 ANSI: 5
sd 1:0:0:0: [sda] 625142448 512-byte hardware sectors (320073 MB)
sd 1:0:0:0: [sda] Write Protect is off
sd 1:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 1:0:0:0: [sda] 625142448 512-byte hardware sectors (320073 MB)
sd 1:0:0:0: [sda] Write Protect is off
sd 1:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sda: sda1 sda2 < sda5 > sda3 sda4
sd 1:0:0:0: [sda] Attached SCSI disk
scsi 1:0:1:0: Direct-Access ATA Maxtor 6E040L0 NAR6 PQ: 0 ANSI: 5
sd 1:0:1:0: [sdb] 80293248 512-byte hardware sectors (41110 MB)
sd 1:0:1:0: [sdb] Write Protect is off
sd 1:0:1:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 1:0:1:0: [sdb] 80293248 512-byte hardware sectors (41110 MB)
sd 1:0:1:0: [sdb] Write Protect is off
sd 1:0:1:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sdb: sdb1
sd 1:0:1:0: [sdb] Attached SCSI disk
ata_piix 0000:00:1f.2: MAP [ P0 -- P1 -- ]
ACPI: PCI Interrupt 0000:00:1f.2[A] -> GSI 18 (level, low) -> IRQ 19
PCI: Setting latency timer of device 0000:00:1f.2 to 64
scsi2 : ata_piix
scsi3 : ata_piix
ata3: SATA max UDMA/133 cmd 0x0001bc00 ctl 0x0001b882 bmdma 0x0001b400 irq 19
ata4: SATA max UDMA/133 cmd 0x0001b800 ctl 0x0001b482 bmdma 0x0001b408 irq 19
ata3.00: ATA-7: Maxtor 6Y080M0, YAR51EW0, max UDMA/133
ata3.00: 160086528 sectors, multi 16: LBA
ata3.00: configured for UDMA/133
scsi 2:0:0:0: Direct-Access ATA Maxtor 6Y080M0 YAR5 PQ: 0 ANSI: 5
sd 2:0:0:0: [sdc] 160086528 512-byte hardware sectors (81964 MB)
sd 2:0:0:0: [sdc] Write Protect is off
sd 2:0:0:0: [sdc] Mode Sense: 00 3a 00 00
sd 2:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 2:0:0:0: [sdc] 160086528 512-byte hardware sectors (81964 MB)
sd 2:0:0:0: [sdc] Write Protect is off
sd 2:0:0:0: [sdc] Mode Sense: 00 3a 00 00
sd 2:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sdc: sdc1 sdc2
sd 2:0:0:0: [sdc] Attached SCSI disk
device-mapper: ioctl: 4.11.0-ioctl (2006-10-12) initialised: [email protected]
kjournald starting. Commit interval 5 seconds
EXT3-fs: mounted filesystem with ordered data mode.
SELinux: Disabled at runtime.
SELinux: Unregistering netfilter hooks
audit(1195256693.209:2): selinux=0 auid=4294967295
intel_rng: FWH not detected
sr0: scsi3-mmc drive: 32x/32x writer cd/rw xa/form2 cdda tray
Uniform CD-ROM driver Revision: 3.20
sr 0:0:0:0: Attached scsi CD-ROM sr0
iTCO_vendor_support: vendor-support=0
sr 0:0:0:0: Attached scsi generic sg0 type 5
sd 1:0:0:0: Attached scsi generic sg1 type 0
sd 1:0:1:0: Attached scsi generic sg2 type 0
sd 2:0:0:0: Attached scsi generic sg3 type 0
iTCO_wdt: Intel TCO WatchDog Timer Driver v1.02 (26-Jul-2007)
iTCO_wdt: Found a ICH5 or ICH5R TCO device (Version=1, TCOBASE=0x0860)
iTCO_wdt: initialized. heartbeat=30 sec (nowayout=0)
Floppy drive(s): fd0 is 1.44M
ACPI: PCI Interrupt 0000:00:1f.3[B] -> GSI 17 (level, low) -> IRQ 20
FDC 0 is a post-1991 82077
input: Power Button (FF) as /class/input/input3
ACPI: Power Button (FF) [PWRF]
input: Power Button (CM) as /class/input/input4
ACPI: Power Button (CM) [PWRB]
ACPI: PCI Interrupt 0000:02:05.0[A] -> GSI 22 (level, low) -> IRQ 21
skge 1.11 addr 0xf6ef8000 irq 21 chip Yukon rev 1
skge eth0: addr 00:0e:a6:2f:2d:a4
ACPI: PCI Interrupt 0000:02:03.0[A] -> GSI 20 (level, low) -> IRQ 22
firewire_ohci: Added fw-ohci device 0000:02:03.0, OHCI version 1.0
ACPI: PCI Interrupt 0000:03:0d.0[A] -> GSI 22 (level, low) -> IRQ 21
firewire_ohci: Added fw-ohci device 0000:03:0d.0, OHCI version 1.10
Linux video capture interface: v2.00
firewire_core: created new fw device fw0 (0 config rom retries, S400)
firewire_core: created new fw device fw1 (0 config rom retries, S400)
cx2388x v4l2 driver version 0.0.6 loaded
ACPI: PCI Interrupt 0000:03:0c.0[A] -> GSI 21 (level, low) -> IRQ 23
CORE cx88[0]: subsystem: 107d:6620, board: Leadtek Winfast DV2000 [card=8,autodetected]
TV tuner 38 at 0x1fe, Radio tuner -1 at 0x1fe
ACPI: PCI Interrupt 0000:00:1f.5[B] -> GSI 17 (level, low) -> IRQ 20
PCI: Setting latency timer of device 0000:00:1f.5 to 64
cx88[0]/0: found at 0000:03:0c.0, rev: 5, irq: 23, latency: 64, mmio: 0xf7000000
tuner 1-0043: chip found @ 0x86 (cx88[0])
tda9887 1-0043: tda988[5/6/7] found @ 0x43 (tuner)
tuner 1-0060: All bytes are equal. It is not a TEA5767
tuner 1-0060: chip found @ 0xc0 (cx88[0])
tuner 1-0060: type set to 38 (Philips PAL/SECAM multi (FM1216ME MK3))
tuner 1-0060: type set to 38 (Philips PAL/SECAM multi (FM1216ME MK3))
cx88[0]/0: registered device video0 [v4l2]
cx88[0]/0: registered device vbi0
cx88[0]/0: registered device radio0
AC'97 0 analog subsections not ready
intel8x0_measure_ac97_clock: measured 50076 usecs
intel8x0: clocking to 48000
NET: Registered protocol family 10
lo: Disabled Privacy Extensions
ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 17
device-mapper: multipath: version 1.0.5 loaded
EXT3 FS on dm-0, internal journal
kjournald starting. Commit interval 5 seconds
EXT3 FS on sda3, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
fuse init (API version 7.8)
Adding 2097144k swap on /dev/mapper/lvmbase-swap. Priority:-1 extents:1 across:2097144k
ip_tables: (C) 2000-2006 Netfilter Core Team
Netfilter messages via NETLINK v0.30.
nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
skge eth0: enabling interface
ADDRCONF(NETDEV_UP): eth0: link is not ready
skge eth0: Link is up at 1000 Mbps, full duplex, flow control both
ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Bluetooth: Core ver 2.11
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
eth0: no IPv6 routers present
Bridge firewalling registered
virbr0: Dropping NETIF_F_UFO since no NETIF_F_HW_CSUM feature.
virbr0: no IPv6 routers present
dummy: module license 'unspecified' taints kernel.
dummy_open
dummy_read
First time decrement goes okay.
Do 1 up.
Do 2 times down.
We will block now, and if you press CTRL-C from here, we get an OOPS.
WARNING: at kernel/rtmutex.c:585 remove_waiter()
[<c0449eb7>] remove_waiter+0x105/0x14a
[<c061da36>] rt_mutex_slowlock+0x1af/0x20d
[<c061d66b>] rt_mutex_lock_interruptible+0x41/0x49
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<c044a2c5>] rt_down_interruptible+0x11/0x30
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<f9bfe0f2>] dummy_read+0x72/0x88 [dummy]
[<c04816b0>] vfs_read+0xa6/0x152
[<c0481b12>] sys_read+0x41/0x67
[<c040512a>] sysenter_past_esp+0x6b/0xa1
[<c0610000>] dump_one_state+0x31b/0x3f8
=======================
---------------------------
| preempt count: 00000001 ]
| 1-level deep critical section nesting:
----------------------------------------
.. [<c061e0ce>] .... __spin_lock_irq+0x17/0x27
.....[<00000000>] .. ( <= 0x0)
We are returning from the read().
dummy_release
dummy_open
dummy_read
First time decrement goes okay.
WARNING: at kernel/rtmutex.c:585 remove_waiter()
[<c0449eb7>] remove_waiter+0x105/0x14a
[<c061da36>] rt_mutex_slowlock+0x1af/0x20d
[<c061d66b>] rt_mutex_lock_interruptible+0x41/0x49
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<c044a2c5>] rt_down_interruptible+0x11/0x30
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<f9bfe0b0>] dummy_read+0x30/0x88 [dummy]
[<c04816b0>] vfs_read+0xa6/0x152
[<c0481b12>] sys_read+0x41/0x67
[<c040512a>] sysenter_past_esp+0x6b/0xa1
[<c0610000>] dump_one_state+0x31b/0x3f8
=======================
---------------------------
| preempt count: 00000001 ]
| 1-level deep critical section nesting:
----------------------------------------
.. [<c061e0ce>] .... __spin_lock_irq+0x17/0x27
.....[<00000000>] .. ( <= 0x0)
Do 1 up.
Do 2 times down.
We will block now, and if you press CTRL-C from here, we get an OOPS.
We are returning from the read().
dummy_release
dummy_open
dummy_read
First time decrement goes okay.
WARNING: at kernel/rtmutex.c:585 remove_waiter()
[<c0449eb7>] remove_waiter+0x105/0x14a
[<c061da36>] rt_mutex_slowlock+0x1af/0x20d
[<c061d66b>] rt_mutex_lock_interruptible+0x41/0x49
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<c044a2c5>] rt_down_interruptible+0x11/0x30
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<f9bfe0b0>] dummy_read+0x30/0x88 [dummy]
[<c04816b0>] vfs_read+0xa6/0x152
[<c0481b12>] sys_read+0x41/0x67
[<c040512a>] sysenter_past_esp+0x6b/0xa1
[<c0610000>] dump_one_state+0x31b/0x3f8
=======================
---------------------------
| preempt count: 00000001 ]
| 1-level deep critical section nesting:
----------------------------------------
.. [<c061e0ce>] .... __spin_lock_irq+0x17/0x27
.....[<00000000>] .. ( <= 0x0)
Do 1 up.
Do 2 times down.
We will block now, and if you press CTRL-C from here, we get an OOPS.
We are returning from the read().
dummy_release
dummy_open
dummy_read
First time decrement goes okay.
WARNING: at kernel/rtmutex.c:585 remove_waiter()
[<c0449eb7>] remove_waiter+0x105/0x14a
[<c061da36>] rt_mutex_slowlock+0x1af/0x20d
[<c061d66b>] rt_mutex_lock_interruptible+0x41/0x49
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<c044a2c5>] rt_down_interruptible+0x11/0x30
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<f9bfe0b0>] dummy_read+0x30/0x88 [dummy]
[<c04816b0>] vfs_read+0xa6/0x152
[<c0481b12>] sys_read+0x41/0x67
[<c040512a>] sysenter_past_esp+0x6b/0xa1
[<c0610000>] dump_one_state+0x31b/0x3f8
=======================
---------------------------
| preempt count: 00000001 ]
| 1-level deep critical section nesting:
----------------------------------------
.. [<c061e0ce>] .... __spin_lock_irq+0x17/0x27
.....[<00000000>] .. ( <= 0x0)
Do 1 up.
Do 2 times down.
We will block now, and if you press CTRL-C from here, we get an OOPS.
We are returning from the read().
dummy_release
dummy_open
dummy_read
First time decrement goes okay.
BUG: unable to handle kernel NULL pointer dereference at virtual address 00000000
printing eip:
c04f44ca
*pde = 00000000
Oops: 0000 [#1]
PREEMPT SMP
Modules linked in: dummy(P) ipt_MASQUERADE iptable_nat nf_nat bridge rfcomm l2cap bluetooth autofs4 sunrpc nf_conntrack_netbios_ns nf_conntrack_ipv4 xt_state nf_conntrack nfnetlink xt_tcpudp ipt_REJECT iptable_filter ip_tables x_tables vfat fat fuse dm_multipath ipv6 tuner snd_intel8x0 snd_ac97_codec ac97_bus snd_seq_dummy cx8800 cx88xx ir_common i2c_algo_bit video_buf snd_seq_oss snd_seq_midi_event tveeprom snd_seq videodev v4l1_compat compat_ioctl32 snd_seq_device snd_pcm_oss v4l2_common snd_mixer_oss firewire_ohci btcx_risc firewire_core snd_pcm skge crc_itu_t button snd_timer floppy i2c_i801 snd i2c_core iTCO_wdt sg iTCO_vendor_support soundcore sr_mod snd_page_alloc cdrom dm_snapshot dm_zero dm_mirror dm_mod ata_piix ata_generic libata sd_mod scsi_mod ext3 jbd mbcache uhci_hcd ohci_hcd ehci_hcd
CPU: 0
EIP: 0060:[<c04f44ca>] Tainted: P VLI
EFLAGS: 00010006 (2.6.23.1-rt5 #1)
EIP is at plist_add+0x4f/0x85
eax: fffffffc ebx: fffffffc ecx: dab12f2c edx: 00000000
esi: dab12f20 edi: dae045bc ebp: dae04030 esp: dab12eac
ds: 007b es: 007b fs: 00d8 gs: 0033 ss: 0068 preempt:00000003
Process cat (pid: 3632, ti=dab12000 task=d37660b0 task.ti=dab12000)
Stack: 000a80d2 c0734600 c06fe4a0 dae045b4 dae045bc dae045b4 dab12f0c c044a016
c0455b79 f9bfe080 00000000 f9bff984 dab12f0c dab12f20 00000000 f9bff984
00000002 00000000 c061d9b7 00000282 00000000 00000000 ffffffff 00000282
Call Trace:
[<c044a016>] task_blocks_on_rt_mutex+0x11a/0x17f
[<c0455b79>] add_preempt_count+0x12/0xcc
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<c061d9b7>] rt_mutex_slowlock+0x130/0x20d
[<c061d66b>] rt_mutex_lock_interruptible+0x41/0x49
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<c044a2c5>] rt_down_interruptible+0x11/0x30
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<f9bfe0b0>] dummy_read+0x30/0x88 [dummy]
[<c04816b0>] vfs_read+0xa6/0x152
[<c0481b12>] sys_read+0x41/0x67
[<c040512a>] sysenter_past_esp+0x6b/0xa1
[<c0610000>] dump_one_state+0x31b/0x3f8
=======================
---------------------------
| preempt count: 00000003 ]
| 3-level deep critical section nesting:
----------------------------------------
.. [<c061e045>] .... __spin_lock_irqsave+0x24/0x5c
.....[<00000000>] .. ( <= 0x0)
.. [<c061df53>] .... __spin_lock+0xd/0x1d
.....[<00000000>] .. ( <= 0x0)
.. [<c061e045>] .... __spin_lock_irqsave+0x24/0x5c
.....[<00000000>] .. ( <= 0x0)
Code: 24 04 a5 0d 6c c0 c7 04 24 7d 80 6a c0 e8 4e a0 f3 ff e8 ff 26 f1 ff 8b 1f 83 eb 04 eb 0d 8b 03 39 06 7c 15 8d 42 fc 74 32 89 c3 <8b> 53 04 0f 18 02 90 8d 43 04 39 f8 75 e5 8d 4b 04 8b 51 04 8d
EIP: [<c04f44ca>] plist_add+0x4f/0x85 SS:ESP 0068:dab12eac
note: cat[3632] exited with preempt_count 2
BUG: sleeping function called from invalid context cat(3632) at kernel/rtmutex.c:1175
in_atomic():1 [00000002], irqs_disabled():0
[<c061d713>] rt_mutex_lock+0x15/0x3f
[<c044a201>] __rt_down_read+0x32/0x3a
[<c0452d41>] acct_collect+0x38/0x13f
[<c0430a2f>] do_exit+0x1c6/0x748
[<c0406749>] die+0x226/0x25c
[<c061ffcd>] do_page_fault+0x53b/0x609
[<c04621cf>] find_lock_page+0x25/0x52
[<c061fa92>] do_page_fault+0x0/0x609
[<c061e5d2>] error_code+0x72/0x78
[<c04f44ca>] plist_add+0x4f/0x85
[<c044a016>] task_blocks_on_rt_mutex+0x11a/0x17f
[<c0455b79>] add_preempt_count+0x12/0xcc
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<c061d9b7>] rt_mutex_slowlock+0x130/0x20d
[<c061d66b>] rt_mutex_lock_interruptible+0x41/0x49
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<c044a2c5>] rt_down_interruptible+0x11/0x30
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<f9bfe0b0>] dummy_read+0x30/0x88 [dummy]
[<c04816b0>] vfs_read+0xa6/0x152
[<c0481b12>] sys_read+0x41/0x67
[<c040512a>] sysenter_past_esp+0x6b/0xa1
[<c0610000>] dump_one_state+0x31b/0x3f8
=======================
---------------------------
| preempt count: 00000002 ]
| 2-level deep critical section nesting:
----------------------------------------
.. [<c061df53>] .... __spin_lock+0xd/0x1d
.....[<00000000>] .. ( <= 0x0)
.. [<c061df53>] .... __spin_lock+0xd/0x1d
.....[<00000000>] .. ( <= 0x0)
BUG: scheduling while atomic: cat/0x10000003/3632, CPU#0
[<c061c1a4>] __sched_text_start+0xac/0x913
[<c0455b79>] add_preempt_count+0x12/0xcc
[<c047ce2f>] kmem_cache_free+0x8a/0x8f
[<c0455b79>] add_preempt_count+0x12/0xcc
[<c0429093>] __cond_resched+0x2b/0x45
[<c061cec7>] cond_resched+0x26/0x31
[<c042f90e>] put_files_struct+0x64/0xa7
[<c0430aad>] do_exit+0x244/0x748
[<c0406749>] die+0x226/0x25c
[<c061ffcd>] do_page_fault+0x53b/0x609
[<c04621cf>] find_lock_page+0x25/0x52
[<c061fa92>] do_page_fault+0x0/0x609
[<c061e5d2>] error_code+0x72/0x78
[<c04f44ca>] plist_add+0x4f/0x85
[<c044a016>] task_blocks_on_rt_mutex+0x11a/0x17f
[<c0455b79>] add_preempt_count+0x12/0xcc
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<c061d9b7>] rt_mutex_slowlock+0x130/0x20d
[<c061d66b>] rt_mutex_lock_interruptible+0x41/0x49
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<c044a2c5>] rt_down_interruptible+0x11/0x30
[<f9bfe080>] dummy_read+0x0/0x88 [dummy]
[<f9bfe0b0>] dummy_read+0x30/0x88 [dummy]
[<c04816b0>] vfs_read+0xa6/0x152
[<c0481b12>] sys_read+0x41/0x67
[<c040512a>] sysenter_past_esp+0x6b/0xa1
[<c0610000>] dump_one_state+0x31b/0x3f8
=======================
---------------------------
| preempt count: 10000003 ]
| 3-level deep critical section nesting:
----------------------------------------
.. [<c061df53>] .... __spin_lock+0xd/0x1d
.....[<00000000>] .. ( <= 0x0)
.. [<c061df53>] .... __spin_lock+0xd/0x1d
.....[<00000000>] .. ( <= 0x0)
.. [<c061c10b>] .... __sched_text_start+0x13/0x913
.....[<00000000>] .. ( <= 0x0)
dummy_release
- Follow-Ups:
- Re: [BUG on PREEMPT_RT, 2.6.23.1-rt5] in rt-mutex code and signals
- From: Steven Rostedt <[email protected]>
- Re: [BUG on PREEMPT_RT, 2.6.23.1-rt5] in rt-mutex code and signals
- References:
- [BUG on PREEMPT_RT, 2.6.23.1-rt5] in rt-mutex code and signals
- From: "Remy Bohmer" <[email protected]>
- Re: [BUG on PREEMPT_RT, 2.6.23.1-rt5] in rt-mutex code and signals
- From: Steven Rostedt <[email protected]>
- [BUG on PREEMPT_RT, 2.6.23.1-rt5] in rt-mutex code and signals
- Prev by Date: Re: Kconfig: ARCH=x86 causes wrong utsname.machine
- Next by Date: [PATCH 2/2] iwlwifi: add power management support -v2
- Previous by thread: Re: [BUG on PREEMPT_RT, 2.6.23.1-rt5] in rt-mutex code and signals
- Next by thread: Re: [BUG on PREEMPT_RT, 2.6.23.1-rt5] in rt-mutex code and signals
- Index(es):
 |