PROBLEM: USB isochronous urb leak on EHCI driver

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi,

I am dealing with a USB EHCI driver bug. Here is the info:

My configuration:
-----------------

Host: Freescale i.MX512 with ARM Cortex A8 (USB 2.0 host controller)
Linux kernel: 2.6.31, using EHCI USB driver
Hub: 4-PORT USB 1.1 HUB (Texas Instruments PN: tusb2046b)
Devices: 4 USB 1.1 audio codecs (Texas Instruments PN: pcm2901)

Note: each codec is being used in R/W access, so with 4 codecs, I have
4 playback and 4 capture streams.

My problem:
-----------

I have usb urb leaks when connecting more than 1 codec to the USB 1.1
Hub. (the result is that some of the audio data is not transferred,
part of the sound is simply missing) No problem when using only 1
of the 4 codecs connected to the hub; When I connect a second codec,
the sound quality starts to degrade. With 3 codecs, we just cannot
recognize a speach.

Tests and observations:
-----------------------

Since I have 3 usb ports available on the i.MX512, I tried to connect
3 codecs directly on USB ports: the sound is perfect on each of the
three ports.

I bought a consumer USB 2.0 Hub: no problem when using 3 codecs
connected to that Hub, however, the audio will completly stop on all
channels when connecting the 4th codec.

I checked the communication between the Hub (USB 1.1) and the Host
controller (USB 2.0) with a scope and concluded that the
communication speed is 1.5 MBytes/s has expected (so the 
communication is downgraded to USB 1.1, since codecs and hub are USB
1.1 devices).

Also, I know that there is physically enough bandwidth to
transfer the data for two reasons:
1) I have an older CPU with a USB 1.1 host controller (using the OHCI
driver), using the same hub and the same codecs: works like a champ,
using less than 50% of the available bandwidth (observed with a
scope)
2) 1 audio stream is 32khz-mono, 16 bits = 64 kB/s,
4 codecs = 8 streams(R/W) x 64 kB/s = 512 kB/s (out of 1.5MB/s)

I noticed that my sound problem starts happening with only 2 codecs
(4 streams, 256 kB/s). I first thought that it was a bandwidth
limitation, so I decided to connect only 1 codec using more bandwidth.
I configured it to 48khz-stereo (16-bits), using 384 kB/s for both
read and write streams: no problem. With that configuration, the 
scope shows about 30% of total bandwidth usage (300us used out of 1ms
periods). Then, I added a second codec (48khz-stereo-16bits): very
strange, now the total bandwidth usage felt down to about 200us, which
seems to keep the same, whatever the number of codec I add (I also
tried 3 and 4...). So it looks like the scheduler is not able to
properly allocate Isochronous time slots when more than one device is
connected to the hub. However, without the hub, it works perfectly.

Another interresting fact is that at application level, the Read and
Write operations are returning the good amount of bytes read/written.
This is not the case at kernel level: I noticed that function
"usb_submit_urb" (from /drivers/usb/core/urb.c) will only tranfer
part of the "urbs" when the sound is degraded. I tried to figure out
where the leak comes from without success. Also, there are no error
messages from kernel so everything appears to work well, excepted
that part of the sound is missing!

I can't change my hardware (this is in the hand of customers), so
the only possible solution for me is to correct the software.

I tried to change my ehci driver with the one from kernel 2.6.39.4
but did not work, same problem.

Question:
---------

Before attempting to upgrade to an earlier kernel driver (this is
a fairly big amount of work), I would really like to know if this
problem would still be in the 3.x kernels. Has anyone seen that
issue in 3.x kernels?

I am pretty new to USB driver debugging, so any ideas of where/how
to find solutions will be appreciated. Thank you very much in advance
for the support. Also don't hesitate to redirect me if I'm not at the
right place to ask these questions. I can also provide some code if
someone need it to help.

Attached is a dump of my "dmesg" after startup.

Michael Tessier







<5>Linux version 2.6.31-770-g0e46b52-0897 (michael.tessier@xxxxxxxxxxxxxxxxxxxxxxxxxxx) (gcc version 4.1.2) #12 PREEMPT Mon Nov 24 18:34:19 EST 2014
<4>CPU: ARMv7 Processor [412fc085] revision 5 (ARMv7), cr=10c53c7f
<4>CPU: VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
<4>Machine: MX51 Xanthus Board
<4>Memory policy: ECC disabled, Data cache writeback
<7>On node 0 totalpages: 65536
<7>free_area_init_node: node 0, pgdat c02f137c, node_mem_map c0307000
<7>  DMA zone: 128 pages used for memmap
<7>  DMA zone: 0 pages reserved
<7>  DMA zone: 16256 pages, LIFO batch:3
<7>  Normal zone: 384 pages used for memmap
<7>  Normal zone: 48768 pages, LIFO batch:15
<4>Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 65024
<5>Kernel command line: console=ttymxc2,115200 CNFGmagic=XATS CNFGversion=1.0.0.0 vendorID=EXPT platformID=LINX productID=XATS mac1=00:1D:9E:00:17:2e mac2=00:1D:9E:00:17:2f XanthusPart=8100050 XanthusSerial=51 XanthusRevLevel=-- UnitPart=0 UnitSerial=0 UnitRevLevel=0 ip= UBversion=1.5.0.0 ethcpu=eth0 root=/dev/ram rw ramdisk_size=55000
<4>PID hash table entries: 1024 (order: 10, 4096 bytes)
<6>Dentry cache hash table entries: 32768 (order: 5, 131072 bytes)
<6>Inode-cache hash table entries: 16384 (order: 4, 65536 bytes)
<6>Memory: 256MB = 256MB total
<5>Memory: 254000KB available (2660K code, 208K data, 104K init, 0K highmem)
<6>SLUB: Genslabs=11, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
<6>NR_IRQS:368
<6>MXC IRQ initialized
<6>MXC_Early serial console at MMIO 0x7000c000 (options '115200')
<6>console [ttymxc2] enabled
<4>Console: colour dummy device 80x30
<6>Calibrating delay loop... 575.07 BogoMIPS (lpj=2875392)
<4>Mount-cache hash table entries: 512
<6>CPU: Testing write buffer coherency: ok
<6>NET: Registered protocol family 16
<6>i.MX IRAM pool: 128 KB@0xd0840000
<6>IRAM READY
<6>CPU is i.MX51 Revision 3.0
<6>MXC GPIO hardware
<4>XANTHUS FPGA irq controler :197
<4>ks8851: mac(00:1d:9e:00:17:2f)
<4>XANTHUS FPGA VERSION: 0.1.0.0
<6>Using SDMA I.API
<6>MXC DMA API initialized
<4>bio: create slab <bio-0> at 0
<5>SCSI subsystem initialized
<7>libata version 3.00 loaded.
<6>CSPI: mxc_spi-0 probed
<6>mxc_spi mxc_spi.0: registering loopback device 'spidev'
<6>mxc_spi mxc_spi.0: registering loopback device 'spidev'
<6>mxc_spi mxc_spi.0: registering loopback device 'spidev'
<6>MXC I2C driver
<6>MXC HS I2C driver
<6>NET: Registered protocol family 2
<6>IP route cache hash table entries: 2048 (order: 1, 8192 bytes)
<7>Switched to high resolution mode on CPU 0
<6>TCP established hash table entries: 8192 (order: 4, 65536 bytes)
<6>TCP bind hash table entries: 8192 (order: 3, 32768 bytes)
<6>TCP: Hash tables configured (established 8192 bind 8192)
<6>TCP reno registered
<6>NET: Registered protocol family 1
<6>Trying to unpack rootfs image as initramfs...
<6>rootfs image is not initramfs (no cpio magic); looks like an initrd
<6>Freeing initrd memory: 2604K
<6>LPMode driver module loaded
<6>msgmni has been set to 501
<6>io scheduler noop registered (default)
<4>Class created!
<6>Triggered GPIO driver. Boundary Devices
<6>XANTHUS Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
<6>serial8250.0: ttyS0 at MMIO 0xb0100000 (irq = 352) is a 16550A
<6>Serial: MXC Internal UART driver
<6>mxcintuart.0: ttymxc0 at MMIO 0x73fbc000 (irq = 31) is a Freescale i.MX
<6>mxcintuart.1: ttymxc1 at MMIO 0x73fc0000 (irq = 32) is a Freescale i.MX
<6>mxcintuart.2: ttymxc2 at MMIO 0x7000c000 (irq = 33) is a Freescale i.MX
<6>console handover: boot [ttymxc2] -> real [ttymxc2]
<6>brd: module loaded
<6>loop: module loaded
<3>pata_fsl pata_fsl: rchan=29 wchan=28
<6>scsi0 : pata_fsl
<6>ata1: PATA max UDMA/100 irq 70
<6>FEC Ethernet Driver
<3>FEC: fec_probe name:fec, id:0, net name:eth0, index:0
<3>FEC: mac(00:1d:9e:00:17:2e)
<6>ata1.00: CFA: TRANSCEND, 20100202, max UDMA/66
<6>ata1.00: 994896 sectors, multi 0: LBA 
<6>ata1.00: configured for UDMA/66
<5>scsi 0:0:0:0: Direct-Access     ATA      TRANSCEND        2010 PQ: 0 ANSI: 5
<5>sd 0:0:0:0: [sda] 994896 512-byte logical blocks: (509 MB/485 MiB)
<5>sd 0:0:0:0: [sda] Write Protect is off
<7>sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
<5>sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
<6> sda: sda1 sda2 sda3 sda4
<5>sd 0:0:0:0: [sda] Attached SCSI disk
<6>fec_enet_mii_bus: probed
<4>IEEE1588: ptp-timer is unavailable
<6>rtc-ds1307 3-0068: rtc core: registered ds1340 as rtc0
<6>i2c /dev entries driver
<6>Xanthus WatchDog Driver 1.2
<4>clk: Unable to get requested clock: wdog_clk
<6>XANTHUS Boot - WDOG Rst - Soft Reset (10010,1)
<6>Xanthus Watchdog # 0 Timer: initial timeout 60 sec
<6>TCP cubic registered
<6>NET: Registered protocol family 17
<6>VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 2
<6>rtc-ds1307 3-0068: setting system clock to 2000-01-01 00:00:44 UTC (946684844)
<5>RAMDISK: gzip image found at block 0
<4>VFS: Mounted root (ext2 filesystem) on device 1:0.
<6>Freeing init memory: 104K
<6>XANTHUS ks8851_mll: Driver version 1.00.
<6>XANTHUS: ks8851_probe name:ks8851_mll, id:0, net name:eth1, index:0
<6>ks8851 hard reset
<6>ks8851_mll ks8851_mll.0: message enable is 31
<6>KS_CIDER:8872
<6>ks8851_mll ks8851_mll.0: the selftest passes
<6>XANTHUS: ks_soft_reset
<6>XANTHUS: KS8851 mac(00:1d:9e:00:17:2f)
<6>ks8851_mll Found chip, family: 0x88, id: 0x7, rev: 0x1
<6>Ethernet Channel Bonding Driver: v3.5.0 (November 4, 2008)
<6>bonding: MII link monitoring set to 100 ms
<6>usbcore: registered new interface driver usbfs
<6>usbcore: registered new interface driver hub
<6>usbcore: registered new device driver usb
<6>ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
<6>fsl-ehci fsl-ehci.0: Freescale On-Chip EHCI Host Controller
<6>fsl-ehci fsl-ehci.0: new USB bus registered, assigned bus number 1
<6>fsl-ehci fsl-ehci.0: irq 18, io base 0x73f80000
<6>fsl-ehci fsl-ehci.0: USB 2.0 started, EHCI 1.00
<6>usb usb1: configuration #1 chosen from 1 choice
<6>hub 1-0:1.0: USB hub found
<6>hub 1-0:1.0: 1 port detected
<6>fsl-ehci fsl-ehci.1: Freescale On-Chip EHCI Host Controller
<6>fsl-ehci fsl-ehci.1: new USB bus registered, assigned bus number 2
<6>fsl-ehci fsl-ehci.1: irq 14, io base 0x73f80200
<6>fsl-ehci fsl-ehci.1: USB 2.0 started, EHCI 1.00
<6>usb usb2: configuration #1 chosen from 1 choice
<6>hub 2-0:1.0: USB hub found
<6>hub 2-0:1.0: 1 port detected
<6>fsl-ehci fsl-ehci.2: Freescale On-Chip EHCI Host Controller
<6>fsl-ehci fsl-ehci.2: new USB bus registered, assigned bus number 3
<6>fsl-ehci fsl-ehci.2: irq 16, io base 0x73f80400
<6>fsl-ehci fsl-ehci.2: USB 2.0 started, EHCI 1.00
<6>usb usb3: configuration #1 chosen from 1 choice
<6>hub 3-0:1.0: USB hub found
<6>hub 3-0:1.0: 1 port detected
<6>Initializing USB Mass Storage driver...
<6>usb 2-1: new full speed USB device using fsl-ehci and address 2
<6>usbcore: registered new interface driver usb-storage
<6>USB Mass Storage support registered.
<6>usb 2-1: configuration #1 chosen from 1 choice
<6>hub 2-1:1.0: USB hub found
<6>hub 2-1:1.0: 4 ports detected
<6>usb 2-1.1: new full speed USB device using fsl-ehci and address 3
<6>kjournald starting.  Commit interval 5 seconds
<4>EXT3-fs warning: maximal mount count reached, running e2fsck is recommended
<6>EXT3 FS on sda3, internal journal
<6>EXT3-fs: recovery complete.
<6>EXT3-fs: mounted filesystem with ordered data mode.
<6>usb 2-1.1: configuration #1 chosen from 1 choice
<6>eth0: Freescale FEC PHY driver [Generic PHY] (mii_bus:phy_addr=0:00, irq=-1)
<4>expio_set_type_irq IRQF_TRIGGER_LOW
<6>XANTHUS: ks_update_link_status
<6>usb 2-1.2: new full speed USB device using fsl-ehci and address 4
<6>usb 2-1.2: configuration #1 chosen from 1 choice
<6>usb 2-1.3: new full speed USB device using fsl-ehci and address 5
<6>usb 2-1.3: configuration #1 chosen from 1 choice
<6>PHY: 0:00 - Link is Up - 100/Full
<6>eth0: Freescale FEC PHY driver [Generic PHY] (mii_bus:phy_addr=0:00, irq=-1)
<6>bonding: bond0: making interface eth0 the new active one.
<6>bonding: bond0: first active interface up!
<6>bonding: bond0: enslaving eth0 as an active interface with an up link.
<6>ks_net_stop
<6>ks8851_mll ks8851_mll.0: eth1: shutting down
<4>expio_set_type_irq IRQF_TRIGGER_LOW
<6>XANTHUS: ks_update_link_status
<6>XANTHUS: KS8851 mac(00:1d:9e:00:17:2e)
<6>bonding: bond0: enslaving eth1 as a backup interface with a down link.
<6>kjournald starting.  Commit interval 5 seconds
<4>EXT3-fs warning: maximal mount count reached, running e2fsck is recommended
<6>EXT3 FS on sda2, internal journal
<6>EXT3-fs: recovery complete.
<6>EXT3-fs: mounted filesystem with ordered data mode.
<6>kjournald starting.  Commit interval 5 seconds
<4>EXT3-fs warning: maximal mount count reached, running e2fsck is recommended
<6>EXT3 FS on sda4, internal journal
<6>EXT3-fs: recovery complete.
<6>EXT3-fs: mounted filesystem with ordered data mode.
<6>PHY: 0:00 - Link is Up - 100/Full
<6>usbcore: registered new interface driver snd-usb-audio
<4>axiodrv: module license 'Proprietary' taints kernel.
<4>Disabling lock debugging due to kernel taint
<6>io: registered with major 250 and delay 1000

[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux