root@beaglebone:~# uname -r
4.4.91-ti-r133
I’ve recently migrated to Debian 9.2 kernel 4.4 from Debian 8.2 kernel 4.1.
This was absolutely not an issue with kernel 4.1
So, we have a custom, cascade powered USB hub with four 4-port USB hub chips combining into a single 4-port USB hub chip. About 1/5 of the time on boot, some of our USB devices are not recognized. Below is the dmesg output. One interesting part of the dmesg output is the following line.
[ 9.582601] usb 1-1.1.1-port2: Cannot enable. Maybe the USB cable is bad?
This has to be a software bug, because loading the same BeagleBone enhanced with the old Debian 8.2 image with kernel 4.1 does not have this problem at all. It is possible to fix this problem by “resetting” the USB hub associated with the unrecognized device by running the following small C program on the USB bus that Linux assigned that USB hub chip. However, is there a way to fix the problem with the USB devices not being recognized in the first place? Is there something we’re doing wrong? Manually searching for the unrecognized USB devices on every boot, and running that program on the associated USB hub chip is not going to work long-term. Any help would be appreciated.
/* usbreset – send a USB port reset to a USB device */
#include <stdio.h>
#include <unistd.h>
#include <fcntl.h>
#include <errno.h>
#include <sys/ioctl.h>
#include <linux/usbdevice_fs.h>
int main(int argc, char **argv)
{
char filename[128];
int fd, rc;
if (argc != 2) {
fprintf(stderr, “Usage: usbreset device-filename\n”);
return 1;
}
snprintf(filename, 127, “/dev/bus/usb/001/%s”, argv[1]);
fd = open(filename, O_WRONLY);
if (fd < 0) {
perror(“Error opening output file”);
return 1;
}
printf(“Resetting USB device %s\n”, filename);
rc = ioctl(fd, USBDEVFS_RESET, 0);
if (rc < 0) {
perror(“Error in ioctl”);
return 1;
}
printf(“Reset successful\n”);
close(fd);
return 0;
}
dmesg output:
[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Initializing cgroup subsys cpuset
[ 0.000000] Initializing cgroup subsys cpu
[ 0.000000] Initializing cgroup subsys cpuacct
[ 0.000000] Linux version 4.4.91-ti-r133 (root@b7-am57xx-beagle-x15-2gb) (gcc version 6.3.0 20170516 (Debian 6.3.0-18) ) #1 SMP Tue Oct 10 05:18:08 UTC 2017
[ 0.000000] CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7), cr=10c5387d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[ 0.000000] Machine model: SanCloud BeagleBone Enhanced
[ 0.000000] cma: Reserved 48 MiB at 0xbc800000
[ 0.000000] Memory policy: Data cache writeback
[ 0.000000] On node 0 totalpages: 261632
[ 0.000000] free_area_init_node: node 0, pgdat c10d8f80, node_mem_map ef6f9000
[ 0.000000] Normal zone: 1728 pages used for memmap
[ 0.000000] Normal zone: 0 pages reserved
[ 0.000000] Normal zone: 196608 pages, LIFO batch:31
[ 0.000000] HighMem zone: 65024 pages, LIFO batch:15
[ 0.000000] CPU: All CPU(s) started in SVC mode.
[ 0.000000] AM335X ES2.1 (sgx neon )
[ 0.000000] PERCPU: Embedded 13 pages/cpu @ef6c1000 s24268 r8192 d20788 u53248
[ 0.000000] pcpu-alloc: s24268 r8192 d20788 u53248 alloc=13*4096
[ 0.000000] pcpu-alloc: [0] 0
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 259904
[ 0.000000] Kernel command line: console=ttyO0,115200n8 bone_capemgr.enable_partno=cape-universala root=/dev/mmcblk1p1 ro rootfstype=ext4 rootwait coherent_pool=1M quiet
[ 0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Memory: 962692K/1046528K available (11720K kernel code, 948K rwdata, 3904K rodata, 756K init, 854K bss, 34684K reserved, 49152K cma-reserved, 210944K highmem)
[ 0.000000] Virtual kernel memory layout:
vector : 0xffff0000 - 0xffff1000 ( 4 kB)
fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
vmalloc : 0xf0800000 - 0xff800000 ( 240 MB)
lowmem : 0xc0000000 - 0xf0000000 ( 768 MB)
pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB)
modules : 0xbf000000 - 0xbfe00000 ( 14 MB)
.text : 0xc0008000 - 0xc0f4a584 (15626 kB)
.init : 0xc0f4b000 - 0xc1008000 ( 756 kB)
.data : 0xc1008000 - 0xc10f5108 ( 949 kB)
.bss : 0xc10f8000 - 0xc11cd820 ( 855 kB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] Hierarchical RCU implementation.
[ 0.000000] Build-time adjustment of leaf fanout to 32.
[ 0.000000] RCU restricting CPUs from NR_CPUS=2 to nr_cpu_ids=1.
[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=32, nr_cpu_ids=1
[ 0.000000] NR_IRQS:16 nr_irqs:16 16
[ 0.000000] IRQ: Found an INTC at 0xfa200000 (revision 5.0) with 128 interrupts
[ 0.000000] OMAP clockevent source: timer2 at 24000000 Hz
[ 0.000016] sched_clock: 32 bits at 24MHz, resolution 41ns, wraps every 89478484971ns
[ 0.000039] clocksource: timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns
[ 0.000053] OMAP clocksource: timer1 at 24000000 Hz
[ 0.000873] clocksource_probe: no matching clocksources found
[ 0.001084] Console: colour dummy device 80x30
[ 0.001113] WARNING: Your ‘console=ttyO0’ has been replaced by ‘ttyS0’
[ 0.001121] This ensures that you still see kernel messages. Please
[ 0.001128] update your kernel commandline.
[ 0.001150] Calibrating delay loop… 995.32 BogoMIPS (lpj=1990656)
[ 0.046777] pid_max: default: 32768 minimum: 301
[ 0.046926] Security Framework initialized
[ 0.046941] Yama: becoming mindful.
[ 0.046979] AppArmor: AppArmor disabled by boot time parameter
[ 0.047152] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.047167] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.048040] Initializing cgroup subsys io
[ 0.048072] Initializing cgroup subsys memory
[ 0.048118] Initializing cgroup subsys devices
[ 0.048138] Initializing cgroup subsys freezer
[ 0.048154] Initializing cgroup subsys net_cls
[ 0.048168] Initializing cgroup subsys perf_event
[ 0.048183] Initializing cgroup subsys net_prio
[ 0.048210] Initializing cgroup subsys pids
[ 0.048265] CPU: Testing write buffer coherency: ok
[ 0.048324] ftrace: allocating 35977 entries in 106 pages
[ 0.150444] CPU0: thread -1, cpu 0, socket -1, mpidr 0
[ 0.150579] Setting up static identity map for 0x80008280 - 0x800082e0
[ 0.155047] Brought up 1 CPUs
[ 0.155075] SMP: Total of 1 processors activated (995.32 BogoMIPS).
[ 0.155083] CPU: All CPU(s) started in SVC mode.
[ 0.156656] devtmpfs: initialized
[ 0.174683] VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 3
[ 0.194803] omap_hwmod: debugss: _wait_target_disable failed
[ 0.236178] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.236212] futex hash table entries: 256 (order: 2, 16384 bytes)
[ 0.240330] xor: measuring software checksum speed
[ 0.278779] arm4regs : 1219.000 MB/sec
[ 0.318780] 8regs : 1092.000 MB/sec
[ 0.358771] 32regs : 1089.000 MB/sec
[ 0.398771] neon : 1747.000 MB/sec
[ 0.398780] xor: using function: neon (1747.000 MB/sec)
[ 0.398913] pinctrl core: initialized pinctrl subsystem
[ 0.400450] NET: Registered protocol family 16
[ 0.404190] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[ 0.405117] cpuidle: using governor ladder
[ 0.405137] cpuidle: using governor menu
[ 0.411441] OMAP GPIO hardware version 0.1
[ 0.423637] No ATAGs?
[ 0.423675] hw-breakpoint: debug architecture 0x4 unsupported.
[ 0.424206] omap4_sram_init:Unable to allocate sram needed to handle errata I688
[ 0.424221] omap4_sram_init:Unable to get sram pool needed to handle errata I688
[ 0.502911] raid6: int32x1 gen() 258 MB/s
[ 0.570820] raid6: int32x1 xor() 227 MB/s
[ 0.638933] raid6: int32x2 gen() 323 MB/s
[ 0.706780] raid6: int32x2 xor() 283 MB/s
[ 0.774904] raid6: int32x4 gen() 329 MB/s
[ 0.842840] raid6: int32x4 xor() 267 MB/s
[ 0.910873] raid6: int32x8 gen() 300 MB/s
[ 0.978900] raid6: int32x8 xor() 234 MB/s
[ 1.046793] raid6: neonx1 gen() 1456 MB/s
[ 1.114790] raid6: neonx1 xor() 845 MB/s
[ 1.182800] raid6: neonx2 gen() 1923 MB/s
[ 1.250771] raid6: neonx2 xor() 1203 MB/s
[ 1.318785] raid6: neonx4 gen() 1085 MB/s
[ 1.386776] raid6: neonx4 xor() 792 MB/s
[ 1.454783] raid6: neonx8 gen() 1036 MB/s
[ 1.522779] raid6: neonx8 xor() 756 MB/s
[ 1.522788] raid6: using algorithm neonx2 gen() 1923 MB/s
[ 1.522796] raid6: … xor() 1203 MB/s, rmw enabled
[ 1.522803] raid6: using intx1 recovery algorithm
[ 1.532220] edma 49000000.edma: TI EDMA DMA engine driver
[ 1.535357] vgaarb: loaded
[ 1.535997] SCSI subsystem initialized
[ 1.536388] libata version 3.00 loaded.
[ 1.536755] usbcore: registered new interface driver usbfs
[ 1.536833] usbcore: registered new interface driver hub
[ 1.536943] usbcore: registered new device driver usb
[ 1.537574] omap_i2c 44e0b000.i2c: could not find pctldev for node /ocp/l4_wkup@44c00000/scm@210000/pinmux@800/pinmux_i2c0_pins, deferring probe
[ 1.537627] omap_i2c 4819c000.i2c: could not find pctldev for node /ocp/l4_wkup@44c00000/scm@210000/pinmux@800/pinmux_i2c2_pins, deferring probe
[ 1.537745] media: Linux media interface: v0.10
[ 1.537811] Linux video capture interface: v2.00
[ 1.537930] pps_core: LinuxPPS API ver. 1 registered