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:
- Square wave generator (yellow) -> GFE -> USB -> FC -> Serial port (blue)
- The "T" at the top at the is the trigger, right at 0 us. That trigger is the "DATA" packet from the GFE to the FC with the payload in it. You can't actually see that event because it's too fast at this scale. Suffice it to say that at time 0, where the trigger is, the data is getting into the FC.
- This means that the delay from the rising edge of the square wave (yellow) to the USB transfer into the host is happening exactly like we expect - there's a 0 - 1 ms jitter of the frame rate, but no weird delay.
- THEN there's a weird but consistent delay of 1.1 ms from when we receive the data until when the data byte comes out the serial port. Huh what? Where is that 1.2 ms coming from?!
Pinging the GFE and looking at timing.
OK, below is a similar image but now it's got more info on it:
- 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.
- 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:
- 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.
- 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!
- The next frame is a SOF, IN, and NAK because of course there hasn't been another rising edge.
- 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:
- We are getting an IN token every frame, so that's not the delay.
- The consistent 1.1 ms delay from the SOF/IN/DATA/ACK packet to the serial byte is clearly inside of the FC. We don't know if it's hardware (e.g., the USB host controller), an OS issue (e.g., the 1KHz CONFIG_HZ time quantum) or something in user space (e.g., libusb).
- We also observed that interrupt transfers are pretty reliable, but isoc transfers are really jittery, bouncing around between the standard 1.1 ms delay and sometimes 4 ms. This is worth more observation.
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.