Hello, wMaxPacketSize if 512. The transfer_buffer_length the problematic message is 8. And yes I meant scan_async doesn't run until 4 seconds later. Yes the debug messages I gave were just to show the time discrepancy between each message. The first line of each time interval is printed inside of scan_async to prove that scan_async is delayed by 4 seconds. Thanks for mentioning the patch. I will look into it. Regards, Daniel P Graves -----Original Message----- From: Alan Stern [mailto:stern@xxxxxxxxxxxxxxxxxxx] Sent: Saturday, June 16, 2012 9:09 AM To: Graves, Daniel (GE Healthcare) Cc: linux-usb@xxxxxxxxxxxxxxx Subject: Re: Help with EHCI Missing Bulk In Callbacks On Fri, 15 Jun 2012, Graves, Daniel (GE Healthcare) wrote: > Hello, > > I'm currently working on a project that communicates with an FPGA > board over a USB link. This board sends a heartbeat message to our PC > every 8 seconds. Every once in a while this message is not processed > by our software that is listening on the USB port until after 12 > seconds expire. After putting an Elysis USB analyzer on the bus we > were able to prove that the message does come over the wire at the > proper 8 second interval. However, the URB call back is not invoked > until 4 seconds later. I put some debug statements in the EHCI driver > and below is the output of what I'm seeing. Basically these logs show > that not even scan_async is invoking qh_completions until 4 seconds later. Do you mean that scan_async runs at the right time but does not call qh_completions, or do you mean that scan_async doesn't run until 4 seconds later? What is the wMaxPacketSize for the endpoint in question? What is the transfer_buffer_length value for the URB? > I put a > new line in between each 8 second interval for easier readability. As > shown, the last one prints 12 seconds later. The first line of each > interval is printed right before scan_async calls qh_completions. The > next two lines are printed inside of qh_completions once a QTD has > been detected as deactivated. I'm just wondering if anyone can help > me determine if this is a hardware problem with the host controller? > I know there have been some updates to the ehci software on newer > kernel releases but I suspect that this specific problem is not > address by those changes and it is not a sw problem. > > The following is what I'm running: > > 2.6.34.8-0.2 Kernel from OpenSuse > EHCI Chipset is an Intel 82801H (ICH8) > > //Message 1 on time > Jun 14 21:06:39 magic kernel: [ 128.156346] TEMPMSGCHECK---Check > invoked for our pipe at scan_async. Time is 4294142,643091 Jun 14 > 21:06:39 magic kernel: [ 128.156352] TEMPMSG---A serial QTD for > endpoint 4 has completed 52 at 4294142,643091. Intresult is 32768 Jun > 14 21:06:39 magic kernel: [ 128.156355] TEMPMSG---This serial QTD is > a short packet. QH State is 1. Total QTDs are 1 > > //Message 2 on time > Jun 14 21:06:47 magic kernel: [ 136.155976] TEMPMSGCHECK---Check > invoked for our pipe at scan_async. Time is 4294150,640875 Jun 14 > 21:06:47 magic kernel: [ 136.155981] TEMPMSG---A serial QTD for > endpoint 4 has completed 53 at 4294150,640875. Intresult is 32768 Jun > 14 21:06:47 magic kernel: [ 136.155984] TEMPMSG---This serial QTD is > a short packet. QH State is 1. Total QTDs are 1 > > //Message 3 on time > Jun 14 21:06:55 magic kernel: [ 144.155479] TEMPMSGCHECK---Check > invoked for our pipe at scan_async. Time is 4294158,639659 Jun 14 > 21:06:55 magic kernel: [ 144.155484] TEMPMSG---A serial QTD for > endpoint 4 has completed 54 at 4294158,639659. Intresult is 32768 Jun > 14 21:06:55 magic kernel: [ 144.155487] TEMPMSG---This serial QTD is > a short packet. QH State is 1. Total QTDs are 1 > > //This message has come late (12 seconds instead of the usual 8 like > the previous messages) USB Analyzer shows this message on the bus on > time at 8 seconds Jun 14 21:07:07 magic kernel: [ 156.011433] > TEMPMSGCHECK---Check invoked for our pipe at scan_async. Time is > 4294170,493857 Jun 14 21:07:07 magic kernel: [ 156.011438] > TEMPMSG---A serial QTD for endpoint 4 has completed 55 at > 4294170,493857. Intresult is 32768 Jun 14 21:07:07 magic kernel: [ > 156.011441] TEMPMSG---This serial QTD is a short packet. QH State is > 1. Total QTDs are 1 It's difficult to understand the implications of these messages, except for the kernel's timestamps. Please try applying the patch in http://marc.info/?l=linux-usb&m=133977231603251&w=2 Your description indicates that IRQs or status information may be lost. Let's see what shows up in the dmesg output (not the system log file; it is less reliable). Alan Stern -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
