usb-storage kernel oops

[wrobelda]

Hi.

After upgrading the firmware and kernel packages to 20130405, I experience random kernel oops when my USB HDD wakes up from idle.

The hardware is RaspberryPi type B, 512MB, being powered by Plugable 7 Port High Speed USB 2.0 Hub - commonly recommended for compatibility with raspberry. The HUB is connected to Seagate 2,5" HDD and a RTL3072 wifi card that is operating in Master mode (AP) using hostapd. Additionally, an USB sound card is connected to raspberry's second USB port.

Software wise, the system runs raspbian off the HDD. SD is only being used for /boot partition.

kdb common dump:

kdb> dumpcommon
[dumpcommon]kdb>   set BTAPROMPT 0

[dumpcommon]kdb>   set LINES 10000

[dumpcommon]kdb>   -summary

sysname    Linux
release    3.6.11+
version    #403 PREEMPT Tue Apr 2 22:48:13 BST 2013
machine    armv6l
nodename   rpi
domainname (none)
ccversion  CCVERSION
date       2013-04-10 19:42:39 tz_minuteswest 0
uptime     13:08
load avg   2.85 1.16 1.07

MemTotal:          78666 kB
MemFree:           31949 kB
Buffers:            1700 kB
[dumpcommon]kdb>   -cpu

Currently on cpu 0
Available cpus: 0
[dumpcommon]kdb>   -ps

44 sleeping system daemon (state M) processes suppressed,
use 'ps A' to see all.
Task Addr       Pid   Parent [*] cpu State Thread     Command
0xd25f2240       40        2  1    0   R  0xd25f2520 *usb-storage

0xd242ac80        1        0  0    0   S  0xd242af60  init
0xd25f2e80       39        2  0    0   D  0xd25f3160  scsi_eh_0
0xd25f2240       40        2  1    0   R  0xd25f2520 *usb-storage
0xd2606260       42        2  0    0   D  0xd2606540  jbd2/sda1-8
0xd26402c0      159        1  0    0   S  0xd26405a0  udevd
0xd18c71a0      295      159  0    0   S  0xd18c7480  udevd
0xd195e620      835        1  0    0   S  0xd195e900  logsave
0xd18124a0      945      159  0    0   S  0xd1812780  udevd
0xd2664f20     1711        1  0    0   S  0xd2665200  logsave
0xd27583e0     4840        1  0    0   S  0xd27586c0  ifplugd
0xd185e520     4845        1  0    0   S  0xd185e800  ifplugd
0xd18d31e0     4864        1  0    0   S  0xd18d34c0  ifplugd
0xd0583300     5447        1  0    0   S  0xd05835e0  ifplugd
0xd275d0a0     5464        1  0    0   S  0xd275d380  rsyslogd
0xd27b8440     5467        1  0    0   S  0xd27b8720  rs:main Q:Reg
0xd26262a0     5470        1  0    0   S  0xd2626580  rsyslogd
0xd05f73a0     5471        1  0    0   S  0xd05f7680  rsyslogd
0xd1808500     5494        1  0    0   S  0xd18087e0  hostapd
0xd1933220     5553        1  0    0   S  0xd1933500  dbus-daemon
0xd19d72c0     5651        1  0    0   S  0xd19d75a0  avahi-daemon
0xd18d25a0     5654     5651  0    0   S  0xd18d2880  avahi-daemon
0xd27243c0     5659        1  0    0   S  0xd27246a0  dnsmasq
0xd1955240     5816        1  0    0   S  0xd1955520  cron
0xd2725000     5890        1  0    0   S  0xd27252e0  thd
0xd19fd2e0     5927        1  0    0   S  0xd19fd5c0  getty
0xd199c660     5928        1  0    0   S  0xd199c940  getty
0xd19325e0     5929        1  0    0   S  0xd19328c0  getty
0xd2759020     5930        1  0    0   S  0xd2759300  getty
0xd05886e0     5931        1  0    0   S  0xd05889c0  getty
0xd261c280     5932        1  0    0   S  0xd261c560  getty
0xd2626ee0     5933        1  0    0   S  0xd26271c0  getty
0xd267c300     6326        1  0    0   S  0xd267c5e0  pulseaudio
0xd0589320     6327        1  0    0   S  0xd0589600  alsa-sink
0xd05ce720     6328        1  0    0   S  0xd05cea00  alsa-source
0xd19fc6a0     6332        1  0    0   S  0xd19fc980  alsa-sink
0xd2434060     7107        1  0    0   S  0xd2434340  pppd
0xd07005e0     7143        1  0    0   S  0xd07008c0  ifplugd
0xce349200     7230        1  0    0   S  0xce3494e0  sshd
0xd2640f00     7251     7230  0    0   S  0xd26411e0  sshd
0xd27b9080     7319     7251  0    0   S  0xd27b9360  sshd
0xd05826c0     7320     7319  0    0   S  0xd05829a0  bash
0xd2606ea0     7334     7320  0    0   S  0xd2607180  su
0xce205260     7401     7334  0    0   S  0xce205540  bash
0xce3485c0     7417        1  0    0   S  0xce3488a0  xbmc-standalone
0xd25a3120     7423        1  0    0   S  0xd25a3400  pulseaudio
0xceed7160     7451        1  0    0   S  0xceed7440  alsa-sink
0xceed6520     7462        1  0    0   S  0xceed6800  alsa-source
0xd0621180     7476        1  0    0   S  0xd0621460  alsa-sink
0xd25a24e0     7425        1  0    0   S  0xd25a27c0  rtkit-daemon
0xcdee7140     7426        1  0    0   S  0xcdee7420  rtkit-daemon
0xcdee6500     7427        1  0    0   S  0xcdee67e0  rtkit-daemon
0xcee011a0     7826     7417  0    0   S  0xcee01480  xbmc
0xd0701220     7836     7826  0    0   S  0xd0701500  xbmc.bin
0xce20f200     7988     7826  0    0   S  0xce20f4e0  VCHIQ completio
0xd06522c0     7989     7826  0    0   S  0xd06525a0  xbmc.bin
0xd2766560     7990     7826  0    0   S  0xd2766840  xbmc.bin
0xce204620     7991     7826  0    0   S  0xce204900  xbmc.bin
0xd1b032a0     7995     7826  0    0   S  0xd1b03580  HDispmanx Notif
0xcdee02a0     7996     7826  0    0   S  0xcdee0580  HTV Notify
0xce2673a0     7997     7826  0    0   S  0xce267680  HCEC Notify
0xd1823320     7998     7826  0    0   S  0xd1823600  xbmc.bin
0xd1b02660     7999     7826  0    0   S  0xd1b02940  ILCS_HOST
0xce266760     8001     7826  0    0   S  0xce266a40  xbmc.bin
0xd26f65e0     8002     7826  0    0   S  0xd26f68c0  xbmc.bin
0xce37d260     8003     7826  0    0   S  0xce37d540  xbmc.bin
0xce37c620     8004     7826  0    0   S  0xce37c900  xbmc.bin
0xcee00560     8006     7826  0    0   S  0xcee00840  xbmc.bin
0xd246ad20     8011     7826  0    0   S  0xd246b000  xbmc.bin
0xd243a080     8012     7826  0    0   S  0xd243a360  xbmc.bin
0xce26a200     8013     7826  0    0   S  0xce26a4e0  xbmc.bin
0xd0620540     8014     7826  0    0   S  0xd0620820  xbmc.bin
0xd0652f00     8015     7826  0    0   S  0xd06531e0  xbmc.bin
0xd18226e0     8016     7826  0    0   S  0xd18229c0  xbmc.bin
0xd26f7220     8017     7826  0    0   S  0xd26f7500  xbmc.bin
0xd1954600     8018     7826  0    0   S  0xd19548e0  xbmc.bin
0xd26d12c0     8026     7826  0    0   S  0xd26d15a0  xbmc.bin
0xceefa200     8037     7826  0    0   S  0xceefa4e0  xbmc.bin
0xd275c460     8038     7826  0    0   S  0xd275c740  xbmc.bin
0xd26d0680     8039     7826  0    0   S  0xd26d0960  xbmc.bin
0xce20e5c0     8040     7826  0    0   S  0xce20e8a0  xbmc.bin
0xd1a66ee0     8041     7826  0    0   S  0xd1a671c0  xbmc.bin
0xd1a662a0     8042     7826  0    0   S  0xd1a66580  xbmc.bin
0xce3fcf00     8043     7826  0    0   S  0xce3fd1e0  xbmc.bin
0xce3fc2c0     8135     7826  0    0   D  0xce3fc5a0  xbmc.bin
0xd05cf360     8136     7826  0    0   D  0xd05cf640  xbmc.bin
0xceefae40     8137     7826  0    0   D  0xceefb120  xbmc.bin
[dumpcommon]kdb>   -dmesg 600

buffer only contains 312 lines, first 312 lines printed
<6>[    0.000000] Booting Linux on physical CPU 0
<6>[    0.000000] Initializing cgroup subsys cpu
<5>[    0.000000] Linux version 3.6.11+ (dc4@dc4-arm-01) (gcc version 4.7.2 20120731 (prerelease) (crosstool-NG linaro-1.13.1+bzr2458 - Linaro GCC 2012.08) ) #403 PREEMPT Tue Apr 2 22:48:13 BST 2013
<4>[    0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
<4>[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
<4>[    0.000000] Machine: BCM2708
<6>[    0.000000] cma: CMA: reserved 16 MiB at 12c00000
<4>[    0.000000] Memory policy: ECC disabled, Data cache writeback
<7>[    0.000000] On node 0 totalpages: 80896
<7>[    0.000000] free_area_init_node: node 0, pgdat c053b854, node_mem_map c05e5000
<7>[    0.000000]   Normal zone: 632 pages used for memmap
<7>[    0.000000]   Normal zone: 0 pages reserved
<7>[    0.000000]   Normal zone: 80264 pages, LIFO batch:15
<7>[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
<7>[    0.000000] pcpu-alloc: [0] 0
<4>[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 80264

<6>[    0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
<6>[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
<6>[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
<6>[    0.000000] Memory: 316MB = 316MB total
<5>[    0.000000] Memory: 298152k/298152k available, 25432k reserved, 0K highmem
<5>[    0.000000] Virtual kernel memory layout:
<5>[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
<5>[    0.000000]     fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
<6>[    0.000000] NR_IRQS:330
<6>[    0.000000] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 4294967ms
<6>[    0.000000] Console: colour dummy device 80x30
<6>[    0.000000] console [tty1] enabled
<6>[    0.005997] Calibrating delay loop... 99.73 BogoMIPS (lpj=498688)
<6>[    0.080524] pid_max: default: 32768 minimum: 301
<6>[    0.082153] Mount-cache hash table entries: 512
<6>[    0.085476] Initializing cgroup subsys cpuacct
<6>[    0.085694] Initializing cgroup subsys devices
<6>[    0.085873] Initializing cgroup subsys freezer
<6>[    0.086040] Initializing cgroup subsys blkio
<6>[    0.086464] CPU: Testing write buffer coherency: ok
<6>[    0.087480] hw perfevents: enabled with v6 PMU driver, 3 counters available
<6>[    0.088098] Setting up static identity map for 0x39d5f8 - 0x39d654
<6>[    0.093928] devtmpfs: initialized
<6>[    0.144134] NET: Registered protocol family 16
<6>[    0.177492] DMA: preallocated 4096 KiB pool for atomic coherent allocations
<4>[    0.182438] bcm2708.uart_clock = 0
<6>[    0.189154] hw-breakpoint: found 6 breakpoint and 1 watchpoint registers.
<6>[    0.189409] hw-breakpoint: maximum watchpoint size is 4 bytes.
<6>[    0.189613] mailbox: Broadcom VideoCore Mailbox driver
<6>[    0.189997] bcm2708_vcio: mailbox at f200b880
<6>[    0.190427] bcm_power: Broadcom power driver
<4>[    0.190613] bcm_power_open() -> 0
<4>[    0.190757] bcm_power_request(0, 8)
<4>[    0.691630] bcm_mailbox_read -> 00000080, 0
<4>[    0.691819] bcm_power_request -> 0
<6>[    0.691964] Serial: AMBA PL011 UART driver
<6>[    0.692599] dev:f1: ttyAMA0 at MMIO 0x20201000 (irq = 83) is a PL011 rev3
<6>[    1.017079] console [ttyAMA0] enabled
<6>[    1.145876] bio: create slab <bio-0> at 0
<5>[    1.153604] SCSI subsystem initialized
<6>[    1.158377] usbcore: registered new interface driver usbfs
<6>[    1.164674] usbcore: registered new interface driver hub
<6>[    1.170884] usbcore: registered new device driver usb
<6>[    1.182385] Switching to clocksource stc
<5>[    1.187242] FS-Cache: Loaded
<6>[    1.191060] CacheFiles: Loaded
<6>[    1.244295] NET: Registered protocol family 2
<6>[    1.252546] TCP established hash table entries: 16384 (order: 5, 131072 bytes)
<6>[    1.263021] TCP bind hash table entries: 16384 (order: 4, 65536 bytes)
<6>[    1.271514] TCP: Hash tables configured (established 16384 bind 16384)
<6>[    1.278506] TCP: reno registered
<6>[    1.281922] UDP hash table entries: 256 (order: 0, 4096 bytes)
<6>[    1.288172] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
<6>[    1.295905] NET: Registered protocol family 1
<6>[    1.302169] RPC: Registered named UNIX socket transport module.
<6>[    1.308580] RPC: Registered udp transport module.
<6>[    1.313466] RPC: Registered tcp transport module.
<6>[    1.318441] RPC: Registered tcp NFSv4.1 backchannel transport module.
<6>[    1.328262] bcm2708_dma: DMA manager at f2007000
<6>[    1.333474] bcm2708_gpio: bcm2708_gpio_probe c0515d98
<4>[    1.340696] vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB)
<6>[    1.353379] audit: initializing netlink socket (disabled)
<5>[    1.359262] type=2000 audit(1.200:1): initialized
<5>[    2.131111] VFS: Disk quotas dquot_6.5.2
<4>[    2.135455] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
<5>[    2.144171] FS-Cache: Netfs 'nfs' registered for caching
<5>[    2.151069] NFS: Registering the id_resolver key type
<5>[    2.156543] Key type id_resolver registered
<5>[    2.161178] Key type id_legacy registered
<6>[    2.166456] msgmni has been set to 614
<6>[    2.176597] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
<6>[    2.185364] io scheduler noop registered
<6>[    2.189806] io scheduler deadline registered
<6>[    2.194335] io scheduler cfq registered (default)
<6>[    2.363128] Console: switching to colour frame buffer device 228x61
<6>[    2.504675] kgdb: Registered I/O driver kgdboc.
<6>[    2.512671] vc-cma: Videocore CMA driver
<6>[    2.517435] vc-cma: vc_cma_base      = 0x00000000
<6>[    2.522909] vc-cma: vc_cma_size      = 0x00000000 (0 MiB)
<6>[    2.529265] vc-cma: vc_cma_initial   = 0x00000000 (0 MiB)
<6>[    2.580631] brd: module loaded
<6>[    2.607963] loop: module loaded
<6>[    2.612977] vchiq: vchiq_init_state: slot_zero = 0xd2c00000, is_master = 0
<6>[    2.623621] Loading iSCSI transport class v2.0-870.
<6>[    2.632764] usbcore: registered new interface driver smsc95xx
<6>[    2.639919] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
<4>[    2.852514] Core Release: 2.80a
<4>[    2.856289] Setting default values for core params
<4>[    2.862183] Finished setting default values for core params
<4>[    3.074989] Using Buffer DMA mode
<4>[    3.079014] Periodic Transfer Interrupt Enhancement - disabled
<4>[    3.085767] Multiprocessor Interrupt Enhancement - disabled
<4>[    3.092314] OTG VER PARAM: 0, OTG VER FLAG: 0
<4>[    3.097494] Dedicated Tx FIFOs mode
<7>[    3.104474] dwc_otg: Microframe scheduler enabled
<6>[    3.105804] dwc_otg bcm2708_usb: DWC OTG Controller
<6>[    3.111854] dwc_otg bcm2708_usb: new USB bus registered, assigned bus number 1
<6>[    3.120607] dwc_otg bcm2708_usb: irq 32, io mem 0x00000000
<4>[    3.127188] Init: Port Power? op_state=1
<4>[    3.131768] Init: Power Port (0)
<6>[    3.135888] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
<6>[    3.143905] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
<6>[    3.186861] usb usb1: Product: DWC OTG Controller
<6>[    3.227276] usb usb1: Manufacturer: Linux 3.6.11+ dwc_otg_hcd
<6>[    3.268278] usb usb1: SerialNumber: bcm2708_usb
<6>[    3.311234] hub 1-0:1.0: USB hub found
<6>[    3.349813] hub 1-0:1.0: 1 port detected
<7>[    3.389546] dwc_otg: FIQ enabled
<7>[    3.389611] dwc_otg: NAK holdoff enabled
<7>[    3.389704] Module dwc_common_port init
<6>[    3.390331] Initializing USB Mass Storage driver...
<6>[    3.430617] usbcore: registered new interface driver usb-storage
<6>[    3.471157] USB Mass Storage support registered.
<6>[    3.511285] usbcore: registered new interface driver libusual
<6>[    3.553207] mousedev: PS/2 mouse device common for all mice
<6>[    3.596363] bcm2835-cpufreq: min=100000 max=850000 cur=100000
<4>[    3.637792] Indeed it is in host mode hprt0 = 00021501
<6>[    3.678812] bcm2835-cpufreq: switching to governor powersave
<6>[    3.726763] bcm2835-cpufreq: switching to governor powersave
<6>[    3.806770] cpuidle: using governor ladder
<6>[    3.859585] cpuidle: using governor menu
<6>[    3.897588] sdhci: Secure Digital Host Controller Interface driver
<6>[    3.938061] sdhci: Copyright(c) Pierre Ossman
<4>[    3.976610] sdhci: Enable low-latency mode
<6>[    4.014345] usb 1-1: new high-speed USB device number 2 using dwc_otg
<4>[    4.057877] Indeed it is in host mode hprt0 = 00001101
<6>[    4.136797] mmc0: SDHCI controller on BCM2708_Arasan [platform] using platform's DMA
<6>[    4.209609] mmc0: BCM2708 SDHC host at 0x20300000 DMA 2 IRQ 77
<6>[    4.255609] sdhci-pltfm: SDHCI platform and OF driver helper
<6>[    4.304242] usbcore: registered new interface driver usbhid
<6>[    4.344513] usbhid: USB HID core driver
<6>[    4.386209] TCP: cubic registered
<6>[    4.425020] usb 1-1: New USB device found, idVendor=0424, idProduct=9512
<6>[    4.467248] Initializing XFRM netlink socket
<6>[    4.506850] NET: Registered protocol family 17
<6>[    4.546273] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
<5>[    4.590564] Key type dns_resolver registered
<6>[    4.635576] hub 1-1:1.0: USB hub found
<6>[    4.677810] mmc0: new high speed SDHC card at address 0001
<6>[    4.720427] VFP support v0.3: implementor 41 architecture 1 part 20 variant b rev 5
<6>[    4.765347] hub 1-1:1.0: 3 ports detected
<6>[    4.808672] mmcblk0: mmc0:0001 00000 7.46 GiB
<6>[    4.854760] registered taskstats version 1
<6>[    4.900315]  mmcblk0: p1 p2
<6>[    4.945736] Waiting for root device /dev/sda1...
<6>[    5.167196] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
<6>[    5.328568] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
<6>[    5.372362] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
<6>[    5.422121] smsc95xx v1.0.4
<6>[    5.542838] smsc95xx 1-1.1:1.0: eth0: register 'smsc95xx' at usb-bcm2708_usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:36:41:df
<6>[    5.687469] usb 1-1.2: new full-speed USB device number 4 using dwc_otg
<6>[    5.873402] usb 1-1.2: New USB device found, idVendor=08bb, idProduct=2902
<6>[    5.918938] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
<6>[    5.965046] usb 1-1.2: Product: USB Audio CODEC
<6>[    6.008351] usb 1-1.2: Manufacturer: Burr-Brown from TI
<6>[    6.070906] input: Burr-Brown from TI               USB Audio CODEC  as /devices/platform/bcm2708_usb/usb1/1-1/1-1.2/1-1.2:1.3/input/input0
<6>[    6.125399] hid-generic 0003:08BB:2902.0001: input,hidraw0: USB HID v1.00 Device [Burr-Brown from TI               USB Audio CODEC ] on usb-bcm2708_usb-1.2/input3
<6>[    6.277395] usb 1-1.3: new high-speed USB device number 5 using dwc_otg
<6>[    6.429944] usb 1-1.3: New USB device found, idVendor=1a40, idProduct=0201
<6>[    6.478049] usb 1-1.3: New USB device strings: Mfr=0, Product=1, SerialNumber=0
<6>[    6.527181] usb 1-1.3: Product: USB 2.0 Hub [MTT]
<6>[    6.577147] hub 1-1.3:1.0: USB hub found
<6>[    6.623341] hub 1-1.3:1.0: 7 ports detected
<6>[    6.947152] usb 1-1.3.6: new high-speed USB device number 6 using dwc_otg
<6>[    7.090123] usb 1-1.3.6: New USB device found, idVendor=0bc2, idProduct=2300
<6>[    7.139691] usb 1-1.3.6: New USB device strings: Mfr=1, Product=2, SerialNumber=3
<6>[    7.188997] usb 1-1.3.6: Product: Portable
<6>[    7.235898] usb 1-1.3.6: Manufacturer: Seagate
<6>[    7.281963] usb 1-1.3.6: SerialNumber: 2GHXPYEV
<6>[    7.332314] usb-storage 1-1.3.6:1.0: Quirks match for vid 0bc2 pid 2300: 200000
<6>[    7.382114] scsi0 : usb-storage 1-1.3.6:1.0
<6>[    7.507351] usb 1-1.3.7: new high-speed USB device number 7 using dwc_otg
<6>[    7.675670] usb 1-1.3.7: New USB device found, idVendor=148f, idProduct=3072
<6>[    7.724437] usb 1-1.3.7: New USB device strings: Mfr=1, Product=2, SerialNumber=3
<6>[    7.774473] usb 1-1.3.7: Product: 802.11 n WLAN
<6>[    7.820952] usb 1-1.3.7: Manufacturer: Ralink
<6>[    7.867207] usb 1-1.3.7: SerialNumber: 1.0
<5>[    8.430340] scsi 0:0:0:0: Direct-Access     Seagate  Portable         0130 PQ: 0 ANSI: 4
<5>[    8.487262] sd 0:0:0:0: [sda] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
<5>[    8.549464] sd 0:0:0:0: [sda] Write Protect is off
<7>[    8.597550] sd 0:0:0:0: [sda] Mode Sense: 2f 08 00 00
<3>[    8.599363] sd 0:0:0:0: [sda] No Caching mode page present
<5>[    8.647986] sd 0:0:0:0: [sda] Assuming drive cache: write back
<3>[    8.703855] sd 0:0:0:0: [sda] No Caching mode page present
<5>[    8.751111] sd 0:0:0:0: [sda] Assuming drive cache: write back
<6>[    8.833489]  sda: sda1 sda2
<3>[    8.889310] sd 0:0:0:0: [sda] No Caching mode page present
<5>[    8.936122] sd 0:0:0:0: [sda] Assuming drive cache: write back
<5>[    8.983079] sd 0:0:0:0: [sda] Attached SCSI disk
<6>[   10.305591] EXT4-fs (sda1): recovery complete
<6>[   10.372238] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
<6>[   10.421441] VFS: Mounted root (ext4 filesystem) on device 8:1.
<6>[   10.502356] devtmpfs: mounted
<6>[   10.548829] Freeing init memory: 128K
<30>[   15.559183] udevd[159]: starting version 175
<7>[   20.755140] Registered led device: led0
<6>[   25.424547] cfg80211: Calling CRDA to update world regulatory domain
<6>[   27.387433] usb 1-1.3.7: reset high-speed USB device number 7 using dwc_otg
<7>[   28.261667] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
<7>[   28.284656] Registered led device: rt2800usb-phy0::radio
<7>[   28.285330] Registered led device: rt2800usb-phy0::assoc
<7>[   28.286218] Registered led device: rt2800usb-phy0::quality
<6>[   28.312542] usbcore: registered new interface driver rt2800usb
<6>[   29.367845] usbcore: registered new interface driver snd-usb-audio
<6>[   30.447300] cfg80211: World regulatory domain updated:
<6>[   30.576884] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
<6>[   30.756874] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
<6>[   31.239692] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
<6>[   31.611884] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
<6>[   31.876931] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
<6>[   32.216332] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
<6>[   46.862714] EXT4-fs (sda1): re-mounted. Opts: (null)
<6>[   49.617883] EXT4-fs (sda1): re-mounted. Opts: (null)
<6>[   52.328742] bcm2835 ALSA card created!
<6>[   52.417720] bcm2835 ALSA chip created!
<6>[   52.497949] bcm2835 ALSA chip created!
<6>[   52.581351] bcm2835 ALSA chip created!
<6>[   52.667748] bcm2835 ALSA chip created!
<6>[   52.722727] bcm2835 ALSA chip created!
<6>[   52.772081] bcm2835 ALSA chip created!
<6>[   52.847818] bcm2835 ALSA chip created!
<6>[   76.023625] SGI XFS with ACLs, security attributes, realtime, large block/inode numbers, no debug enabled
<5>[   76.139173] XFS (sda2): Mounting Filesystem
<5>[   76.820607] XFS (sda2): Starting recovery (logdev: internal)
<5>[   78.595858] XFS (sda2): Ending recovery (logdev: internal)
<6>[  166.108607] smsc95xx 1-1.1:1.0: eth0: link up, 100Mbps, full-duplex, lpa 0x41E1
<6>[  166.143648] PPP generic driver version 2.4.2
<6>[  166.659734] NET: Registered protocol family 24
<6>[  176.848948] ip_tables: (C) 2000-2006 Netfilter Core Team
<6>[  192.610975] bcm2835-cpufreq: switching to governor ondemand
<6>[  192.611070] bcm2835-cpufreq: switching to governor ondemand
<6>[  194.016448] NET: Registered protocol family 10
<5>[  194.045690] Bridge firewalling registered
<6>[  194.057823] device wlan0 entered promiscuous mode
<6>[  194.681304] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
<6>[  194.681587] IPv6: ADDRCONF(NETDEV_UP): br0: link is not ready
<6>[  194.682754] cfg80211: Calling CRDA for country: PL
<6>[  194.769408] cfg80211: Regulatory domain changed to country: PL
<6>[  194.769437] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
<6>[  194.769450] cfg80211:   (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm)
<6>[  194.769460] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm)
<6>[  194.769470] cfg80211:   (5250000 KHz - 5330000 KHz @ 40000 KHz), (N/A, 2000 mBm)
<6>[  194.769479] cfg80211:   (5490000 KHz - 5710000 KHz @ 40000 KHz), (N/A, 2700 mBm)
<6>[  195.267370] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
<6>[  195.267582] br0: port 1(wlan0) entered forwarding state
<6>[  195.267619] br0: port 1(wlan0) entered forwarding state
<6>[  195.267693] IPv6: ADDRCONF(NETDEV_CHANGE): br0: link becomes ready
<6>[  196.041107] nf_conntrack version 0.5.0 (4916 buckets, 19664 max)
<6>[  199.378693] Adding 1048572k swap on /swap.  Priority:-1 extents:265 across:6178812k
<6>[  210.316792] br0: port 1(wlan0) entered forwarding state
<6>[ 2050.317301] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[ 2082.317483] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[ 5780.317000] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[ 5812.316986] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[ 9381.356609] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[12980.316502] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[16580.316223] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[16612.316467] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[20181.355924] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[23781.275652] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[23813.355619] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[27380.315375] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[30981.355080] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[31013.354973] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[31409.274895] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[32062.315237] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[34581.274203] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[35126.314755] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[37341.274220] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<7>[37690.934925] delay: estimated 133, actual 0
<7>[37690.973513] delay: estimated 178, actual 1
<7>[37690.973780] delay: estimated 310, actual 1
<7>[37691.111829] delay: estimated 353, actual 0
<7>[37691.112436] delay: estimated 309, actual 0
<6>[38180.313902] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[38348.775301] smsc95xx 1-1.1:1.0: eth0: link down
<6>[40055.114392] smsc95xx 1-1.1:1.0: eth0: link up, 100Mbps, full-duplex, lpa 0x41E1
<6>[40056.736228] smsc95xx 1-1.1:1.0: eth0: link down
<6>[40059.779213] smsc95xx 1-1.1:1.0: eth0: link up, 100Mbps, full-duplex, lpa 0x4DE1
<6>[40070.385839] smsc95xx 1-1.1:1.0: eth0: link down
<6>[40072.075802] smsc95xx 1-1.1:1.0: eth0: link up, 100Mbps, full-duplex, lpa 0x41E1
<6>[41780.314616] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[42622.313391] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<6>[44085.833187] Bluetooth: Core ver 2.16
<6>[44085.835515] NET: Registered protocol family 31
<6>[44085.835541] Bluetooth: HCI device and connection manager initialized
<6>[44085.835554] Bluetooth: HCI socket layer initialized
<6>[44085.835563] Bluetooth: L2CAP socket layer initialized
<6>[44085.835617] Bluetooth: SCO socket layer initialized
<6>[44085.893164] Bluetooth: RFCOMM TTY layer initialized
<6>[44085.893221] Bluetooth: RFCOMM socket layer initialized
<6>[44085.893235] Bluetooth: RFCOMM ver 1.11
<6>[46888.313091] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
<1>[46888.413738] Unable to handle kernel NULL pointer dereference at virtual address 00000030
<1>[46888.426898] pgd = c0004000
<1>[46888.434623] [00000030] *pgd=00000000
<0>[46888.443277] Internal error: Oops: 17 [#1] PREEMPT ARM
[dumpcommon]kdb>   -bt

Stack traceback for pid 40
0xd25f2240       40        2  1    0   R  0xd25f2520 *usb-storage
[<c0013a7c>] (unwind_backtrace+0x0/0xf0) from [<c0010f64>] (show_stack+0x10/0x14)
[<c0010f64>] (show_stack+0x10/0x14) from [<c00766ec>] (kdb_show_stack+0x3c/0x58)
[<c00766ec>] (kdb_show_stack+0x3c/0x58) from [<c0076790>] (kdb_bt1.isra.0+0x88/0xd0)
[<c0076790>] (kdb_bt1.isra.0+0x88/0xd0) from [<c0076a8c>] (kdb_bt+0x2b4/0x360)
[<c0076a8c>] (kdb_bt+0x2b4/0x360) from [<c0074320>] (kdb_parse+0x2b4/0x630)
[<c0074320>] (kdb_parse+0x2b4/0x630) from [<c0074728>] (kdb_exec_defcmd+0x8c/0xe4)
[<c0074728>] (kdb_exec_defcmd+0x8c/0xe4) from [<c0074320>] (kdb_parse+0x2b4/0x630)
[<c0074320>] (kdb_parse+0x2b4/0x630) from [<c0074f38>] (kdb_main_loop+0x4d8/0x6fc)
[<c0074f38>] (kdb_main_loop+0x4d8/0x6fc) from [<c00774ec>] (kdb_stub+0x154/0x380)
[<c00774ec>] (kdb_stub+0x154/0x380) from [<c006e620>] (kgdb_handle_exception+0x1f8/0x668)
[<c006e620>] (kgdb_handle_exception+0x1f8/0x668) from [<c00131fc>] (kgdb_notify+0x24/0x40)
[<c00131fc>] (kgdb_notify+0x24/0x40) from [<c039b6d4>] (notifier_call_chain+0x44/0x84)
[<c039b6d4>] (notifier_call_chain+0x44/0x84) from [<c039b74c>] (__atomic_notifier_call_chain+0x38/0x4c)
[<c039b74c>] (__atomic_notifier_call_chain+0x38/0x4c) from [<c039b778>] (atomic_notifier_call_chain+0x18/0x20)
[<c039b778>] (atomic_notifier_call_chain+0x18/0x20) from [<c039b7b8>] (notify_die+0x38/0x44)
[<c039b7b8>] (notify_die+0x38/0x44) from [<c001102c>] (die+0xc4/0x39c)
[<c001102c>] (die+0xc4/0x39c) from [<c0394510>] (__do_kernel_fault.part.9+0x54/0x74)
[<c0394510>] (__do_kernel_fault.part.9+0x54/0x74) from [<c039b3e4>] (do_page_fault+0x1e8/0x3ec)
[<c039b3e4>] (do_page_fault+0x1e8/0x3ec) from [<c000832c>] (do_DataAbort+0x34/0x98)
[<c000832c>] (do_DataAbort+0x34/0x98) from [<c0399bd8>] (__dabt_svc+0x38/0x60)
Exception stack(0xd25f7db8 to 0xd25f7e00)
7da0:                                                       d2582a80 d25b1434
7dc0: ffffff94 00000000 d25b1434 d2582a80 d25de9f0 d25b1434 d2582a80 d25e2540
7de0: d25c52e8 00000020 00000000 d25f7e00 c0273bcc c02724e8 60000093 ffffffff
[<c0399bd8>] (__dabt_svc+0x38/0x60) from [<c02724e8>] (unlink1+0x14/0x160)
[<c02724e8>] (unlink1+0x14/0x160) from [<c0273bcc>] (usb_hcd_flush_endpoint+0x128/0x158)
[<c0273bcc>] (usb_hcd_flush_endpoint+0x128/0x158) from [<c0276148>] (usb_disable_endpoint+0x4c/0x80)
[<c0276148>] (usb_disable_endpoint+0x4c/0x80) from [<c02761b8>] (usb_disable_interface+0x3c/0x54)
[<c02761b8>] (usb_disable_interface+0x3c/0x54) from [<c026eef8>] (usb_reset_and_verify_device+0x350/0x4c4)
[<c026eef8>] (usb_reset_and_verify_device+0x350/0x4c4) from [<c026f10c>] (usb_reset_device+0xa0/0x15c)
[<c026f10c>] (usb_reset_device+0xa0/0x15c) from [<c02a28ac>] (usb_stor_port_reset+0x54/0x64)
[<c02a28ac>] (usb_stor_port_reset+0x54/0x64) from [<c02a2a54>] (usb_stor_invoke_transport+0x198/0x4fc)
[<c02a2a54>] (usb_stor_invoke_transport+0x198/0x4fc) from [<c02a3d28>] (usb_stor_control_thread+0x19c/0x28c)
[<c02a3d28>] (usb_stor_control_thread+0x19c/0x28c) from [<c003a7b4>] (kthread+0x88/0x94)
[<c003a7b4>] (kthread+0x88/0x94) from [<c000e9fc>] (kernel_thread_exit+0x0/0x8)

[wrobelda]

The stack trace dump appears corrupted after posting, here's the source for it:
http://dawidwrobel.com/files/usb_storage_oops.txt

[popcornmix]

Seems to be a null pointer defererence in dwc_otg/usb.
@ghollingworth ? @P33M?

[hvenzke]

kernel 3.8.4 compile

CC [M] drivers/usb/host/dwc_otg/dwc_otg_pcd_intr.o
drivers/usb/host/dwc_otg/dwc_otg_pcd_intr.c: In function 'dwc_otg_pcd_handle_out_ep_intr':
drivers/usb/host/dwc_otg/dwc_otg_pcd_intr.c:4279:21: warning: operation on 'status.d32' may be undefined [-Wsequence-point]

[P33M]

I've seen several OOPSes during driver shutdown, port disconnect, device reset and the like. Sporadic and hard to find.

I note that you are using quite wide frequency ranges and an overclock at 850MHz - does this happen with a fixed 700MHz default frequency?

[hvenzke]

I ´m I am use 850 MhZ on my type B Pi´s .
But i don´t have any ops with kernel 3.6.11 and up.
But It happend at 3.2.27 i.e on opensuse , fc remix 17.x

Thats why i am here :-) .
I thank for popcornmix and others work past weeks to get the dwc_otg fixed with SDHC/SDHX .

Note : I had Ops when using external HDD without an Powered HUB.

[wrobelda]

@P33M it happens also when not overclocked, but I didn't test with a fixed 700 MHz. I will and let you know.

[wrobelda]

Running plain 700 MHz and got the following in dmesg. On a first look it seems unrelated (br), but then again eth runs off the USB, so I thought you might want to have a look:

[33612.297448] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
[33850.217140] ------------[ cut here ]------------
[33850.217330] WARNING: at net/bridge/br_multicast.c:284 br_multicast_port_group_expired+0x74/0x78 bridge
[33850.217358] Modules linked in: xt_TCPMSS xt_tcpmss xt_tcpudp iptable_mangle ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 ip_tables x_tables aes_generic bridge ipv6 stp llc pppoe pppox ppp_generic slhc snd_bcm2835 snd_usb_audio snd_pcm snd_page_alloc snd_hwdep snd_usbmidi_lib snd_seq_midi snd_seq_midi_event snd_rawmidi arc4 snd_seq snd_timer snd_seq_device rt2800usb rt2800lib crc_ccitt rt2x00usb rt2x00lib mac80211 snd evdev cfg80211 rfkill leds_gpio led_class
[33850.217600] from
[33850.217661] from
[33850.217777] from [](br_multicast_port_group_expired+0x74/0x78 [bridge])
[33850.217972] [](br_multicast_port_group_expired+0x74/0x78 [bridge]) from
[33850.218029] from
[33850.218060] from
[33850.218095] from
[33850.218157] from
[33850.218187] from
[33850.218213] from
[33850.218261] from
[33850.218275] ---[ end trace 8828e1cfadc48e2e ]---
[34155.994472] delay: estimated 177, actual 0
[34794.297402] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
[36234.297207] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
[36888.297026] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg
[37269.067285] delay: estimated 221, actual 0
[37625.337019] usb 1-1.3.6: reset high-speed USB device number 6 using dwc_otg

[wrobelda]

sorry, corrupted again: http://www.dawidwrobel.com/files/br_oops.txt

[wrobelda]

OK, had another USB storage kernel oops this morning (same as initially reported) with fixed 700 MHz frequency, so frequency scaling is not the cause here.

Funny thing is that it always happens in the morning. The only pattern that comes to mind and makes sense with this scenario is that after not being used for a long time at night, some memory swapping occurs (?) and whenever I connect to WiFi in the morning, it oops exactly at this very moment. Is there an equivalent to "dmesg -T" in kdb that would help me to confirm the timing of the oops?

[licaon-kter]

did you disable any sort of power management? say USB? or WiFi?

[hvenzke]

@wrobelda may you use an POWERD USB HUB ?

Model B require ~900 mA for itsself under load at least for Stable work.

With external HDD the power exhaused with standard ( 1000 mA ) power sources.

[wrobelda]

@licaon-kter I did not.
EDIT: However the HDD itself is by default set to go into suspend mode (spin down) when not used for a while. It must be reported to USB subsystem and the "reset high-speed USB device number 6 using dwc_otg" messages printed upon disk wake-up seem to confirm that. So essentially some power saving is in place for the HDD, but I did not enable it explicitly and it is configured to work this way on its own. I bet that by changing the power saving parameters with hdparm I would make the symptoms go away, but not really solve the underlying cause. Besides that, I do want to have the HDD to spin down when not used.

@remsnet "Plugable 7 Port" hub that I use is powered and said to be one of the most compatible with Raspberry. The HDD is 2,5" inch USB-powered with no external power source connector, so I seriously doubt it would exhaust the standard USB limits.

BTW, something interesting I sometimes also notice:

[pon kwi 15 22:04:54 2013] sd 0:0:0:0: [sda] Device not ready
[pon kwi 15 22:04:54 2013] sd 0:0:0:0: [sda]
[pon kwi 15 22:04:54 2013] Result: hostbyte=0x00 driverbyte=0x08
[pon kwi 15 22:04:54 2013] sd 0:0:0:0: [sda]
[pon kwi 15 22:04:54 2013] Sense Key : 0x2 [current]
[pon kwi 15 22:04:54 2013] Info fld=0x0
[pon kwi 15 22:04:54 2013] sd 0:0:0:0: [sda]
[pon kwi 15 22:04:54 2013] ASC=0x4 ASCQ=0x2
[pon kwi 15 22:04:54 2013] sd 0:0:0:0: [sda] CDB:
[pon kwi 15 22:04:54 2013] cdb[0]=0x28: 28 00 00 74 00 4f 00 00 08 00
[pon kwi 15 22:04:54 2013] end_request: I/O error, dev sda, sector 7602255

[hvenzke]

@wrobelda , problem looks like the USB POWER EXhaused !!
issue seems not not the compatible Standard Hub, as Linux SEE the device correctly.

What it looks for me been that kernel starts to load , and at the point where the kernel access the drive UNDER LOAD ( kernel boot IO load..) the USB Power seem exhaused. This shuold never ever happen .
Your 2,5 HDD seems to exhause what your RPI´s powersource can deliver via the RPI USB Conector.

Same will Issue happen on some old Laptops that don´t deliver enoth Power.

I HAD the same with 64G & 128G USB sticks on RPI 3.x kernal equal withóut extra Power for the PI

I use an 7 port belkim POWERD with 2500 mA , have 7 x 64G sticks attached witz raid5 fuse-zfs
Such Hub costs here in the EU arround 20 eur ( www.conrad.com i.e )

As written : 900mA for the PI and addional arround 1500mA für exernal disk see your HDD disk specs.
My PI´s has an own USB Power Supply with 1200mA witch fully used under PI max load.

[wrobelda]

"Your 2,5 HDD seems to exhause what your RPI´s powersource can deliver via the RPI USB Conector."
@remsnet As I already explained, my HDD is connected to the HUB - just like the wifi card. Only the soundcard connects directly to raspberry's second USB port. I can reconnect it to the HUB but seriously doubt it will make any difference.