Alan Stern wrote:
You should try sched_setparam() and sched_setscheduler(). Use the
SCHED_FIFO policy.
You should also have your program print out the current time just
before and after each of the USB transfers. Comparing those values to
the values from usbmon will provide some clues.
I did the above, and set the program to run at
sced_priority_max (as root). I ran a short series of 3 usb
write-reads and compared the output of usbmon and
the printout from my program. Here are the results,
where I have added comments after "*" and I've
marked suspicious areas with "*****":
printout from my program:
-------------------------------------------------------------
Time before usb_write = -150869400 * before 1st usb_write 0ms
Time after usb_write = -150867516 * after 1st usb_write 1.884ms
Time before usb_read = -150866652 * before 1st usb_read 2.748ms
Time after usb_read = -150861938 ***** after 1st usb_read 7.462ms
Time before usb_write = -150861873 * before 2nd usb_write 7.527ms
Time after usb_write = -150860535 * after 2nd usb_write 8.865ms
Time before usb_read = -150859699 * before 2nd usb_read 9.701ms
Time after usb_read = -150853937 ***** after 2nd usb_read 15.463ms
Time before usb_write = -150853896 * before 3rd usb_write 15.504ms
Time after usb_write = -150852535 * after 3rd usb_write 16.865ms
Time before usb_read = -150851799 * before 3rd usb_read 17.601ms
Time after usb_read = -150850528 * after 3rd usb_read 18.872ms
Press any A/N key to continue:
----------------------------------------------------------------
usbmon output:
----------------------------------------------------------------
d8648540 776071827 S Io:002:02 -115 64 = 043e0100 0c00000e 00000000
00000000 00000000 00000000 00000000 00000000 * 1st usb_write submitted 0ms
d8648540 776073646 C Io:002:02 0 64 > * 1st usb_write completed 1.819ms
d8648540 776074560 S Ii:002:01 -115 62 < * 1st usb_read submitted 2.733ms
d8648540 776076636 C Ii:002:01 0 62 = 01000c00 000e0000 00000000
00000000 00000000 00000000 00000000 00000000 ***** 1st usb_read
completed 4.809ms
d8648540 776079335 S Io:002:02 -115 64 = 043e0100 0c000e0e 00000000
00000000 00000000 00000000 00000000 00000000 * 2nd usb_write submitted
7.508ms
d8648540 776080636 C Io:002:02 0 64 > * 2nd usb_write completed 8.809ms
d8648540 776081508 S Ii:002:01 -115 62 < * 2nd usb_read submitted 9.681ms
d8648540 776083638 C Ii:002:01 0 62 = 01000c00 0e0e0000 00000000
00000000 00000000 00000000 00000000 00000000 ***** 2nd usb_read
completed 11.811ms
d8648540 776087311 S Io:002:02 -115 28 = 041a0100 0c001c05 00000000
00000000 00000000 00000000 00000000O * 3rd usb_write submitted 15.484ms
d8648540 776088635 C Io:002:02 0 28 > * 3rd usb_write completed 16.808ms
d8648540 776089408 S Ii:002:01 -115 26 < * 3rd usb_read submitted 17.581ms
d8648540 776090639 C Ii:002:01 0 26 = 01000c00 1c050000 00000000
00000000 00000000 00000000 0000 * 3rd usb_read completed 18.812ms
------------------------------------------------------------------------
I found that for the 1st and 2nd interrupt read transactions, there
is about 3ms extra delay between when usbmon says that the read
transaction is completed, and when my program gets out of the
usb_interrupt_read() routine and prints its message. Of course
there are other intervening instructions, such as a gettimeofday
call, however this does not add so much delay when I call it
elsewhere in the program. Here is the relevant part of my code
around the usb_interrupt_read() call:
---------------------------------------------------------------
printw("%s%ld%s","Time before usb_read = ",time_usec,"\n");
if
(
(
num_read =
usb_interrupt_read(usb_handle_usb,usb_endpoint_address_in,bytes_recd,wLength-2,500)
)
> 0
)
{ // have echoed bytes
gettimeofday(tv,NULL);
time_usec=(tv->tv_sec*1000000) + tv->tv_usec;
printw("%s%ld%s","Time after usb_read = ",time_usec,"\n");
----------------------------------------------------------------------
Another thing I noticed is that this extra delay does not
occur for the 3rd interrupt read transaction. For that one
only 26 bytes are read, instead of 62.
It appears that there is a delay in getting out of the
usb_interrupt_read() function for the case of reading
62 bytes. Do you have any idea why this might occur?
Or is there something else I am missing?
I also have a general question - given that this
device enumerates as a HID device, how is it that
the HID driver never enters into the picture?
I can't tell you in detail because you didn't describe exactly how your
program works. However, if the HID driver were bound to your device
then your program would not be allowed to access the interrupt
endpoints.
Does your program call usb_detach_kernel_driver_np()? If it does, that
removes the HID driver from the picture.
I don't call usb_detach_kernel_driver_np(). However one thing
I noticed that might give a clue, when I attach the device I
get the following message on the terminal:
HID device not claimed by input or hiddev
Thanks very much,
Richard
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
