Linux/AM3352: USB Mass Storage issues

The log shows

1. USB babble condition happened;

2. CPPI driver crash dump happened during babble recovery;

so I think this is what happened:

The noise in EFT causes USB babble condition, the USB driver tries to recover the babble condition, but there is a driver bug in CPPI (or elsewhere) which causes the recovery failed, so the SCSI driver is unable to communicate to the USB device to create the SCSI block device nodes.

I notice the dmesg log has information of usb_emmc_test.s(h?), is it a shell script you used during the test to transfer data from/to the USB devices? Can you please share the script? If I can reproduce the CPPI driver crash, I might be able to find the root cause of the bug and solve it.

usb_emmc_test.s(h?) is shell script I used during test to transfer data from/to the USB devices. 
I have attached the script for your reference; you may need to do some modifications to the script. 

#!/bin/bash
# EXERCISE THE USB PORTS and eMMC partition
# -> Script usage:
# 	 Ex. ./usb_emmc_test.sh sda1, ./usb_emmc_test.sh sdb1, ./usb_emmc_test.sh sdc1 or ./usb_emmc_test.sh mmcblk0p4
# Note: The script assumes all the USB ports have USB flash drives connected during testing  

# make file system as Read-Write file system
#mount -o remount,rw /

# Check to see if particular USB/eMMC partition exist (sda1,sdb1,sdc1 or mmcblk0p4)
PART_EXIST=$(cat /proc/partitions | grep -w $1)

# Check to see if particular USB partition exist
# Check to see if USB0_DRVBUS and USB1_DRVBUS ststus is High 
if [[ ("$PART_EXIST" != "") && ("$(devmem 0x47401018 | grep -w '0x00000001')" != "") && 
	  ("$(devmem 0x47401818 | grep -w '0x00000001')" != "") ]]; then

# Check if mount directory is created under /mnt
# Create mount directory under /mnt if not present/created 
	if [ ! -e /mnt/$1 ] ; then
		mkdir /mnt/$1
	fi

# Check if partition is mounted 	
# If partition is not mounted, then try to mount the partition
# Exit script in case of failure to mount partition
	if ! mountpoint -q /mnt/$1/ ; then
	
		if ! mount /dev/$1 /mnt/$1/ ; then
			exit 1
		fi
		
	fi

# Check if file exists on mounted partition, if not then copy file		
# Copy test file to mounted partition, and force changed blocks to disk using 'sync' command 
# Exit script in case of failure to copy file	
	if [ ! -e /mnt/$1/testFileCopy.bin ] ; then 
		echo "Copy File"
		if ! dd if=./testFile.bin of=/mnt/$1/testFileCopy.bin ; then
			exit 1
		else
			sync
		fi
	else
		echo "File Exists"
	fi
	
# Compare original and copied file, if files are not identical exit script
    # first, make sure the file system cache is cleared, so that we actually read from the flash disk under test
    echo 3 > /proc/sys/vm/drop_caches
	if ! diff -s ./testFile.bin /mnt/$1/testFileCopy.bin ; then
		exit 1
	fi		
	
# delete copied file from mounted partition, exit script if file delete fails
#	if ! rm -rf /mnt/$1/testFileCopy.bin ; then
#		exit 1
#	fi 	
	
else 
# re-initialize the USB peripheral
# re-initializing USB0 as well as USB1, id DRVBUS status is observed to be LOW or any of the USB block partitions are missing 

# unmount already mounted USB flash drivs, so that after USB reset we get same partion numbers 
	umount /mnt/sda1/
	umount /mnt/sdb1/
	umount /mnt/sdc1/
	
#USB0
	echo 0 > /sys/kernel/debug/musb-hdrc.0/softconnect
	usleep 100 
	echo 1 > /sys/kernel/debug/musb-hdrc.0/softconnect
	
#USB1	
	echo 0 > /sys/kernel/debug/musb-hdrc.1/softconnect
	usleep 100 
	echo 1 > /sys/kernel/debug/musb-hdrc.1/softconnect
	
	exit 1
fi

sleep 1

Can you please try if the following patch solves the issue?

diff --git a/drivers/dma/cppi41.c b/drivers/dma/cppi41.c
index 675de6a27e39..791528520f09 100644
--- a/drivers/dma/cppi41.c
+++ b/drivers/dma/cppi41.c
@@ -653,7 +653,7 @@ static int cppi41_tear_down_chan(struct cppi41_channel *c)
                reg |= GCR_TEARDOWN;
                cppi_writel(reg, c->gcr_reg);
                c->td_queued = 1;
-               c->td_retry = 500;
+               c->td_retry = 1000;
        }
 
        if (!c->td_seen || !c->td_desc_seen) {

I am unable to replicate the exact issue you see, you got the kernel dump by cppi41.c line 702, but I got the kernel dump by line 696. They both show the dma channel teardown problem but in different points of the process.

The sdk4.0 you use was released at the beginning of this year, I just tested with the latest TI 4.9 kernel (git tag ti2017.06-rc4-int, on repo git://git.ti.com/ti-linux-kernel/ti-linux-kernel.git), now dma channel teardown process doesn't generate any kernel dump when babble condition happens, (kernel still dumps in fs/fs-writeback.c, but usb recovers properly, /dev/sda node always present after the babble recovery.)

Can you please test the latest kernel to see if you still have the issue?

The TI Processor SDK releases and the the kernel git repo I mentioned are different.

Once a while (generally about every quarter) TI releases a Processor Linux SDK, which might include updates for uboot, Linux kernel, filesystem components, or GCC toolchain. You can download the SDK package from ti.com.

But the git repo I referred is TI Linux kernel development repository. It is tagged for each kernel release (TI internal release candidates for Processor SDK kernel update), The tag I mentioned (ti2017.06-rc4-int) is the latest tag for kernel ti2017.06 release.

You would need tool git to clone and check this repo tag to build the kernel. Please let me know if you have any issue using it.

EFT_Kernel_V4.9.69.txtI tested the USB issue with latest kernel you suggested, I still have the issue: please see the crash dump messages below.

I also have attached detailed log for your reference.

dmesg output:

[  367.427031] ------------[ cut here ]------------

[  367.431922] WARNING: CPU: 0 PID: 4 at drivers/dma/cppi41.c:700 cppi41_stop_chan+0x260/0x350

[  367.440662] Modules linked in: ti_am335x_adc omap_aes_driver crypto_engine omap_sham cdc_ether usbnet mii omap_wdt ti_am335x_tscadc

[  367.453119] CPU: 0 PID: 4 Comm: kworker/0:0 Tainted: G        W       4.9.69-pic6-02469-g9a0da80 #1

[  367.462584] Hardware name: Generic AM33XX (Flattened Device Tree)

[  367.468984] Workqueue: usb_hub_wq hub_event

[  367.473365] Backtrace:

[  367.475955] [<c010b9dc>] (dump_backtrace) from [<c010bc98>] (show_stack+0x18/0x1c)

[  367.483884]  r7:00000009 r6:00000000 r5:c0849eec r4:00000000

[  367.489818] [<c010bc80>] (show_stack) from [<c037af10>] (dump_stack+0x24/0x28)

[  367.497389] [<c037aeec>] (dump_stack) from [<c0129bd0>] (__warn+0xe8/0x100)

[  367.504682] [<c0129ae8>] (__warn) from [<c0129ca0>] (warn_slowpath_null+0x28/0x30)

[  367.512612]  r9:c4041000 r8:0000003c r7:00000001 r6:c3bd2010 r5:c3bd2018 r4:c3be8130

[  367.520723] [<c0129c78>] (warn_slowpath_null) from [<c03cf5d4>] (cppi41_stop_chan+0x260/0x350)

[  367.529752] [<c03cf374>] (cppi41_stop_chan) from [<c049e450>] (cppi41_dma_channel_abort+0x144/0x2b4)

[  367.539317]  r9:c0a7e1ac r8:c3c56010 r7:c0a7e1c0 r6:00000004 r5:00000000 r4:c3c25848

[  367.547430] [<c049e30c>] (cppi41_dma_channel_abort) from [<c049b000>] (musb_cleanup_urb+0x60/0x1e0)

[  367.556904]  r10:c3c25848 r9:c3c56010 r8:c88fd410 r7:00000000 r6:c3e0ac00 r5:00000080

[  367.565097]  r4:c3c564e8

[  367.567755] [<c049afa0>] (musb_cleanup_urb) from [<c049b7f8>] (musb_urb_dequeue+0xf4/0x12c)

[  367.576501]  r10:00000001 r9:c000a280 r8:a0070093 r7:00000000 r6:c3c56010 r5:c3e0a500

[  367.584694]  r4:c3e0ac00

[  367.587354] [<c049b704>] (musb_urb_dequeue) from [<c046c694>] (unlink1+0x34/0x110)

[  367.595282]  r10:c38ec400 r9:c38ec48c r8:c3c3a200 r7:ffffff94 r6:c3c3a200 r5:c3db0000

[  367.603477]  r4:c3e0ac00 r3:c049b704

[  367.607226] [<c046c660>] (unlink1) from [<c046e934>] (usb_hcd_flush_endpoint+0xfc/0x110)

[  367.615700]  r9:c38ec48c r8:c3c3a200 r7:c0a2d1e0 r6:c3db0018 r5:c3db0000 r4:c3e0ac00

[  367.623812] [<c046e838>] (usb_hcd_flush_endpoint) from [<c0471588>] (usb_disable_endpoint+0x90/0x98)

[  367.633377]  r9:c38ec48c r8:00000000 r7:c3dc2000 r6:c3d4e288 r5:c3dc2000 r4:c3db0000

[  367.641487] [<c04714f8>] (usb_disable_endpoint) from [<c04715dc>] (usb_disable_interface+0x4c/0x5c)

[  367.650954]  r5:00000001 r4:00000038

[  367.654704] [<c0471590>] (usb_disable_interface) from [<c0473e58>] (usb_unbind_interface+0x1fc/0x2b8)

[  367.664360]  r9:c38ec48c r8:c38ec420 r7:c0a2df10 r6:00000000 r5:c38ec454 r4:c0a2df10

[  367.672474] [<c0473c5c>] (usb_unbind_interface) from [<c0419acc>] (device_release_driver_internal+0x154/0x1e0)

[  367.682948]  r10:c3c58c00 r9:c38ec48c r8:00000034 r7:c0a2df10 r6:00000000 r5:c38ec454

[  367.691140]  r4:c38ec420

[  367.693797] [<c0419978>] (device_release_driver_internal) from [<c0419b70>] (device_release_driver+0x18/0x1c)

[  367.704180]  r9:c38ec48c r8:c38ec428 r7:c0a7d740 r6:c0a2d2e8 r5:c38ec420 r4:c399563c

[  367.712289] [<c0419b58>] (device_release_driver) from [<c0418aa4>] (bus_remove_device+0xe0/0x10c)

[  367.721588] [<c04189c4>] (bus_remove_device) from [<c041590c>] (device_del+0x1f0/0x304)

[  367.729968]  r7:c0a7d740 r6:c3dc2070 r5:c38ec420 r4:c38ec48c

[  367.735897] [<c041571c>] (device_del) from [<c0471694>] (usb_disable_device+0xa8/0x1ec)

[  367.744280]  r9:c3d95a00 r8:c38ec400 r7:c3c3a200 r6:00000000 r5:00000001 r4:c3dc2000

[  367.752391] [<c04715ec>] (usb_disable_device) from [<c046874c>] (usb_disconnect+0x78/0x230)

[  367.761138]  r9:c3d95a00 r8:c3c59800 r7:c3dc20a4 r6:c3dc2070 r5:c3dc2000 r4:00000000

[  367.769249] [<c04686d4>] (usb_disconnect) from [<c046a004>] (hub_event+0x408/0x11e0)

[  367.777360]  r10:c3c58c00 r9:00000001 r8:c3c59b24 r7:00000000 r6:c3c59800 r5:00000001

[  367.785554]  r4:00000000 r3:c3dc2000

[  367.789306] [<c0469bfc>] (hub_event) from [<c013f3c8>] (process_one_work+0x1b8/0x3e8)

[  367.797507]  r10:c384c000 r9:00000000 r8:c7e9d400 r7:00000000 r6:c0a0f700 r5:c381f380

[  367.805700]  r4:c3c59b24

[  367.808356] [<c013f210>] (process_one_work) from [<c013f650>] (worker_thread+0x58/0x5a4)

[  367.816829]  r10:c384c000 r9:c0a0f724 r8:c0a15580 r7:00000008 r6:c381f398 r5:c0a0f700

[  367.825022]  r4:c381f380

[  367.827685] [<c013f5f8>] (worker_thread) from [<c0144f2c>] (kthread+0xf8/0x110)

[  367.835341]  r10:00000000 r9:00000000 r8:c013f5f8 r7:c381f380 r6:c384c000 r5:c3840e00

[  367.843533]  r4:00000000

[  367.846193] [<c0144e34>] (kthread) from [<c0107d50>] (ret_from_fork+0x14/0x24)

[  367.853756]  r8:00000000 r7:00000000 r6:00000000 r5:c0144e34 r4:c3840e00

[  367.860769] ---[ end trace 16f899ddd7f2f57f ]---

[  367.903566] usb 2-1: USB disconnect, device number 46

[  367.915405] usb 2-1.1: USB disconnect, device number 48

[  367.946822] usb 2-1.2: USB disconnect, device number 47

[  367.963054] cdc_ether 2-1.2:1.0 usb0: unregister 'cdc_ether' usb-musb-hdrc.1-1.2, CDC Ethernet Device

[  368.026579] usb 2-1.3: USB disconnect, device number 49

[  368.316338] usb 2-1: new high-speed USB device number 50 using musb-hdrc

[  368.439549] usb 2-1: New USB device found, idVendor=0424, idProduct=2513

[  368.446669] usb 2-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0

[  368.460244] hub 2-1:1.0: USB hub found

[  368.466764] hub 2-1:1.0: 3 ports detected

[  368.578363] usb 1-1: new high-speed USB device number 35 using musb-hdrc

[  368.702104] usb 1-1: New USB device found, idVendor=0781, idProduct=5575

[  368.709758] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3

[  368.717302] usb 1-1: Product: Cruzer Glide

[  368.722107] usb 1-1: Manufacturer: SanDisk

[  368.726724] usb 1-1: SerialNumber: 2005173961119B5080A5

[  368.738144] usb-storage 1-1:1.0: USB Mass Storage device detected

[  368.748035] scsi host0: usb-storage 1-1:1.0

[  368.760354] usb 2-1.2: new high-speed USB device number 51 using musb-hdrc

[  368.856550] usb 2-1.2: New USB device found, idVendor=0525, idProduct=a4a2

[  368.863797] usb 2-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0

[  368.872182] usb 2-1.2: Product: RNDIS/Ethernet Gadget

[  368.877850] usb 2-1.2: Manufacturer: Linux 3.14.28-ltsi with r8a66597_udc

[  368.906999] cdc_ether 2-1.2:1.0 usb0: register 'cdc_ether' at usb-musb-hdrc.1-1.2, CDC Ethernet Device, 3a:7b:d5:ee:6a:89

[  369.130344] usb 2-1.1: new high-speed USB device number 52 using musb-hdrc

[  369.226117] usb 2-1.1: New USB device found, idVendor=0781, idProduct=5575

[  369.233373] usb 2-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3

[  369.241740] usb 2-1.1: Product: Cruzer Glide

[  369.246596] usb 2-1.1: Manufacturer: SanDisk

[  369.251414] usb 2-1.1: SerialNumber: 2003500181119B5080AB

[  369.262867] usb-storage 2-1.1:1.0: USB Mass Storage device detected

[  369.273209] scsi host1: usb-storage 2-1.1:1.0

[  369.467337] usb 2-1.3: new high-speed USB device number 53 using musb-hdrc

[  369.563163] usb 2-1.3: New USB device found, idVendor=0781, idProduct=5575

[  369.570414] usb 2-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3

[  369.578800] usb 2-1.3: Product: Cruzer Glide

[  369.583638] usb 2-1.3: Manufacturer: SanDisk

[  369.588464] usb 2-1.3: SerialNumber: 2006057272119B5080AA

[  369.601804] usb-storage 2-1.3:1.0: USB Mass Storage device detected

[  369.610133] scsi host2: usb-storage 2-1.3:1.0

[  370.315680] scsi 1:0:0:0: Direct-Access     SanDisk  Cruzer Glide     1.00 PQ: 0 ANSI: 6

[  370.330568] sd 1:0:0:0: [sda] 30595072 512-byte logical blocks: (15.7 GB/14.6 GiB)

[  370.347091] sd 1:0:0:0: [sda] Write Protect is off

[  370.353841] sd 1:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA

[  370.375753]  sda: sda1

[  370.386961] sd 1:0:0:0: [sda] Attached SCSI removable disk

[  370.636275] scsi 2:0:0:0: Direct-Access     SanDisk  Cruzer Glide     1.00 PQ: 0 ANSI: 6

[  370.652520] sd 2:0:0:0: [sdb] 30595072 512-byte logical blocks: (15.7 GB/14.6 GiB)

[  370.670467] sd 2:0:0:0: [sdb] Write Protect is on

[  370.682459] sd 2:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA

[  370.706064]  sdb: sdb1

[  370.720571] sd 2:0:0:0: [sdb] Attached SCSI removable disk

[  373.522612] usb_emmc_test.s (3356): drop_caches: 3

[  375.131374] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.

[  375.168900] usb_emmc_test.s (3373): drop_caches: 3

[  377.202561] usb_emmc_test.s (3391): drop_caches: 3

[  379.076801] usb 1-1: USB disconnect, device number 35

[  379.086049] ------------[ cut here ]------------

[  379.090941] WARNING: CPU: 0 PID: 1784 at drivers/dma/cppi41.c:700 cppi41_stop_chan+0x260/0x350

[  379.099954] Modules linked in: ti_am335x_adc omap_aes_driver crypto_engine omap_sham cdc_ether usbnet mii omap_wdt ti_am335x_tscadc

[  379.112412] CPU: 0 PID: 1784 Comm: kworker/0:4 Tainted: G        W       4.9.69-pic6-02469-g9a0da80 #1

[  379.122150] Hardware name: Generic AM33XX (Flattened Device Tree)

[  379.128549] Workqueue: usb_hub_wq hub_event

[  379.132929] Backtrace:

[  379.135518] [<c010b9dc>] (dump_backtrace) from [<c010bc98>] (show_stack+0x18/0x1c)

[  379.143446]  r7:00000009 r6:00000000 r5:c0849eec r4:00000000

[  379.149382] [<c010bc80>] (show_stack) from [<c037af10>] (dump_stack+0x24/0x28)

[  379.156953] [<c037aeec>] (dump_stack) from [<c0129bd0>] (__warn+0xe8/0x100)

[  379.164246] [<c0129ae8>] (__warn) from [<c0129ca0>] (warn_slowpath_null+0x28/0x30)

[  379.172174]  r9:c4041000 r8:0000003c r7:00000001 r6:c3bd2010 r5:c3bd2018 r4:c3be8130

[  379.180286] [<c0129c78>] (warn_slowpath_null) from [<c03cf5d4>] (cppi41_stop_chan+0x260/0x350)

[  379.189315] [<c03cf374>] (cppi41_stop_chan) from [<c049e450>] (cppi41_dma_channel_abort+0x144/0x2b4)

[  379.198879]  r9:c0a7e1ac r8:c3c56010 r7:c0a7e1c0 r6:00000004 r5:00000000 r4:c3c25848

[  379.206992] [<c049e30c>] (cppi41_dma_channel_abort) from [<c049b000>] (musb_cleanup_urb+0x60/0x1e0)

[  379.216465]  r10:c3c25848 r9:c3c56010 r8:c88fd410 r7:00000000 r6:c3db0000 r5:00000080

[  379.224658]  r4:c3c564e8

[  379.227316] [<c049afa0>] (musb_cleanup_urb) from [<c049b7f8>] (musb_urb_dequeue+0xf4/0x12c)

[  379.236062]  r10:00000001 r9:c000a380 r8:a0070093 r7:00000000 r6:c3c56010 r5:c3db0880

[  379.244255]  r4:c3db0000

[  379.246915] [<c049b704>] (musb_urb_dequeue) from [<c046c694>] (unlink1+0x34/0x110)

[  379.254843]  r10:c3e23a00 r9:c3e23a8c r8:c3c3a200 r7:ffffff94 r6:c3c3a200 r5:c2b19480

[  379.263038]  r4:c3db0000 r3:c049b704

[  379.266787] [<c046c660>] (unlink1) from [<c046e934>] (usb_hcd_flush_endpoint+0xfc/0x110)

[  379.275261]  r9:c3e23a8c r8:c3c3a200 r7:c0a2d1e0 r6:c2b19498 r5:c2b19480 r4:c3db0000

[  379.283373] [<c046e838>] (usb_hcd_flush_endpoint) from [<c0471588>] (usb_disable_endpoint+0x90/0x98)

[  379.292937]  r9:c3e23a8c r8:00000000 r7:c3dc2800 r6:c3d4ed08 r5:c3dc2800 r4:c2b19480

[  379.301047] [<c04714f8>] (usb_disable_endpoint) from [<c04715dc>] (usb_disable_interface+0x4c/0x5c)

[  379.310514]  r5:00000001 r4:00000038

[  379.314265] [<c0471590>] (usb_disable_interface) from [<c0473e58>] (usb_unbind_interface+0x1fc/0x2b8)

[  379.323920]  r9:c3e23a8c r8:c3e23a20 r7:c0a2df10 r6:00000000 r5:c3e23a54 r4:c0a2df10

[  379.332035] [<c0473c5c>] (usb_unbind_interface) from [<c0419acc>] (device_release_driver_internal+0x154/0x1e0)

[  379.342508]  r10:c3c58c00 r9:c3e23a8c r8:00000034 r7:c0a2df10 r6:00000000 r5:c3e23a54

[  379.350701]  r4:c3e23a20

[  379.353357] [<c0419978>] (device_release_driver_internal) from [<c0419b70>] (device_release_driver+0x18/0x1c)

[  379.363740]  r9:c3e23a8c r8:c3e23a28 r7:c0a7d740 r6:c0a2d2e8 r5:c3e23a20 r4:c399563c

[  379.371850] [<c0419b58>] (device_release_driver) from [<c0418aa4>] (bus_remove_device+0xe0/0x10c)

[  379.381149] [<c04189c4>] (bus_remove_device) from [<c041590c>] (device_del+0x1f0/0x304)

[  379.389528]  r7:c0a7d740 r6:c3dc2870 r5:c3e23a20 r4:c3e23a8c

[  379.395458] [<c041571c>] (device_del) from [<c0471694>] (usb_disable_device+0xa8/0x1ec)

[  379.403841]  r9:c3daa400 r8:c3e23a00 r7:c3c3a200 r6:00000000 r5:00000001 r4:c3dc2800

[  379.411953] [<c04715ec>] (usb_disable_device) from [<c046874c>] (usb_disconnect+0x78/0x230)

[  379.420699]  r9:c3daa400 r8:c3c59800 r7:c3dc28a4 r6:c3dc2870 r5:c3dc2800 r4:00000000

[  379.428811] [<c04686d4>] (usb_disconnect) from [<c046a004>] (hub_event+0x408/0x11e0)

[  379.436921]  r10:c3c58c00 r9:00000001 r8:c3c59b24 r7:00000000 r6:c3c59800 r5:00000001

[  379.445115]  r4:00000000 r3:c3dc2800

[  379.448867] [<c0469bfc>] (hub_event) from [<c013f3c8>] (process_one_work+0x1b8/0x3e8)

[  379.457069]  r10:c3ffe000 r9:00000000 r8:c7e9d400 r7:00000000 r6:c0a0f700 r5:c3e0bd00

[  379.465261]  r4:c3c59b24

[  379.467917] [<c013f210>] (process_one_work) from [<c013f650>] (worker_thread+0x58/0x5a4)

[  379.476391]  r10:c3ffe000 r9:c0a0f724 r8:c0a15580 r7:00000008 r6:c3e0bd18 r5:c0a0f700

[  379.484584]  r4:c3e0bd00

[  379.487246] [<c013f5f8>] (worker_thread) from [<c0144f2c>] (kthread+0xf8/0x110)

[  379.494903]  r10:00000000 r9:00000000 r8:c013f5f8 r7:c3e0bd00 r6:c3ffe000 r5:c3dee5c0

[  379.503095]  r4:00000000

[  379.505754] [<c0144e34>] (kthread) from [<c0107d50>] (ret_from_fork+0x14/0x24)

[  379.513318]  r8:00000000 r7:00000000 r6:00000000 r5:c0144e34 r4:c3dee5c0

[  379.520330] ---[ end trace 16f899ddd7f2f580 ]---  

Nikhilesh,

NIKHILESH CHAVAN said:

I tested the USB issue with latest kernel you suggested, I still have the issue: please see the crash dump messages below.

Unfortunately, I am still unable to reproduce the same issue (actually I don't get any kernel dump with the latest TI v4.9.69 kernel - TI tag ti2017.06-int), so I cannot provide any kernel patch to workaround it.

I guess the only option Is to fix it in H/W design, so that EFT will not trigger babble condition?

Nikhilesh,

Can you please try the following patch to see it affects any of the symptoms?

diff --git a/drivers/usb/musb/musb_cppi41.c b/drivers/usb/musb/musb_cppi41.c
index c2e5bcbef8ef..34e26d9c7428 100644
--- a/drivers/usb/musb/musb_cppi41.c
+++ b/drivers/usb/musb/musb_cppi41.c
@@ -614,7 +614,6 @@ static int cppi41_dma_channel_abort(struct dma_channel *channel)
 	}
 
 	/* DA8xx Advisory 2.3.27: wait 250 ms before to start the teardown */
-	if (musb->io.quirks & MUSB_DA8XX)
 		mdelay(250);
 
 	tdbit = 1 << cppi41_channel->port_num;

I tried latest patch you suggested. With the latest patch applied also I see similar issue where USB drive is detected but block partition is not shown under /dev/

please see following log messages:

[  241.136253] musb-hdrc musb-hdrc.0: Babble

[  241.140789] usb 1-1: USB disconnect, device number 14

[  241.787916] usb 1-1: new high-speed USB device number 15 using musb-hdrc

[  241.911757] usb 1-1: New USB device found, idVendor=0781, idProduct=5575

[  241.918826] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3

[  241.927034] usb 1-1: Product: Cruzer Glide

[  241.931673] usb 1-1: Manufacturer: SanDisk

[  241.936288] usb 1-1: SerialNumber: 2005173961119B5080A5

[  241.948064] usb-storage 1-1:1.0: USB Mass Storage device detected

[  241.958139] scsi host3: usb-storage 1-1:1.0

[  242.463785] usb_emmc_test.s (1401): drop_caches: 3

[  242.913533] musb-hdrc musb-hdrc.0: Babble

[  242.918061] usb 1-1: USB disconnect, device number 15

[  243.563909] usb 1-1: new high-speed USB device number 16 using musb-hdrc

[  243.687745] usb 1-1: New USB device found, idVendor=0781, idProduct=5575

[  243.694814] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3

[  243.703041] usb 1-1: Product: Cruzer Glide

[  243.707683] usb 1-1: Manufacturer: SanDisk

[  243.712286] usb 1-1: SerialNumber: 2005173961119B5080A5

[  243.727053] usb-storage 1-1:1.0: USB Mass Storage device detected

[  243.737001] scsi host3: usb-storage 1-1:1.0

[  243.998866] usb_emmc_test.s (1419): drop_caches: 3

[  244.391064] usb 1-1: USB disconnect, device number 16

[  244.731938] usb 1-1: new high-speed USB device number 17 using musb-hdrc

[  244.863735] usb 1-1: New USB device found, idVendor=0781, idProduct=5575

[  244.870806] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3

[  244.879007] usb 1-1: Product: Cruzer Glide

[  244.883645] usb 1-1: Manufacturer: SanDisk

[  244.888296] usb 1-1: SerialNumber: 2005173961119B5080A5

[  244.899786] usb-storage 1-1:1.0: USB Mass Storage device detected

[  244.909720] scsi host0: usb-storage 1-1:1.0

[  245.836803] usb_emmc_test.s (1430): drop_caches: 3

[  245.968680] scsi 0:0:0:0: Direct-Access     SanDisk  Cruzer Glide     1.00 PQ: 0 ANSI: 6

[  245.988715] sd 0:0:0:0: [sda] 30595072 512-byte logical blocks: (15.7 GB/14.6 GiB)

[  246.266963] sd 0:0:0:0: [sda] Write Protect is off

[  246.278737] sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00

[  246.532089] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA

[  247.315226]  sda: sda1

[  247.888181] sd 0:0:0:0: [sda] Attached SCSI removable disk

[  249.825860] usb_emmc_test.s (1448): drop_caches: 3

[  251.293763] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.

[  251.327519] usb_emmc_test.s (1456): drop_caches: 3

[  251.806054] musb-hdrc musb-hdrc.0: Babble

[  251.810593] usb 1-1: USB disconnect, device number 17

[  252.064961] ------------[ cut here ]------------

[  252.069845] WARNING: CPU: 0 PID: 78 at drivers/dma/cppi41.c:700 cppi41_stop_chan+0x260/0x350

[  252.078675] Modules linked in: ti_am335x_adc omap_aes_driver omap_sham crypto_engine ti_am335x_tscadc omap_wdt cdc_ether usbnet mii

[  252.091139] CPU: 0 PID: 78 Comm: kworker/0:3 Not tainted 4.9.69-pic6-02469-g1721b66-dirty #2

[  252.099969] Hardware name: Generic AM33XX (Flattened Device Tree)

[  252.106368] Workqueue: usb_hub_wq hub_event

[  252.110748] Backtrace:

[  252.113338] [<c010b9dc>] (dump_backtrace) from [<c010bc98>] (show_stack+0x18/0x1c)

[  252.121266]  r7:00000009 r6:00000000 r5:c0849ef4 r4:00000000

[  252.127201] [<c010bc80>] (show_stack) from [<c037af10>] (dump_stack+0x24/0x28)

[  252.134772] [<c037aeec>] (dump_stack) from [<c0129bd0>] (__warn+0xe8/0x100)

[  252.142064] [<c0129ae8>] (__warn) from [<c0129ca0>] (warn_slowpath_null+0x28/0x30)

[  252.149993]  r9:c4041000 r8:0000003c r7:00000001 r6:c3bd2010 r5:c3bd2018 r4:c3be8130

[  252.158104] [<c0129c78>] (warn_slowpath_null) from [<c03cf5d4>] (cppi41_stop_chan+0x260/0x350)

[  252.167134] [<c03cf374>] (cppi41_stop_chan) from [<c049e460>] (cppi41_dma_channel_abort+0x154/0x264)

[  252.176699]  r9:c0a7e1ac r8:c3c56010 r7:c0a7e1c0 r6:00000004 r5:00000000 r4:c3c25848

[  252.184811] [<c049e30c>] (cppi41_dma_channel_abort) from [<c049b000>] (musb_cleanup_urb+0x60/0x1e0)

[  252.194285]  r10:c3c25848 r9:c3c56010 r8:c88fd410 r7:00000000 r6:c3fce600 r5:00000080

[  252.202478]  r4:c3c564e8

[  252.205136] [<c049afa0>] (musb_cleanup_urb) from [<c049b7f8>] (musb_urb_dequeue+0xf4/0x12c)

[  252.213883]  r10:00000001 r9:c0009180 r8:a00e0093 r7:00000000 r6:c3c56010 r5:c3e8a380

[  252.222076]  r4:c3fce600

[  252.224736] [<c049b704>] (musb_urb_dequeue) from [<c046c694>] (unlink1+0x34/0x110)

[  252.232665]  r10:c3ce8600 r9:c3ce868c r8:c3c3a200 r7:ffffff94 r6:c3c3a200 r5:c3e8a600

[  252.240860]  r4:c3fce600 r3:c049b704

[  252.244610] [<c046c660>] (unlink1) from [<c046e934>] (usb_hcd_flush_endpoint+0xfc/0x110)

[  252.253083]  r9:c3ce868c r8:c3c3a200 r7:c0a2d1e0 r6:c3e8a618 r5:c3e8a600 r4:c3fce600

[  252.261195] [<c046e838>] (usb_hcd_flush_endpoint) from [<c0471588>] (usb_disable_endpoint+0x90/0x98)

[  252.270760]  r9:c3ce868c r8:00000000 r7:c3d98800 r6:c28c24c8 r5:c3d98800 r4:c3e8a600

[  252.278869] [<c04714f8>] (usb_disable_endpoint) from [<c04715dc>] (usb_disable_interface+0x4c/0x5c)

[  252.288336]  r5:00000001 r4:00000038

[  252.292087] [<c0471590>] (usb_disable_interface) from [<c0473e58>] (usb_unbind_interface+0x1fc/0x2b8)

[  252.301742]  r9:c3ce868c r8:c3ce8620 r7:c0a2df10 r6:00000000 r5:c3ce8654 r4:c0a2df10

[  252.309857] [<c0473c5c>] (usb_unbind_interface) from [<c0419acc>] (device_release_driver_internal+0x154/0x1e0)

[  252.320331]  r10:c3c58c00 r9:c3ce868c r8:00000034 r7:c0a2df10 r6:00000000 r5:c3ce8654

[  252.328524]  r4:c3ce8620

[  252.331180] [<c0419978>] (device_release_driver_internal) from [<c0419b70>] (device_release_driver+0x18/0x1c)

[  252.341563]  r9:c3ce868c r8:c3ce8628 r7:c0a7d740 r6:c0a2d2e8 r5:c3ce8620 r4:c399563c

[  252.349673] [<c0419b58>] (device_release_driver) from [<c0418aa4>] (bus_remove_device+0xe0/0x10c)

[  252.358972] [<c04189c4>] (bus_remove_device) from [<c041590c>] (device_del+0x1f0/0x304)

[  252.367352]  r7:c0a7d740 r6:c3d98870 r5:c3ce8620 r4:c3ce868c

[  252.373282] [<c041571c>] (device_del) from [<c0471694>] (usb_disable_device+0xa8/0x1ec)

[  252.381665]  r9:c3dbc400 r8:c3ce8600 r7:c3c3a200 r6:00000000 r5:00000001 r4:c3d98800

[  252.389775] [<c04715ec>] (usb_disable_device) from [<c046874c>] (usb_disconnect+0x78/0x230)

[  252.398522]  r9:c3dbc400 r8:c3c59800 r7:c3d988a4 r6:c3d98870 r5:c3d98800 r4:00000000

[  252.406633] [<c04686d4>] (usb_disconnect) from [<c046a004>] (hub_event+0x408/0x11e0)

[  252.414744]  r10:c3c58c00 r9:00000001 r8:c3c59b24 r7:00000000 r6:c3c59800 r5:00000001

[  252.422938]  r4:00000000 r3:c3d98800

[  252.426691] [<c0469bfc>] (hub_event) from [<c013f3c8>] (process_one_work+0x1b8/0x3e8)

[  252.434892]  r10:c3cec000 r9:00000000 r8:c7e9d400 r7:00000000 r6:c0a0f700 r5:c3cb1480

[  252.443085]  r4:c3c59b24

[  252.445742] [<c013f210>] (process_one_work) from [<c013f650>] (worker_thread+0x58/0x5a4)

[  252.454216]  r10:c3cec000 r9:c0a0f724 r8:c0a15580 r7:00000008 r6:c3cb1498 r5:c0a0f700

[  252.462408]  r4:c3cb1480

[  252.465071] [<c013f5f8>] (worker_thread) from [<c0144f2c>] (kthread+0xf8/0x110)

[  252.472727]  r10:00000000 r9:00000000 r8:c013f5f8 r7:c3cb1480 r6:c3cec000 r5:c3c69c80

[  252.480920]  r4:00000000

[  252.483579] [<c0144e34>] (kthread) from [<c0107d50>] (ret_from_fork+0x14/0x24)

[  252.491143]  r8:00000000 r7:00000000 r6:00000000 r5:c0144e34 r4:c3c69c80

[  252.498155] ---[ end trace 9fecbfb5cd70f8aa ]---

[  252.513078] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x01 driverbyte=0x00

[  252.521717] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 04 8b 60 00 00 f0 00

[  252.529669] blk_update_request: I/O error, dev sda, sector 297824

[  252.566666] scsi 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x01 driverbyte=0x00

[  252.575506] scsi 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 04 8c 50 00 00 10 00

[  252.583655] blk_update_request: I/O error, dev sda, sector 298064

[  252.728196] usb_emmc_test.s (1469): drop_caches: 3

[  252.817935] usb 1-1: new high-speed USB device number 18 using musb-hdrc

[  252.946085] usb 1-1: New USB device found, idVendor=0781, idProduct=5575

[  252.953194] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3

[  252.962199] usb 1-1: Product: Cruzer Glide

[  252.970129] usb 1-1: Manufacturer: SanDisk

[  252.975587] usb 1-1: SerialNumber: 2005173961119B5080A5

[  252.992802] usb-storage 1-1:1.0: USB Mass Storage device detected

[  253.003001] scsi host0: usb-storage 1-1:1.0

[  254.479385] usb 1-1: USB disconnect, device number 18

[  254.855241] usb_emmc_test.s (1481): drop_caches: 3

[  254.959001] usb 1-1: new high-speed USB device number 19 using musb-hdrc

[  255.091080] usb 1-1: New USB device found, idVendor=0781, idProduct=5575

[  255.098191] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3

[  255.107406] usb 1-1: Product: Cruzer Glide

[  255.115287] usb 1-1: Manufacturer: SanDisk

[  255.121161] usb 1-1: SerialNumber: 2005173961119B5080A5

[  255.138485] usb-storage 1-1:1.0: USB Mass Storage device detected

[  255.154960] scsi host0: usb-storage 1-1:1.0

[  257.036668] usb_emmc_test.s (1501): drop_caches: 3

[  257.145812] usb 1-1: USB disconnect, device number 19

I also have attached a complete log file fro your reference:

8510.logFile.txt

I’m wondering if you could have some kind of “babble handler” that would do the following:

1. Issue soft connect commands.
   1. echo 0 > /sys/kernel/debug/musb-hdrc.0/softconnect
   2. echo 1 > /sys/kernel/debug/musb-hdrc.0/softconnect
2. Do a rmmod and insmod/modprobe of the USB modules.

In separate emails with Nikhilesh, he indicated that manually executing the commands above will bring back the drive.  I think we would need some way of automating this sequence in response to a babble to fully workaround this issue.

Brad Griffis said:

echo 1 > /sys/kernel/debug/musb-hdrc.0/softconnect

You probably don't need this step, because you will re-load usb modules, which will connect anyway.

Brad Griffis said:

Do a rmmod and insmod/modprobe of the USB modules.

Which exact modules do you reload? It might do some kind of reset which recovers it.

We unload and load following modules:

Unload modules:

# rmmod usb_storage
rmmod: can't unload module 'usb_storage': Resource temporarily unavailable
# rmmod musb_dsps
[ 1456.298295] musb-hdrc musb-hdrc.1: remove, state 1
[ 1456.303478] usb usb2: USB disconnect, device number 1
[ 1456.309766] usb 2-1: USB disconnect, device number 2
[ 1456.315411] usb 2-1.1: USB disconnect, device number 5
[ 1456.334344] usb 2-1.2: USB disconnect, device number 3
[ 1456.345508] cdc_ether 2-1.2:1.0 usb0: unregister 'cdc_ether' usb-musb-hdrc.1-1.2, CDC Ethernet Device
[ 1456.372668] usb 2-1.3: USB disconnect, device number 4
[ 1456.675032] musb-hdrc musb-hdrc.1: USB bus 2 deregistered
[ 1456.683704] musb-hdrc musb-hdrc.0: remove, state 1
[ 1456.688933] usb usb1: USB disconnect, device number 1
[ 1456.695003] usb 1-1: USB disconnect, device number 23
[ 1456.710512] musb-hdrc musb-hdrc.0: USB bus 1 deregistered
# rmmod musb_hdrc
# rmmod phy_am335x
# rmmod cdc_ether
[ 1456.759930] usbcore: deregistering interface driver cdc_ether
# rmmod usbnet
# rmmod mii
# rmmod usbcore
rmmod: can't unload module 'usbcore': Resource temporarily unavailable
# rmmod usb_common
rmmod: can't unload module 'usb_common': Resource temporarily unavailable
# rmmod cppi41
# rmmod phy_generic
# rmmod phy_am335x_control
#

Load Module:

# modprobe phy_am335x_control
# sleep 1
# modprobe phy_generic
# sleep 1
# modprobe cppi41
# sleep 1
# modprobe usb_common
# sleep 1
# modprobe usbcore
# sleep 1
# modprobe mii
# sleep 1
# modprobe usbnet
# sleep 1
# modprobe cdc_ether
[ 1504.664285] usbcore: registered new interface driver cdc_ether
# sleep 1
# modprobe musb_hdrc
# sleep 1
# modprobe musb_dsps
# sleep 1
# modprobe usb_storage
# sleep 1
# echo "the next command should result in USB devices to get discovered"
the next command should result in USB devices to get discovered
# sleep 1
# modprobe phy_am335x
[ 1509.820418] 47401300.usb-phy supply vcc not found, using dummy regulator
[ 1509.835826] 47401b00.usb-phy supply vcc not found, using dummy regulator
[ 1509.848710] musb-hdrc musb-hdrc.0: MUSB HDRC host driver
[ 1509.848774] musb-hdrc musb-hdrc.0: new USB bus registered, assigned bus number 1
[ 1509.854714] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 1509.854725] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 1509.854734] usb usb1: Product: MUSB HDRC host driver
[ 1509.854742] usb usb1: Manufacturer: Linux 4.9.69-pic6-02469-g1721b66-dirty musb-hcd
[ 1509.854749] usb usb1: SerialNumber: musb-hdrc.0
[ 1509.859774] hub 1-0:1.0: USB hub found
[ 1509.860220] hub 1-0:1.0: 1 port detected
# echo "waiting for some time to allow the USB device discovery to complete"
waiting for some time to allow the USB device discovery to compl[ 1509.935052] musb-hdrc musb-hdrc.1: MUSB HDRC host driver
ete
# sleep 6
[ 1509.955579] musb-hdrc musb-hdrc.1: new USB bus registered, assigned bus number 2
[ 1509.964597] usb usb2: New USB device found, idVendor=1d6b, idProduct=0002
[ 1509.972220] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 1509.980179] usb usb2: Product: MUSB HDRC host driver
[ 1509.985704] usb usb2: Manufacturer: Linux 4.9.69-pic6-02469-g1721b66-dirty musb-hcd
[ 1509.994049] usb usb2: SerialNumber: musb-hdrc.1
[ 1510.004599] hub 2-0:1.0: USB hub found
[ 1510.011775] hub 2-0:1.0: 1 port detected
[ 1510.399120] usb 2-1: new high-speed USB device number 2 using musb-hdrc
[ 1510.522339] usb 2-1: New USB device found, idVendor=0424, idProduct=2513
[ 1510.529535] usb 2-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 1510.542740] hub 2-1:1.0: USB hub found
[ 1510.549571] hub 2-1:1.0: 3 ports detected
[ 1510.615132] usb 1-1: new high-speed USB device number 2 using musb-hdrc
[ 1510.926287] musb-hdrc musb-hdrc.1: Babble
[ 1510.930579] musb-hdrc musb-hdrc.1: Babble
[ 1511.027996] usb 1-1: New USB device found, idVendor=0781, idProduct=5575
[ 1511.035139] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1511.043304] usb 1-1: Product: Cruzer Glide
[ 1511.047954] usb 1-1: Manufacturer: SanDisk
[ 1511.052572] usb 1-1: SerialNumber: 2005173961119B5080A5
[ 1511.064009] usb-storage 1-1:1.0: USB Mass Storage device detected
[ 1511.074510] scsi host0: usb-storage 1-1:1.0
[ 1511.227148] usb 2-1: reset high-speed USB device number 2 using musb-hdrc
[ 1511.455350] usb 2-1: USB disconnect, device number 2
[ 1511.925125] usb 2-1: new high-speed USB device number 3 using musb-hdrc
[ 1512.048346] usb 2-1: New USB device found, idVendor=0424, idProduct=2513
[ 1512.055435] usb 2-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 1512.068632] hub 2-1:1.0: USB hub found
[ 1512.075314] hub 2-1:1.0: 3 ports detected
[ 1512.128631] scsi 0:0:0:0: Direct-Access SanDisk Cruzer Glide 1.00 PQ: 0 ANSI: 6
[ 1512.143497] sd 0:0:0:0: [sda] 30595072 512-byte logical blocks: (15.7 GB/14.6 GiB)
[ 1512.410183] sd 0:0:0:0: [sda] Write Protect is off
[ 1512.665927] ------------[ cut here ]------------
[ 1512.670825] WARNING: CPU: 0 PID: 5568 at drivers/dma/cppi41.c:466 cppi41_run_queue+0x100/0x10c [cppi41]
[ 1512.680685] Modules linked in: phy_am335x musb_dsps musb_hdrc cdc_ether usbnet mii cppi41 phy_generic phy_am335x_control usb_storage usbcore usb_common ti_am335x_adc omap_aes_driver omap_sham crypto_engine ti_am335x_tscadc musb_am335x omap_wdt [last unloaded: phy_am335x_control]
[ 1512.706746] CPU: 0 PID: 5568 Comm: kworker/0:3 Tainted: G W 4.9.69-pic6-02469-g1721b66-dirty #3
[ 1512.717061] Hardware name: Generic AM33XX (Flattened Device Tree)
[ 1512.723780] Workqueue: events_power_efficient hub_init_func3 [usbcore]
[ 1512.730620] Backtrace:
[ 1512.733218] [<c010b9dc>] (dump_backtrace) from [<c010bc98>] (show_stack+0x18/0x1c)
[ 1512.741172] r7:00000009 r6:00000000 r5:bf149814 r4:00000000
[ 1512.747126] [<c010bc80>] (show_stack) from [<c037af10>] (dump_stack+0x24/0x28)
[ 1512.754721] [<c037aeec>] (dump_stack) from [<c0129bd0>] (__warn+0xe8/0x100)
[ 1512.762037] [<c0129ae8>] (__warn) from [<c0129ca0>] (warn_slowpath_null+0x28/0x30)
[ 1512.769991] r9:c3d90410 r8:81004000 r7:c3d90700 r6:c3d90678 r5:c3d904d0 r4:c3ec1b10
[ 1512.778135] [<c0129c78>] (warn_slowpath_null) from [<bf1481fc>] (cppi41_run_queue+0x100/0x10c [cppi41])
[ 1512.788014] [<bf1480fc>] (cppi41_run_queue [cppi41]) from [<bf148c70>] (cppi41_dma_issue_pending+0xf0/0xf4 [cppi41])
[ 1512.799067] r10:c3ff2e80 r9:bf148a5c r8:c3ec1b10 r7:400f0093 r6:c3d90708 r5:c3ec1b10
[ 1512.807284] r4:c3d90410
[ 1512.810032] [<bf148b80>] (cppi41_dma_issue_pending [cppi41]) from [<bf170f58>] (cppi41_dma_channel_program+0x1c8/0x294 [musb_hdrc])
[ 1512.822450] r7:00000002 r6:00000000 r5:c2a94288 r4:c2a94288
[ 1512.828453] [<bf170d90>] (cppi41_dma_channel_program [musb_hdrc]) from [<bf16c558>] (musb_start_urb+0x80c/0xd8c [musb_hdrc])
[ 1512.840235] r10:c2aaebe8 r9:bf173104 r8:c3ff2780 r7:c2a94288 r6:00001000 r5:bf170d90
[ 1512.848451] r4:c2aae010
[ 1512.851171] [<bf16bd4c>] (musb_start_urb [musb_hdrc]) from [<bf16db64>] (musb_urb_enqueue+0x534/0x66c [musb_hdrc])
[ 1512.862041] r10:00000000 r9:c3d48000 r8:ffffff81 r7:c2aaebe8 r6:c3ff2780 r5:c2aae010
[ 1512.870258] r4:c2a38800
[ 1512.873107] [<bf16d630>] (musb_urb_enqueue [musb_hdrc]) from [<bf0951d4>] (usb_hcd_submit_urb+0xc0/0x8a0 [usbcore])
[ 1512.884069] r10:00000002 r9:00000001 r8:02400000 r7:c3ff2788 r6:00000000 r5:c3d48000
[ 1512.892286] r4:c3ff2780
[ 1512.895195] [<bf095114>] (usb_hcd_submit_urb [usbcore]) from [<bf09695c>] (usb_submit_urb+0x2bc/0x4c4 [usbcore])
[ 1512.905884] r10:00000002 r9:00000001 r8:00000200 r7:00000003 r6:c3a19000 r5:02400000
[ 1512.914101] r4:c3ff2780
[ 1512.917006] [<bf0966a0>] (usb_submit_urb [usbcore]) from [<bf08d9e4>] (hub_activate+0x218/0x61c [usbcore])
[ 1512.927149] r10:00000002 r9:c3a19000 r8:c7e9b400 r7:00000000 r6:c090f640 r5:c3a190a4
[ 1512.935366] r4:c3d8e000
[ 1512.938269] [<bf08d7cc>] (hub_activate [usbcore]) from [<bf08de38>] (hub_init_func3+0x18/0x1c [usbcore])
[ 1512.948228] r10:c2a74000 r9:00000000 r8:c7e9b400 r7:00000000 r6:c090f640 r5:c2a6bd80
[ 1512.956446] r4:c3d8e0f4
[ 1512.959234] [<bf08de20>] (hub_init_func3 [usbcore]) from [<c013f3c8>] (process_one_work+0x1b8/0x3e8)
[ 1512.968827] [<c013f210>] (process_one_work) from [<c013f650>] (worker_thread+0x58/0x5a4)
[ 1512.977327] r10:c2a74000 r9:c090f664 r8:c09154c0 r7:00000008 r6:c2a6bd98 r5:c090f640
[ 1512.985546] r4:c2a6bd80
[ 1512.988216] [<c013f5f8>] (worker_thread) from [<c0144f2c>] (kthread+0xf8/0x110)
[ 1512.995895] r10:00000000 r9:00000000 r8:c013f5f8 r7:c2a6bd80 r6:c2a74000 r5:c2997480
[ 1513.004112] r4:00000000
[ 1513.006779] [<c0144e34>] (kthread) from [<c0107d50>] (ret_from_fork+0x14/0x24)
[ 1513.014366] r8:00000000 r7:00000000 r6:00000000 r5:c0144e34 r4:c2997480
[ 1513.021399] ---[ end trace edd6658907717844 ]---
[ 1513.035358] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[ 1513.797274] usb 2-1.1: new high-speed USB device number 4 using musb-hdrc
[ 1513.810127] sda: sda1
[ 1514.325689] sd 0:0:0:0: [sda] Attached SCSI removable disk
[ 1514.334152] usb 2-1.1: New USB device found, idVendor=0781, idProduct=5575
[ 1514.343699] usb 2-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1514.353758] usb 2-1.1: Product: Cruzer Glide
[ 1514.359371] usb 2-1.1: Manufacturer: SanDisk
[ 1514.364918] usb 2-1.1: SerialNumber: 2003500181119B5080AB
[ 1514.379384] usb-storage 2-1.1:1.0: USB Mass Storage device detected
[ 1514.391825] scsi host3: usb-storage 2-1.1:1.0
[ 1514.482218] usb 2-1.2: new high-speed USB device number 5 using musb-hdrc
[ 1514.580752] usb 2-1.2: New USB device found, idVendor=0525, idProduct=a4a2
[ 1514.588118] usb 2-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 1514.597339] usb 2-1.2: Product: RNDIS/Ethernet Gadget
[ 1514.603367] usb 2-1.2: Manufacturer: Linux 3.14.28-ltsi with r8a66597_udc
[ 1514.628552] cdc_ether 2-1.2:1.0 usb0: register 'cdc_ether' at usb-musb-hdrc.1-1.2, CDC Ethernet Device, 42:ca:54:c5:97:d4
[ 1514.734158] usb 2-1.3: new high-speed USB device number 6 using musb-hdrc
[ 1514.829974] usb 2-1.3: New USB device found, idVendor=0781, idProduct=5575
[ 1514.837247] usb 2-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1514.845598] usb 2-1.3: Product: Cruzer Glide
[ 1514.850438] usb 2-1.3: Manufacturer: SanDisk
[ 1514.855271] usb 2-1.3: SerialNumber: 2006057272119B5080AA
[ 1514.867045] usb-storage 2-1.3:1.0: USB Mass Storage device detected
[ 1514.876857] scsi host4: usb-storage 2-1.3:1.0
[ 1515.456566] scsi 3:0:0:0: Direct-Access SanDisk Cruzer Glide 1.00 PQ: 0 ANSI: 6
[ 1515.471546] sd 3:0:0:0: [sdd] 30595072 512-byte logical blocks: (15.7 GB/14.6 GiB)
[ 1515.737737] sd 3:0:0:0: [sdd] Write Protect is off
# mount /dev/sda1 /mnt/sda1
[ 1515.999487] scsi 4:0:0:0: Direct-Access SanDisk Cruzer Glide 1.00 PQ: 0 ANSI: 6
[ 1516.023710] sd 4:0:0:0: [sde] 30595072 512-byte logical blocks: (15.7 GB/14.6 GiB)
[ 1516.049468] sd 3:0:0:0: [sdd] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[ 1516.307820] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[ 1516.318806] sd 4:0:0:0: [sde] Write Protect is on
# ifconfig usb0 192.168.1.1 netmask 255.255.255.0
#
# [ 1516.591570] sd 4:0:0:0: [sde] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[ 1518.112469] sde: sde1
[ 1518.115455] sdd: sdd1
[ 1518.875702] sd 4:0:0:0: [sde] Attached SCSI removable disk
[ 1519.144623] sd 3:0:0:0: [sdd] Attached SCSI removable disk

# ls /dev/sd*
evmem 0x47401018
devmem 0x47401818
ping 192.168.1.2 -c 2
lsusb

/dev/sda /dev/sda1 /dev/sdd /dev/sdd1 /dev/sde /dev/sde1
# devmem 0x47401018
0x00000001
# devmem 0x47401818
0x00000001
# ping 192.168.1.2 -c 2
PING 192.168.1.2 (192.168.1.2): 56 data bytes
64 bytes from 192.168.1.2: seq=0 ttl=64 time=2.461 ms
64 bytes from 192.168.1.2: seq=1 ttl=64 time=1.735 ms

--- 192.168.1.2 ping statistics ---
2 packets transmitted, 2 packets received, 0% packet loss
round-trip min/avg/max = 1.735/2.098/2.461 ms
# lsusb
Bus 002 Device 005: ID 0525:a4a2
Bus 002 Device 003: ID 0424:2513
Bus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 0781:5575
Bus 002 Device 006: ID 0781:5575
Bus 002 Device 004: ID 0781:5575
Bus 002 Device 001: ID 1d6b:0002
#

Bin,

Do you have any suggestions related to "babble detection".  Is there a way for the babble condition to notify some kind of user space handler?  Would it be difficult for example to implement a sysfs entry that counts the number of babbles detected?  That might be useful info just to know how often babbles are being detected, and that would make it easy for someone to implement a user space thread that polls for babble_count>0 and then performs the associated unloading and reloading of modules (e.g. for a case like this one where perhaps they need to guarantee the USB remains accessible).

Brad