Stale frames with larger image sizes

Hi,

I am using Aravis in an application that can request single “still” images, or can enter a “streaming” mode where images are delivered continuously. Everything has been working fine, but now we are integrating a newer camera with a much larger sensor size (FLIR BFS-PGE-244S8M-C, ~24 megapixels).

I have found that when streaming for a short period (during which we queue 20 buffers in a round-robin format), when we stop streaming and then request a new single “still” image some time later, the first image delivered is what would have been the final frame of the previous streaming sequence. Subsequent still images are properly acquired and delivered.

Some details: shrinking the Region of Interest tends to eliminate the problem. performing a “frame flush” after streaming sessions conclude also tends to reduce the problem so long as we wait long enough:

         arv_camera_stop_acquisition(camera, &error);
            handleAravisError("Unable to stop stream", error);

            ArvBuffer* b = nullptr;
            while ((b = arv_stream_timeout_pop_buffer(stream, 500*1000)) != nullptr) {
                arv_stream_push_buffer(streams[channel], b);
            }

However, this causes each “stop stream” operation to incur additional latency of maybe a half a second while we wait for the final buffer to clear.

My current hypothesis is that the larger frames have a longer transfer time and when we stop streaming and DO NOT flush the final buffers, the stale frame is still waiting for final packets to arrive at the socket or NIC buffer. Once they do, it becomes the next frame for the next “still” image request and is delivered as thought it were just acquired. This is just a hypothesis.

Is there a proper way to stop a stream and flush all buffers without incurring additional latency such that nothing is already pending during the next grab?

Here is a short debug snippet when i see this happen:

[17:06:09.290] 🅸 stream> [GvStream::stream_new] Destination stream port = 50346
[17:06:09.291] 🅸 stream> [GvStream::stream_new] Source stream port = 49153
[17:06:09.291] 🅸 stream> [GvStream::loop] Standard socket method
[17:06:13.875] 🅸 stream>     bins    ;frame_retent; packet_time;inter_packet
0;           0;         493;       48235
2000;           0;         451;          62
4000;           0;         447;          20
6000;           0;         593;           5
8000;           0;         391;           0
10000;           0;         516;           1
12000;           0;         499;           0
14000;           0;         426;           0
16000;           0;         502;           0
18000;           0;         627;           0
20000;           0;         430;           0
22000;           0;         519;           0
24000;           0;         467;           0
26000;           0;         454;           0
28000;           0;         428;           0
30000;           0;         678;           0
32000;           0;         453;           0
34000;           0;         436;           0
36000;           0;         485;           0
38000;           0;         439;           0
40000;           0;         558;           0
42000;           0;         460;           0
44000;           0;         419;           0
46000;           0;         552;           0
48000;           0;         551;           0
50000;           0;         421;           0
52000;           0;         571;           0
54000;           0;         528;           0
56000;           0;         506;           0
58000;           0;         469;           0
60000;           0;         534;           0
62000;           0;         473;           0
64000;           0;         470;           0
66000;           0;         535;           0
68000;           0;         467;           0
70000;           0;         476;           0
72000;           0;         510;           0
74000;           0;         427;           0
76000;           0;         448;           0
78000;           0;         598;           0
80000;           0;         458;           0
82000;           0;         508;           0
84000;           0;         520;           0
86000;           0;         445;           0
88000;           0;         513;           0
90000;           0;         498;           0
92000;           0;         389;           0
94000;           0;         582;           0
96000;           0;         528;           0
98000;           0;         420;           0
100000;           0;         492;           0
102000;           0;         588;           0
104000;           0;         473;           0
106000;           0;         433;           0
108000;           0;         492;           0
110000;           0;         419;           0
112000;           0;         534;           0
114000;           0;         518;           0
116000;           0;         539;           0
118000;           0;         484;           0
120000;           0;         500;           0
122000;           0;         458;           0
124000;           0;         417;           0
126000;           0;         432;           0
128000;           0;         565;           0
130000;           0;         556;           0
132000;           1;         526;           0
134000;           0;         436;           0
136000;           0;         353;           0
138000;           0;         631;           0
140000;           0;         439;           0
142000;           0;         428;           0
144000;           0;         482;           0
146000;           0;         486;           0
148000;           0;         428;           0
150000;           0;         530;           0
152000;           0;         442;           0
154000;           0;         397;           0
156000;           0;         545;           0
158000;           0;         417;           0
160000;           0;         475;           0
162000;           0;         482;           0
164000;           0;         398;           0
166000;           0;         490;           0
168000;           0;         463;           0
170000;           0;         454;           0
172000;           0;         482;           0
174000;           0;         536;           0
176000;           0;         454;           0
178000;           0;         426;           0
180000;           0;         484;           0
182000;           0;         465;           0
184000;           0;         437;           0
186000;           0;         457;           0
188000;           0;         477;           0
190000;           0;         479;           0
192000;           0;         522;           0
194000;           0;         444;           0
196000;           2;         427;           0
198000;          12;         454;           0
-------------
>=    200000;           3;          27;           0
<          0;           0;           0;           0
min         :      132538;           0;           0
max         :      200491;      200491;       10240
last max at :           0;        2724;       31768
counter     :          18:       48341:       48323
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_completed_buffers    = 17
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_failures             = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_underruns            = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_timeouts             = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_aborteds             = 1
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_missing_frames       = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_size_mismatch_errors = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_received_packets     = 48341
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_missing_packets      = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_error_packets        = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_ignored_packets      = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_resend_requests      = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_resent_packets       = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_resend_ratio_reached = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_resend_disabled      = 0
[17:06:13.875] 🅸 stream> [GvStream::finalize] n_duplicated_packets   = 0
[17:06:13.876] 🅸 stream> [GvStream::finalize] n_transferred_bytes    = 432618151
[17:06:13.876] 🅸 stream> [GvStream::finalize] n_ignored_bytes        = 0
[17:06:13.876] 🅸 stream> [Stream::finalize] Flush 19 buffer[s] in input queue
[17:06:13.876] 🅸 stream> [Stream::finalize] Flush 1 buffer[s] in output queue

[17:06:16.138] 🅸 stream> [GvStream::stream_new] Destination stream port = 44279
[17:06:16.138] 🅸 stream> [GvStream::stream_new] Source stream port = 49153
[17:06:16.138] 🅸 stream> [GvStream::loop] Standard socket method
[17:06:16.465] 🅸 stream>     bins    ;frame_retent; packet_time;inter_packet
0;           0;          60;        4418
2000;           0;          49;           2
4000;           0;          62;           1
6000;           0;          51;           0
8000;           0;          51;           1
10000;           0;          62;           0
12000;           0;          51;           0
14000;           0;          56;           0
16000;           0;          52;           0
18000;           0;          57;           0
20000;           0;          56;           0
22000;           0;          56;           0
24000;           0;          52;           0
26000;           0;          51;           0
28000;           0;          62;           0
30000;           0;          51;           0
32000;           0;          51;           0
34000;           0;          62;           0
36000;           0;          51;           0
38000;           0;          51;           0
40000;           0;          57;           0
42000;           0;          56;           0
44000;           0;          57;           0
46000;           0;          57;           0
48000;           0;          51;           0
50000;           0;          51;           0
52000;           0;          51;           0
54000;           0;          26;           0
56000;           0;          92;           0
58000;           0;          52;           0
60000;           0;          56;           0
62000;           0;          51;           0
64000;           0;          62;           0
66000;           0;          52;           0
68000;           0;          56;           0
70000;           0;          51;           0
72000;           0;          57;           0
74000;           0;          25;           0
76000;           0;          31;           0
78000;           0;          42;           0
80000;           0;          25;           0
82000;           0;          26;           0
84000;           0;          32;           0
86000;           0;          57;           0
88000;           0;         176;           0
90000;           0;          56;           0
92000;           0;          50;           0
94000;           0;          56;           0
96000;           0;          58;           0
98000;           0;          45;           0
100000;           0;          61;           0
102000;           0;          57;           0
104000;           0;          52;           0
106000;           0;          56;           0
108000;           0;          57;           0
110000;           0;          51;           0
112000;           0;          62;           0
114000;           0;          50;           0
116000;           0;          52;           0
118000;           0;          62;           0
120000;           0;          46;           0
122000;           0;          25;           0
124000;           1;          77;           0
126000;           0;          26;           0
128000;           0;          25;           0
130000;           0;          31;           0
132000;           0;          26;           0
134000;           0;          25;           0
136000;           0;          26;           0
138000;           0;          31;           0
140000;           0;          26;           0
142000;           0;          30;           0
144000;           0;          26;           0
146000;           0;          26;           0
148000;           0;          25;           0
150000;           0;          31;           0
152000;           0;          26;           0
154000;           0;          31;           0
156000;           0;          25;           0
158000;           0;          26;           0
160000;           0;          31;           0
162000;           0;          25;           0
164000;           0;          26;           0
166000;           0;          31;           0
168000;           0;          26;           0
170000;           0;          25;           0
172000;           0;          31;           0
174000;           0;          26;           0
176000;           0;          25;           0
178000;           0;          31;           0
180000;           0;          26;           0
182000;           0;          26;           0
184000;           0;          31;           0
186000;           0;          25;           0
188000;           0;          26;           0
190000;           0;          25;           0
192000;           0;          33;           0
194000;           0;          24;           0
196000;           0;          31;           0
198000;           1;          22;           0
-------------
>=    200000;           0;           0;           0
<          0;           0;           0;           0
min         :      124798;           0;           0
max         :      199458;      199458;        8336
last max at :           0;        2732;        3764
counter     :           2:        4424:        4422
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_completed_buffers    = 1
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_failures             = 0
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_underruns            = 69
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_timeouts             = 0
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_aborteds             = 1
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_missing_frames       = 0
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_size_mismatch_errors = 0
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_received_packets     = 4493
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_missing_packets      = 0
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_error_packets        = 0
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_ignored_packets      = 69
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_resend_requests      = 92
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_resent_packets       = 92
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_resend_ratio_reached = 0
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_resend_disabled      = 0
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_duplicated_packets   = 0
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_transferred_bytes    = 39595486
[17:06:16.466] 🅸 stream> [GvStream::finalize] n_ignored_bytes        = 618033
[17:06:16.466] 🅸 stream> [Stream::finalize] Flush 1 buffer[s] in input queue
[17:06:16.466] 🅸 stream> [Stream::finalize] Flush 1 buffer[s] in output queue

Thank you!

Note: post edited to remove the CRITICAL error from the debug log as i have since fixed this and it was unrelated to the issue at hand.

Another solution that seems to be more robust with way less induce latency: check the buffer timestamp against the stream start timestamp.

            long long diff = static_cast<long long>(arv_buffer_get_system_timestamp(buffer)) - static_cast<long long>(streamStartTime);
            if (diff <= 0) {
                // this buffer is from before we started streaming
                // push the buffer back
                arv_stream_push_buffer(streams.at(channel), buffer);
                // return false, the caller will check again for fresh frame shortly
                return false;
            }

does this strike anyone as unnecessary or inappropriate/bad practice?

Thanks!

I just tried another camera with similar sensor size (Basler a2A5328-4gmBAS) and it DID NOT suffer from the same symptoms.

I’m also having other issues with stability using the FLIR referenced above. This is looking more like an issue with the FLIR camera rather than the frame size.

Reset camera's frame id to 1 on start_acquisition() [flir/pointgrey gige cameras] · Issue #762 · AravisProject/aravis · GitHub led me to try a newer version of Aravis. The problem goes away with 0.8.31 as far as I can tell.

Hi,

I guess stopping the stream channel flushes the camera buffers. Let’s hope it fixes your issue for good. If not, don’t hesitate to open an issue on github.

Cheers,

Emmanuel.