After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 699517 - uvch264src: v4l2src delivered buffer from C920 camera to uvch264src corrupt?
uvch264src: v4l2src delivered buffer from C920 camera to uvch264src corrupt?
Status: RESOLVED DUPLICATE of bug 706083
Product: GStreamer
Classification: Platform
Component: gst-plugins-bad
1.1.3
Other Linux
: Normal major
: git master
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on: 682770 707534
Blocks:
 
 
Reported: 2013-05-02 19:43 UTC by Robert Krakora
Modified: 2013-09-07 12:40 UTC
See Also:
GNOME target: ---
GNOME version: ---

Attachments
Fix memory corruption and memory leak (409 bytes, patch)
2013-07-26 18:33 UTC, Robert Krakora 		committed Details | Review
Patch to add back "always-copy=true" default functionality for v4l2src (713 bytes, patch)
2013-07-26 20:08 UTC, Robert Krakora 		needs-work Details | Review
uvch264src improved patch (609 bytes, patch)
2013-07-28 21:11 UTC, Robert Krakora 		rejected Details | Review
Hack Patch 1 of 2 to fix bug...need proper fix... (21.18 KB, patch)
2013-08-11 02:15 UTC, Robert Krakora 		none Details | Review
Hack Patch 2 of 2 to fix bug...need proper fix... (5.33 KB, patch)
2013-08-11 02:17 UTC, Robert Krakora 		none Details | Review
Hack Patch 2 of 2 to fix bug...need proper fix... (6.19 KB, patch)
2013-08-12 13:58 UTC, Robert Krakora 		none Details | Review
Replacement for Hack Patch 1 of 2... (19.28 KB, patch)
2013-08-12 16:29 UTC, Robert Krakora 		none Details | Review
Replacement for Hack Patch 2 of 2... (4.81 KB, patch)
2013-08-12 16:30 UTC, Robert Krakora 		none Details | Review
Replacement for Hack Patch 2 of 2... (6.17 KB, patch)
2013-08-12 18:23 UTC, Robert Krakora 		none Details | Review
Replacement for Hack Patch 2 of 2... (6.20 KB, patch)
2013-08-12 18:50 UTC, Robert Krakora 		none Details | Review
Replacement for Hack Patch 2 of 2... (6.10 KB, patch)
2013-08-12 19:45 UTC, Robert Krakora 		none Details | Review
Replacement for Hack Patch 2 of 2... (6.09 KB, patch)
2013-08-12 19:55 UTC, Robert Krakora 		none Details | Review
Replacement for Hack Patch 1 of 2...hopefully final... (9.10 KB, patch)
2013-08-13 19:31 UTC, Robert Krakora 		none Details | Review
Replacement for Hack Patch 2 of 2...hopefully final... (6.01 KB, patch)
2013-08-13 19:32 UTC, Robert Krakora 		none Details | Review
Patch for v4l2src to put back replaced buffer... (790 bytes, patch)
2013-08-15 10:44 UTC, Robert Krakora 		reviewed Details | Review
Patch for v4l2src to put back replaced buffer... (3.69 KB, patch)
2013-08-16 22:14 UTC, Robert Krakora 		rejected Details | Review

Description Robert Krakora 2013-05-02 19:43:10 UTC 
I am using a C920 camera with uvch264src plugin in the pipeline below and I get the following error...

0:00:34.837102759  3092      0x204c0f0 WARN        uvch264mjpgdemux gstuvch264_mjpgdemux.c:507:gst_uvc_h264_mjpg_demux_chain:<uvch264mjpgdemux0> error: Not enough data to read marker content

Although uvch264src was renamed from uvch264_src when it was ported from 0.10 to 1.0, diffing the files the code is basically the same with no changes beyond porting IMHO.  However, diffing v4lsrc between 0.10 and 1.0 yields many differences.  I am new to GStreamer 1.0 and more familiar with GStreamer 0.10, so I may be wrong.  However, after testing over the past week and a half, all signs seem to point towards v4l2src.  I can collect any data that is needed in order to diagnose the problem.

GST_DEBUG=*v4l2*:5,*uvch264*:5 GST_DEBUG_NO_COLOR=1 gst-launch-1.0 uvch264src device=/dev/video0 name=src auto-start=true src.vidsrc ! video/x-h264,width=800,height=600,framerate=30/1 ! queue ! fakesink src.vfsrc ! video/x-raw,width=432,height=240,framerate=30/1 ! fakesink
Comment 1 Robert Krakora 2013-07-26 18:33:18 UTC 
Created attachment 250223 [details] [review]
Fix memory corruption and memory leak

This patch fixes memory corruption and memory leak caused by uvch264src port.  The attached patch is against gst-plugins-bad-1.1.2.
Comment 2 Robert Krakora 2013-07-26 20:08:16 UTC 
Created attachment 250238 [details] [review]
Patch to add back "always-copy=true" default functionality for v4l2src

The previously attached patch works to fix the corruption and memory leak caused by uvch264src.  However, in version 0.10 v4l2src, which is utilized by uvch264src, defaulted to always allocating buffers to copy data from buffers in it's buffer pool for consumption by downstream plugins.  This default behaviour has been removed for 1.xx.  I "hacked" "always-copy=true" back in by setting the "copy_threshold" to "num_buffers+1" to insure the buffer pool buffers are always copied to newly allocated buffers for consumption by downstream plugins.  I can run indefinitely with C920 camera with uvch264src with this modification as well as the previous patch.  By default, uvch264_src in version 0.10 always ran with v4l2src with "always-copy=true" since that was the default.

Test stream:

gst-launch-1.0 uvch264src device=/dev/video0 name=src auto-start=true src.vfsrc ! queue ! fakesink src.vidsrc ! queue ! video/x-h264 ! fakesink
Comment 3 Nicolas Dufresne (ndufresne) 2013-07-28 07:37:42 UTC 
Review of attachment 250238 [details] [review]:

::: gst-plugins-good-1.1.2/sys/v4l2/gstv4l2bufferpool.c
@@ +416,3 @@
         /* we are certain that we have enough buffers so we don't need to
          * copy */
+        copy_threshold = num_buffers + 1;

The comment no longer match the code, and we are doing if for no reason, not sure if this is the right fix though, but to be correct these would need to be fixed.
Comment 4 Nicolas Dufresne (ndufresne) 2013-07-28 07:37:45 UTC 
Review of attachment 250223 [details] [review]:

This should go in 1.0.X branch too I think.
Comment 5 Robert Krakora 2013-07-28 11:24:39 UTC 
Review of attachment 250238 [details] [review]:

This is not the right fix.  The manual for 1.x states that there is a property called "always-copy" and that it defaults to "true".  However, the code does not implement "always-copy" property.  This is a "hack" that I did to achieve the same effect for 1.x to test out another fix for which I came up with a patch for uvch264src.  I believe that the "always-copy" property should be added back to v4l2src.  The fix for uvch264src was to fix a memory leak.
Comment 6 Olivier Crête 2013-07-28 15:28:48 UTC 
I'm very much against adding back the "always-copy" property to v4l2src, it was a hack that really only worked in very specific pipelines.

I would guess you may be hitting the situation described in bug #628770 comment #22. That said, if we don't get #682770 fixed before 1.2.x, I suggest just having the equivalent of always-copy=true always on until that bug is fixed (ie, possibly applying your current patch as-is with a big "FIXME" in there).
Comment 7 Olivier Crête 2013-07-28 15:30:13 UTC 
Comment on attachment 250223 [details] [review]
Fix memory corruption and memory leak

commit bd386a2785aa31d64441bb89e0d136765ed5c3bc
Author: Robert Krakora <rob.krakora@messagenetsystems.com>
Date:   Fri Jul 26 18:33:00 2013 +0000

    uvcv4l2_mjpegdemux: Unmap buffer
    
    https://bugzilla.gnome.org/show_bug.cgi?id=699517
Comment 8 Robert Krakora 2013-07-28 16:27:12 UTC 
I totally agree with you Olivier.  The only time I every used "always-copy" on 0.10 was implicitly via uvch264_src for the C920.  Every other v4l2 device I used with GStreamer on 0.10 I always set "always-copy=false".  Just grasping at straws here on 1.x.  However, I did find a memory leak with uvch264src in 1.x.  Also, I was able to see the memory corruption issue with my "always-copy=true" hack in place after 27 hours of continuous running with the memory leak fix also applied on uvch264src.  Without the memory leak fix, it just occurs a lot faster like 36 seconds vs. hours/days.
Comment 9 Robert Krakora 2013-07-28 21:11:19 UTC 
Created attachment 250329 [details] [review]
uvch264src improved patch

Improved uvch264src patch...uses info.size returned from gst_buffer_map() instead of gst_buffer_get_size()...
Comment 10 Olivier Crête 2013-07-28 21:29:07 UTC 
Comment on attachment 250329 [details] [review]
uvch264src improved patch

I already comitted your earlier patch and something similar to this new one.
Comment 11 Nicolas Dufresne (ndufresne) 2013-07-28 22:23:55 UTC 
Might be nice to merge these in to 1.0.X too no ?
Comment 12 Robert Krakora 2013-07-28 23:51:30 UTC 
Understood.  However, the second patch is an attempt to address an issue where it appears that gst_buffer_get_size() returns the wrong overall size of the memory chunks of which it is comprised.  A symptom of this appears in uvch264src as an error message to the affect that "Incomplete auxiliary stream.  %d bytes missing".  Usually I could only run 15-20 minutes without this change.  I have now been running for four hours with no change to v4l2src and the previous uvch264src patch and this new one applied.  I am still testing.
Comment 13 Olivier Crête 2013-07-29 05:08:58 UTC 
Did you try running the current git master?
Comment 14 Olivier Crête 2013-07-29 05:09:00 UTC 
Did you try running the current git master?
Comment 15 Robert Krakora 2013-07-29 11:59:48 UTC 
No, I will do that today.  It can take a few hours for the problem to occur, so it may be a while before I have anything to report back.
Comment 16 Robert Krakora 2013-07-29 22:39:18 UTC 
After running C920 with uvch264src for nine hours and the HEAD gstreamer and gst-plugins I see this still (GstBuffer or GstMemory problem maybe?):

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.254497829 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008380
8:26:09.254729664 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.280199273 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008050
8:26:09.280271172 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:25.953353000 now 120:10:26.160539833 delay 0:00:00.207186833
8:26:09.280313123 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.299696317 out ts 8:26:08.651026115

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.289073630 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008050
8:26:09.289156412 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.312167340 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008160
8:26:09.312233234 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:25.982806000 now 120:10:26.192501802 delay 0:00:00.209695802
8:26:09.312278884 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.333029650 out ts 8:26:08.680479324

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.318165359 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008160
8:26:09.318244426 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.348062733 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008270
8:26:09.348088114 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.012470000 now 120:10:26.228359425 delay 0:00:00.215889425
8:26:09.348100053 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.366362983 out ts 8:26:08.710146497

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.351712510 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008270
8:26:09.351743131 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.380156953 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008380
8:26:09.380226121 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.041865000 now 120:10:26.260494577 delay 0:00:00.218629577
8:26:09.380270907 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.399696316 out ts 8:26:08.739538453

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.385209438 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008380
8:26:09.385253151 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.412110937 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008050
8:26:09.412141572 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.071482000 now 120:10:26.292412628 delay 0:00:00.220930628
8:26:09.412156400 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.433029649 out ts 8:26:08.769158210

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.416136320 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008050
8:26:09.416175737 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.448111143 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008160
8:26:09.448179449 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.326056000 now 120:10:26.328448060 delay 0:00:00.002392060
8:26:09.448222778 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.466362982 out ts 8:26:09.023729617

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.454662660 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008160
8:26:09.455234367 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.480089989 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008270
8:26:09.480132507 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.361728000 now 120:10:26.360402706 delay 0:00:00.000000000
8:26:09.480158178 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.499696315 out ts 8:26:09.058078228

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.486026291 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008270
8:26:09.486101896 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.512115930 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008380
8:26:09.512153591 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.393554000 now 120:10:26.392424619 delay 0:00:00.000000000
8:26:09.512168577 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.533029648 out ts 8:26:09.090098992

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.516121671 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008380
8:26:09.516162036 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.548082898 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008050
8:26:09.548149435 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.445443000 now 120:10:26.428418152 delay 0:00:00.000000000
8:26:09.548192121 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.566362981 out ts 8:26:09.126091734

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.555404349 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008050
8:26:09.555449247 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.580051319 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008160
8:26:09.580080383 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.475004000 now 120:10:26.460351631 delay 0:00:00.000000000
8:26:09.580093135 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.599696314 out ts 8:26:09.158027976

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.585259497 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008160
8:26:09.585298043 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.612048237 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008270
8:26:09.612076224 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.504470000 now 120:10:26.492347366 delay 0:00:00.000000000
8:26:09.612088789 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.633029647 out ts 8:26:09.190023551

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.616587078 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008270
8:26:09.616633936 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.648079902 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008380
8:26:09.648144910 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.533246000 now 120:10:26.528413594 delay 0:00:00.000000000
8:26:09.648187573 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.666362980 out ts 8:26:09.226087713

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.654346019 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008380
8:26:09.654948084 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.680044758 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008050
8:26:09.680084245 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.563556000 now 120:10:26.560355285 delay 0:00:00.000000000
8:26:09.680099717 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.699696313 out ts 8:26:09.258030795

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.684626537 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008050
8:26:09.684668645 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.712067129 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008160
8:26:09.712096551 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.592155000 now 120:10:26.592367678 delay 0:00:00.000212678
8:26:09.712111114 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.733029646 out ts 8:26:09.289831153

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.714972233 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008160
8:26:09.715009632 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.748009427 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008270
8:26:09.748041030 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.622612000 now 120:10:26.628312083 delay 0:00:00.005700083
8:26:09.748054799 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.766362979 out ts 8:26:09.320288075

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.752145242 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008270
8:26:09.752183998 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.780056617 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008380
8:26:09.780098210 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.650996000 now 120:10:26.660368389 delay 0:00:00.009372389
8:26:09.780125473 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.799696312 out ts 8:26:09.348671381

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.784242062 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008380
8:26:09.784278093 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.812115107 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008050
8:26:09.812190003 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.680930000 now 120:10:26.692458641 delay 0:00:00.011528641
8:26:09.812235167 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.833029645 out ts 8:26:09.378603734

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.821392733 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008050
8:26:09.821485098 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.848071110 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008160
8:26:09.848136378 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.710147000 now 120:10:26.728405049 delay 0:00:00.018258049
8:26:09.848179902 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.866362978 out ts 8:26:09.407820602

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.854716438 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008160
8:26:09.855348779 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.880030401 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008270
8:26:09.880061670 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.739917000 now 120:10:26.760332778 delay 0:00:00.020415778
8:26:09.880076539 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.899696311 out ts 8:26:09.437592706

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.884009607 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008270
8:26:09.884049128 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.912018062 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008380
8:26:09.912047059 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.770173000 now 120:10:26.792318244 delay 0:00:00.022145244
8:26:09.912061070 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.933029644 out ts 8:26:09.467848785

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.914644410 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008380
8:26:09.914677097 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.947986628 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008050
8:26:09.948019148 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.798853000 now 120:10:26.828290081 delay 0:00:00.029437081
8:26:09.948033652 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.966362977 out ts 8:26:09.496528971

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.952089826 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008050
8:26:09.952122927 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:09.980000724 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008160
8:26:09.980036697 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.829181000 now 120:10:26.860307487 delay 0:00:00.031126487
8:26:09.980055099 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:08.999696310 out ts 8:26:09.526856629

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:09.983123262 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008160
8:26:09.983161399 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:10.012006774 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008270
8:26:10.012042344 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.857845000 now 120:10:26.892313562 delay 0:00:00.034468562
8:26:10.012056471 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:09.033029643 out ts 8:26:09.555521075

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:10.016729147 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008270
8:26:10.016767878 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:10.048043239 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008380
8:26:10.048109352 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.888190000 now 120:10:26.928378222 delay 0:00:00.040188222
8:26:10.048149157 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:09.066362976 out ts 8:26:09.585863887

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:10.053788881 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008380
8:26:10.054361579 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:10.080008505 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008050
8:26:10.080041008 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.916786000 now 120:10:26.960312112 delay 0:00:00.043526112
8:26:10.080054088 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:09.099696309 out ts 8:26:09.614462067

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:10.085592964 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008050
8:26:10.085631096 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:10.112017736 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008160
8:26:10.112058810 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.947248000 now 120:10:26.992329037 delay 0:00:00.045081037
8:26:10.112083430 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:09.133029642 out ts 8:26:09.644923226

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:10.115652380 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008160
8:26:10.115696249 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:10.147963689 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008270
8:26:10.147999472 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:26.976780000 now 120:10:27.028270634 delay 0:00:00.051490634
8:26:10.148013214 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:09.166362975 out ts 8:26:09.674455892

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:10.151870316 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008270
8:26:10.151921768 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:10.180045855 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008380
8:26:10.180108506 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:27.006273000 now 120:10:27.060377360 delay 0:00:00.054104360
8:26:10.180152033 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:09.199696308 out ts 8:26:09.703946895

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
8:26:10.185016710 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008380
8:26:10.185050332 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:832:gst_v4l2_buffer_pool_acquire_buffer:<v4l2bufferpool0> acquire
8:26:10.212067832 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:1167:gst_v4l2_buffer_pool_process:<v4l2bufferpool0> process buffer 0x7fb1dc008050
8:26:10.212134466 31411      0x21e2590 DEBUG                v4l2src gstv4l2src.c:823:gst_v4l2src_fill:<v4l2src0> ts: 120:10:27.035819000 now 120:10:27.092402995 delay 0:00:00.056583995
8:26:10.212181373 31411      0x21e2590 INFO                 v4l2src gstv4l2src.c:861:gst_v4l2src_fill:<v4l2src0> sync to 8:26:09.233029641 out ts 8:26:09.733492953

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3916:gst_pad_push_data:<capsfilter0:src> Got data flow before segment event

(gst-launch-1.0:31411): GStreamer-WARNING **: gstpad.c:3685:gst_pad_chain_data_unchecked:<fakesink1:sink> Got data flow before segment event
ERROR: from element /GstPipeline:pipeline0/GstUvcH264Src:src/GstUvcH264MjpgDemux:uvch264mjpgdemux0: Incomplete auxiliary stream. 65531 bytes missing
Additional debug info:
gstuvch264_mjpgdemux.c(686): gst_uvc_h264_mjpg_demux_chain (): /GstPipeline:pipeline0/GstUvcH264Src:src/GstUvcH264MjpgDemux:uvch264mjpgdemux0
Execution ended after 8:26:09.799064745
Setting pipeline to PAUSED ...
8:26:10.221458614 31411      0x21e2590 DEBUG                   v4l2 gstv4l2bufferpool.c:933:gst_v4l2_buffer_pool_release_buffer:<v4l2bufferpool0> release buffer 0x7fb1dc008050
Setting pipeline to READY ...
8:26:10.223266079 31411      0x212d6a0 DEBUG                   v4l2 gstv4l2bufferpool.c:566:gst_v4l2_buffer_pool_stop:<v4l2bufferpool0> stopping pool
8:26:10.223281281 31411      0x212d6a0 DEBUG                   v4l2 gstv4l2bufferpool.c:579:gst_v4l2_buffer_pool_stop:<v4l2bufferpool0> STREAMOFF
8:26:10.359607163 31411      0x212d6a0 DEBUG                   v4l2 gstv4l2object.c:2598:gst_v4l2_object_stop:<v4l2src0> stopping
8:26:10.359648991 31411      0x212d6a0 DEBUG                   v4l2 gstv4l2object.c:2606:gst_v4l2_object_stop:<v4l2src0> deactivating pool
Setting pipeline to NULL ...
8:26:10.384480763 31411      0x212d6a0 DEBUG                   v4l2 v4l2_calls.c:618:gst_v4l2_close:<v4l2src0> Trying to close /dev/video0
8:26:10.384569296 31411      0x212d6a0 DEBUG                   v4l2 v4l2_calls.c:456:gst_v4l2_empty_lists:<v4l2src0> deleting enumerations
Freeing pipeline ...
[root@DevKrakora GStreamer-1.0]#
Comment 17 Nicolas Dufresne (ndufresne) 2013-07-30 09:58:19 UTC 
Please try and avoid long trace in the comment, attach file instead.
Comment 18 Robert Krakora 2013-07-30 10:36:21 UTC 
Sorry...just meant to cut/paste these few lines...

ERROR: from element
/GstPipeline:pipeline0/GstUvcH264Src:src/GstUvcH264MjpgDemux:uvch264mjpgdemux0:
Incomplete auxiliary stream. 65531 bytes missing
Additional debug info:
gstuvch264_mjpgdemux.c(686): gst_uvc_h264_mjpg_demux_chain ():
/GstPipeline:pipeline0/GstUvcH264Src:src/GstUvcH264MjpgDemux:uvch264mjpgdemux0
Comment 19 Robert Krakora 2013-07-30 18:47:38 UTC 
I am running the following pipeline under GStreamer 0.10 with uvch264_src to see if the same error is encountered after a few hours of continuous capture from C920 as is seen under GStreamer 1.x with uvch264src.

gst-launch --gst-debug=*v4l2*:5 --gst-debug-no-color=1 uvch264_src device=/dev/video0 auto-start=true ! queue ! video/x-h264 ! fakesink

If the error occurs under 0.10 as it does under 1.x this may indicate a nuance with the camera that needs to be accommodated in the uvch264_src and uvch264src plugins respectively.
Comment 20 Robert Krakora 2013-07-31 13:30:13 UTC 
The test I have been running for the last 18 hours with C920 against GStreamer 0.10 uvch264_src has not yielded any errors whatsoever and it is identical to it's GStreamer 1.0 uvch264src in most respects, especially the error checking.  So, there has to be a bug in either the GStreamer 1.0 v4l2src plugin or GstMemory or the revamped GstBuffer.
Comment 21 Robert Krakora 2013-08-11 01:21:32 UTC 
I found the problem.  In v4l2src, four buffers are acquired from the UVC driver, and each is mapped to user space and each wrapped in a GstMemory object which is then appended to a GstBuffer.  However, in v4l2src gst_buffer_resize() can be called on a GstBuffer and this function allocates a new GstMemory object with an appropriately sized data area and copies the contents of the current GstMemory object's data area in to it.  The old GstMemory object with a data area comprised of one of the four buffers previously acquired from the UVC driver is then replaced by the new GstMemory object whose data area was allocated in user space of which the UVC has no knowledge.  The replaced GstMemory object is unreferenced (deallocated) and the UVC driver buffer is orphaned and it's lights out for the pipeline.  I was able to hack a fix by removing the to instances of gst_buffer_resize() and placing the real size from vbuffer.bytesused in the GstBuffer metadata in v4l2src and then retrieving it from the GstBuffer metadata in uvch264src.  I cannot think of a proper way to fix this right now.
Comment 22 Robert Krakora 2013-08-11 02:15:17 UTC 
Created attachment 251284 [details] [review]
Hack Patch 1 of 2 to fix bug...need proper fix...

This is a hack patch #1 for v4l2src to fix the bug.  Need proper fix, use at your own risk...works for me.
Comment 23 Robert Krakora 2013-08-11 02:17:12 UTC 
Created attachment 251285 [details] [review]
Hack Patch 2 of 2 to fix bug...need proper fix...

This is a hack patch #2 for uvch264src to fix the bug.  Need proper fix, use at your own risk...works for me.
Comment 24 Robert Krakora 2013-08-12 13:58:00 UTC 
Created attachment 251355 [details] [review]
Hack Patch 2 of 2 to fix bug...need proper fix...

Total hack to prevent GstMemory wrapped UVC driver buffers from becoming orphans...
Comment 25 Robert Krakora 2013-08-12 14:00:24 UTC 
Use with Patch 1.
Comment 26 Robert Krakora 2013-08-12 16:29:22 UTC 
Created attachment 251393 [details] [review]
Replacement for Hack Patch 1 of 2...
Comment 27 Robert Krakora 2013-08-12 16:30:00 UTC 
Created attachment 251394 [details] [review]
Replacement for Hack Patch 2 of 2...
Comment 28 Robert Krakora 2013-08-12 18:23:42 UTC 
Created attachment 251400 [details] [review]
Replacement for Hack Patch 2 of 2...

Let us try this again...
Comment 29 Robert Krakora 2013-08-12 18:50:58 UTC 
Created attachment 251402 [details] [review]
Replacement for Hack Patch 2 of 2...
Comment 30 Robert Krakora 2013-08-12 19:45:45 UTC 
Created attachment 251420 [details] [review]
Replacement for Hack Patch 2 of 2...
Comment 31 Robert Krakora 2013-08-12 19:55:02 UTC 
Created attachment 251422 [details] [review]
Replacement for Hack Patch 2 of 2...

Mistake...sorry for so many iterations of this patch...
Comment 32 Robert Krakora 2013-08-13 19:31:47 UTC 
Created attachment 251546 [details] [review]
Replacement for Hack Patch 1 of 2...hopefully final...
Comment 33 Robert Krakora 2013-08-13 19:32:38 UTC 
Created attachment 251547 [details] [review]
Replacement for Hack Patch 2 of 2...hopefully final...
Comment 34 Robert Krakora 2013-08-15 10:44:29 UTC 
Created attachment 251716 [details] [review]
Patch for v4l2src to put back replaced buffer...

After many attempts at patching this problem, I believe that I have finally found the patch that works.  It is a two line patch for the v4l2src plugin which uses the v4l2 buffer structure stored in the GstBuffer's meta data to replace the memory in the GstBuffer when it is queued.  This is done because the v4l2 buffer memory initially wrapped in a GstMemory object and placed in the GstBuffer may have been replaced implicitly by another GstMemory object with different memory by the GstBuffer API (I have verified that this indeed does happen).
Comment 35 Sebastian Dröge (slomo) 2013-08-16 07:23:03 UTC 
Comment on attachment 251716 [details] [review]
Patch for v4l2src to put back replaced buffer...

The real solution for this problem would be to get rid of the memory-meta and instead create a custom GstMemory for the v4l2 memory. That way there's never the problem of breaking the connection between the buffer (and thus the meta) and the memory.

As a first step to get this fixed with minimal effort, maybe only replace the memory now if it was really replaced by something else before? And also make sure that the meta still on the buffer. Otherwise this patch looks good.
Comment 36 Robert Krakora 2013-08-16 11:46:59 UTC 
The meta was already being used in the qbuf function, that is why I used it to recover the v4l2 allocated buffer and replace what memory to which the GstBuffer current referenced.  It sure does seem like GstBuffer and GstMemory need the capability of supporting kernel allocated user spaced mapped memory without the possibility of replacement.  Replacement means more latency and CPU usage in the pipeline because memory is allocated and then copied.  GstBuffer needs notion of whether it contains wrapped GstMemory objects and if so, when it is resized maybe have a bytesused member indicating how much useful data exists in the expanse of wrapped GstMemory objects it contains regardless of there overall size instead of replacing the GstMemory object.  GstBuffer should then either contain *only* wrapped GstMemory objects or *only* non-wrapped GstMemory objects and definitely not a mixture.
Comment 37 Robert Krakora 2013-08-16 22:14:10 UTC 
Created attachment 251957 [details] [review]
Patch for v4l2src to put back replaced buffer...
Comment 38 Sebastian Dröge (slomo) 2013-08-19 09:48:36 UTC 
There are no wrapped GstMemory, it's just a special feature of the system memory. GstBuffer should be completely ignorant about the type of memory contained inside it. That's exactly why I said that there should be a custom GstMemory for v4l2 buffers :) And now either we continue talking about this specific aspect in the other bug, or the other bug should be closed :)
Comment 39 Sebastian Dröge (slomo) 2013-08-19 09:48:55 UTC 
Comment on attachment 251957 [details] [review]
Patch for v4l2src to put back replaced buffer...

newer version in bug #706083
Comment 40 Robert Krakora 2013-08-19 11:02:33 UTC 
Agreed.  I think that we are on the same page.  However, the comment is a little vague (below from gst_memory.c).  ;-)  I could see why the person(s) who did the port of v4l2src may have thought it safe.

 * New memory can be created with gst_memory_new_wrapped() that wraps the memory
 * allocated elsewhere.
Comment 41 Olivier Crête 2013-09-05 04:43:29 UTC 
This is the same as #706083, lets keep it there since the patches are there.

*** This bug has been marked as a duplicate of bug 706083 ***
Comment 42 Olivier Crête 2013-09-05 22:57:38 UTC 
I got my hands on a C920, how reproducible is this ?
Comment 43 Robert Krakora 2013-09-06 01:14:16 UTC 
It will happen anywhere from one hour to a little over 24 hours according to my testing without the patch.  With the patch, I was able to run for over 72 hours straight.