[aravis] Debugging latency & long pause issues with Blackfly camera...

  • From: Patrick Doyle <wpdster@xxxxxxxxx>
  • To: aravis@xxxxxxxxxxxxx
  • Date: Mon, 14 Apr 2014 09:38:01 -0400

I'm looking for some tips anybody can offer in debugging latency &
long pause issues I am seeing using the Aravis gstreamer plugin to
grab frames from a Point Grey Blackfly camera.

I have gstreamer pipeline that looks like this:

gst-launch-1.0 aravissrc do-timestamp=true !
video/x-raw,framerate=30/1 ! xbac usehw=true ! fakesink

"xbac" is my custom plugin whose "usehw=true" property says to use the
hardware acceleration for my algorithm.  The hardware acceleration
supports 30 frames/second.

Right now, I have in my transform code something that looks like this:

  static int timestamps_counter = 20;

  if (GST_CLOCK_TIME_IS_VALID (GST_BUFFER_TIMESTAMP (inbuf)))
    gst_object_sync_values (GST_OBJECT (filter), GST_BUFFER_TIMESTAMP (inbuf));

  if (timestamps_counter > 0) {
      static GstClockTime prev;
      static int count = 0;
      GstClockTime current = GST_BUFFER_TIMESTAMP (inbuf);
      timestamps_counter--;
      g_print("[%2d]: timestamp = %12lld, delta = %12lld\n", count++,
current, current - prev);
      prev = current;
  }

so I can see the timestamps of the video frames when I first start the pipeline.

An example session is shown below:

gst-launch-1.0 aravissrc do-timestamp=true !
video/x-raw,framerate=30/1 ! xbac usehw=true ! fakesink
Setting pipeline to PAUSED ...
Pipeline is live and does not need PREROLL ...
Setting pipeline to PLAYING ...
New clock: GstSystemClock
[ 0]: timestamp = 136916963097, delta = 136916963097
[ 1]: timestamp = 136952813649, delta =     35850552
[ 2]: timestamp = 136987539840, delta =     34726191
[ 3]: timestamp = 137022487216, delta =     34947376
[ 4]: timestamp = 137057121245, delta =     34634029
[ 5]: timestamp = 137091681546, delta =     34560301
[ 6]: timestamp = 137126278711, delta =     34597165
[ 7]: timestamp = 137160654690, delta =     34375979
[ 8]: timestamp = 137194920077, delta =     34265387
[ 9]: timestamp = 156214789943, delta =  19019869866
[10]: timestamp = 156249442405, delta =     34652462
[11]: timestamp = 156283781519, delta =     34339114
[12]: timestamp = 156318102202, delta =     34320683
[13]: timestamp = 156352496613, delta =     34394411
[14]: timestamp = 156386854161, delta =     34357548
[15]: timestamp = 156421267004, delta =     34412843
[16]: timestamp = 156455661415, delta =     34394411
[17]: timestamp = 156490111123, delta =     34449708
[18]: timestamp = 156524431806, delta =     34320683
[19]: timestamp = 156558770921, delta =     34339115
^CCaught interrupt -- handling interrupt.
Interrupt: Stopping pipeline ...
Execution ended after 178973734146 ns.
Setting pipeline to PAUSED ...
Setting pipeline to READY ...
Setting pipeline to NULL ...
Freeing pipeline …

This shows a rather long pause at the beginning (137 seconds, which
correlates with the wall clock time I measured) getting the pipeline
up and running, followed by 8 frames whose timestamps differ by 34e6
nanoseconds (34 ms, which is sort of correct for 30 frames/sec),
followed by a 19 second pause (again, correlates well with the wall
clock), followed by more frames.

I'm not asking that anybody solve this (although, if you've seen this
sort of thing with the Blackfly, or other cameras and can tell me what
to fix, you would have my eternal gratitude), but if anybody has some
suggestions as to what I might look at, or what tools I might use, to
diagnose these pauses, I would be grateful.

I have connected the camera through a switch to my embedded
development board.  I suppose the MTU could be an issue, and perhaps
there is some sort of MTU negotiation going on.  I don't see any specs
for the MTU for the switch; I know I can control it on the (Linux
based) embedded development board; I'm not sure what knobs I have on
the GigE Blackfly camera that might affect this.

Thanks for any tips or pointers.  I need to figure out how to keep the
latency below 100ms (yes, I know that's 3 frames!) or if it's not
possible to keep it below 100ms in the next few hours (ouch!).

--wpd

Other related posts: