isochronous support broken?

[Duncan Sands]

Hi Alistair,

> To see whether isoc support would help my 4MBit DSL cap, I attempted to check 
> out the CVS version of the driver and modprobed it with enable_isoc=1
> 
> I have a Via Epia M10000 which has a uhci USB 1.1 controller and an ehci USB 
> 2.0 controller. I've not had USB issues with the machine since I bought it. 
> Kernel is 2.6.15.

is the modem plugged into the USB 1 or the USB 2 controller?  Is the uhci
or ehci driver being used with it?

> In bulk mode, the CVS driver works fine, however in isochronous mode, I get 
> the following errors to dmesg. The modem does not allow me to establish a ppp 
> connection over it, even though it synchronises successfully. This suggests a 
> driver bug.

It does.  I presume that you built and inserted both the speedtch and usbatm
modules from CVS, not just the speedtch module?

> usb 4-1.4: new full speed USB device using ehci_hcd and address 4
> speedtch 4-1.4:1.0: usbatm_usb_probe: trying driver speedtch with vendor=06b9, 
> product=4061, ifnum  0
> speedtch 4-1.4:1.0: speedtch_bind entered
> speedtch 4-1.4:1.0: speedtch_bind: firmware not loaded
> usb 4-1.4: reset full speed USB device using ehci_hcd and address 4
> speedtch 4-1.4:1.0: usbatm_usb_probe: using 3200 byte buffer for channel 
> 0xd8258ea0

This buffer size looks strange.  It should be a multiple of the maxpacket size
for the isochronous endpoint.  What is in /proc/bus/usb/devices for the modem?

> speedtch 4-1.4:1.0: usbatm_usb_probe: using 3392 byte buffer for channel 
> 0xd8258ee8
> speedtch 4-1.4:1.0: speedtch_find_firmware: looking for speedtch-1.bin.4.00
> speedtch 4-1.4:1.0: speedtch_find_firmware: looking for speedtch-1.bin.4
> speedtch 4-1.4:1.0: speedtch_find_firmware: looking for speedtch-1.bin
> speedtch 4-1.4:1.0: found stage 1 firmware speedtch-1.bin
> speedtch 4-1.4:1.0: speedtch_find_firmware: looking for speedtch-2.bin.4.00
> speedtch 4-1.4:1.0: speedtch_find_firmware: looking for speedtch-2.bin.4
> speedtch 4-1.4:1.0: speedtch_find_firmware: looking for speedtch-2.bin
> speedtch 4-1.4:1.0: found stage 2 firmware speedtch-2.bin
> speedtch 4-1.4:1.0: speedtch_upload_firmware entered
> speedtch 4-1.4:1.0: speedtch_upload_firmware: BLOCK1 uploaded (935 bytes)
> speedtch 4-1.4:1.0: speedtch_upload_firmware: BLOCK2 downloaded (511 bytes)
> speedtch 4-1.4:1.0: speedtch_upload_firmware: BLOCK3 uploaded (775545 bytes)
> speedtch 4-1.4:1.0: speedtch_upload_firmware: BLOCK4 downloaded (511 bytes)
> ATM dev 3: speedtch_atm_start entered
> ATM dev 3: speedtch_start_synchro entered
> ATM dev 3: speedtch_start_synchro: modem prodded. 2 bytes returned: 00 00
> /usr/src/speedtouch/usbatm.c: usbatm_get_instance
> printk: 77 messages suppressed.
> ATM dev 3: usbatm_submit_urb: urb 0xd70ada40 submission failed (-28)!

-ENOSPC         This request would overcommit the usb bandwidth reserved
                for periodic transfers (interrupt, isochronous).

Interesting.  What kernel version is this (I noticed some bandwidth changes
going into 2.6.15)?  Do you have other iso devices connected at the same time?

> ATM dev 3: usbatm_submit_urb: urb 0xd70adbc0 submission failed (-28)!
> ATM dev 3: usbatm_submit_urb: urb 0xd70ad980 submission failed (-28)!
> ATM dev 3: usbatm_submit_urb: urb 0xd70ad8c0 submission failed (-28)!
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!

-EAGAIN         a) specified ISO start frame too early
                b) (using ISO-ASAP) too much scheduled for the future
                   wait some time and try again.

(We are using ISO-ASAP).  Also seems like a bandwidth problem.

> ATM dev 3: speedtch_check_status: line state 0x10
> ATM dev 3: ADSL line is synchronising
> printk: 83 messages suppressed.
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!
> printk: 299 messages suppressed.
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!
> printk: 299 messages suppressed.
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!
> ATM dev 3: speedtch_check_status: line state 0x20
> ATM dev 3: ADSL line is up (6752 kb/s down | 576 kb/s up)
> printk: 299 messages suppressed.
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!
> printk: 299 messages suppressed.
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!
> syslog-ng[3299]: STATS: dropped 0
> printk: 299 messages suppressed.
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!
> printk: 299 messages suppressed.
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!
> pppd[7528]: Plugin pppoatm.so loaded.
> pppd[7528]: PPPoATM plugin_init
> pppd[7528]: PPPoATM setdevname_pppoatm - SUCCESS:0.38
> pppd[7529]: pppd 2.4.3 started by root, uid 0
> ATM dev 0: usbatm_atm_open: vpi 0, vci 38
> ATM dev 0: usbatm_atm_open: disconnected!
> pppd[7529]: connect(0.38): No such device
> pppd[7529]: Exit.
> printk: 299 messages suppressed.
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!
> printk: 299 messages suppressed.
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!
> printk: 299 messages suppressed.
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!
> printk: 299 messages suppressed.
> ATM dev 3: usbatm_rx_process: status -11 in frame 0!

I will have to think about this (and read up on bandwidth allocation).
Thanks for testing, it looks like you found something serious!

Ciao,

Duncan.