lockdep, false positive ? - Kernel

This is a discussion on lockdep, false positive ? - Kernel ; Hi ! I adapted lockdep to ppc64 and see this on my G5: Crash kernel location must be 0x2000000 Reserving 0MB of memory at 32MB for crashkernel (System RAM: 3584MB) DART table allocated at: c00000007f000000 Using PowerMac machine description Page ...

+ Reply to Thread
Results 1 to 4 of 4

Thread: lockdep, false positive ?

  1. lockdep, false positive ?

    Hi !

    I adapted lockdep to ppc64 and see this on my G5:

    Crash kernel location must be 0x2000000
    Reserving 0MB of memory at 32MB for crashkernel (System RAM: 3584MB)
    DART table allocated at: c00000007f000000
    Using PowerMac machine description
    Page orders: linear mapping = 24, virtual = 12, io = 12
    Found U3 memory controller & host bridge @ 0xf8000000 revision: 0x35
    Mapped at 0xd000080080000000
    Found a K2 mac-io controller, rev: 96, mapped at 0xd000080080041000
    PowerMac motherboard: PowerMac G5
    DART IOMMU initialized for U3 type chipset
    console [udbg0] enabled
    CPU maps initialized for 1 thread per core
    (thread shift is 0)
    Starting Linux PPC64 #18 SMP Wed Apr 9 14:04:12 EST 2008
    -----------------------------------------------------
    ppc64_pft_size = 0x0
    physicalMemorySize = 0xe0000000
    htab_address = 0xc00000015c000000
    htab_hash_mask = 0x7ffff
    -----------------------------------------------------
    Linux version 2.6.25-rc8 (benh@grosgo) (gcc version 4.1.3 20070929 (prerelease) (Ubuntu 4.1.2-16ubuntu2)) #18 SMP Wed Apr 9 14:04:12 EST 2008
    [boot]0012 Setup Arch
    Entering add_active_range(0, 0, 524288) 0 entries of 256 used
    Entering add_active_range(0, 1048576, 1441792) 1 entries of 256 used
    Found U3-AGP PCI host bridge. Firmware bus number: 240->255
    PCI host bridge /pci@0,f0000000 ranges:
    MEM 0x00000000f1000000..0x00000000f1ffffff -> 0x00000000f1000000
    IO 0x00000000f0000000..0x00000000f07fffff -> 0x0000000000000000
    MEM 0x0000000090000000..0x00000000afffffff -> 0x0000000090000000
    Can't get bus-range for /ht@0,f2000000, assume bus 0
    Found U3-HT PCI host bridge. Firmware bus number: 0->239
    PCI host bridge /ht@0,f2000000 (primary) ranges:
    via-pmu: Server Mode is disabled
    PMU driver v2 initialized for Core99, firmware: 0c
    nvram: Checking bank 0...
    nvram: gen0=398, gen1=397
    nvram: Active bank is: 0
    nvram: OF partition at 0x410
    nvram: XP partition at 0x1020
    nvram: NR partition at 0x1120
    Top of RAM: 0x160000000, Total RAM: 0xe0000000
    Memory hole size: 2048MB
    Zone PFN ranges:
    DMA 0 -> 1441792
    Normal 1441792 -> 1441792
    Movable zone start PFN for each node
    early_node_map[2] active PFN ranges
    0: 0 -> 524288
    0: 1048576 -> 1441792
    On node 0 totalpages: 917504
    DMA zone: 33792 pages used for memmap
    DMA zone: 0 pages reserved
    DMA zone: 883712 pages, LIFO batch:31
    Normal zone: 0 pages used for memmap
    Movable zone: 0 pages used for memmap
    [boot]0015 Setup Done
    Built 1 zonelists in Zone order, mobility grouping on. Total pages: 883712
    Kernel command line:
    mpic: Setting up MPIC " MPIC 1 " version 1.2 at 80040000, max 4 CPUs
    mpic: ISU size: 120, shift: 7, mask: 7f
    mpic: Initializing for 120 sources
    mpic: Setting up MPIC " MPIC 2 " version 1.2 at f8040000, max 4 CPUs
    mpic: ISU size: 124, shift: 7, mask: 7f
    mpic: Initializing for 124 sources
    PID hash table entries: 4096 (order: 12, 32768 bytes)
    time_init: decrementer frequency = 33.333333 MHz
    time_init: processor frequency = 2500.000000 MHz
    clocksource: timebase mult[7800001] shift[22] registered
    clockevent: decrementer mult[888] shift[16] cpu[0]
    Console: colour dummy device 80x25
    console handover: boot [udbg0] -> real [tty0]
    Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
    .... MAX_LOCKDEP_SUBCLASSES: 8
    .... MAX_LOCK_DEPTH: 48
    .... MAX_LOCKDEP_KEYS: 2048
    .... CLASSHASH_SIZE: 1024
    .... MAX_LOCKDEP_ENTRIES: 8192
    .... MAX_LOCKDEP_CHAINS: 16384
    .... CHAINHASH_SIZE: 8192
    memory used by lock dependency info: 1712 kB
    per task-struct memory footprint: 3456 bytes
    ------------------------
    | Locking API testsuite:
    ----------------------------------------------------------------------------
    | spin |wlock |rlock |mutex | wsem | rsem |
    --------------------------------------------------------------------------
    A-A deadlock: ok | ok | ok | ok | ok | ok |
    A-B-B-A deadlock: ok | ok | ok | ok | ok | ok |
    A-B-B-C-C-A deadlock: ok | ok | ok | ok | ok | ok |
    A-B-C-A-B-C deadlock: ok | ok | ok | ok | ok | ok |
    A-B-B-C-C-D-D-A deadlock: ok | ok | ok | ok | ok | ok |
    A-B-C-D-B-D-D-A deadlock: ok | ok | ok | ok | ok | ok |
    A-B-C-D-B-C-D-A deadlock: ok | ok | ok | ok | ok | ok |
    double unlock: ok | ok | ok | ok | ok | ok |
    initialize held: ok | ok | ok | ok | ok | ok |
    bad unlock order: ok | ok | ok | ok | ok | ok |
    --------------------------------------------------------------------------
    recursive read-lock: | ok | | ok |
    recursive read-lock #2: | ok | | ok |
    mixed read-write-lock: | ok | | ok |
    mixed write-read-lock: | ok | | ok |
    --------------------------------------------------------------------------
    hard-irqs-on + irq-safe-A/12: ok | ok | ok |
    soft-irqs-on + irq-safe-A/12: ok | ok | ok |
    hard-irqs-on + irq-safe-A/21: ok | ok | ok |
    soft-irqs-on + irq-safe-A/21: ok | ok | ok |
    sirq-safe-A => hirqs-on/12: ok | ok | ok |
    sirq-safe-A => hirqs-on/21: ok | ok | ok |
    hard-safe-A + irqs-on/12: ok | ok | ok |
    soft-safe-A + irqs-on/12: ok | ok | ok |
    hard-safe-A + irqs-on/21: ok | ok | ok |
    soft-safe-A + irqs-on/21: ok | ok | ok |
    hard-safe-A + unsafe-B #1/123: ok | ok | ok |
    soft-safe-A + unsafe-B #1/123: ok | ok | ok |
    hard-safe-A + unsafe-B #1/132: ok | ok | ok |
    soft-safe-A + unsafe-B #1/132: ok | ok | ok |
    hard-safe-A + unsafe-B #1/213: ok | ok | ok |
    soft-safe-A + unsafe-B #1/213: ok | ok | ok |
    hard-safe-A + unsafe-B #1/231: ok | ok | ok |
    soft-safe-A + unsafe-B #1/231: ok | ok | ok |
    hard-safe-A + unsafe-B #1/312: ok | ok | ok |
    soft-safe-A + unsafe-B #1/312: ok | ok | ok |
    hard-safe-A + unsafe-B #1/321: ok | ok | ok |
    soft-safe-A + unsafe-B #1/321: ok | ok | ok |
    hard-safe-A + unsafe-B #2/123: ok | ok | ok |
    soft-safe-A + unsafe-B #2/123: ok | ok | ok |
    hard-safe-A + unsafe-B #2/132: ok | ok | ok |
    soft-safe-A + unsafe-B #2/132: ok | ok | ok |
    hard-safe-A + unsafe-B #2/213: ok | ok | ok |
    soft-safe-A + unsafe-B #2/213: ok | ok | ok |
    hard-safe-A + unsafe-B #2/231: ok | ok | ok |
    soft-safe-A + unsafe-B #2/231: ok | ok | ok |
    hard-safe-A + unsafe-B #2/312: ok | ok | ok |
    soft-safe-A + unsafe-B #2/312: ok | ok | ok |
    hard-safe-A + unsafe-B #2/321: ok | ok | ok |
    soft-safe-A + unsafe-B #2/321: ok | ok | ok |
    hard-irq lock-inversion/123: ok | ok | ok |
    soft-irq lock-inversion/123: ok | ok | ok |
    hard-irq lock-inversion/132: ok | ok | ok |
    soft-irq lock-inversion/132: ok | ok | ok |
    hard-irq lock-inversion/213: ok | ok | ok |
    soft-irq lock-inversion/213: ok | ok | ok |
    hard-irq lock-inversion/231: ok | ok | ok |
    soft-irq lock-inversion/231: ok | ok | ok |
    hard-irq lock-inversion/312: ok | ok | ok |
    soft-irq lock-inversion/312: ok | ok | ok |
    hard-irq lock-inversion/321: ok | ok | ok |
    soft-irq lock-inversion/321: ok | ok | ok |
    hard-irq read-recursion/123: ok |
    soft-irq read-recursion/123: ok |
    hard-irq read-recursion/132: ok |
    soft-irq read-recursion/132: ok |
    hard-irq read-recursion/213: ok |
    soft-irq read-recursion/213: ok |
    hard-irq read-recursion/231: ok |
    soft-irq read-recursion/231: ok |
    hard-irq read-recursion/312: ok |
    soft-irq read-recursion/312: ok |
    hard-irq read-recursion/321: ok |
    soft-irq read-recursion/321: ok |
    -------------------------------------------------------
    Good, all 218 testcases passed! |
    ---------------------------------
    Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes)
    Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes)
    Memory: 3431144k/3670016k available (7668k kernel code, 2335348k reserved, 1228k data, 4246k bss, 676k init)
    SLUB: Genslabs=12, HWalign=128, Order=0-1, MinObjects=4, CPUs=2, Nodes=1
    Calibrating delay loop... 66.56 BogoMIPS (lpj=133120)
    Mount-cache hash table entries: 256
    PowerMac SMP probe found 2 cpus
    KeyWest i2c @0xf8001003 irq 16 /u3@0,f8000000/i2c@f8001000
    channel 0 bus
    channel 1 bus
    KeyWest i2c @0x80018000 irq 26 /ht@0,f2000000/pci@3/mac-io@7/i2c@18000
    channel 0 bus
    PMU i2c /ht@0,f2000000/pci@3/mac-io@7/via-pmu@16000/pmu-i2c
    channel 1 bus
    channel 2 bus
    Processor timebase sync using Pulsar i2c clock
    mpic: requesting IPIs ...
    Processor 1 found.
    clockevent: decrementer mult[888] shift[16] cpu[1]
    Brought up 2 CPUs
    CPU0 attaching sched-domain:
    domain 0: span 3
    groups: 1 2
    CPU1 attaching sched-domain:
    domain 0: span 3
    groups: 2 1
    khelper used greatest stack depth: 10976 bytes left
    net_namespace: 1000 bytes
    NET: Registered protocol family 16
    PCI: Probing PCI hardware
    IOMMU table initialized, virtual merging enabled
    PCI: Closing bogus Apple Firmware region 2 on bus 0x01
    PCI: Closing bogus Apple Firmware region 2 on bus 0x02
    PCI: Closing bogus Apple Firmware region 2 on bus 0x03
    PCI: Closing bogus Apple Firmware region 2 on bus 0x04
    PCI: Closing bogus Apple Firmware region 2 on bus 0x05
    PCI: Bridge: 0001:00:01.0
    IO window: disabled.
    MEM window: disabled.
    PREFETCH window: disabled.
    PCI: Bridge: 0001:00:02.0
    IO window: disabled.
    MEM window: disabled.
    PREFETCH window: disabled.
    PCI: Bridge: 0001:00:03.0
    IO window: disabled.
    MEM window: 0x80000000-0x800fffff
    PREFETCH window: disabled.
    PCI: Bridge: 0001:00:04.0
    IO window: disabled.
    MEM window: 0x80100000-0x801fffff
    PREFETCH window: disabled.
    PCI: Bridge: 0001:00:05.0
    IO window: disabled.
    MEM window: 0x80200000-0x802fffff
    PREFETCH window: disabled.
    PCI: Bridge: 0001:00:06.0
    IO window: disabled.
    MEM window: 0x80300000-0x805fffff
    PREFETCH window: disabled.
    PCI: Bridge: 0001:00:07.0
    IO window: disabled.
    MEM window: 0x80600000-0x806fffff
    PREFETCH window: disabled.
    PCI: Probing PCI hardware done
    Registering pmac pic with sysfs...
    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
    Switched to high resolution mode on CPU 0
    Switched to high resolution mode on CPU 1
    NET: Registered protocol family 2
    IP route cache hash table entries: 131072 (order: 8, 1048576 bytes)
    TCP established hash table entries: 524288 (order: 11, 8388608 bytes)
    TCP bind hash table entries: 65536 (order: 10, 4194304 bytes)
    TCP: Hash tables configured (established 524288 bind 65536)
    TCP reno registered
    nvram_init: Could not find nvram partition for nvram buffered error logging.
    Registering G5 CPU frequency driver
    Frequency method: i2c/pfunc, Voltage method: i2c/pfunc
    Low: 2000 Mhz, High: 2500 Mhz, Cur: 2000 MHz
    Total HugeTLB memory allocated, 0
    Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
    Block layer SCSI generic (bsg) driver version 0.4 loaded (major 254)
    io scheduler noop registered
    io scheduler anticipatory registered (default)
    io scheduler deadline registered
    io scheduler cfq registered
    pci 0001:00:01.0: MSI quirk detected; subordinate MSI disabled
    pci 0001:00:01.0: AMD8131 rev 12 detected; disabling PCI-X MMRBC
    pci 0001:00:02.0: MSI quirk detected; subordinate MSI disabled
    pci 0001:00:02.0: AMD8131 rev 12 detected; disabling PCI-X MMRBC
    PCI: Enabling device 0000:f0:10.0 (0006 -> 0007)
    radeonfb: Found Open Firmware ROM Image
    radeonfb: Retrieved PLL infos from Open Firmware
    radeonfb: Reference=27.00 MHz (RefDiv=12) Memory=310.00 Mhz, System=400.00 MHz
    radeonfb: PLL min 12000 max 35000
    i2c-adapter i2c-2: unable to read EDID block.
    i2c-adapter i2c-2: unable to read EDID block.
    i2c-adapter i2c-2: unable to read EDID block.
    radeonfb: Monitor 1 type CRT found
    radeonfb: EDID probed
    radeonfb: Monitor 2 type no found
    Display is GTF capable
    Attempt to iounmap early bolted mapping at 0xd0000800800c1000
    Console: switching to colour frame buffer device 160x64
    radeonfb (0000:f0:10.0): ATI Radeon AR
    Generic RTC Driver v1.07
    Linux agpgart interface v0.103
    [drm] Initialized drm 1.1.0 20060810
    [drm] Initialized radeon 1.28.0 20060524 on minor 0
    pmac_zilog: 0.6 (Benjamin Herrenschmidt )
    ttyS0 at MMIO 0x80013020 (irq = 22) is a Z85c30 ESCC - Serial port
    ttyS1 at MMIO 0x80013000 (irq = 23) is a Z85c30 ESCC - Serial port
    brd: module loaded
    loop: module loaded
    Intel(R) PRO/1000 Network Driver - version 7.3.20-k2
    Copyright (c) 1999-2006 Intel Corporation.
    sungem.c:v0.98 8/24/03 David S. Miller (davem@redhat.com)
    PHY ID: 2062e0, addr: 1
    eth0: Sun GEM (PCI) 10/100/1000BaseT Ethernet 00:0d:93:43:75:28
    eth0: Found BCM5421-K2 PHY
    MacIO PCI driver attached to K2 chipset
    input: Macintosh mouse button emulation as /class/input/input0
    PowerMac G5 Thermal control driver 1.3
    Detected fan controls:
    0: PWM fan, id 1, location: BACKSIDE,SYS CTRLR FAN
    1: RPM fan, id 2, location: DRIVE BAY
    2: PWM fan, id 2, location: SLOT,PCI FAN
    3: RPM fan, id 3, location: CPU A INTAKE
    4: RPM fan, id 4, location: CPU A EXHAUST
    5: RPM fan, id 5, location: CPU B INTAKE
    6: RPM fan, id 6, location: CPU B EXHAUST
    7: RPM fan, id 1, location: CPU A PUMP
    8: RPM fan, id 0, location: CPU B PUMP
    Uniform Multi-Platform E-IDE driver
    ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
    PCI: Enabling device 0001:03:0d.0 (0014 -> 0016)
    ide0: Found Apple K2 ATA-6 controller, bus ID 3, irq 39
    Probing IDE interface ide0...
    hda: HL-DT-ST DVD-RW GWA-4082B, ATAPI CD/DVD-ROM drive
    hda: host max PIO4 wanted PIO255(auto-tune) selected PIO4
    hda: UDMA/66 mode selected
    ide0 at 0xd000080082352000-0xd000080082352007,0xd000080082352160 on irq 39
    hda: ATAPI 32X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache
    Uniform CD-ROM driver Revision: 3.20
    st: Version 20080221, fixed bufsize 32768, s/g segs 256
    Driver 'st' needs updating - please use bus_type methods
    Driver 'sd' needs updating - please use bus_type methods
    Driver 'sr' needs updating - please use bus_type methods
    sata_svw 0001:05:0c.0: version 2.3
    scsi0 : sata_svw
    scsi1 : sata_svw
    scsi2 : sata_svw
    scsi3 : sata_svw
    ata1: SATA max UDMA/133 mmio m8192@0x80600000 port 0x80600000 irq 17
    ata2: SATA max UDMA/133 mmio m8192@0x80600000 port 0x80600100 irq 17
    ata3: SATA max UDMA/133 mmio m8192@0x80600000 port 0x80600200 irq 17
    ata4: SATA max UDMA/133 mmio m8192@0x80600000 port 0x80600300 irq 17
    ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
    ata1.00: ATA-7: ST3250410AS, 3.AAC, max UDMA/133
    ata1.00: 488397168 sectors, multi 16: LBA48 NCQ (depth 0/32)
    ata1.00: configured for UDMA/133
    eth0: Link is up at 100 Mbps, full-duplex.
    ata2: SATA link down (SStatus 4 SControl 300)
    ata3: SATA link down (SStatus 4 SControl 300)
    ata4: SATA link down (SStatus 4 SControl 300)
    scsi 0:0:0:0: Direct-Access ATA ST3250410AS 3.AA PQ: 0 ANSI: 5
    sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors (250059 MB)
    sd 0:0:0:0: [sda] Write Protect is off
    sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
    sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
    sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors (250059 MB)
    sd 0:0:0:0: [sda] Write Protect is off
    sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
    sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
    sda: [mac] sda1 sda2 sda3 sda4
    sd 0:0:0:0: [sda] Attached SCSI disk
    sd 0:0:0:0: Attached scsi generic sg0 type 0
    PCI: Enabling device 0001:03:0e.0 (0000 -> 0002)
    ohci1394: fw-host0: OHCI-1394 1.0 (PCI): IRQ=[40] MMIO=[80200000-802007ff] Max Packet=[4096] IR/IT contexts=[8/8]
    ieee1394: raw1394: /dev/raw1394 device initialized
    PCI: Enabling device 0001:02:0b.2 (0004 -> 0006)
    ehci_hcd 0001:02:0b.2: EHCI Host Controller
    ehci_hcd 0001:02:0b.2: new USB bus registered, assigned bus number 1
    ehci_hcd 0001:02:0b.2: irq 63, io mem 0x80100000
    ehci_hcd 0001:02:0b.2: 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: 5 ports detected
    ohci_hcd: 2006 August 04 USB 1.1 'Open' Host Controller (OHCI) Driver
    PCI: Enabling device 0001:01:08.0 (0000 -> 0002)
    ohci_hcd 0001:01:08.0: OHCI Host Controller
    ohci_hcd 0001:01:08.0: new USB bus registered, assigned bus number 2
    ohci_hcd 0001:01:08.0: irq 27, io mem 0x80081000
    usb usb2: configuration #1 chosen from 1 choice
    hub 2-0:1.0: USB hub found
    hub 2-0:1.0: 2 ports detected
    PCI: Enabling device 0001:01:09.0 (0000 -> 0002)
    ohci_hcd 0001:01:09.0: OHCI Host Controller
    ohci_hcd 0001:01:09.0: new USB bus registered, assigned bus number 3
    ohci_hcd 0001:01:09.0: irq 28, io mem 0x80080000
    usb usb3: configuration #1 chosen from 1 choice
    hub 3-0:1.0: USB hub found
    hub 3-0:1.0: 2 ports detected
    PCI: Enabling device 0001:02:0b.0 (0000 -> 0002)
    ohci_hcd 0001:02:0b.0: OHCI Host Controller
    ohci_hcd 0001:02:0b.0: new USB bus registered, assigned bus number 4
    ohci_hcd 0001:02:0b.0: irq 63, io mem 0x80102000
    usb usb4: configuration #1 chosen from 1 choice
    hub 4-0:1.0: USB hub found
    hub 4-0:1.0: 3 ports detected
    PCI: Enabling device 0001:02:0b.1 (0000 -> 0002)
    ohci_hcd 0001:02:0b.1: OHCI Host Controller
    ohci_hcd 0001:02:0b.1: new USB bus registered, assigned bus number 5
    ohci_hcd 0001:02:0b.1: irq 63, io mem 0x80101000
    usb usb5: configuration #1 chosen from 1 choice
    hub 5-0:1.0: USB hub found
    hub 5-0:1.0: 2 ports detected
    ieee1394: Host added: ID:BUS[0-00:1023] GUID[000d93fffe437528]
    usb 5-2: new full speed USB device using ohci_hcd and address 2
    usb 5-2: configuration #1 chosen from 1 choice
    hub 5-2:1.0: USB hub found
    hub 5-2:1.0: 3 ports detected
    usb 5-2.1: new low speed USB device using ohci_hcd and address 3
    usb 5-2.1: configuration #1 chosen from 1 choice
    usb 5-2.3: new full speed USB device using ohci_hcd and address 4
    usb 5-2.3: configuration #1 chosen from 1 choice
    usbcore: registered new interface driver usblp
    Initializing USB Mass Storage driver...
    usbcore: registered new interface driver usb-storage
    USB Mass Storage support registered.
    mice: PS/2 mouse device common for all mice
    i2c /dev entries driver
    PowerMac i2c bus pmu 2 registered
    PowerMac i2c bus pmu 1 registered
    PowerMac i2c bus mac-io 0 registered
    PowerMac i2c bus u3 1 registered
    Liquid cooling pumps detected, using new algorithm !
    PowerMac i2c bus u3 0 registered
    md: linear personality registered for level -1
    FCU Initialized, RPM fan shift is 3
    md: raid0 personality registered for level 0
    md: raid1 personality registered for level 1
    device-mapper: ioctl: 4.13.0-ioctl (2007-10-18) initialised: dm-devel@redhat.com
    usbcore: registered new interface driver hiddev
    input: HID 04b3:3107 as /class/input/input1
    input: USB HID v1.00 Mouse [HID 04b3:3107] on usb-0001:02:0b.1-2.1
    input: Mitsumi Electric Apple Extended USB Keyboard as /class/input/input2
    input: USB HID v1.10 Keyboard [Mitsumi Electric Apple Extended USB Keyboard] on usb-0001:02:0b.1-2.3
    input: Mitsumi Electric Apple Extended USB Keyboard as /class/input/input3
    input: USB HID v1.10 Device [Mitsumi Electric Apple Extended USB Keyboard] on usb-0001:02:0b.1-2.3
    usbcore: registered new interface driver usbhid
    drivers/hid/usbhid/hid-core.c: v2.6:USB HID core driver
    oprofile: using ppc64/970 performance monitoring.
    IPv4 over IPv4 tunneling driver
    TCP cubic registered
    NET: Registered protocol family 1
    NET: Registered protocol family 17
    RPC: Registered udp transport module.
    RPC: Registered tcp transport module.
    input: PMU as /class/input/input4
    md: Autodetecting RAID arrays.
    md: Scanned 0 and added 0 devices.
    md: autorun ...
    md: ... autorun DONE.
    kjournald starting. Commit interval 5 seconds
    EXT3-fs: mounted filesystem with ordered data mode.
    VFS: Mounted root (ext3 filesystem) readonly.
    Freeing unused kernel memory: 676k freed
    khelper used greatest stack depth: 9072 bytes left
    runlevel used greatest stack depth: 8880 bytes left
    grep used greatest stack depth: 6864 bytes left
    Adding 9937800k swap on /dev/sda4. Priority:-1 extents:1 across:9937800k
    EXT3 FS on sda3, internal journal
    ioctl32(pbbuttonsd:3234): Unknown cmd fd(9) cmd(40044201){t:'B';sz:4} arg(ff91c9dc) on /dev/pmu
    warning: `avahi-daemon' uses 32-bit capabilities (legacy support in use)
    eth0: Link is up at 100 Mbps, full-duplex.
    eth0: Pause is enabled (rxfifo: 10240 off: 7168 on: 5632)
    hcid used greatest stack depth: 6560 bytes left
    ioctl32(gnome-terminal:4017): Unknown cmd fd(20) cmd(0000530b){t:'S';sz:0} arg(0fbfe7c4) on /dev/pts/0
    ioctl32(gnome-terminal:4017): Unknown cmd fd(20) cmd(0000530b){t:'S';sz:0} arg(0fbfe7cc) on /dev/pts/0
    ioctl32(gnome-terminal:4017): Unknown cmd fd(20) cmd(0000530b){t:'S';sz:0} arg(0fbfe7d4) on /dev/pts/0
    jockey-gtk used greatest stack depth: 6368 bytes left

    =============================================
    [ INFO: possible recursive locking detected ]
    2.6.25-rc8 #18
    ---------------------------------------------
    swapper/0 is trying to acquire lock:
    (&dev->event_lock){++..}, at: [] .input_event+0x64/0xd0

    but task is already holding lock:
    (&dev->event_lock){++..}, at: [] .input_event+0x64/0xd0

    other info that might help us debug this:
    2 locks held by swapper/0:
    #0: (&dev->event_lock){++..}, at: [] .input_event+0x64/0xd0
    #1: (rcu_read_lock){..--}, at: [] .input_pass_event+0x0/0x160

    stack backtrace:
    Call Trace:
    [c00000000fff2fa0] [c00000000000f58c] .show_stack+0x78/0x1c8 (unreliable)
    [c00000000fff3050] [c00000000000f6fc] .dump_stack+0x20/0x34
    [c00000000fff30d0] [c0000000000800c4] .__lock_acquire+0xac4/0xee0
    [c00000000fff31c0] [c0000000000805b8] .lock_acquire+0xd8/0x124
    [c00000000fff3280] [c0000000004ee1a0] ._spin_lock_irqsave+0x60/0xc8
    [c00000000fff3320] [c0000000003ef5f8] .input_event+0x64/0xd0
    [c00000000fff33d0] [c000000000338958] .mac_hid_mouse_emulate_buttons+0x94/0xf8
    [c00000000fff3450] [c0000000002b36bc] .kbd_event+0x1d0/0x82c
    [c00000000fff3540] [c0000000003ed9b0] .input_pass_event+0xe0/0x160
    [c00000000fff35f0] [c0000000003ee724] .input_handle_event+0x4fc/0x544
    [c00000000fff36b0] [c0000000003ef628] .input_event+0x94/0xd0
    [c00000000fff3760] [c0000000004229a4] .hidinput_hid_event+0x358/0x3bc
    [c00000000fff3810] [c00000000041d458] .hid_process_event+0x4c/0xc4
    [c00000000fff38c0] [c00000000041d874] .hid_input_field+0x3a4/0x3f0
    [c00000000fff39a0] [c00000000041d9d4] .hid_input_report+0x114/0x18c
    [c00000000fff3a50] [c0000000004263b4] .hid_irq_in+0xb0/0x1c8
    [c00000000fff3af0] [c0000000003bff50] .usb_hcd_giveback_urb+0xe8/0x15c
    [c00000000fff3b90] [c0000000003db9d8] .finish_urb+0xcc/0x15c
    [c00000000fff3c30] [c0000000003dbad4] .takeback_td+0x6c/0x19c
    [c00000000fff3cd0] [c0000000003df4cc] .ohci_irq+0x4d0/0x750
    [c00000000fff3db0] [c0000000003c0590] .usb_hcd_irq+0x58/0xc8
    [c00000000fff3e40] [c000000000091708] .handle_IRQ_event+0x60/0xe0
    [c00000000fff3ef0] [c000000000093950] .handle_fasteoi_irq+0x130/0x1d0
    [c00000000fff3f90] [c0000000000223b0] .call_handle_irq+0x1c/0x2c
    [c00000015a11fac0] [c00000000000c508] .do_IRQ+0x114/0x1d0
    [c00000015a11fb60] [c000000000004694] hardware_interrupt_entry+0x1c/0x20
    --- Exception: 501 at .cpu_idle+0xe8/0x150
    LR = .cpu_idle+0xe8/0x150
    [c00000015a11fe50] [c000000000011da4] .cpu_idle+0xbc/0x150 (unreliable)
    [c00000015a11fef0] [c0000000004f10e4] .start_secondary+0x15c/0x188
    [c00000015a11ff90] [c0000000000073c0] .start_secondary_prolog+0xc/0x10

    Now, I -think- that this is fine, that is, I believe the lock is first
    taken by the HID/kbd driver calling input_event, and then by mac-hid
    mouse emulation which has a separate input_dev and thus a separate
    instance of the lock.

    (I may be wrong and we -might- have a real bug here, but I'll let
    others more familiar with the input layer have a look).

    Is it a known issue that lockdep can issue false positives like that ?

    Cheers,
    Ben.


    --
    To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
    the body of a message to majordomo@vger.kernel.org
    More majordomo info at http://vger.kernel.org/majordomo-info.html
    Please read the FAQ at http://www.tux.org/lkml/

  2. Re: lockdep, false positive ?

    On Wed, 2008-04-09 at 14:16 +1000, Benjamin Herrenschmidt wrote:
    > Hi !
    >
    > I adapted lockdep to ppc64 and see this on my G5:
    >
    > Crash kernel location must be 0x2000000
    > Reserving 0MB of memory at 32MB for crashkernel (System RAM: 3584MB)
    > DART table allocated at: c00000007f000000
    > Using PowerMac machine description
    > Page orders: linear mapping = 24, virtual = 12, io = 12
    > Found U3 memory controller & host bridge @ 0xf8000000 revision: 0x35
    > Mapped at 0xd000080080000000
    > Found a K2 mac-io controller, rev: 96, mapped at 0xd000080080041000
    > PowerMac motherboard: PowerMac G5
    > DART IOMMU initialized for U3 type chipset
    > console [udbg0] enabled
    > CPU maps initialized for 1 thread per core
    > (thread shift is 0)
    > Starting Linux PPC64 #18 SMP Wed Apr 9 14:04:12 EST 2008
    > -----------------------------------------------------
    > ppc64_pft_size = 0x0
    > physicalMemorySize = 0xe0000000
    > htab_address = 0xc00000015c000000
    > htab_hash_mask = 0x7ffff
    > -----------------------------------------------------
    > Linux version 2.6.25-rc8 (benh@grosgo) (gcc version 4.1.3 20070929 (prerelease) (Ubuntu 4.1.2-16ubuntu2)) #18 SMP Wed Apr 9 14:04:12 EST 2008
    > [boot]0012 Setup Arch
    > Entering add_active_range(0, 0, 524288) 0 entries of 256 used
    > Entering add_active_range(0, 1048576, 1441792) 1 entries of 256 used
    > Found U3-AGP PCI host bridge. Firmware bus number: 240->255
    > PCI host bridge /pci@0,f0000000 ranges:
    > MEM 0x00000000f1000000..0x00000000f1ffffff -> 0x00000000f1000000
    > IO 0x00000000f0000000..0x00000000f07fffff -> 0x0000000000000000
    > MEM 0x0000000090000000..0x00000000afffffff -> 0x0000000090000000
    > Can't get bus-range for /ht@0,f2000000, assume bus 0
    > Found U3-HT PCI host bridge. Firmware bus number: 0->239
    > PCI host bridge /ht@0,f2000000 (primary) ranges:
    > via-pmu: Server Mode is disabled
    > PMU driver v2 initialized for Core99, firmware: 0c
    > nvram: Checking bank 0...
    > nvram: gen0=398, gen1=397
    > nvram: Active bank is: 0
    > nvram: OF partition at 0x410
    > nvram: XP partition at 0x1020
    > nvram: NR partition at 0x1120
    > Top of RAM: 0x160000000, Total RAM: 0xe0000000
    > Memory hole size: 2048MB
    > Zone PFN ranges:
    > DMA 0 -> 1441792
    > Normal 1441792 -> 1441792
    > Movable zone start PFN for each node
    > early_node_map[2] active PFN ranges
    > 0: 0 -> 524288
    > 0: 1048576 -> 1441792
    > On node 0 totalpages: 917504
    > DMA zone: 33792 pages used for memmap
    > DMA zone: 0 pages reserved
    > DMA zone: 883712 pages, LIFO batch:31
    > Normal zone: 0 pages used for memmap
    > Movable zone: 0 pages used for memmap
    > [boot]0015 Setup Done
    > Built 1 zonelists in Zone order, mobility grouping on. Total pages: 883712
    > Kernel command line:
    > mpic: Setting up MPIC " MPIC 1 " version 1.2 at 80040000, max 4 CPUs
    > mpic: ISU size: 120, shift: 7, mask: 7f
    > mpic: Initializing for 120 sources
    > mpic: Setting up MPIC " MPIC 2 " version 1.2 at f8040000, max 4 CPUs
    > mpic: ISU size: 124, shift: 7, mask: 7f
    > mpic: Initializing for 124 sources
    > PID hash table entries: 4096 (order: 12, 32768 bytes)
    > time_init: decrementer frequency = 33.333333 MHz
    > time_init: processor frequency = 2500.000000 MHz
    > clocksource: timebase mult[7800001] shift[22] registered
    > clockevent: decrementer mult[888] shift[16] cpu[0]
    > Console: colour dummy device 80x25
    > console handover: boot [udbg0] -> real [tty0]
    > Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
    > .... MAX_LOCKDEP_SUBCLASSES: 8
    > .... MAX_LOCK_DEPTH: 48
    > .... MAX_LOCKDEP_KEYS: 2048
    > .... CLASSHASH_SIZE: 1024
    > .... MAX_LOCKDEP_ENTRIES: 8192
    > .... MAX_LOCKDEP_CHAINS: 16384
    > .... CHAINHASH_SIZE: 8192
    > memory used by lock dependency info: 1712 kB
    > per task-struct memory footprint: 3456 bytes
    > ------------------------
    > | Locking API testsuite:
    > ----------------------------------------------------------------------------
    > | spin |wlock |rlock |mutex | wsem | rsem |
    > --------------------------------------------------------------------------
    > A-A deadlock: ok | ok | ok | ok | ok | ok |
    > A-B-B-A deadlock: ok | ok | ok | ok | ok | ok |
    > A-B-B-C-C-A deadlock: ok | ok | ok | ok | ok | ok |
    > A-B-C-A-B-C deadlock: ok | ok | ok | ok | ok | ok |
    > A-B-B-C-C-D-D-A deadlock: ok | ok | ok | ok | ok | ok |
    > A-B-C-D-B-D-D-A deadlock: ok | ok | ok | ok | ok | ok |
    > A-B-C-D-B-C-D-A deadlock: ok | ok | ok | ok | ok | ok |
    > double unlock: ok | ok | ok | ok | ok | ok |
    > initialize held: ok | ok | ok | ok | ok | ok |
    > bad unlock order: ok | ok | ok | ok | ok | ok |
    > --------------------------------------------------------------------------
    > recursive read-lock: | ok | | ok |
    > recursive read-lock #2: | ok | | ok |
    > mixed read-write-lock: | ok | | ok |
    > mixed write-read-lock: | ok | | ok |
    > --------------------------------------------------------------------------
    > hard-irqs-on + irq-safe-A/12: ok | ok | ok |
    > soft-irqs-on + irq-safe-A/12: ok | ok | ok |
    > hard-irqs-on + irq-safe-A/21: ok | ok | ok |
    > soft-irqs-on + irq-safe-A/21: ok | ok | ok |
    > sirq-safe-A => hirqs-on/12: ok | ok | ok |
    > sirq-safe-A => hirqs-on/21: ok | ok | ok |
    > hard-safe-A + irqs-on/12: ok | ok | ok |
    > soft-safe-A + irqs-on/12: ok | ok | ok |
    > hard-safe-A + irqs-on/21: ok | ok | ok |
    > soft-safe-A + irqs-on/21: ok | ok | ok |
    > hard-safe-A + unsafe-B #1/123: ok | ok | ok |
    > soft-safe-A + unsafe-B #1/123: ok | ok | ok |
    > hard-safe-A + unsafe-B #1/132: ok | ok | ok |
    > soft-safe-A + unsafe-B #1/132: ok | ok | ok |
    > hard-safe-A + unsafe-B #1/213: ok | ok | ok |
    > soft-safe-A + unsafe-B #1/213: ok | ok | ok |
    > hard-safe-A + unsafe-B #1/231: ok | ok | ok |
    > soft-safe-A + unsafe-B #1/231: ok | ok | ok |
    > hard-safe-A + unsafe-B #1/312: ok | ok | ok |
    > soft-safe-A + unsafe-B #1/312: ok | ok | ok |
    > hard-safe-A + unsafe-B #1/321: ok | ok | ok |
    > soft-safe-A + unsafe-B #1/321: ok | ok | ok |
    > hard-safe-A + unsafe-B #2/123: ok | ok | ok |
    > soft-safe-A + unsafe-B #2/123: ok | ok | ok |
    > hard-safe-A + unsafe-B #2/132: ok | ok | ok |
    > soft-safe-A + unsafe-B #2/132: ok | ok | ok |
    > hard-safe-A + unsafe-B #2/213: ok | ok | ok |
    > soft-safe-A + unsafe-B #2/213: ok | ok | ok |
    > hard-safe-A + unsafe-B #2/231: ok | ok | ok |
    > soft-safe-A + unsafe-B #2/231: ok | ok | ok |
    > hard-safe-A + unsafe-B #2/312: ok | ok | ok |
    > soft-safe-A + unsafe-B #2/312: ok | ok | ok |
    > hard-safe-A + unsafe-B #2/321: ok | ok | ok |
    > soft-safe-A + unsafe-B #2/321: ok | ok | ok |
    > hard-irq lock-inversion/123: ok | ok | ok |
    > soft-irq lock-inversion/123: ok | ok | ok |
    > hard-irq lock-inversion/132: ok | ok | ok |
    > soft-irq lock-inversion/132: ok | ok | ok |
    > hard-irq lock-inversion/213: ok | ok | ok |
    > soft-irq lock-inversion/213: ok | ok | ok |
    > hard-irq lock-inversion/231: ok | ok | ok |
    > soft-irq lock-inversion/231: ok | ok | ok |
    > hard-irq lock-inversion/312: ok | ok | ok |
    > soft-irq lock-inversion/312: ok | ok | ok |
    > hard-irq lock-inversion/321: ok | ok | ok |
    > soft-irq lock-inversion/321: ok | ok | ok |
    > hard-irq read-recursion/123: ok |
    > soft-irq read-recursion/123: ok |
    > hard-irq read-recursion/132: ok |
    > soft-irq read-recursion/132: ok |
    > hard-irq read-recursion/213: ok |
    > soft-irq read-recursion/213: ok |
    > hard-irq read-recursion/231: ok |
    > soft-irq read-recursion/231: ok |
    > hard-irq read-recursion/312: ok |
    > soft-irq read-recursion/312: ok |
    > hard-irq read-recursion/321: ok |
    > soft-irq read-recursion/321: ok |
    > -------------------------------------------------------
    > Good, all 218 testcases passed! |
    > ---------------------------------
    > Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes)
    > Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes)
    > Memory: 3431144k/3670016k available (7668k kernel code, 2335348k reserved, 1228k data, 4246k bss, 676k init)
    > SLUB: Genslabs=12, HWalign=128, Order=0-1, MinObjects=4, CPUs=2, Nodes=1
    > Calibrating delay loop... 66.56 BogoMIPS (lpj=133120)
    > Mount-cache hash table entries: 256
    > PowerMac SMP probe found 2 cpus
    > KeyWest i2c @0xf8001003 irq 16 /u3@0,f8000000/i2c@f8001000
    > channel 0 bus
    > channel 1 bus
    > KeyWest i2c @0x80018000 irq 26 /ht@0,f2000000/pci@3/mac-io@7/i2c@18000
    > channel 0 bus
    > PMU i2c /ht@0,f2000000/pci@3/mac-io@7/via-pmu@16000/pmu-i2c
    > channel 1 bus
    > channel 2 bus
    > Processor timebase sync using Pulsar i2c clock
    > mpic: requesting IPIs ...
    > Processor 1 found.
    > clockevent: decrementer mult[888] shift[16] cpu[1]
    > Brought up 2 CPUs
    > CPU0 attaching sched-domain:
    > domain 0: span 3
    > groups: 1 2
    > CPU1 attaching sched-domain:
    > domain 0: span 3
    > groups: 2 1
    > khelper used greatest stack depth: 10976 bytes left
    > net_namespace: 1000 bytes
    > NET: Registered protocol family 16
    > PCI: Probing PCI hardware
    > IOMMU table initialized, virtual merging enabled
    > PCI: Closing bogus Apple Firmware region 2 on bus 0x01
    > PCI: Closing bogus Apple Firmware region 2 on bus 0x02
    > PCI: Closing bogus Apple Firmware region 2 on bus 0x03
    > PCI: Closing bogus Apple Firmware region 2 on bus 0x04
    > PCI: Closing bogus Apple Firmware region 2 on bus 0x05
    > PCI: Bridge: 0001:00:01.0
    > IO window: disabled.
    > MEM window: disabled.
    > PREFETCH window: disabled.
    > PCI: Bridge: 0001:00:02.0
    > IO window: disabled.
    > MEM window: disabled.
    > PREFETCH window: disabled.
    > PCI: Bridge: 0001:00:03.0
    > IO window: disabled.
    > MEM window: 0x80000000-0x800fffff
    > PREFETCH window: disabled.
    > PCI: Bridge: 0001:00:04.0
    > IO window: disabled.
    > MEM window: 0x80100000-0x801fffff
    > PREFETCH window: disabled.
    > PCI: Bridge: 0001:00:05.0
    > IO window: disabled.
    > MEM window: 0x80200000-0x802fffff
    > PREFETCH window: disabled.
    > PCI: Bridge: 0001:00:06.0
    > IO window: disabled.
    > MEM window: 0x80300000-0x805fffff
    > PREFETCH window: disabled.
    > PCI: Bridge: 0001:00:07.0
    > IO window: disabled.
    > MEM window: 0x80600000-0x806fffff
    > PREFETCH window: disabled.
    > PCI: Probing PCI hardware done
    > Registering pmac pic with sysfs...
    > 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
    > Switched to high resolution mode on CPU 0
    > Switched to high resolution mode on CPU 1
    > NET: Registered protocol family 2
    > IP route cache hash table entries: 131072 (order: 8, 1048576 bytes)
    > TCP established hash table entries: 524288 (order: 11, 8388608 bytes)
    > TCP bind hash table entries: 65536 (order: 10, 4194304 bytes)
    > TCP: Hash tables configured (established 524288 bind 65536)
    > TCP reno registered
    > nvram_init: Could not find nvram partition for nvram buffered error logging.
    > Registering G5 CPU frequency driver
    > Frequency method: i2c/pfunc, Voltage method: i2c/pfunc
    > Low: 2000 Mhz, High: 2500 Mhz, Cur: 2000 MHz
    > Total HugeTLB memory allocated, 0
    > Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
    > Block layer SCSI generic (bsg) driver version 0.4 loaded (major 254)
    > io scheduler noop registered
    > io scheduler anticipatory registered (default)
    > io scheduler deadline registered
    > io scheduler cfq registered
    > pci 0001:00:01.0: MSI quirk detected; subordinate MSI disabled
    > pci 0001:00:01.0: AMD8131 rev 12 detected; disabling PCI-X MMRBC
    > pci 0001:00:02.0: MSI quirk detected; subordinate MSI disabled
    > pci 0001:00:02.0: AMD8131 rev 12 detected; disabling PCI-X MMRBC
    > PCI: Enabling device 0000:f0:10.0 (0006 -> 0007)
    > radeonfb: Found Open Firmware ROM Image
    > radeonfb: Retrieved PLL infos from Open Firmware
    > radeonfb: Reference=27.00 MHz (RefDiv=12) Memory=310.00 Mhz, System=400.00 MHz
    > radeonfb: PLL min 12000 max 35000
    > i2c-adapter i2c-2: unable to read EDID block.
    > i2c-adapter i2c-2: unable to read EDID block.
    > i2c-adapter i2c-2: unable to read EDID block.
    > radeonfb: Monitor 1 type CRT found
    > radeonfb: EDID probed
    > radeonfb: Monitor 2 type no found
    > Display is GTF capable
    > Attempt to iounmap early bolted mapping at 0xd0000800800c1000
    > Console: switching to colour frame buffer device 160x64
    > radeonfb (0000:f0:10.0): ATI Radeon AR
    > Generic RTC Driver v1.07
    > Linux agpgart interface v0.103
    > [drm] Initialized drm 1.1.0 20060810
    > [drm] Initialized radeon 1.28.0 20060524 on minor 0
    > pmac_zilog: 0.6 (Benjamin Herrenschmidt )
    > ttyS0 at MMIO 0x80013020 (irq = 22) is a Z85c30 ESCC - Serial port
    > ttyS1 at MMIO 0x80013000 (irq = 23) is a Z85c30 ESCC - Serial port
    > brd: module loaded
    > loop: module loaded
    > Intel(R) PRO/1000 Network Driver - version 7.3.20-k2
    > Copyright (c) 1999-2006 Intel Corporation.
    > sungem.c:v0.98 8/24/03 David S. Miller (davem@redhat.com)
    > PHY ID: 2062e0, addr: 1
    > eth0: Sun GEM (PCI) 10/100/1000BaseT Ethernet 00:0d:93:43:75:28
    > eth0: Found BCM5421-K2 PHY
    > MacIO PCI driver attached to K2 chipset
    > input: Macintosh mouse button emulation as /class/input/input0
    > PowerMac G5 Thermal control driver 1.3
    > Detected fan controls:
    > 0: PWM fan, id 1, location: BACKSIDE,SYS CTRLR FAN
    > 1: RPM fan, id 2, location: DRIVE BAY
    > 2: PWM fan, id 2, location: SLOT,PCI FAN
    > 3: RPM fan, id 3, location: CPU A INTAKE
    > 4: RPM fan, id 4, location: CPU A EXHAUST
    > 5: RPM fan, id 5, location: CPU B INTAKE
    > 6: RPM fan, id 6, location: CPU B EXHAUST
    > 7: RPM fan, id 1, location: CPU A PUMP
    > 8: RPM fan, id 0, location: CPU B PUMP
    > Uniform Multi-Platform E-IDE driver
    > ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
    > PCI: Enabling device 0001:03:0d.0 (0014 -> 0016)
    > ide0: Found Apple K2 ATA-6 controller, bus ID 3, irq 39
    > Probing IDE interface ide0...
    > hda: HL-DT-ST DVD-RW GWA-4082B, ATAPI CD/DVD-ROM drive
    > hda: host max PIO4 wanted PIO255(auto-tune) selected PIO4
    > hda: UDMA/66 mode selected
    > ide0 at 0xd000080082352000-0xd000080082352007,0xd000080082352160 on irq 39
    > hda: ATAPI 32X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache
    > Uniform CD-ROM driver Revision: 3.20
    > st: Version 20080221, fixed bufsize 32768, s/g segs 256
    > Driver 'st' needs updating - please use bus_type methods
    > Driver 'sd' needs updating - please use bus_type methods
    > Driver 'sr' needs updating - please use bus_type methods
    > sata_svw 0001:05:0c.0: version 2.3
    > scsi0 : sata_svw
    > scsi1 : sata_svw
    > scsi2 : sata_svw
    > scsi3 : sata_svw
    > ata1: SATA max UDMA/133 mmio m8192@0x80600000 port 0x80600000 irq 17
    > ata2: SATA max UDMA/133 mmio m8192@0x80600000 port 0x80600100 irq 17
    > ata3: SATA max UDMA/133 mmio m8192@0x80600000 port 0x80600200 irq 17
    > ata4: SATA max UDMA/133 mmio m8192@0x80600000 port 0x80600300 irq 17
    > ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
    > ata1.00: ATA-7: ST3250410AS, 3.AAC, max UDMA/133
    > ata1.00: 488397168 sectors, multi 16: LBA48 NCQ (depth 0/32)
    > ata1.00: configured for UDMA/133
    > eth0: Link is up at 100 Mbps, full-duplex.
    > ata2: SATA link down (SStatus 4 SControl 300)
    > ata3: SATA link down (SStatus 4 SControl 300)
    > ata4: SATA link down (SStatus 4 SControl 300)
    > scsi 0:0:0:0: Direct-Access ATA ST3250410AS 3.AA PQ: 0 ANSI: 5
    > sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors (250059 MB)
    > sd 0:0:0:0: [sda] Write Protect is off
    > sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
    > sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
    > sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors (250059 MB)
    > sd 0:0:0:0: [sda] Write Protect is off
    > sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
    > sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
    > sda: [mac] sda1 sda2 sda3 sda4
    > sd 0:0:0:0: [sda] Attached SCSI disk
    > sd 0:0:0:0: Attached scsi generic sg0 type 0
    > PCI: Enabling device 0001:03:0e.0 (0000 -> 0002)
    > ohci1394: fw-host0: OHCI-1394 1.0 (PCI): IRQ=[40] MMIO=[80200000-802007ff] Max Packet=[4096] IR/IT contexts=[8/8]
    > ieee1394: raw1394: /dev/raw1394 device initialized
    > PCI: Enabling device 0001:02:0b.2 (0004 -> 0006)
    > ehci_hcd 0001:02:0b.2: EHCI Host Controller
    > ehci_hcd 0001:02:0b.2: new USB bus registered, assigned bus number 1
    > ehci_hcd 0001:02:0b.2: irq 63, io mem 0x80100000
    > ehci_hcd 0001:02:0b.2: 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: 5 ports detected
    > ohci_hcd: 2006 August 04 USB 1.1 'Open' Host Controller (OHCI) Driver
    > PCI: Enabling device 0001:01:08.0 (0000 -> 0002)
    > ohci_hcd 0001:01:08.0: OHCI Host Controller
    > ohci_hcd 0001:01:08.0: new USB bus registered, assigned bus number 2
    > ohci_hcd 0001:01:08.0: irq 27, io mem 0x80081000
    > usb usb2: configuration #1 chosen from 1 choice
    > hub 2-0:1.0: USB hub found
    > hub 2-0:1.0: 2 ports detected
    > PCI: Enabling device 0001:01:09.0 (0000 -> 0002)
    > ohci_hcd 0001:01:09.0: OHCI Host Controller
    > ohci_hcd 0001:01:09.0: new USB bus registered, assigned bus number 3
    > ohci_hcd 0001:01:09.0: irq 28, io mem 0x80080000
    > usb usb3: configuration #1 chosen from 1 choice
    > hub 3-0:1.0: USB hub found
    > hub 3-0:1.0: 2 ports detected
    > PCI: Enabling device 0001:02:0b.0 (0000 -> 0002)
    > ohci_hcd 0001:02:0b.0: OHCI Host Controller
    > ohci_hcd 0001:02:0b.0: new USB bus registered, assigned bus number 4
    > ohci_hcd 0001:02:0b.0: irq 63, io mem 0x80102000
    > usb usb4: configuration #1 chosen from 1 choice
    > hub 4-0:1.0: USB hub found
    > hub 4-0:1.0: 3 ports detected
    > PCI: Enabling device 0001:02:0b.1 (0000 -> 0002)
    > ohci_hcd 0001:02:0b.1: OHCI Host Controller
    > ohci_hcd 0001:02:0b.1: new USB bus registered, assigned bus number 5
    > ohci_hcd 0001:02:0b.1: irq 63, io mem 0x80101000
    > usb usb5: configuration #1 chosen from 1 choice
    > hub 5-0:1.0: USB hub found
    > hub 5-0:1.0: 2 ports detected
    > ieee1394: Host added: ID:BUS[0-00:1023] GUID[000d93fffe437528]
    > usb 5-2: new full speed USB device using ohci_hcd and address 2
    > usb 5-2: configuration #1 chosen from 1 choice
    > hub 5-2:1.0: USB hub found
    > hub 5-2:1.0: 3 ports detected
    > usb 5-2.1: new low speed USB device using ohci_hcd and address 3
    > usb 5-2.1: configuration #1 chosen from 1 choice
    > usb 5-2.3: new full speed USB device using ohci_hcd and address 4
    > usb 5-2.3: configuration #1 chosen from 1 choice
    > usbcore: registered new interface driver usblp
    > Initializing USB Mass Storage driver...
    > usbcore: registered new interface driver usb-storage
    > USB Mass Storage support registered.
    > mice: PS/2 mouse device common for all mice
    > i2c /dev entries driver
    > PowerMac i2c bus pmu 2 registered
    > PowerMac i2c bus pmu 1 registered
    > PowerMac i2c bus mac-io 0 registered
    > PowerMac i2c bus u3 1 registered
    > Liquid cooling pumps detected, using new algorithm !
    > PowerMac i2c bus u3 0 registered
    > md: linear personality registered for level -1
    > FCU Initialized, RPM fan shift is 3
    > md: raid0 personality registered for level 0
    > md: raid1 personality registered for level 1
    > device-mapper: ioctl: 4.13.0-ioctl (2007-10-18) initialised: dm-devel@redhat.com
    > usbcore: registered new interface driver hiddev
    > input: HID 04b3:3107 as /class/input/input1
    > input: USB HID v1.00 Mouse [HID 04b3:3107] on usb-0001:02:0b.1-2.1
    > input: Mitsumi Electric Apple Extended USB Keyboard as /class/input/input2
    > input: USB HID v1.10 Keyboard [Mitsumi Electric Apple Extended USB Keyboard] on usb-0001:02:0b.1-2.3
    > input: Mitsumi Electric Apple Extended USB Keyboard as /class/input/input3
    > input: USB HID v1.10 Device [Mitsumi Electric Apple Extended USB Keyboard] on usb-0001:02:0b.1-2.3
    > usbcore: registered new interface driver usbhid
    > drivers/hid/usbhid/hid-core.c: v2.6:USB HID core driver
    > oprofile: using ppc64/970 performance monitoring.
    > IPv4 over IPv4 tunneling driver
    > TCP cubic registered
    > NET: Registered protocol family 1
    > NET: Registered protocol family 17
    > RPC: Registered udp transport module.
    > RPC: Registered tcp transport module.
    > input: PMU as /class/input/input4
    > md: Autodetecting RAID arrays.
    > md: Scanned 0 and added 0 devices.
    > md: autorun ...
    > md: ... autorun DONE.
    > kjournald starting. Commit interval 5 seconds
    > EXT3-fs: mounted filesystem with ordered data mode.
    > VFS: Mounted root (ext3 filesystem) readonly.
    > Freeing unused kernel memory: 676k freed
    > khelper used greatest stack depth: 9072 bytes left
    > runlevel used greatest stack depth: 8880 bytes left
    > grep used greatest stack depth: 6864 bytes left
    > Adding 9937800k swap on /dev/sda4. Priority:-1 extents:1 across:9937800k
    > EXT3 FS on sda3, internal journal
    > ioctl32(pbbuttonsd:3234): Unknown cmd fd(9) cmd(40044201){t:'B';sz:4} arg(ff91c9dc) on /dev/pmu
    > warning: `avahi-daemon' uses 32-bit capabilities (legacy support in use)
    > eth0: Link is up at 100 Mbps, full-duplex.
    > eth0: Pause is enabled (rxfifo: 10240 off: 7168 on: 5632)
    > hcid used greatest stack depth: 6560 bytes left
    > ioctl32(gnome-terminal:4017): Unknown cmd fd(20) cmd(0000530b){t:'S';sz:0} arg(0fbfe7c4) on /dev/pts/0
    > ioctl32(gnome-terminal:4017): Unknown cmd fd(20) cmd(0000530b){t:'S';sz:0} arg(0fbfe7cc) on /dev/pts/0
    > ioctl32(gnome-terminal:4017): Unknown cmd fd(20) cmd(0000530b){t:'S';sz:0} arg(0fbfe7d4) on /dev/pts/0
    > jockey-gtk used greatest stack depth: 6368 bytes left
    >
    > =============================================
    > [ INFO: possible recursive locking detected ]
    > 2.6.25-rc8 #18
    > ---------------------------------------------
    > swapper/0 is trying to acquire lock:
    > (&dev->event_lock){++..}, at: [] .input_event+0x64/0xd0
    >
    > but task is already holding lock:
    > (&dev->event_lock){++..}, at: [] .input_event+0x64/0xd0
    >
    > other info that might help us debug this:
    > 2 locks held by swapper/0:
    > #0: (&dev->event_lock){++..}, at: [] .input_event+0x64/0xd0
    > #1: (rcu_read_lock){..--}, at: [] .input_pass_event+0x0/0x160
    >
    > stack backtrace:
    > Call Trace:
    > [c00000000fff2fa0] [c00000000000f58c] .show_stack+0x78/0x1c8 (unreliable)
    > [c00000000fff3050] [c00000000000f6fc] .dump_stack+0x20/0x34
    > [c00000000fff30d0] [c0000000000800c4] .__lock_acquire+0xac4/0xee0
    > [c00000000fff31c0] [c0000000000805b8] .lock_acquire+0xd8/0x124
    > [c00000000fff3280] [c0000000004ee1a0] ._spin_lock_irqsave+0x60/0xc8
    > [c00000000fff3320] [c0000000003ef5f8] .input_event+0x64/0xd0
    > [c00000000fff33d0] [c000000000338958] .mac_hid_mouse_emulate_buttons+0x94/0xf8
    > [c00000000fff3450] [c0000000002b36bc] .kbd_event+0x1d0/0x82c
    > [c00000000fff3540] [c0000000003ed9b0] .input_pass_event+0xe0/0x160
    > [c00000000fff35f0] [c0000000003ee724] .input_handle_event+0x4fc/0x544
    > [c00000000fff36b0] [c0000000003ef628] .input_event+0x94/0xd0
    > [c00000000fff3760] [c0000000004229a4] .hidinput_hid_event+0x358/0x3bc
    > [c00000000fff3810] [c00000000041d458] .hid_process_event+0x4c/0xc4
    > [c00000000fff38c0] [c00000000041d874] .hid_input_field+0x3a4/0x3f0
    > [c00000000fff39a0] [c00000000041d9d4] .hid_input_report+0x114/0x18c
    > [c00000000fff3a50] [c0000000004263b4] .hid_irq_in+0xb0/0x1c8
    > [c00000000fff3af0] [c0000000003bff50] .usb_hcd_giveback_urb+0xe8/0x15c
    > [c00000000fff3b90] [c0000000003db9d8] .finish_urb+0xcc/0x15c
    > [c00000000fff3c30] [c0000000003dbad4] .takeback_td+0x6c/0x19c
    > [c00000000fff3cd0] [c0000000003df4cc] .ohci_irq+0x4d0/0x750
    > [c00000000fff3db0] [c0000000003c0590] .usb_hcd_irq+0x58/0xc8
    > [c00000000fff3e40] [c000000000091708] .handle_IRQ_event+0x60/0xe0
    > [c00000000fff3ef0] [c000000000093950] .handle_fasteoi_irq+0x130/0x1d0
    > [c00000000fff3f90] [c0000000000223b0] .call_handle_irq+0x1c/0x2c
    > [c00000015a11fac0] [c00000000000c508] .do_IRQ+0x114/0x1d0
    > [c00000015a11fb60] [c000000000004694] hardware_interrupt_entry+0x1c/0x20
    > --- Exception: 501 at .cpu_idle+0xe8/0x150
    > LR = .cpu_idle+0xe8/0x150
    > [c00000015a11fe50] [c000000000011da4] .cpu_idle+0xbc/0x150 (unreliable)
    > [c00000015a11fef0] [c0000000004f10e4] .start_secondary+0x15c/0x188
    > [c00000015a11ff90] [c0000000000073c0] .start_secondary_prolog+0xc/0x10
    >
    > Now, I -think- that this is fine, that is, I believe the lock is first
    > taken by the HID/kbd driver calling input_event, and then by mac-hid
    > mouse emulation which has a separate input_dev and thus a separate
    > instance of the lock.
    >
    > (I may be wrong and we -might- have a real bug here, but I'll let
    > others more familiar with the input layer have a look).
    >
    > Is it a known issue that lockdep can issue false positives like that ?


    Yes, if both locks are of the same class it will report this. Lockdep
    does lock chain validation on classes, never on individual locks.

    A class usually consists of all locks that share the lock init site; but
    there are ways to explicity set another class.

    In case of these recursions we have helpers like spin_lock_nested(&lock,
    subclass) that allow you to annotate these. These sub-classes must then
    always be taken in the same order; subclass < 8.

    In this case its probably easier to explicity set a class, as the
    nesting is not exposed to the input layer, so it doesn't know about it.

    Something like this should do I guess.

    ---
    Subject: mac_hid: lockdep annotate the emumousebtn input nesting

    The mouse button emulation calls input device methods from an input
    device. This causes funny lock nesting which is harmless as each device
    has its own locks.

    Give the nesting device its own lock classes so that lockdep will not
    consider them the same.

    Signed-off-by: Peter Zijlstra
    ---
    diff --git a/drivers/macintosh/mac_hid.c b/drivers/macintosh/mac_hid.c
    index 8930230..f972ff3 100644
    --- a/drivers/macintosh/mac_hid.c
    +++ b/drivers/macintosh/mac_hid.c
    @@ -103,6 +103,9 @@ int mac_hid_mouse_emulate_buttons(int caller, unsigned int keycode, int down)
    return 0;
    }

    +static struct lock_class_key emumousebtn_event_class;
    +static struct lock_class_key emumousebtn_mutex_class;
    +
    static int emumousebtn_input_register(void)
    {
    int ret;
    @@ -111,6 +114,9 @@ static int emumousebtn_input_register(void)
    if (!emumousebtn)
    return -ENOMEM;

    + lockdep_set_class(emumousebtn->event_lock, &emumousebtn_event_class);
    + lockdep_set_class(emumousebtn->mutex, &emumousebtn_mutex_class);
    +
    emumousebtn->name = "Macintosh mouse button emulation";
    emumousebtn->id.bustype = BUS_ADB;
    emumousebtn->id.vendor = 0x0001;


    --
    To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
    the body of a message to majordomo@vger.kernel.org
    More majordomo info at http://vger.kernel.org/majordomo-info.html
    Please read the FAQ at http://www.tux.org/lkml/

  3. Re: lockdep, false positive ?

    On Wed, 2008-04-09 at 12:11 -0400, Dmitry Torokhov wrote:
    > Hi Peter,
    >
    > On Wed, Apr 09, 2008 at 11:44:41AM +0200, Peter Zijlstra wrote:
    > >
    > > Yes, if both locks are of the same class it will report this. Lockdep
    > > does lock chain validation on classes, never on individual locks.
    > >
    > > A class usually consists of all locks that share the lock init site; but
    > > there are ways to explicity set another class.
    > >
    > > In case of these recursions we have helpers like spin_lock_nested(&lock,
    > > subclass) that allow you to annotate these. These sub-classes must then
    > > always be taken in the same order; subclass < 8.
    > >
    > > In this case its probably easier to explicity set a class, as the
    > > nesting is not exposed to the input layer, so it doesn't know about it.
    > >

    >
    > Is there a way in lockdep to mark all instances of a given lock as distinct?
    > I'd rather do that in input core once and be done with it.


    Nope. Do you have a lot of nesting in input?

    > Also another question I've been meaning to ask - we have lockdep annotations
    > in serio code and they work fine first time around but if you reload
    > psmouse module lockdep will barf if you have SYnaptics touchpad with
    > pass-through port. What gives?


    Could you show me one such dump? - And yes, module reloading is a tad
    tricky, but it should work for a while.

    --
    To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
    the body of a message to majordomo@vger.kernel.org
    More majordomo info at http://vger.kernel.org/majordomo-info.html
    Please read the FAQ at http://www.tux.org/lkml/

  4. Re: lockdep, false positive ?

    Hi Peter,

    On Wed, Apr 09, 2008 at 11:44:41AM +0200, Peter Zijlstra wrote:
    >
    > Yes, if both locks are of the same class it will report this. Lockdep
    > does lock chain validation on classes, never on individual locks.
    >
    > A class usually consists of all locks that share the lock init site; but
    > there are ways to explicity set another class.
    >
    > In case of these recursions we have helpers like spin_lock_nested(&lock,
    > subclass) that allow you to annotate these. These sub-classes must then
    > always be taken in the same order; subclass < 8.
    >
    > In this case its probably easier to explicity set a class, as the
    > nesting is not exposed to the input layer, so it doesn't know about it.
    >


    Is there a way in lockdep to mark all instances of a given lock as distinct?
    I'd rather do that in input core once and be done with it.

    Also another question I've been meaning to ask - we have lockdep annotations
    in serio code and they work fine first time around but if you reload
    psmouse module lockdep will barf if you have SYnaptics touchpad with
    pass-through port. What gives?

    --
    Dmitry
    --
    To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
    the body of a message to majordomo@vger.kernel.org
    More majordomo info at http://vger.kernel.org/majordomo-info.html
    Please read the FAQ at http://www.tux.org/lkml/

+ Reply to Thread