wiki/ news/ 2012-08-07 - Even further USB Latency Testing

This time, we managed to get the MDO4104 to trigger off USB Data output. What we saw really surprised us - we were getting the data off the USB bus within the 1 ms time frame, but there was some 1 ms delay after we get the delay and before the character went out.

Finding our mysterious 1.1 ms delay

The following image needs some explanation:

This delay is not the delay you are looking for.

Pinging the GFE and looking at timing.

OK, below is a similar image but now it's got more info on it:

  1. The trigger is now the blue serial port. So we're triggering on us sending out acknowledgment that we got the data from the GFE.
  2. The small green and red squares are various USB packets, beginning with start of frame (SOF) and including INs and OUTs. We zoomed in on each of those and found that:
    1. The first frame is just an SOF with an IN and a NAK by the GFE - there's no data to be had because the square wave hasn't risen yet.
    2. The second frame is an SOF, an IN, DATA, and an ACK because now the GFE is sending a data byte out because it's seen the rising edge. Note how the pretty yellow lines go between frame (1) and frame (2). Pretty!
    3. The next frame is a SOF, IN, and NAK because of course there hasn't been another rising edge.
    4. The fourth frame is a SOF, OUT, DATA, and ACK because the OUT transfer we started right after we sent the serial byte out finally gets sent to the GFE... two frames after we'd hoped.

We learned that we can't use the OUT packet as a better timer then the serial port, and that this no better answers the question where that 1.1 ms delay is coming from. Also:

Look at all the pretty things.

Things to try next

The next obvious thing to do is run ftrace (and other kernel tracing tools) and figure out where the time is going inside the kernel. If it's not in the kernel, then we can blame userspace.

Later, we should also figure out why isoc transfers are so jittery. Note that when multiple isoc transfers were submitted at the same time to one endpoint it removed the jitters, but the 1.1 ms delay was still there.