Unaccounted for delay when using an image transport

[buckleytoby]

Hello,

Unsure if it's better to post here or in https://github.com/ros-misc-utilities/ffmpeg_image_transport. I'm getting huge unaccounted for delays when using that image transport with this library.

First, regular spinnaker_camera_driver can get an image onto ros in average delay: 0.008 -> 8 ms, as measured by ros2 topic delay. Second, from using the built-in timing I know that ffmpeg_image_transport takes 16.5 ms to create the FFMPEGPacket:
[camera_driver_node-1] [INFO] [1704242172.148202070] [FFMPEGEncoder]: FFMPEGPublisher pktsz: 8741 compr: 719.747 debay: 0.0165 fmcp: 0.0125 send: 0.0019 recv: 0.0000 cout: 0.0000 publ: 0.0001 tot: 0.0165

However, when I ros2 topic delay the topic /flir_camera/image_raw/ffmpeg I get average delay: 0.068 -> 68 ms So it's not clear to me where the missing 51 ms of delay is coming from. Obviously it can't be explained by the extraction of the image from the camera, as that is bounded above at 8 ms.

Thanks for the help!

[berndpfrommer]

Interesting, I never looked at the delay. I'm pretty confident this is a case for ffmpeg_image_transport. My hunch is that the callback from the decoder comes on the next frame. You would see 68 ms delay (60ms + 8ms) if you are running at about 17 fps. If this is indeed the case, would you mind opening this issue cut-and-paste against ffmpeg_image_transport?

[buckleytoby]

The image is 4k and being read at 40 FPS -> every 25 ms. Since the artificial delay is around 50 ms, my only thought is maybe it's two loops delayed?

[berndpfrommer]

50ms is close to 68ms but further off than expected. Can you check the delay due to the encoder by measuring the time difference between wall clock time and header stamp in packetReady() ? I think you can instantiate a rclcpp::Clock::Clock() object, then call "now()" on it, get the header time by rclcpp::Time(header.stamp), and then use a rclcpp::Duration to get the time difference.

[buckleytoby]

I ran some additional tests to provide better debugging data: It does seem to be two cycles off.

@ 40 FPS -> total delay = 68 -> subtract off the time to encode the image (~17 ms) -> ~50 ms = 2x the image delay @ 20 FPS -> total delay = 119 -> subtract off the time to encode the image (~17 ms) -> ~100 ms = 2x the image delay @ 10 FPS -> total delay = 217 -> subtract off the time to encode the image (~17 ms) -> ~200 ms = 2x the image delay

[berndpfrommer]

OK, so this definitely is not an issue with the FLIR camera driver. Let's close this issue. I have opened a place holder here