Buffer timeout status after buffer underflow

[Pibben]

Describe the bug
I'm using the Aravis library with a GenICam ethernet camera.

If I don’t call arv_stream_timeout_pop_buffer() often enough and Aravis runs out of input buffers and gets buffer underruns, after a while (a few calls) I start to get ARV_BUFFER_STATUS_TIMEOUT status on my buffers. Why does buffer underrun cause timeouts to happen? What can I do about it?

To Reproduce
Steps to reproduce the behavior:

• Set up streaming from camera
• Call arv_stream_timeout_pop_buffer at a frequency lower than the camera frame rate
• After a while the returned buffers have ARV_BUFFER_STATUS_TIMEOUT status

Expected behavior
The buffers having ARV_BUFFER_STATUS_SUCCESS status.

Camera description:

• Dalsa
• Genie Nano
• Ethernet

Platform description:

• Aravis version 0.8.20
• OS: Ubuntu 20.04
• Hardware x86_64

[EmmanuelP]

Could run your software with ARV_DEBUG=all:3 and attach the console output here.

[avsegal]

I ran into (what I think is) the same issue with GigE cameras when using arv_stream_timeout_pop_buffer.

I was able to resolve it by switching to the try_pop version. If this issue is the same as mine, it turned out to be due to a conceptual misunderstanding on my part. I was under the impression that if the consumer doesn't pop buffers fast enough, aravis would internally overwrite / reuse the buffers owned by the streaming thread. It turns out that when the stream puts a buffer in its output queue, that buffer will not be reused until you pop it and give it back to the stream. I think this behavior is different from how v4l2 handles the situation, which is what led me astray.

I was able to resolve by using try_pop in a buffer_ready callback and using a mutex+condition_variable to keep track of only the 'latest' popped buffer for the consumer thread. This means that if a new buffer becomes ready before the consumer processes the previous ready buffer, it will be immediately dropped and pushed back into the stream queue. This made my use case a lot more robust to small hiccups in processing. Previously any delay in processing on the consumer thread would cause a cascading failure which resulted in all buffers being popped with a timed out status from that point on.

[avsegal]

On second thought, there may be something more complicated going on. I'm not sure if v4l actually does this differently, or if v4l is just able to recover from a starved buffer queue without me noticing? In either case, the observed behavior described in my previous comment is what it is, but I'm not sure about the root cause.

[Pibben]

Yes it's clearly the same phenomenon that I'm seeing. I think the name and the documentation of "ARV_BUFFER_STATUS_TIMEOUT" is misleading. I would expect it to be set in an underflow situation: the camera is not "delivering" an image until the receiver thread times out. What we both are seeing is rather an overflow situation: the receiver does not have buffers available to fill. "ARV_BUFFER_STATUS_OVERFLOW" would be a better error message, imho.

I can write a minimal program to show the situation, if that is still needed @EmmanuelP.

[EmmanuelP]

I can write a minimal program to show the situation, if that is still needed @EmmanuelP.

Yes, please.

[Pibben]

After a while this starts printing "buffer pop not successful: <enum ARV_BUFFER_STATUS_TIMEOUT of type Aravis.BufferStatus>"

if the time.sleep(0.1) is removed, no timeout occurs.

Tested using Dalsa Nano-M1930-NIR camera and Aravis 0.8.30 (python bindings)

import gi
gi.require_version('Aravis', '0.8')
from gi.repository import Aravis, GLib
import time

camera = Aravis.Camera.new(None)
payload = camera.get_payload()

print("Using camera:", camera.get_model_name())

stream = camera.create_stream(None, None)

for _ in range(10):
    stream.push_buffer(Aravis.Buffer.new_allocate(payload))

camera.set_frame_rate(20)

camera.start_acquisition()

count = 0
while True:
    image = None
    buffer = stream.pop_buffer()

    if buffer:
        count += 1
        if buffer.get_status() != Aravis.BufferStatus.SUCCESS:
            print(f"Buffer pop not successful: {buffer.get_status()} {count}")

        stream.push_buffer(buffer)

    else:
        print("Buffer is none")


    time.sleep(0.1)  # Simulate slow processing

[EmmanuelP]

Please try #1009

[EmmanuelP]

It is for the main branch, but should apply to aravis-0-8

[Pibben]

Thanks! I'll try to make time for testing it.

I'm trying to understand what's happening here. Here is my view:

1. The first packet of a new frame arrives
2. There are no input buffers available so _find_frame_data() returns NULL
3. Eventually a buffer is available so a new frame is created, but the first packet(s) are forever lost
4. Some time after the last packet is received, _check_frame_completion() notices that the frame is incomplete (due to the missing packets) and no packets have been received for some time, and marks the frame as ARV_BUFFER_STATUS_TIMEOUT.

Is this roughly correct, @EmmanuelP ?

[EmmanuelP]

Is this roughly correct, @EmmanuelP ?

Yes. With the minor nitpick the first packets are not necessarily forever lost, if the buffer is not too late, aravis will ask for a resend of the missing packets.