Skip to content

Commit 7d9f9a6

Browse files
authored
Document v4l latency (#1676)
1 parent 2d19908 commit 7d9f9a6

File tree

4 files changed

+137
-0
lines changed

4 files changed

+137
-0
lines changed
Binary file not shown.
Binary file not shown.
Lines changed: 136 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,136 @@
1+
# Latency Characterization
2+
3+
4+
## A primer on time
5+
6+
Expecially starting around 2022 with AprilTags making localization easier, providing a way to know when a camera image was captured at became more important for localization.
7+
Since the [creation of USBFrameProvider](https://github.com/PhotonVision/photonvision/commit/f92bf670ded52b59a00352a4a49c277f01bae305), we used the time [provided by CSCore](https://github.wpilib.org/allwpilib/docs/release/java/edu/wpi/first/cscore/CvSink.html#grabFrame(org.opencv.core.Mat)) to tell when a camera image was captured at, but just keeping track of "CSCore told us frame N was captured 104.21s after the Raspberry Pi turned on" isn't very helpful. We can decompose this into asking:
8+
9+
- At what time was a particular image captured at, in the coprocessor's timebase?
10+
- How do I convert a time in a coprocessor's timebase into the RoboRIO's timebase, so I can integrate the measurement with my other sensor measurements (like encoders)?
11+
12+
The first one seems easy - CSCore tells us the time, so just keep track of that? Should be easy. For the second, translating this time, as measured by the coprocessor's clock, into a timebase also used by user code on the RoboRIO, is actually a [fairly hard problem](time-sync.md) that involved reinventing [PTP](https://en.wikipedia.org/wiki/PTP).
13+
14+
And on latency vs timestamps - PhotonVision has exposed a magic "latency" number since forever, but latency (as in, the time from image capture to acting on data) can be useful for benchmarking code, but robots actually want to answer "what time was this image from, relative to "?
15+
16+
17+
## CSCore's Frame Time
18+
19+
WPILib's CSCore is a platform-agnostic wrapper around Windows, Linux, and MacOS camera APIs. On Linux, CSCore uses [Video4Linux](https://en.wikipedia.org/wiki/Video4Linux) to access USB Video Class (UVC) devices like webcams, as well as CSI cameras on some platforms. At a high level, CSCore's [Linux USB Camera driver](https://github.com/wpilibsuite/allwpilib/blob/17a03514bad6de195639634b3d57d5ac411d601e/cscore/src/main/native/linux/UsbCameraImpl.cpp) works by:
20+
21+
- Opening a camera with `open`
22+
- Creating and `mmap`ing a handful of buffers V4L will fill with frame data into program memory
23+
- Asking V4L to start streaming
24+
- While the camera is running:
25+
- Wait for new frames
26+
- Dequeue one buffer
27+
- Call `SourceImpl::PutFrame`, which will copy the image out and convert as needed
28+
- Return the buffer to V4L to fill again
29+
30+
Prior to https://github.com/wpilibsuite/allwpilib/pull/7609, CSCore used the [time it dequeued the buffer at](https://github.com/wpilibsuite/allwpilib/blob/17a03514bad6de195639634b3d57d5ac411d601e/cscore/src/main/native/linux/UsbCameraImpl.cpp#L559) as the image capture time. But this doesn't account for exposure time or latency introduced by the camera + USB stack + Linux itself.
31+
32+
V4L does expose (with some [very heavy caviets](https://github.com/torvalds/linux/blob/fc033cf25e612e840e545f8d5ad2edd6ba613ed5/drivers/media/usb/uvc/uvc_video.c#L600) for some troublesome cameras) its best guess at the time an image was captured at via [buffer flags](https://www.kernel.org/doc/html/v4.9/media/uapi/v4l/buffer.html#buffer-flags). In my testing, all my cameras were able to provide timestamps with both these flags set:
33+
- `V4L2_BUF_FLAG_TIMESTAMP_MONOTONIC`: The buffer timestamp has been taken from the CLOCK_MONOTONIC clock [...] accessible via `clock_gettime()`.
34+
- `V4L2_BUF_FLAG_TSTAMP_SRC_SOE`: Start Of Exposure. The buffer timestamp has been taken when the exposure of the frame has begun.
35+
36+
I'm sure that we'll find a camera that doesn't play nice, because we can't have nice things :). But until then, using this timestamp gets us a free accuracy bump.
37+
38+
Other things to note: This gets us an estimate at when the camera *started* collecting photons. The camera's sensor will remain collecitng light for up to the total integration time, plus readout time for rolling shutter cameras.
39+
40+
## Latency Testing
41+
42+
Here, I've got a RoboRIO with an LED, an Orange Pi 5, and a network switch on a test bench. The LED is assumed to turn on basically instantly once we apply current, and based on DMA testing, the total time to switch a digital output on is on the order of 10uS. The RoboRIO is running a TimeSync Server, and the Orange Pi is running a TimeSync Client.
43+
44+
### Test Setup
45+
46+
<details>
47+
<summary>Show RoboRIO Test Code</summary>
48+
49+
```java
50+
package frc.robot;
51+
52+
import org.photonvision.PhotonCamera;
53+
54+
import edu.wpi.first.wpilibj.DigitalOutput;
55+
import edu.wpi.first.wpilibj.TimedRobot;
56+
import edu.wpi.first.wpilibj.Timer;
57+
import edu.wpi.first.wpilibj.smartdashboard.SmartDashboard;
58+
59+
public class Robot extends TimedRobot {
60+
PhotonCamera camera;
61+
DigitalOutput light;
62+
63+
@Override
64+
public void robotInit() {
65+
camera = new PhotonCamera("Arducam_OV9782_USB_Camera");
66+
67+
light = new DigitalOutput(0);
68+
light.set(false);
69+
}
70+
71+
@Override
72+
public void robotPeriodic() {
73+
super.robotPeriodic();
74+
75+
try {
76+
light.set(false);
77+
for (int i = 0; i < 50; i++) {
78+
Thread.sleep(20);
79+
camera.getAllUnreadResults();
80+
}
81+
82+
var t1 = Timer.getFPGATimestamp();
83+
light.set(true);
84+
var t2 = Timer.getFPGATimestamp();
85+
86+
87+
for (int i = 0; i < 100; i++) {
88+
for (var result : camera.getAllUnreadResults()) {
89+
if (result.hasTargets()) {
90+
var t3 = result.getTimestampSeconds();
91+
var t1p5 = (t1 + t2) / 2;
92+
var error = t3-t1p5;
93+
SmartDashboard.putNumber("blink_error_ms", error * 1000);
94+
return;
95+
}
96+
}
97+
98+
Thread.sleep(20);
99+
}
100+
} catch (InterruptedException e) {
101+
e.printStackTrace();
102+
}
103+
}
104+
}
105+
```
106+
</details>
107+
108+
I've decreased camera exposure as much as possible (so we know with reasonable confidence that the image was collected right at the start of the exposure time reported by V4L), but we only get back new images at 60fps. So we don't know when between frame N and N+1 the LED turned on - just that somtime between now and 1/60th of a second a go, the LED turned on.
109+
110+
The test coprocessor was an Orange Pi 5 running a PhotonVision 2025 (Ubuntu 24.04 based) image, with an ArduCam OV9782 at 1280x800, 60fps, MJPG running a reflective pipeline.
111+
112+
113+
### Test Results
114+
115+
The videos above show the difference between when the RoboRIO turned the LED on and when PhotonVision first seeing a camera frame with the LED on, what I've called error and plotted in yellow with units of seconds. This error decreases when I use the frame time reported by V4L from a mean delta of 26 ms to a mean delta of 11 ms (below the maximum temporal resolution of my camera).
116+
117+
Old CSCore:
118+
```{raw} html
119+
<video width="85%" controls>
120+
<source src="../../../_static/assets/latency-tests/ov9782_1280x720x60xMJPG_old.mp4" type="video/mp4">
121+
Your browser does not support the video tag.
122+
</video>
123+
```
124+
CSCore using V4L frame time:
125+
```{raw} html
126+
<video width="85%" controls>
127+
<source src="../../../_static/assets/latency-tests/ov9782_1280x720x60xMJPG_new.mp4" type="video/mp4">
128+
Your browser does not support the video tag.
129+
</video>
130+
```
131+
132+
With the camera capturing at 60fps, the time between successive frames is only ~16.7 ms, so I don't expect to be able to resolve anything smaller. Given sufficient time and with perfect latency compensation, and with more noise in the robot program to make sure we vary LED toggle times, I'd expect the error to converge to ~half the interval between frames - so being within this frame interval with CSCore updates is a very good sign.
133+
134+
### Future Work
135+
136+
This test also makes no effort to isolate error from time syncronization from error introduced by frame time measurement - we're just interested in overall error. Future work could investigate the latency contribution

docs/source/docs/contributing/design-descriptions/index.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,4 +5,5 @@
55
image-rotation
66
time-sync
77
camera-matching
8+
e2e-latency
89
```

0 commit comments

Comments
 (0)