Hi Ian, On Thu, 24 Feb 2005, Ian Campbell wrote: > The driver queues an URB with length PEGASUS_MTU + 8. PEGASUS_MTU is > 1536, I guess the extra 8 is a status header added by the dongle, this > gives an URB that is large enough to contain the largest packet that > could arrive. > > 72 is 64 + 8, and 64 is the minimum Ethernet packet size, so this just > seems to be a smaller than maximum size packet arriving, which is fine > and normal.
I tried to analyze one 72-byte data portion from the log. I broke the lines in the data where I felt the field boundaries may exist. The following is just a speculation. Feb 24 10:57:15 viper kernel: CC=9 EP=1 DIR=2 CNT=72 LEN=832 MPS=64 TGL=0 ACT=0 FA=2 SPD=0 LST=1 B5=0 Feb 24 10:57:15 viper kernel: 9048 1840 0b40 0002 Feb 24 10:57:15 viper kernel: <--in-- ff ff ff ff ff ff # dest address 00 07 e9 2f d1 4a # src address 88 6d # ether-type (1) 00 01 00 01 ca 5e 1b 00 01 00 00 07 e9 2f d1 4a # (2) 00 00 40 00 00 00 00 00 00 00 58 00 55 88 48 c4 76 88 00 00 00 00 01 00 00 00 0d 00 01 00 52 65 # CRC 53 65 c2 e2 58 14 48 00 # ??? (1) according to http://standards.ieee.org/regauth/ethertype/eth.txt the type field coinsides with the one assigned to Intel. (2) note that the data contains the src address. > The amount of debug still seemed to be too much over a serial line, but > if I redirect it all via syslog to /var/log/debug I get the attached (I > added KERN_DEBUG to dump_ptd_*), this is with the fix for the reporting > of short_not_ok corrected. > > Writing via syslog was fast enough that I didn't need to restrict the > PTDs that were printed and I could include the dump_ptd_*_data as well. There are still some portions of the log missing here and there even through the syslog. I propose that you comment out both dump_ptd() and dump_ptd_out_data() in the pack_fifo() function. The much more interesting printout from unpack_fifo() mostly duplicates that info (except for TOGGLE bit, which may or may not be important here). Anyway, this would cut the printout down to half. Or, you can just print from pack_fifo() only something lime "EP=%d TGL=%d" which would give us all the info. > I see a lot of PTDs with CC=f (TD_NOTACCESSED). Is it normal to see so > many? It may be a sign that something has gone wrong with the configuration. For example, if some urbs won't get scheduled in the isp116x driver in time (see below) then the device just may sit half configured and cannot provide any data the driver is waiting for. > I see one CC=3 (DataToggleMismatch) and a whole load of CC=9's > (DataUnderrun). The log seems to be incomplete close to this message, but the message itself seems to report a real problem (good that you noticed it!). With the current log I was not able to track down the cause of this error. Therefore, if cutting down the log (as described above), it would be perhaps still good to keep printing the TOGGLE info from pack_fifo(). > The DataUnderrun seem to correspond to the allowed underruns we > discussed above. I see 39 CC=9's and 40 allowed data underruns (I'm > willing to believe that syslog dropped the occasional message). Data underruns seem to be normal. > I have to admit I don't have a clue what toggle is supposed to do... In general, it is meant to keep track of successful packet transfers over usb and toggling is simple if all works. However, isp116x chips seem to have their own idiosyncrasies related to TOGGLE bit handling in certain failures of packet transfers and I am not sure I have fully understood them. The datasheet is quiet on this topic. > Is there any further debugging I can enable that will help? I noticed that the sceduling of urbs is performed incorrectly in some circumstances. The following patch makes 2 changes to that. First, it cuts the large urbs down to multiples of MaxPacketSize. Second, it eliminates possible starving of urbs at the end of urb queue by moving the queue head around. Both problems seemed to happen, according to your logs. --- linux-2.6.10-isp/drivers/usb/host/isp116x-hcd.c.schedule-bug 2005-02-25 13:48:24.000000000 +0200 +++ linux-2.6.10-isp/drivers/usb/host/isp116x-hcd.c 2005-02-25 14:38:12.000000000 +0200 @@ -626,19 +626,22 @@ static void start_atl_transfers(struct i len = min(len, speed == USB_SPEED_LOW ? MAX_TRANSFER_SIZE_LOWSPEED : MAX_TRANSFER_SIZE_FULLSPEED); - /// Finally cut to the real needed length - /// this handles len == 0 packets as well - len = min(len, urb->transfer_buffer_length - - urb->actual_length); - BUG_ON(len < 0); + + /* Finally cut to the multiple of MaxPacketSize, or to the + real length if there's enough room. + */ + if(len < (urb->transfer_buffer_length - urb->actual_length)) { + len -= len % ep->maxpacket; + if(! len) + continue; + } else + len = urb->transfer_buffer_length - urb->actual_length; + BUG_ON(len < 0); } // DBG("load %d, len %d, byte_time %d\n", load, len, byte_time); load += len * byte_time; if (load > MAX_LOAD_LIMIT) { - // Move list head so that the first unserviced - // ep remains in the head - list_move_tail(&isp116x->async, &ep->schedule); DBG("%s: load %d, MAX_LOAD_LIMIT %d\n", __func__, load, MAX_LOAD_LIMIT); break; @@ -652,6 +655,10 @@ static void start_atl_transfers(struct i last_ep = ep; } // list_for_each_entry (ep, &isp116x->async, schedule) + /* Avoid possible starving of urbs */ + if ((&isp116x->async)->next != (&isp116x->async)->prev) + list_move(&isp116x->async, (&isp116x->async)->next); + if (isp116x->atl_active) { preproc_atl_queue(isp116x); pack_fifo(isp116x); You can also try to reduce the MAX_TRANSFER_SIZE_FULLSPEED from 832 down to, say, 320 (NB!!! it must be multiple of 64). This would avoid certain class of possible scheduling bugs. Also, you can try the latest version of the driver. I don't want to put is up to the web page as it needs some more work, but I attach the files isp116x-hcd.c and isp116x.h here and you can just copy them to drivers/usb/host directory to try out. Let me know Olav
isp116x-hcd.c.bz2
Description: Binary data
isp116x.h.bz2
Description: Binary data
