How to avoid or minimize 'Maximum number of requests reached at'

Using Aravis
1

Hello,

We have a Hikvision camera and used the Hikvision library’s, but we want to try Aravis because we have some strange behaviour with Hikvision.

So we introduced Aravis in our project and the good news is: it was working in a little bit more than one day. So that’s great. Overall, I am happy to use an open source project instead of closed source Chinese stuff.

So we had a problem and I looked into the code, but I don’t know what to do about it. First a bit about the system: we have a pc with two Hikvision camera’s. The mtu of the network interfaces is 9000, otherwise we get the error mentioned in the title every frame.

We use an external trigger (TriggerSource is Line0, trigger mode is 1, acquisition mode is ARV_ACQUISITION_MODE_CONTINUOUS, AcquisitionFrameRateEnable=true AcquisitionFrameRate=65.0). Those settings worked with the Hikvision driver and seem to work with Aravis as well. The heartbeat timeout (whatever it is) is set to 3000.

The camera’s are triggered 30 - 40 times per second. So we use a stream (created with arv_camera_create_stream) with two buffers (also tried 8 but that doesn’t change anything, I think 1 should even be enough). Another thread is calling arv_stream_timeout_pop_buffer, copies the data for processing, pushes the buffer back in the stream and calls arv_stream_timeout_pop_buffer again.

This works well, but once every few minutes (2 - 7 or so), there is a timeout of the buffer. I turned on the debugging info and the log is:
[GvStream::missing_packet_check] Maximum number of requests reached at dt = 0, n_packet_requests = 94 (335 packets/frame), frame_id = 47982
followed by
[GvStream::check_frame_completion] Timeout for frame 47982 at dt = 216148

We miss 1 - 11 frames or so when this happens.

I also see this sometimes:

packet_type  =   (null) (0x8011)
content_type = data-block (0x0003)
frame_id     =    15615 
packet_id    =      334
data_size    =        0

followed by:
[GvStream::check_frame_completion] Timeout for frame 15615 at dt = 307206

Which also causes some frames missing.

Before creating the stream, I added this:
arv_camera_gv_set_stream_options (camera_, ARV_GV_STREAM_OPTION_NONE);
but that doesn’t seem to help.

I also tried to net resend packages:
g_object_set(stream_, "packet-resend", ARV_GV_STREAM_PACKET_RESEND_NEVER, nullptr);
but that results in having regularly missed frames because of missing packets.

Are there any settings we could try to minimize this problem? Is there maybe a timeout we can set? If we miss so many frames in a row, that’s a problem. We can handle missing 1 frame every few minutes.

What is causing this?

I hope someone can help. Thanks!

2

Hi Maaike,

0x8011 means the packet could not be resent because it is not anymore available in camera memory. It probably happens when aravis asks for a packet resend too late.

In order to minimize the number of missing packets, the usual advices are:

  • Use a dedicated link between your machine and the camera, or at least a dedicated network
  • Try to increase the socket buffer
  • Try to make the stream receiving thread real-time or high priority
  • Try to use the packet socket

Please have a look at the different examples in the tests directory.

3

Hello Emmanuel,

Thanks for your quick reply!

I looked in the tests directory for examples and mainly used arvcameratest.

  • Every camera has it’s own ethernet port / cable / card with it’s own subnet.
  • Should I set ARV_GV_STREAM_SOCKET_BUFFER_FIXED to increase the socket buffer? And what size should I use then?
  • I gave the stream receiving thread a nice value of -19.
  • I already read about using packet socket and I hoped setting arv_camera_gv_set_stream_options (camera_, ARV_GV_STREAM_OPTION_NONE); was doing that. If not, how to use/enable packet socket?

I tried setting ARV_GV_STREAM_SOCKET_BUFFER_FIXED and then the packet size to something big, but that does not really help:

[GvStream::update_socket] Socket buffer size set to 522977280
[GvStream::missing_packet_check] Maximum number of requests reached at dt = 11709, n_packet_requests = 36 (335 packets/frame), frame_id = 40280

When this happens, why is it missing so many frames and not just one? Is there a timeout it is waiting for or something?
I already set packet timeout to 30ms but I don’t think that changes anything.

4

Packet socket requires root privileges, so run the application using sudo.

What would help is some statistics about the resent packets, given after letting run this command for a few seconds:

./tests/arv-camera-test -d stream
5

I tried to enable packet socket but it doesn’t seem to help.

I ran my own simple application with debug stream info. It has two camera’s. Output:

Camera 1:
[GvStream::finalize] n_completed_buffers = 1773
[GvStream::finalize] n_failures = 0
[GvStream::finalize] n_timeouts = 0
[GvStream::finalize] n_aborteds = 1
[GvStream::finalize] n_underruns = 0
[GvStream::finalize] n_missing_frames = 0
[GvStream::finalize] n_size_mismatch_errors = 0
[GvStream::finalize] n_received_packets = 593981
[GvStream::finalize] n_missing_packets = 0
[GvStream::finalize] n_error_packets = 0
[GvStream::finalize] n_ignored_packets = 0
[GvStream::finalize] n_resend_requests = 9
[GvStream::finalize] n_resent_packets = 9
[GvStream::finalize] n_resend_ratio_reached = 0
[GvStream::finalize] n_duplicated_packets = 0
[Stream::finalize] Flush 1 buffer[s] in input queue
[Stream::finalize] Flush 1 buffer[s] in output queue

Camera 2:
[GvStream::finalize] n_completed_buffers = 1771
[GvStream::finalize] n_failures = 0
[GvStream::finalize] n_timeouts = 0
[GvStream::finalize] n_aborteds = 1
[GvStream::finalize] n_underruns = 0
[GvStream::finalize] n_missing_frames = 0
[GvStream::finalize] n_size_mismatch_errors = 0
[GvStream::finalize] n_received_packets = 593400
[GvStream::finalize] n_missing_packets = 0
[GvStream::finalize] n_error_packets = 0
[GvStream::finalize] n_ignored_packets = 0
[GvStream::finalize] n_resend_requests = 16
[GvStream::finalize] n_resent_packets = 16
[GvStream::finalize] n_resend_ratio_reached = 0
[GvStream::finalize] n_duplicated_packets = 0
[Stream::finalize] Flush 1 buffer[s] in input queue
[Stream::finalize] Flush 1 buffer[s] in output queue

With the Hikvision driver, we did not have those problems. And we did not need to use packet socket or something. So what is the difference then?

6

By the way, I changed some packet settings:

            g_object_set (stream_,
                      "packet-timeout", 5 * 1000,
                      "frame-retention", 25 * 1000,
                      "packet-request-ratio", 0.1,
                      nullptr);

With this settings, when a timeout occurs, it seems I only miss one frame. But it would be great if we don’t miss any frames at all.

7

In the statistic you are showing, there is no error. Could you show the same statistics when there is at least 5 missing frame events ?

Thanks.

8

Oops, sorry, not so smart of me :).

Camera 1:

[GvStream::finalize] n_completed_buffers    = 83461
[GvStream::finalize] n_failures             = 5
[GvStream::finalize] n_timeouts             = 5
[GvStream::finalize] n_aborteds             = 1
[GvStream::finalize] n_underruns            = 156
[GvStream::finalize] n_missing_frames       = 0
[GvStream::finalize] n_size_mismatch_errors = 0
[GvStream::finalize] n_received_packets     = 27961019
[GvStream::finalize] n_missing_packets      = 994
[GvStream::finalize] n_error_packets        = 1
[GvStream::finalize] n_ignored_packets      = 156
[GvStream::finalize] n_resend_requests      = 244
[GvStream::finalize] n_resent_packets       = 242
[GvStream::finalize] n_resend_ratio_reached = 4
[GvStream::finalize] n_duplicated_packets   = 0
[Stream::finalize] Flush 1 buffer[s] in input queue
[Stream::finalize] Flush 1 buffer[s] in output queue

Camera 2:

[GvStream::finalize] n_completed_buffers    = 83463
[GvStream::finalize] n_failures             = 1
[GvStream::finalize] n_timeouts             = 1
[GvStream::finalize] n_aborteds             = 1
[GvStream::finalize] n_underruns            = 1
[GvStream::finalize] n_missing_frames       = 0
[GvStream::finalize] n_size_mismatch_errors = 0
[GvStream::finalize] n_received_packets     = 27960528
[GvStream::finalize] n_missing_packets      = 197
[GvStream::finalize] n_error_packets        = 0
[GvStream::finalize] n_ignored_packets      = 1
[GvStream::finalize] n_resend_requests      = 213
[GvStream::finalize] n_resent_packets       = 213
[GvStream::finalize] n_resend_ratio_reached = 1
[GvStream::finalize] n_duplicated_packets   = 0
[Stream::finalize] Flush 1 buffer[s] in input queue
[Stream::finalize] Flush 1 buffer[s] in output queue
9

And our ‘real’ application (so not the test application that only acquires images):

Camera 1:

[GvStream::finalize] n_completed_buffers    = 7543
[GvStream::finalize] n_failures             = 1
[GvStream::finalize] n_timeouts             = 1
[GvStream::finalize] n_aborteds             = 0
[GvStream::finalize] n_underruns            = 42
[GvStream::finalize] n_missing_frames       = 0
[GvStream::finalize] n_size_mismatch_errors = 0
[GvStream::finalize] n_received_packets     = 2527233
[GvStream::finalize] n_missing_packets      = 61
[GvStream::finalize] n_error_packets        = 0
[GvStream::finalize] n_ignored_packets      = 42
[GvStream::finalize] n_resend_requests      = 193
[GvStream::finalize] n_resent_packets       = 193
[GvStream::finalize] n_resend_ratio_reached = 1
[GvStream::finalize] n_duplicated_packets   = 0
[Stream::finalize] Flush 0 buffer[s] in input queue
[Stream::finalize] Flush 2 buffer[s] in output queue

Camera 2:

[GvStream::finalize] n_completed_buffers    = 7539
[GvStream::finalize] n_failures             = 6
[GvStream::finalize] n_timeouts             = 6
[GvStream::finalize] n_aborteds             = 0
[GvStream::finalize] n_underruns            = 10250
[GvStream::finalize] n_missing_frames       = 0
[GvStream::finalize] n_size_mismatch_errors = 0
[GvStream::finalize] n_received_packets     = 2537370
[GvStream::finalize] n_missing_packets      = 1186
[GvStream::finalize] n_error_packets        = 2
[GvStream::finalize] n_ignored_packets      = 10250
[GvStream::finalize] n_resend_requests      = 78
[GvStream::finalize] n_resent_packets       = 74
[GvStream::finalize] n_resend_ratio_reached = 4
[GvStream::finalize] n_duplicated_packets   = 0
[Stream::finalize] Flush 0 buffer[s] in input queue
[Stream::finalize] Flush 2 buffer[s] in output queue
10

I’m a bit puzzled you are reaching the resend ratio limit. Try to increase it.

What platform are you using ? What is the CPU use ?

11

Something I’ve overlooked is the number of underruns. It happens when there is no available buffers for data storage. How many buffer do you push in the queue ? There should be at least 2 buffers. 1 may work, but that means your processing must not last longer than the time between the end of one frame and the beginning of the next one.

12

I had 2 buffers but I just changed it to 8. I’ll retry.

How do i increase the resend ratio limit?
Like this: g_object_set (stream_, "packet-request-ratio", 0.5, nullptr); ?

The platform is Linux (Ubuntu), running from a docker container (also Ubuntu), 8 cpu’s with hyperthreading (so 16 ‘threads’), they are all in use for not more than 25%, but most of the time around 15%.

13

So this is already much better. No underruns anymore. I changed the packet request ratio to 0.5 and change the number of buffers to 8.

[GvStream::finalize] n_completed_buffers    = 27912
[GvStream::finalize] n_failures             = 2
[GvStream::finalize] n_timeouts             = 2
[GvStream::finalize] n_aborteds             = 0
[GvStream::finalize] n_underruns            = 0
[GvStream::finalize] n_missing_frames       = 0
[GvStream::finalize] n_size_mismatch_errors = 0
[GvStream::finalize] n_received_packets     = 9351318
[GvStream::finalize] n_missing_packets      = 2
[GvStream::finalize] n_error_packets        = 2
[GvStream::finalize] n_ignored_packets      = 0
[GvStream::finalize] n_resend_requests      = 417
[GvStream::finalize] n_resent_packets       = 281
[GvStream::finalize] n_resend_ratio_reached = 0
[GvStream::finalize] n_duplicated_packets   = 128
[Stream::finalize] Flush 8 buffer[s] in input queue
[Stream::finalize] Flush 0 buffer[s] in output queue

Now I had the 0x8011 error twice:

[GvStream::process_packet] Error packet at dt = 34869, packet id = 334 frame id = 7923
packet_type  =   (null) (0x8011)
content_type = data-block (0x0003)
frame_id     =     7923 
packet_id    =      334
data_size    =        0
14

That happens when the packet request is too late, the corresponding frame is not available anymore on the camera. Try to decrease the packet timeout.

15

Ok the ‘packet settings’ are now:

            g_object_set (stream_,
                      "packet-timeout", 3 * 1000,
                      "frame-retention", 25 * 1000,
                      "packet-request-ratio", 0.75,
                      nullptr);

After 13 minutes I had one 0x8011 error. However, I also had some delayed frames once, which is not preferrable as well. I thought to try to pin the aravis threads to a seperate core, maybe that helps.

Oh, by the way, thanks a lot for your help! It’s a challenge to find out how to tweak those settings.

16

You should check the camera documentation to see if there is more than one frame stored in the camera memory.On some lower end devices, there is only one image at the same time, which means packet resend only works until the next frame is read from the sensor data.

I guess you can lower the packet timeout to 1ms.

17

Another question: are you running the 2 cameras at the same time ?

18

Ok I’ll try to lower the timeout to 1ms.

What if indeed only one frame is stored? I mean, what does that mean for the above settings? Maybe frame retention is still a bit too long then?

Yes, I am using them both at the same time. They have their own ethernet port and subnetmask and I am creating a stream for each of them. They are triggered at the same time and they are ‘stitched’ together later in the process (by another thread of course). So that’s why I don’t want to have delayed frames as well, because in that case stitching becomes a bit hard and there will be congestion, while the process has to be sort of realtime.

What I also see is that most of the time one of the two camera’s has the timeout problems and the other does not.

I also see these errors sometimes now:

[GvStream::find_frame_data] Discard late frame 41892 (last: 41893)
packet_type  =   resend (0x0100)
content_type = data-block (0x0003)
frame_id     =    41892 
packet_id    =      328
data_size    =     8128

(5 in a row).

19

The camera has a buffer of 128 mb.

I changed the settings a bit, so packet timeout is now 1ms, frame retention 20ms and packet request ratio 1.5. I use two buffers because that should be enough. I played with it a lot and thinking about it, this is quite reasonable. We want to have a frame rate of around 35 fps, so a frame retention of 20ms fits well I think.

It is working quite well for several minutes, but then all of a sudden, the frame numbers start ‘seperating’. So they should be in sync, but all of a sudden they are not anymore. It looks like it reaches a state it can not recover from. It does not help to stop triggering and start triggering again.

This is the output:
Camera 1:

[GvStream::finalize] n_completed_buffers    = 20307
[GvStream::finalize] n_failures             = 0
[GvStream::finalize] n_timeouts             = 0
[GvStream::finalize] n_aborteds             = 0
[GvStream::finalize] n_underruns            = 0
[GvStream::finalize] n_missing_frames       = 0
[GvStream::finalize] n_size_mismatch_errors = 0
[GvStream::finalize] n_received_packets     = 6804897
[GvStream::finalize] n_missing_packets      = 0
[GvStream::finalize] n_error_packets        = 0
[GvStream::finalize] n_ignored_packets      = 0
[GvStream::finalize] n_resend_requests      = 2377
[GvStream::finalize] n_resent_packets       = 1007
[GvStream::finalize] n_resend_ratio_reached = 0
[GvStream::finalize] n_duplicated_packets   = 2052
[Stream::finalize] Flush 2 buffer[s] in input queue
[Stream::finalize] Flush 0 buffer[s] in output queue

Camera 2:

[GvStream::finalize] n_completed_buffers    = 20302
[GvStream::finalize] n_failures             = 1
[GvStream::finalize] n_timeouts             = 1
[GvStream::finalize] n_aborteds             = 0
[GvStream::finalize] n_underruns            = 0
[GvStream::finalize] n_missing_frames       = 0
[GvStream::finalize] n_size_mismatch_errors = 0
[GvStream::finalize] n_received_packets     = 6804138
[GvStream::finalize] n_missing_packets      = 1
[GvStream::finalize] n_error_packets        = 1
[GvStream::finalize] n_ignored_packets      = 0
[GvStream::finalize] n_resend_requests      = 3259
[GvStream::finalize] n_resent_packets       = 538
[GvStream::finalize] n_resend_ratio_reached = 0
[GvStream::finalize] n_duplicated_packets   = 2633
[Stream::finalize] Flush 2 buffer[s] in input queue
[Stream::finalize] Flush 0 buffer[s] in output queue

I see quite a lot of resend requests and I think the number of resent packages should be equal to the resend requests number, isn’t it? So what could be causing this? Are there other settings I did not mention yet that can affect this?

The heartbeat timeout is something totally different, isn’t it? That is the time to end the connection if the camera could not be found anymore or something?

20

In this case, the frame retention don’t need to be longer than the acquisition period.

It is most probably harmless, it is a resent packet received after the corresponding frame was closed. Sometimes packet are resent twice.