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
