#11370 NORM 1.75-so: 1.75: bad sdhci lock request
Zarro Boogs per Child
bugtracker at laptop.org
Mon Oct 31 12:53:04 EDT 2011
#11370: 1.75: bad sdhci lock request
--------------------+-------------------------------------------------------
Reporter: pgf | Owner:
Type: defect | Status: new
Priority: normal | Milestone: 1.75-software
Component: kernel | Version: Development source as of this date
Keywords: | Next_action: diagnose
Verified: 0 | Deployment_affected:
Blockedby: | Blocking:
--------------------+-------------------------------------------------------
got the following trace with lock debugging turned on.
it occurred during the resume after the first suspend. branch was the pm3
branch, plus a few (non-sdhci) additions. i'll save a copy of the branch
in case it's needed.
{{{
Type any key to interrupt automatic startup
Boot device: /sd/disk at 3:\boot\olpc.fth Arguments:
Boot device: /sd at d4280000/disk at 3:\boot\vmlinuz Arguments:
no_console_suspend nottyS3
Loading ramdisk image from /sd at d4280000/disk at 3:\boot\initrd.img ...
Uncompressing Linux... done, booting the kernel.
[ 0.000000] Initializing cgroup subsys cpu
[ 0.000000] Linux version 3.0.0-00187-g68292ac-dirty (pgf at chalk) (gcc
version 4.4.5 (Ubuntu/Linaro 4.4.4-14ubuntu4) ) #161 PREEMPT Mon Oct 31
12:21:19 EDT 2011
[ 0.000000] CPU: ARMv7 Processor [560f5815] revision 5 (ARMv7),
cr=10c5387f
[ 0.000000] CPU: VIPT nonaliasing data cache, VIPT aliasing instruction
cache
[ 0.000000] Machine: OLPC XO-1.75
[ 0.000000] Ignoring unrecognised tag 0x54410008
[ 0.000000] OFW detected in memory, cif @ 0xfda34e04:
[ 0.000000] 0xfd800000 - 0xfdbfffff (4MB)
[ 0.000000] 0xfdc00000 - 0xfdffffff (4MB)
[ 0.000000] Reserved memory (67108864 bytes at 0x18000000)
[ 0.000000] Memory policy: ECC disabled, Data cache writeback
[ 0.000000] PROM DT: Built device tree with 28672 bytes of memory.
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on.
Total pages: 111632
[ 0.000000] Kernel command line: console=ttyS2,115200 console=tty0
selinux=0 fbcon=font:SUN12x22 no_console_suspend nottyS3
[ 0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144
bytes)
[ 0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072
bytes)
[ 0.000000] Memory: 384MB 56MB = 440MB total
[ 0.000000] Memory: 431616k/431616k available, 84480k reserved, 0K
highmem
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000] fixmap : 0xfff00000 - 0xfffe0000 ( 896 kB)
[ 0.000000] DMA : 0xff600000 - 0xffe00000 ( 8 MB)
[ 0.000000] vmalloc : 0xe0000000 - 0xfd600000 ( 470 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xdf800000 ( 504 MB)
[ 0.000000] modules : 0xbf000000 - 0xc0000000 ( 16 MB)
[ 0.000000] .init : 0xc0008000 - 0xc002c000 ( 144 kB)
[ 0.000000] .text : 0xc002c000 - 0xc04d2674 (4762 kB)
[ 0.000000] .data : 0xc04d4000 - 0xc0504f18 ( 196 kB)
[ 0.000000] .bss : 0xc0504f3c - 0xc0a6735c (5514 kB)
[ 0.000000] NR_IRQS:320 nr_irqs:320 320
[ 0.000000] sched_clock: 32 bits at 6MHz, resolution 153ns, wraps every
660764ms
[ 0.000000] Console: colour dummy device 80x30
[ 0.000000] console [tty0] enabled
[ 0.000000] Lock dependency validator: Copyright (c) 2006 Red Hat,
Inc., Ingo Molnar
[ 0.000000] ... MAX_LOCKDEP_SUBCLASSES: 8
[ 0.000000] ... MAX_LOCK_DEPTH: 48
[ 0.000000] ... MAX_LOCKDEP_KEYS: 8191
[ 0.000000] ... CLASSHASH_SIZE: 4096
[ 0.000000] ... MAX_LOCKDEP_ENTRIES: 16384
[ 0.000000] ... MAX_LOCKDEP_CHAINS: 32768
[ 0.000000] ... CHAINHASH_SIZE: 16384
[ 0.000000] memory used by lock dependency info: 3695 kB
[ 0.000000] per task-struct memory footprint: 1152 bytes
[ 0.000099] Calibrating delay loop... 795.44 BogoMIPS (lpj=3977216)
[ 0.090099] pid_max: default: 32768 minimum: 301
[ 0.090760] Mount-cache hash table entries: 512
[ 0.090760] CPU: Testing write buffer coherency: ok
[ 0.100779] devtmpfs: initialized
[ 0.110138] print_constraints: dummy:
[ 0.111013] NET: Registered protocol family 16
[ 0.111914] Tauros2: Disable L2 prefetch, burst8 and WCO.
[ 0.112145] Tauros2: CP15 extra feature register: 0x61000000
[ 0.112180] Tauros2: L2 cache support initialised in ARMv7 mode.
[ 0.113046] mmp-sram vsram: initialized
[ 0.128610] bio: create slab <bio-0> at 0
[ 0.130599] SCSI subsystem initialized
[ 0.130599] usbcore: registered new interface driver usbfs
[ 0.130916] usbcore: registered new interface driver hub
[ 0.131334] usbcore: registered new device driver usb
[ 0.131437] i2c-gpio i2c-gpio.7: using pins 109 (SDA) and 108 (SCL)
[ 0.132536] i2c-gpio i2c-gpio.6: using pins 110 (SDA) and 161 (SCL)
[ 0.132866] i2c-gpio i2c-gpio.2: using pins 5 (SDA) and 4 (SCL)
[ 0.133802] I2C: i2c-3: PXA I2C adapter
[ 0.134738] I2C: i2c-1: PXA I2C adapter
[ 0.135469] I2C: i2c-0: PXA I2C adapter
[ 0.136169] I2C: i2c-5: PXA I2C adapter
[ 0.136807] Advanced Linux Sound Architecture Driver Version 1.0.24.
[ 0.140186] cfg80211: Calling CRDA to update world regulatory domain
[ 0.140844] Switching to clocksource clocksource
[ 0.150217] Switched to NOHz mode on CPU #0
[ 0.160586] NET: Registered protocol family 2
[ 0.160586] IP route cache hash table entries: 4096 (order: 2, 16384
bytes)
[ 0.162515] TCP established hash table entries: 16384 (order: 5, 131072
bytes)
[ 0.162515] TCP bind hash table entries: 16384 (order: 7, 589824 bytes)
[ 0.163249] TCP: Hash tables configured (established 16384 bind 16384)
[ 0.171301] TCP reno registered
[ 0.171301] UDP hash table entries: 256 (order: 2, 20480 bytes)
[ 0.171340] UDP-Lite hash table entries: 256 (order: 2, 20480 bytes)
[ 0.172005] NET: Registered protocol family 1
[ 0.172478] Trying to unpack rootfs image as initramfs...
[ 0.212043] Freeing initrd memory: 3712K
[ 0.233646] VFS: Disk quotas dquot_6.5.2
[ 0.233851] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 0.235850] msgmni has been set to 850
[ 0.238258] io scheduler noop registered
[ 0.238420] io scheduler deadline registered
[ 0.238528] io scheduler cfq registered (default)
[ 0.238559] start plist test
[ 0.242341] end plist test
[ 0.282040] Console: switching to colour frame buffer device 100x40
[ 0.292008] pxa2xx-uart.2: ttyS2 at MMIO 0xd4018000 (irq = 24) is a
STUART
[ 0.780884] console [ttyS2] enabled
[ 0.786158]
[ 0.786164] [galcore] registerBase =0xd420d000, registerMemSize =
0x0003ffff, contiguousBase= 0x18000000, contiguousSize = 0x03ffffff
[ 0.802011]
[ 0.805272] [galcore] real contiguouSize = 0x03ffffff
[ 0.823753]
[ 0.823753] [galcore]
chipModel=0x860,chipRevision=0x4603,chipFeatures=0xe02c6eed,chipMinorFeatures=0xcbf99fff
[ 0.862131] brd: module loaded
[ 0.879363] lis3lv02d: 8 bits sensor found
[ 1.022012] input: ST LIS3LV02DL Accelerometer as
/devices/platform/lis3lv02d/input/input0
[ 1.038984] OLPC XO-1.75 Embedded Controller driver probed
[ 1.052503] input: Power Button as /devices/platform/olpc-
ec-1.75.0/input/input1
[ 1.077516] OLPC board revision 1B1 (EC api 2)
[ 1.089468] OLPC XO-1.75 lid and ebook switches
[ 1.101203] input: OLPC lid switch as /devices/virtual/input/input2
[ 1.114239] input: OLPC ebook switch as /devices/virtual/input/input3
[ 1.127805] usbcore: registered new interface driver ipheth
[ 1.141099] usbcore: registered new interface driver hwa-rc
[ 1.153559] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 1.167493] pxau2o-ehci pxau2o-ehci.0: pxa9xx ehci
[ 1.182033] pxau2o-ehci pxau2o-ehci.0: new USB bus registered, assigned
bus number 1
[ 1.196894] pxau2o-ehci pxau2o-ehci.0: irq 44, io mem 0xd4208000
[ 1.222075] pxau2o-ehci pxau2o-ehci.0: USB 2.0 started, EHCI 1.00
[ 1.235667] usb usb1: New USB device found, idVendor=1d6b,
idProduct=0002
[ 1.249164] usb usb1: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[ 1.263048] usb usb1: Product: pxa9xx ehci
[ 1.273668] usb usb1: Manufacturer: Linux 3.0.0-00187-g68292ac-dirty
ehci_hcd
[ 1.287522] usb usb1: SerialNumber: pxau2o-ehci.0
[ 1.302132] hub 1-0:1.0: USB hub found
[ 1.312942] hub 1-0:1.0: 1 port detected
[ 1.326064] usbcore: registered new interface driver wusb-cbaf
[ 1.339089] Initializing USB Mass Storage driver...
[ 1.350813] usbcore: registered new interface driver usb-storage
[ 1.363867] USB Mass Storage support registered.
[ 1.375323] usbcore: registered new interface driver libusual
[ 1.388519] usbcore: registered new interface driver mdc800
[ 1.400884] mdc800: v0.7.5 (30/10/2000):USB Driver for Mustek MDC800
Digital Camera
[ 1.415200] usbcore: registered new interface driver usbserial
[ 1.428585] USB Serial support registered for generic
[ 1.440907] usbcore: registered new interface driver usbserial_generic
[ 1.454299] usbserial: USB Serial Driver core
[ 1.465326] olpc_keyboard_probe
[ 1.475012] calling serio_register_port
[ 1.486351] done calling serio_register_port
[ 1.500386] RAYDIUM_init
[ 1.510047] RAYDIUM_i2c_probe, i2c new style format
[ 1.521249] i2c-core: driver [raydium_ts] using legacy suspend method
[ 1.534083] i2c-core: driver [raydium_ts] using legacy resume method
[ 1.547201] RAYDIUM_i2c_register_device, add i2c device, success
[ 1.559412] RAYDIUM_i2c_register_device, client.addr: 0x30
[ 1.571074] RAYDIUM_i2c_register_device, client.adapter: 0xDC0A9860
[ 1.583331] RAYDIUM_i2c_register_device, client.driver: 0xC04F28F4
[ 1.620279] input: AT Translated Set 2 keyboard as /devices/platform
/olpc-kbd.0/serio0/input/input4
[ 1.662021] usb 1-1: new high speed USB device number 2 using pxau2o-
ehci
[ 1.823865] usb 1-1: New USB device found, idVendor=05e3,
idProduct=0608
[ 1.836834] usb 1-1: New USB device strings: Mfr=0, Product=1,
SerialNumber=0
[ 1.850210] usb 1-1: Product: USB2.0 Hub
[ 1.862246] hub 1-1:1.0: USB hub found
[ 1.872579] hub 1-1:1.0: 4 ports detected
[ 3.632014] RAYDIUM_i2c_read, i2c read error, ret -121
[ 3.643773] input: raydium_ts as /devices/platform/pxa2xx-
i2c.3/i2c-3/3-0030/input/input5
[ 3.658697] RAYDIUM_i2c_register_device, register input device, success
[ 3.671808] RAYDIUM_i2c_register_device, request irq, success
[ 3.684062] irq disable 67
[ 3.692961] irq disable 66
[ 3.702006] mmp-rtc mmp-rtc: rtc core: registered mmp-rtc as rtc0
[ 3.716550] rtc_idt1338 1-0068: rtc core: registered rtc_idt1338 as
rtc1
[ 3.730257] lirc_dev: IR Remote Control driver registered, major 252
[ 3.742933] IR RC5 (streamzap) protocol handler initialized
[ 3.754800] IR LIRC bridge handler initialized
[ 3.765635] Linux video capture interface: v2.00
[ 3.962413] sdhci: Secure Digital Host Controller Interface driver
[ 3.975130] sdhci: Copyright(c) Pierre Ossman
[ 3.985718] mmc0: no vmmc regulator found
[ 3.997731] mmc0: SDHCI controller on MMC [sdhci-pxa.0] using DMA
[ 4.010402] mmc1: no vmmc regulator found
[ 4.021224] mmc1: SDHCI controller on MMC [sdhci-pxa.1] using DMA
[ 4.033771] mmc2: no vmmc regulator found
[ 4.045993] mmc2: SDHCI controller on MMC [sdhci-pxa.2] using DMA
[ 4.064113] usbcore: registered new interface driver usbhid
[ 4.076335] usbhid: USB HID core driver
[ 4.086454] i2c-core: driver [olpc_dcon] using legacy suspend method
[ 4.099364] i2c-core: driver [olpc_dcon] using legacy resume method
[ 4.115401] olpc-dcon: Discovered DCON version 2
[ 4.146769] usbcore: registered new interface driver snd-usb-audio
[ 4.270719] asoc: alc5631-hifi <-> mmp2-i2s.0 mapping ok
[ 4.287794] input: OLPC XO-1.75 Headphone Jack as /devices/platform
/soc-audio/sound/card0/input6
[ 4.307467] input: OLPC XO-1.75 Microphone Jack as /devices/platform
/soc-audio/sound/card0/input7
[ 4.324254] ALSA device list:
[ 4.333762] #0: OLPC XO-1.75
[ 4.343246] TCP bic registered
[ 4.353462] Initializing XFRM netlink socket
[ 4.364454] NET: Registered protocol family 10
[ 4.377085] NET: Registered protocol family 17
[ 4.389216] lib80211: common routines for IEEE802.11 drivers
[ 4.401459] Registering the dns_resolver key type
[ 4.412549] VFP support v0.3: implementor 56 architecture 2 part 20
variant 9 rev 5
[ 4.427058] ThumbEE CPU extension supported.
[ 4.437776] Registering SWP/SWPB emulation handler
[ 4.448887] PJ4 iWMMXt coprocessor enabled.
[ 4.459525] sram: allocated 4k from d1021000
[ 4.470329] MPMU_REG(0x0038): 5
[ 4.479739] initcall mmp2_pm_init+0x0/0x14c returned with preemption
imbalance
[ 4.495090] mmp-rtc mmp-rtc: setting system clock to 1970-01-01
00:00:00 UTC (0)
[ 4.510055] Freeing init memory: 144K
[ 4.651287] udev[46]: starting version 161
[ 4.808904] mmc2: new high speed DDR MMC card at address 0001
[ 4.837337] mmcblk0: mmc2:0001 SEM04G 3.68 GiB
[ 4.862140] mmcblk0boot0: mmc2:0001 SEM04G partition 1 1.00 MiB
[ 4.885296] mmcblk0boot1: mmc2:0001 SEM04G partition 2 1.00 MiB
[ 4.906775] mmcblk0: p1 p2
[ 4.921106] mmcblk0boot1: unknown partition table
[ 4.935484] mmcblk0boot0: unknown partition table
[ 7.011285] EXT4-fs (mmcblk0p2): couldn't mount as ext3 due to feature
incompatibilities
[ 7.033729] EXT4-fs (mmcblk0p2): couldn't mount as ext2 due to feature
incompatibilities
[ 7.062730] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data
mode. Opts: (null)
[ 7.096436] dracut: Mounted root filesystem /dev/disk/mmc/mmc2p2
[ 7.124810] EXT4-fs (mmcblk0p2): re-mounted. Opts:
user_xattr,acl,barrier=1,data=ordered
[ 7.154593] EXT4-fs (mmcblk0p1): couldn't mount as ext3 due to feature
incompatibilities
[ 7.173110] EXT4-fs (mmcblk0p1): mounting ext2 file system using the
ext4 subsystem
[ 7.192253] EXT4-fs (mmcblk0p1): warning: mounting unchecked fs,
running e2fsck is recommended
[ 7.209189] EXT4-fs (mmcblk0p1): mounted filesystem without journal.
Opts:
[ 7.742295] dcon_freeze_store: 0
[ 7.747681] dcon_source_switch to CPU
[ 7.793547] olpc-dcon: The CPU has control
[ 7.833033] EXT4-fs (mmcblk0p2): re-mounted. Opts:
user_xattr,acl,barrier=1,data=ordered
[ 7.993294] dracut: Switching root
[ 8.866069] udev[194]: starting version 161
[ 9.836243] mousedev: PS/2 mouse device common for all mice
[ 10.732462] Finger Sensing Pad, hw: 13.2.1, sw: 1.0.0-K, buttons: 4
[ 11.031606] input: FSPPS/2 Sentelic FingerSensingPad as
/devices/platform/olpc-kbd.0/serio1/input/input8
[ 11.184025] ov7670 7-0021: chip found @ 0x42 (i2c-gpio7)
[ 11.612130] mmp-camera mmp-camera.0: Release, 0 frames, 0 singles, 0
delivered
[ 13.971718] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[ 14.896134] init: ck-log-system-start main process (525) terminated
with status 1
[ 17.852158] dcon_freeze_store: 1
[ 17.861595] dcon_source_switch to DCON
[ 17.887550] olpc-dcon: The DCON has control
[ 19.651559] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 19.762140] input: olpc-kbdshim virtual input as
/devices/virtual/input/input9
bash-4.1#
bash-4.1#
bash-4.1#
bash-4.1# [ 21.263408] init: olpc-switchd main process (647) terminated
with status 1
[ 21.270350] init: olpc-switchd main process ended, respawning
bash-4.1#
bash-4.1#
bash-4.1# rtcwake -s 10 -m mem
[ 26.635599] irq enable 67
[ 26.638218] irq enable 66
rtcwake: wakeup from "mem" using /dev/rtc0 at Thu Jan 1 00:00:33 1970
[ 26.786778] PM: Syncing filesystems ... done.
[ 26.893758] Freezing user space processes ... (elapsed 0.02 seconds)
done.
[ 26.922058] Freezing remaining freezable tasks ... (elapsed 0.01
seconds) done.
[ 27.195344] irq disable 227
[ 27.195344] RAYDIUM_i2c_suspend, disable i2c irq
[ 27.204427] [galcore]: gpu_suspend, 1358
[ 27.208581] >>>>>>[_gpu_off]@1127
[ 27.222018] <<<<<<[_gpu_off]@1145
[ 27.227115] PM: suspend of devices complete after 284.688 msecs
[ 27.233310] irq disable 7
[ 27.236131] irq disable 20
[ 27.236131] irq disable 24
[ 27.241780] irq disable 40
[ 27.244602] irq disable 41
[ 27.244617] irq disable 42
[ 27.247427] irq disable 44
[ 27.253041] irq disable 66
[ 27.253101] irq disable 67
[ 27.255903] irq disable 68
[ 27.258703] irq disable 70
[ 27.264319] irq disable 72
[ 27.264335] irq disable 224
[ 27.267464] irq disable 225
[ 27.273341] irq disable 252
[ 27.276242] irq disable 256
[ 27.276242] irq disable 257
[ 27.283378] PM: late suspend of devices complete after 49.910 msecs
[ 27.290065] TIMERS1_VIRT_BASE + TMR_IER(0): 0
[ 27.290065] TIMERS1_VIRT_BASE + TMR_ICR(0): 1
[ 27.294576] PMUM_PCR_SP: fe086000
[ 27.299090] PMUA_SP_IDLE_CFG: 80200020
[ 27.302518] MPMU_AWUCRM: 3223f9c
[ 27.309738] APMU_MC_HW_SLP_TYPE: 0
[ 27.313253] APMU_IDLE_CFG: c03a0322
[ 27.313253] MPMU_APCR: fe086000
[ 27.316863] APMU_SRAM_PWR_DWN: c0000
[ 27.320111] APMU_REG(0x010c): 0
[ 27.323807] APMU_REG(0x004c): 0
[ 27.327054] addr: 4
[ 27.332474] addr: 4
[ 27.332474] addr: 7
[ 27.334645] addr: 4
[ 27.339798] addr: 7
[ 27.344742] addr: 4
[ 27.349472] APBC_MMP2_MPMU: 0
[ 27.354108] APBC_MMP2_IPC: 0
[ 27.359570] APBC_MMP2_THSENS1: 0
[ 27.370546] addr: 4
[ 27.370546] addr: 4
[ 27.374956] SCU_AXIFAB_CKGT_CTRL0: 0
[ 27.379196] SCU_AXIFAB_CKGT_CTRL1: 0
[ 27.385027] SCU_MCB_CONF: f9
[ 27.390870] APMU_REG(0x0054): 400
[ 27.396055] APMU_REG(0x0058): 0
[ 27.407291] APMU_REG(0x00e8): 0
[ 27.412839] APMU_REG(0x00d4): 80
[ 27.412839] APMU_REG(0x0060): 80
[ 27.418482] APMU_REG(0x00d8): 1c0
[ 27.429872] APMU_REG(0x010c): 0
[ 27.435462] APMU_REG(0x00dc): 2
[ 27.435462] APMU_REG(0x005c): 0
[ 27.446637] MPMU_ACGR: a010
[ 27.446637] MPMU_REG(0x0024): a010
[ 27.451910] MPMU_ISCCR1: 50048049
[ 27.451910] MPMU_ISCCR2: 5820130b
[ 27.451910] MPMU_WUCRS_PJ: 90000000
[ 27.451910] MMP2_ICU_PJ4_IRQ_GLOBAL_MASK: 1
[ 27.451910] MPMU_APCR: 20006000
[ 27.451910] APMU_IDLE_CFG: f0000300
[ 27.451910] MPMU_ACGR: 838f33c
[ 27.457833] MPMU_REG(0x0024): dffefffe
[ 27.457836] MPMU_ISCCR1: d0048049
[ 27.463943] MPMU_ISCCR2: 5820130b
[ 27.469614] APMU_REG(0x005c): 1
[ 27.480727] APMU_REG(0x005c): 9
[ 27.480727] APMU_REG(0x0054): 41b
[ 27.486909] APMU_REG(0x0058): 1b
[ 27.492435] APMU_REG(0x00e8): 1b
[ 27.503272] APMU_REG(0x00d4): 9b
[ 27.503272] APMU_REG(0x0060): bf
[ 27.514115] APMU_REG(0x010c): 0
[ 27.514479] APMU_REG(0x00dc): 1ffff
[ 27.525561] SCU_AXIFAB_CKGT_CTRL0: 3003003
[ 27.525561] SCU_AXIFAB_CKGT_CTRL1: 303030
[ 27.538329] SCU_MCB_CONF: 9
[ 27.538329] APBC_MMP2_MPMU: 3
[ 27.543446] APBC_MMP2_IPC: 7
[ 27.553930] APBC_MMP2_THSENS1: 7
[ 27.553930] addr: 3
[ 27.559515] addr: 3
[ 27.563908] addr: 3
[ 27.568302] addr: 0
[ 27.572626] addr: 0
[ 27.581130] addr: 3
[ 27.581130] addr: 0
[ 27.585369] addr: 3
[ 27.593803] addr: 0
[ 27.593803] APMU_REG(0x010c): 712
[ 27.598016] APMU_REG(0x004c): 71b
[ 27.603513] TIMERS1_VIRT_BASE + TMR_IER(0): 1
[ 27.609009] TIMERS1_VIRT_BASE + TMR_ICR(0): 1
[ 27.623764] PM: early resume of devices complete after 0.528 msecs
[ 27.632516] irq enable 7
[ 27.632553] irq enable 20
[ 27.642710] irq enable 24
[ 27.647823] irq enable 40
[ 27.652818] irq enable 41
[ 27.657856] irq enable 42
[ 27.662738] irq enable 44
[ 27.662836] irq enable 66
[ 27.673485] irq enable 67
[ 27.673510] irq enable 68
[ 27.683015] irq enable 70
[ 27.683036] irq enable 72
[ 27.692304] irq enable 224
[ 27.692640] irq enable 225
[ 27.702097] irq enable 252
[ 27.702168] irq enable 256
[ 27.711598] irq enable 257
[ 27.711613] mmp2_pm_finish
[ 27.721172] MPMU_VRCR: 1
[ 27.728442] [galcore]: gpu_resume, 1369
[ 27.734661] >>>>>>[_gpu_on]@1153
[ 27.740996] <<<<<<[_gpu_on]@1173
[ 27.827574] irq enable 227
[ 27.941115] PM: resume of devices complete after 219.928 msecs
[ 27.951321] Restarting tasks ...
[ 27.958169] usb 1-1: USB disconnect, device number 2
[ 27.974305]
[ 27.974305] =================================
[ 27.974317] [ INFO: inconsistent lock state ]
[ 27.985503] 3.0.0-00187-g68292ac-dirty #161
[ 27.992664] ---------------------------------
[ 27.999741] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
[ 28.016350] mmcqd/2/60 [HC0[0]:SC0[0]:HE1:SE1] takes:
[ 28.024780] (&(&host->lock)->rlock){?.-...}, at: [<c0264af8>]
sdhci_execute_tuning+0x24/0x4ec
[ 28.037220] {IN-HARDIRQ-W} state was registered at:
[ 28.037220] [<c00727b4>] __lock_acquire+0x590/0x1834
[ 28.045938] [<c0073f04>] lock_acquire+0x60/0x74
[ 28.063718] [<c0384a20>] _raw_spin_lock+0x40/0x50
[ 28.063718] [<c02663a8>] sdhci_irq+0x1c/0x928
[ 28.081140] [<c008d684>] handle_irq_event_percpu+0x28/0x178
[ 28.081140] [<c008d810>] handle_irq_event+0x3c/0x5c
[ 28.090858] [<c008f870>] handle_level_irq+0xb8/0xe8
[ 28.099904] [<c008d64c>] generic_handle_irq+0x24/0x2c
[ 28.109001] [<c002c060>] asm_do_IRQ+0x60/0x84
[ 28.118367] [<c0031c20>] __irq_svc+0x60/0xac
[ 28.127146] [<c0188274>] strcmp+0x8/0x34
[ 28.135907] [<c0183e64>] kset_find_obj_hinted+0x70/0xc0
[ 28.144384] [<c01d2c48>] driver_find+0x18/0x24
[ 28.154318] [<c01d2d48>] driver_register+0x80/0x134
[ 28.163554] [<c002c3ec>] do_one_initcall+0x98/0x16c
[ 28.173306] [<c00083c8>] kernel_init+0x6c/0x114
[ 28.183128] [<c0032ff8>] kernel_thread_exit+0x0/0x8
[ 28.192682] irq event stamp: 169238
[ 28.202669] hardirqs last enabled at (169238): [<c0385310>]
_raw_spin_unlock_irqrestore+0x3c/0x6c
[ 28.230997] hardirqs last disabled at (169237): [<c0384b14>]
_raw_spin_lock_irqsave+0x18/0x64
[ 28.245531] softirqs last enabled at (168569): [<c004d1bc>]
irq_exit+0x54/0xb8
[ 28.245531] softirqs last disabled at (168556): [<c004d1bc>]
irq_exit+0x54/0xb8
[ 28.272298]
[ 28.272298] other info that might help us debug this:
[ 28.272302] Possible unsafe locking scenario:
[ 28.290899]
[ 28.309129] CPU0
[ 28.309129] ----
[ 28.317580] lock(&(&host->lock)->rlock);
[ 28.325877] <Interrupt>
[ 28.335887] lock(&(&host->lock)->rlock);
[ 28.344296]
[ 28.354445] *** DEADLOCK ***
[ 28.354450]
[ 28.377501] no locks held by mmcqd/2/60.
[ 28.387063]
[ 28.387063] stack backtrace:
[ 28.402205] [<c0037b80>] (unwind_backtrace+0x0/0x120) from [<c0070330>]
(print_usage_bug+0x234/0x298)
[ 28.402205] [<c0070330>] (print_usage_bug+0x234/0x298) from
[<c00706e8>] (mark_lock+0x354/0x620)
[ 28.437011] [<c00706e8>] (mark_lock+0x354/0x620) from [<c0072840>]
(__lock_acquire+0x61c/0x1834)
[ 28.437011] [<c0072840>] (__lock_acquire+0x61c/0x1834) from
[<c0073f04>] (lock_acquire+0x60/0x74)
[ 28.451822] [<c0073f04>] (lock_acquire+0x60/0x74) from [<c0384a20>]
(_raw_spin_lock+0x40/0x50)
[ 28.466865] [<c0384a20>] (_raw_spin_lock+0x40/0x50) from [<c0264af8>]
(sdhci_execute_tuning+0x24/0x4ec)
[ 28.481752] [<c0264af8>] (sdhci_execute_tuning+0x24/0x4ec) from
[<c0265164>] (sdhci_request+0x1a4/0x1f0)
[ 28.504047] [<c0265164>] (sdhci_request+0x1a4/0x1f0) from [<c025453c>]
(mmc_wait_for_req+0x23c/0x278)
[ 28.527261] [<c025453c>] (mmc_wait_for_req+0x23c/0x278) from
[<c025d2f4>] (mmc_blk_issue_rw_rq+0x290/0x5e0)
[ 28.576160] [<c025d2f4>] (mmc_blk_issue_rw_rq+0x290/0x5e0) from
[<c025d8b8>] (mmc_blk_issue_rq+0x274/0x28c)
[ 28.576160] [<c025d8b8>] (mmc_blk_issue_rq+0x274/0x28c) from
[<c025e688>] (mmc_queue_thread+0xc4/0xc8)
[ 28.602128] [<c025e688>] (mmc_queue_thread+0xc4/0xc8) from [<c00607e0>]
(kthread+0x80/0x88)
[ 28.628510] [<c00607e0>] (kthread+0x80/0x88) from [<c0032ff8>]
(kernel_thread_exit+0x0/0x8)
[ 28.675469] done.
[ 28.711072] usb 1-1: unregistering device
disable rtc alarm interrupt: Invalid argument[ 28.742082] irq disable 67
[ 28.742360] irq disable 66
bash-4.1# [ 28.756867] usb 1-1: unregistering interface 1-1:1.0
[ 28.778731] usb 1-1: usb_disable_device nuking all URBs
[ 28.871103] atkbd serio0: keyboard reset failed on olpc_keyboard/serio0
[ 30.271005] atkbd serio0: keyboard reset failed on olpc_keyboard/serio0
[ 31.391085] hub 1-0:1.0: hub_suspend
[ 31.394721] usb usb1: bus auto-suspend
[ 31.394721] pxau2o-ehci pxau2o-ehci.0: suspend root hub
[ 31.871001] psmouse serio1: Unable get OPC state.
[ 32.202925] dcon_freeze_store: 0
[ 32.206714] dcon_source_switch to CPU
[ 32.250560] olpc-dcon: The CPU has control
[ 34.070971] write failed? which=100, val=f2, CMD_FIFO_STS=103,
prev_val=f4
}}}
--
Ticket URL: <http://dev.laptop.org/ticket/11370>
One Laptop Per Child <http://laptop.org/>
OLPC bug tracking system
More information about the Bugs
mailing list