Latency Analysis with LibArgus

I am capturing images from four cameras on a Jetson AGX Xavier using LibArgus.
The images are 4032x3040, 15 FPS from four Leopard Imaging IMX577 cameras with hardware sync.

I am currently trying to understand all of the sources of latency in our system, and this post pertains to the acquisition section.

In my capture loop, I call cudaEGLStreamConsumerAcquireFrame to get the next available image from LibArgus. As soon as my program returns from this function with the desired frame, I take the current time and compare it to the frame’s timestamp.

Depending on the camera, I see a difference of 48-60 ms between the current time and the timestamp, which means that something happened between the time the timestamp was applied and the time where I got the image.

I have a few questions regarding this:

  • Does the ISP run before or after the moment where the timestamp is taken?
  • If it runs after, is it the source of the 50-60 ms delay I am seeing above?
  • If it runs before, how much additional latency would the ISP be expected to inject in this process, given the 4032x3040 @ 15 fps resolution above?

Notes:

  • The images received from the EGL stream are YUV420
  • Postprocess is not disabled
  • Denoise is set to fast, 0.4

Thanks.

ISP run after the moment taking timestamp.
Have a reference to below topic for more information about timestamp.

Can you confirm that it is the source of the latency we are seeing?

I don’t clean your question.
Howerver, the timestamp is the time of start of frame(SOF) from sensor output package.

The timestamp (the old style, obtained via ICatureMetadata::getSensorTimestamp()) reports time A.
When my program returns from cudaEGLStreamConsumerAcquireFrame(), I get the current time, time B
std::chrono::nanoseconds(std::chrono::steady_clock::now().time_since_epoch()).count()

B minus A = 40 to 60 ms

Do you know what causes this delay?
Based on what you said previously, the timestamp A is taken before the frame is presented to the ISP. My conclusion is that this 40-60 ms latency is due to the ISP. Can you please confirm?

This latency could be time of EOF -SOF + buffer transfer time + ISP process time.

Thanks.

  • It’s not clear to me what SOF and EOF represent - would you be so kind as to elaborate a bit further? I measure the differentct between the two to be roughly 32 ms if I am not mistaken.
  • Is there a block diagram somewhere that explains the exact path taken by the images from the point where they are received on the CSI-MIPI interface to the point where they are available to the application via cudaEGLStreamConsumerAcquireFrame? This image has too many paths to understand what is happening in my scenario: https://docs.nvidia.com/jetson/l4t/Tegra%20Linux%20Driver%20Package%20Development%20Guide/images/image4_9.png

Also, the SOF and EOF timestamps appear to be using a different reference clock than the original timestamp (seems to be a 13 s discrepancy) - is there an way to put these clocks on the same reference?

I have found a number of articles on the forum, but I have not had much success finding answers to these questions. Thanks.

SOF - Start Of Frame
EOF - End Of Frame
If the frame rate is 30 the SOF - EOF should be ~= 1/30

In my previous comment the reference link should explain why the timestamp using different clock domain.

Ok, I went back and re-read the article. It points to several articles so I will try to summarize the information here. Please let me know if anything is wrong.

Meaning of SOF/EOF
“The help says: Returns the start timestamp for the sensor (in nanoseconds). This is the time that the first data from this capture arrives from the sensor.”

My understanding:

  • SOF indicates the time at which the frame data started arriving from the sensor across the CSI/MIPI interface
  • EOF indicates the time at which the last of the frame data arrived from the sensor on the CSI/MIPI interface.

These values are obtained using the iSensorTimestampTsc interface from the metadata:

const Ext::ISensorTimestampTsc *iSensorTimestampTsc = 
         interface_cast<const Ext::ISensorTimestampTsc>(metaData);
iSensorTimestampTsc->getSensorSofTimestampTsc(),
iSensorTimestampTsc->getSensorEofTimestampTsc());

Time domain of SOF/EOF
/sys/devices/system/clocksource/clocksource0/offset_ns defines the offset between the time reported by the new timestamps’ time domain and the standard library steady_clock.

#include <ctime>

...

// Get the timestamp-vs-steady_clock offset
FILE * of = fopen("/sys/devices/system/clocksource/clocksource0/offset_ns", "r");
uint64_t offset_ns = 0;
int result = fscanf(of, "%" PRIu64, &offset_ns);
fclose(of);

...

// Get the legacy timestamp
Argus::ICaptureMetadata *iCaptureMetadata = 
    Argus::interface_cast<Argus::ICaptureMetadata>(metadata);
sensorTimestamp_ns = iCaptureMetadata->getSensorTimestamp();

// Get the new timestamps
const Argus::Ext::ISensorTimestampTsc *iSensorTimestampTsc = 
    Argus::interface_cast<const Argus::Ext::ISensorTimestampTsc>(metadata);
auto sof = iSensorTimestampTsc->getSensorSofTimestampTsc() - offset_ns;
auto eof = iSensorTimestampTsc->getSensorEofTimestampTsc() - offset_ns;

// Get the current time from steady_clock
					    struct timespec ts;
						clock_gettime( CLOCK_MONOTONIC_RAW, &ts );
						auto now = static_cast<unsigned long long>(1000000000UL)*static_cast<long long>(ts.tv_sec) + static_cast<long long>(ts.tv_nsec);
						
printf("legacy ts= %lu sof= %lu, eof= %lu now=%llu %llu\n",
    sensorTimestamp_ns,
    sof,
    eof,
    now,
    (now - sof) / 1000000);

One thing I noticed is that there appears to be a drift betweem the legacy timestamps and the TSC timestamps. Is it possible that the legacy timestamp is based on CLOCK_REALTIME instead of CLOCK_MONOTONIC?

Please let me know if the data above is correct. I hope it helps others to collect it here.
Thanks.

Yes, that’s correct.
And in current design unable change to CLOCK_REALTIME.

Not a problem.
I’ll just use the appropriate clock for each timestamp.

for the legacy timestamp:

  • clock_gettime(CLOCK_REALTIME), or
  • std::chrono::steady_clock::now() (C++)

for SOF/EOF

  • clock_gettime(CLOCK_MONOTONIC_RAW)

So in my situation, EOF-SOF = 32 ms, and the rest is anything between 8ms to 26ms depending on the camera. Based on the formula you gave me above, that remaining time is buffer transfer time or ISP procssing time.

Any suggestions on how we could reduce this without dropping libargus completely?

Is there a way to clip the sensor edges to reduce the amount of data that is transferred and processed by the ISP? We are using lenses that underfill the sensor so we can afford to crop out the left and right edges a bit.
Could IStreamSettings::setSourceClipRect() help with this?