isochronous support broken?

[Alistair John Strachan]

On Monday 23 January 2006 11:31, Duncan Sands wrote:
> > > I need to reduce the number of iso packet via module parameter.
> >
> > Are you saying there is a parameter to help with this problem? What is
> > it?
>
> Look at the output of "modinfo usbatm".  In the latest version of the
> driver, you can set the receive buffer size using rcv_buf_bytes.  Try
> setting it to a smaller size (and let us know what happens).

Well, it's all rather bizarre, but I think I might have located the problem. 
Ultimately the isoc option doesn't seem to make the difference that I hoped 
it would. Here's what I got when I first loaded the driver (2.6.15.1, latest 
CVS, enable_isoc=1).

/home/alistair/speedtouch/speedtch.c: speedtch_usb_init: driver version 1.10
usbcore: registered new driver speedtch
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: isoc support enabled
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 
0xd979a2a4
speedtch 4-1.4:1.0: usbatm_usb_probe: using 3392 byte buffer for channel 
0xd979a2ec
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 0: speedtch_atm_start entered
ATM dev 0: speedtch_start_synchro entered
ATM dev 0: speedtch_start_synchro: modem prodded. 2 bytes returned: 00 00
/home/alistair/speedtouch/usbatm.c: usbatm_get_instance
ATM dev 0: usbatm_submit_urb: urb 0xde6a1b40 submission failed (-28)!
ATM dev 0: usbatm_submit_urb: urb 0xd62e8aa0 submission failed (-28)!
ATM dev 0: usbatm_submit_urb: urb 0xd62e89e0 submission failed (-28)!
ATM dev 0: usbatm_submit_urb: urb 0xd62e8920 submission failed (-28)!
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
ATM dev 0: usbatm_rx_process: status -11 in frame 1!
ATM dev 0: usbatm_rx_process: status -11 in frame 2!
ATM dev 0: usbatm_rx_process: status -11 in frame 3!
ATM dev 0: usbatm_rx_process: status -11 in frame 4!
ATM dev 0: usbatm_submit_urb: urb 0xd62e8920 submission failed (-28)!
ATM dev 0: speedtch_check_status: line state 0x10
ATM dev 0: ADSL line is synchronising
printk: 288 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 299 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 299 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
ATM dev 0: speedtch_check_status: line state 0x20
ATM dev 0: ADSL line is up (6688 kb/s down | 576 kb/s up)
printk: 299 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
ATM dev 0: speedtch_handle_int entered
ATM dev 0: speedtch_handle_int: nonzero urb status -71!
usb 4-1.4: USB disconnect, address 4
speedtch 4-1.4:1.0: usbatm_usb_disconnect entered
ATM dev 0: speedtch_atm_stop entered
speedtch 4-1.4:1.0: speedtch_unbind entered
speedtch 4-1.4:1.1: usbatm_usb_disconnect entered
speedtch 4-1.4:1.1: usbatm_usb_disconnect: NULL instance!
speedtch 4-1.4:1.2: usbatm_usb_disconnect entered
speedtch 4-1.4:1.2: usbatm_usb_disconnect: NULL instance!
/home/alistair/speedtouch/usbatm.c: usbatm_atm_dev_close
/home/alistair/speedtouch/usbatm.c: usbatm_put_instance
/home/alistair/speedtouch/usbatm.c: usbatm_put_instance
/home/alistair/speedtouch/usbatm.c: usbatm_destroy_instance
/home/alistair/speedtouch/speedtch.c: speedtch_usb_cleanup

.. as you can see, it doesn't work in the same way as before. Then I tried 
unloading both usbatm, and speedtch. Then I reloaded usbatm with:

modprobe usbatm rcv_buf_bytes=2048
modprobe speedtch enable_isoc=1

And got the following:

/home/alistair/speedtouch/speedtch.c: speedtch_usb_init: driver version 1.10
usbcore: registered new driver speedtch
usb 4-1.4: new full speed USB device using ehci_hcd and address 5
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: isoc support enabled
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 5
speedtch 4-1.4:1.0: usbatm_usb_probe: using 1920 byte buffer for channel 
0xdad026a4
speedtch 4-1.4:1.0: usbatm_usb_probe: using 3392 byte buffer for channel 
0xdad026ec
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 0: speedtch_atm_start entered
ATM dev 0: speedtch_start_synchro entered
ATM dev 0: speedtch_start_synchro: modem prodded. 2 bytes returned: 00 00
/home/alistair/speedtouch/usbatm.c: usbatm_get_instance
printk: 17 messages suppressed.
ATM dev 0: usbatm_submit_urb: urb 0xd62e8860 submission failed (-28)!
ATM dev 0: usbatm_submit_urb: urb 0xd62e8920 submission failed (-28)!
ATM dev 0: usbatm_submit_urb: urb 0xd62e89e0 submission failed (-28)!
ATM dev 0: usbatm_submit_urb: urb 0xd62e8aa0 submission failed (-28)!
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
ATM dev 0: usbatm_rx_process: status -11 in frame 1!
ATM dev 0: usbatm_rx_process: status -11 in frame 2!
ATM dev 0: usbatm_submit_urb: urb 0xd62e8aa0 submission failed (-28)!
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
ATM dev 0: usbatm_rx_process: status -11 in frame 1!
ATM dev 0: speedtch_check_status: line state 0x10
ATM dev 0: ADSL line is synchronising
printk: 190 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
ATM dev 0: speedtch_check_status: line state 0x20
ATM dev 0: ADSL line is up (6720 kb/s down | 576 kb/s up)
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
printk: 199 messages suppressed.
ATM dev 0: usbatm_rx_process: status -11 in frame 0!
ATM dev 0: speedtch_handle_int entered
ATM dev 0: speedtch_handle_int: nonzero urb status -71!
usb 4-1.4: USB disconnect, address 5
speedtch 4-1.4:1.0: usbatm_usb_disconnect entered
ATM dev 0: speedtch_atm_stop entered
speedtch 4-1.4:1.0: speedtch_unbind entered
speedtch 4-1.4:1.1: usbatm_usb_disconnect entered
speedtch 4-1.4:1.1: usbatm_usb_disconnect: NULL instance!
speedtch 4-1.4:1.2: usbatm_usb_disconnect entered
speedtch 4-1.4:1.2: usbatm_usb_disconnect: NULL instance!
/home/alistair/speedtouch/usbatm.c: usbatm_atm_dev_close
/home/alistair/speedtouch/usbatm.c: usbatm_put_instance
/home/alistair/speedtouch/usbatm.c: usbatm_put_instance
/home/alistair/speedtouch/usbatm.c: usbatm_destroy_instance

As you can see, the recv buffer has dropped but nothing has changed. Then I 
had the idea to remove ehci-hcd, and force it to use uhci-hcd for the USB 1.1 
device (I have no USB 2.x devices anyway). This was successful:

ehci_hcd 0000:00:10.3: remove, state 1
usb usb4: USB disconnect, address 1
usb 4-1: USB disconnect, address 2
usb 4-1.3: USB disconnect, address 3
drivers/usb/class/usblp.c: usblp0: removed
ehci_hcd 0000:00:10.3: USB bus 4 deregistered
ACPI: PCI interrupt for device 0000:00:10.3 disabled
usb 1-1: new full speed USB device using uhci_hcd and address 10
hub 1-1:1.0: USB hub found
hub 1-1:1.0: 4 ports detected
usb 1-1.3: new full speed USB device using uhci_hcd and address 11
drivers/usb/class/usblp.c: usblp0: USB Bidirectional printer dev 11 if 0 alt 1 
proto 2 vid 0x03F0 pid 0x1204
usb 1-1.4: new full speed USB device using uhci_hcd and address 12
speedtch 1-1.4:1.0: usbatm_usb_probe: trying driver speedtch with vendor=06b9, 
product=4061, ifnum  0
speedtch 1-1.4:1.0: speedtch_bind entered
speedtch 1-1.4:1.0: isoc support enabled
speedtch 1-1.4:1.0: speedtch_bind: firmware not loaded
usb 1-1.4: reset full speed USB device using uhci_hcd and address 12
speedtch 1-1.4:1.0: usbatm_usb_probe: using 1920 byte buffer for channel 
0xd979a8a4
speedtch 1-1.4:1.0: usbatm_usb_probe: using 3392 byte buffer for channel 
0xd979a8ec
speedtch 1-1.4:1.0: speedtch_find_firmware: looking for speedtch-1.bin.4.00
speedtch 1-1.4:1.0: speedtch_find_firmware: looking for speedtch-1.bin.4
speedtch 1-1.4:1.0: speedtch_find_firmware: looking for speedtch-1.bin
speedtch 1-1.4:1.0: found stage 1 firmware speedtch-1.bin
speedtch 1-1.4:1.0: speedtch_find_firmware: looking for speedtch-2.bin.4.00
speedtch 1-1.4:1.0: speedtch_find_firmware: looking for speedtch-2.bin.4
speedtch 1-1.4:1.0: speedtch_find_firmware: looking for speedtch-2.bin
speedtch 1-1.4:1.0: found stage 2 firmware speedtch-2.bin
speedtch 1-1.4:1.0: speedtch_upload_firmware entered
speedtch 1-1.4:1.0: speedtch_upload_firmware: BLOCK1 uploaded (935 bytes)
speedtch 1-1.4:1.0: speedtch_upload_firmware: BLOCK2 downloaded (511 bytes)
speedtch 1-1.4:1.0: speedtch_upload_firmware: BLOCK3 uploaded (775545 bytes)
speedtch 1-1.4:1.0: speedtch_upload_firmware: BLOCK4 downloaded (511 bytes)
ATM dev 0: speedtch_atm_start entered
ATM dev 0: speedtch_start_synchro entered
ATM dev 0: speedtch_start_synchro: modem prodded. 2 bytes returned: 00 00
/home/alistair/speedtouch/usbatm.c: usbatm_get_instance
ATM dev 0: speedtch_check_status: line state 0x10
ATM dev 0: ADSL line is synchronising
ATM dev 0: speedtch_check_status: line state 0x20
ATM dev 0: ADSL line is up (6624 kb/s down | 576 kb/s up)
ATM dev 0: usbatm_atm_open: vpi 0, vci 38
ATM dev 0: usbatm_atm_open: allocated vcc data 0xd4cec8a0

I was able to bring pppd up over the interface. /proc/bus/usb/devices looks 
like this; only 79% utilisation.

T:  Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=12  MxCh= 2
B:  Alloc=710/900 us (79%), #Int=  2, #Iso=  4
D:  Ver= 1.10 Cls=09(hub  ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=0000 ProdID=0000 Rev= 2.06
S:  Manufacturer=Linux 2.6.15.1 uhci_hcd
S:  Product=UHCI Host Controller
S:  SerialNumber=0000:00:10.0
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  0mA
I:  If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   2 Ivl=255m

My bandwidth is still locked to just under 500KB/s (4MBits). So either a) isoc 
isn't working or b) you need to do more than just switch from bulk to isoc to 
get 8Mbits from this device. The Windows workaround does not suggest this, 
but I suppose it is impossible to tell.

If it's a useful datapoint, I used to get sporadic errors and the USB LED 
would flash RED if the bandwidth was held close to 4Mbit for a long period of 
time. This no longer seems to happen with isoc, suggesting the bandwidth 
bottleneck has been lifted. However, I do not see the 6.6 megabits I've 
synced at.

-- 
Cheers,
Alistair.

'No sense being pessimistic, it probably wouldn't work anyway.'
Third year Computer Science undergraduate.
1F2 55 South Clerk Street, Edinburgh, UK.