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 776293 - GStreamer-CRITICAL **: gst_stream_collection_get_size: assertion 'collection->priv->streams' failed
GStreamer-CRITICAL **: gst_stream_collection_get_size: assertion 'collection-...
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gstreamer (core)
git master
Other Linux
: Normal normal
: 1.11.90
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2016-12-19 21:10 UTC by minfrin
Modified: 2017-03-31 11:04 UTC
See Also:
GNOME target: ---
GNOME version: ---

Attachments
fix racy user-after-free (1.92 KB, patch)
2017-03-31 09:40 UTC, Vincent Penquerc'h 		committed Details | Review

Description minfrin 2016-12-19 21:10:58 UTC 
While running a transcoder stream with a pipeline that is decodebin ! encodebin, after a period of time the pipeline crashes with an assertion failure like below:

0:14:25.135366841 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:249:gst_object_ref:<bus6> 0x70715ef8 ref 11->12
0:14:25.135476944 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:<bus6> 0x70715ef8 unref 12->11
0:14:25.135605432 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:249:gst_object_ref:<multiqueue0:sink_3> 0x74853a58 ref 4->5
0:14:25.135706681 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:249:gst_object_ref:<bus6> 0x70715ef8 ref 11->12
0:14:25.135802409 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74282ed0 unref 1->0
0:14:25.135903866 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:<multiqueue0:sink_3> 0x74853a58 unref 5->4
0:14:25.135996366 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74282f28 unref 1->0
0:14:25.136100323 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:<multiqueue0:sink_3> 0x74853a58 unref 4->3
0:14:25.136205686 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:<bus6> 0x70715ef8 unref 12->11
0:14:25.136299904 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:<tsdemux0> 0x70b3e178 unref 5->4
0:14:25.136397299 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:<multiqueue0:sink_3> 0x74853a58 unref 3->2
0:14:25.136505839 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:760:gst_object_unparent:<tsdemux0:subpicture_0_1d51> unparent
0:14:25.136589380 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:<'':subpicture_0_1d51> 0x74860c08 unref 2->1
0:14:25.136683598 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c5e50 ref 2->3
0:14:25.136796097 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e50 unref 3->2
0:14:25.136880210 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740913b0 ref 1->2
0:14:25.137002918 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740913b0 unref 2->1
0:14:25.137106823 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:stream text 0x7425a570, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d51, flags 0x1, caps [subpicture/x-dvb], tags [taglist, language-code=(string)en, subtitle-codec=(string)"DVB\ subtitles";] 0x7425a570 unref 2->1
0:14:25.137207082 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74266cb0 unref 1->0
0:14:25.138691702 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74090cc0 unref 1->0
0:14:25.139196697 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x4b11aa60 unref 1->0
0:14:25.143023219 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c65b8 ref 1->2
0:14:25.145077677 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c65b8 unref 2->1
0:14:25.145205957 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740912c0 ref 1->2
0:14:25.145341268 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740912c0 unref 2->1
0:14:25.147272342 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c5e00 ref 1->2
0:14:25.147453746 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e00 unref 2->1
0:14:25.147599318 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x74090c30 ref 1->2
0:14:25.147763118 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74090c30 unref 2->1
0:14:25.147910773 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c5e28 ref 1->2
0:14:25.148036657 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e28 unref 2->1
0:14:25.148122229 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x74090c00 ref 1->2
0:14:25.148242228 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74090c00 unref 2->1
0:14:25.148463371 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c5e50 ref 2->3
0:14:25.148574412 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e50 unref 3->2
0:14:25.148658213 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740913b0 ref 1->2
0:14:25.148793368 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740913b0 unref 2->1
0:14:25.148977324 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:collection 0x7425ae50 (4 streams) < stream video 0x7425a438, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d4d, flags 0x0, caps [video/x-h264, stream-format=(string)byte-stream, alignment=(string)nal], tags [taglist, video-codec=(string)H.264;], stream audio 0x7425a4a0, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d4e, flags 0x0, caps [audio/mpeg, mpegversion=(int)4, stream-format=(string)loas], tags [taglist, language-code=(string)en, audio-codec=(string)"MPEG-4\ AAC";], stream audio 0x7425a508, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d52, flags 0x0, caps [audio/mpeg, mpegversion=(int)4, stream-format=(string)loas], tags [taglist, language-code=(string)en, audio-codec=(string)"MPEG-4\ AAC";], stream text 0x7425a570, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d51, flags 0x1, caps [subpicture/x-dvb], tags [taglist, language-code=(string)en, subtitle-codec=(string)"DVB\ subtitles";], > 0x7425ae50 unref 1->0
0:14:25.149154301 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c65b8 ref 1->2
0:14:25.149835648 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c65b8 unref 2->1
0:14:25.150809545 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740912c0 ref 1->2
0:14:25.152081563 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740912c0 unref 2->1
0:14:25.152201197 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:stream video 0x7425a438, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d4d, flags 0x0, caps [video/x-h264, stream-format=(string)byte-stream, alignment=(string)nal], tags [taglist, video-codec=(string)H.264;] 0x7425a438 unref 1->0
0:14:25.153051865 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c65b8 ref 1->2
0:14:25.153184572 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c65b8 unref 2->1
0:14:25.153273686 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740912c0 ref 1->2
0:14:25.153379726 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740912c0 unref 2->1
0:14:25.153958366 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:364:gst_object_dispose:stream video 0x7425a438, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d4d, flags 0x0, caps [video/x-h264, stream-format=(string)byte-stream, alignment=(string)nal], tags [taglist, video-codec=(string)H.264;] 0x7425a438 dispose
0:14:25.154484558 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:482:gst_mini_object_replace: replace 0x740912c0 (1) with (nil) (0)
0:14:25.154598255 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740912c0 unref 1->0
0:14:25.154713514 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:482:gst_mini_object_replace: replace 0x740c65b8 (1) with (nil) (0)
0:14:25.154816065 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c65b8 unref 1->0
0:14:25.154949397 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:406:gst_object_finalize:stream video 0x7425a438, ID , flags 0x0, caps [], tags [] 0x7425a438 finalize
0:14:25.155808295 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c5e00 ref 1->2
0:14:25.155946366 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e00 unref 2->1
0:14:25.156034907 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x74090c30 ref 1->2
0:14:25.156157458 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74090c30 unref 2->1
0:14:25.156264175 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:stream audio 0x7425a4a0, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d4e, flags 0x0, caps [audio/mpeg, mpegversion=(int)4, stream-format=(string)loas], tags [taglist, language-code=(string)en, audio-codec=(string)"MPEG-4\ AAC";] 0x7425a4a0 unref 1->0
0:14:25.156356206 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c5e00 ref 1->2
0:14:25.156478027 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e00 unref 2->1
0:14:25.156564328 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x74090c30 ref 1->2
0:14:25.156689692 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74090c30 unref 2->1
0:14:25.156792138 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:364:gst_object_dispose:stream audio 0x7425a4a0, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d4e, flags 0x0, caps [audio/mpeg, mpegversion=(int)4, stream-format=(string)loas], tags [taglist, language-code=(string)en, audio-codec=(string)"MPEG-4\ AAC";] 0x7425a4a0 dispose
0:14:25.156872606 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:482:gst_mini_object_replace: replace 0x74090c30 (1) with (nil) (0)
0:14:25.156970470 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74090c30 unref 1->0
0:14:25.157068073 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:482:gst_mini_object_replace: replace 0x740c5e00 (1) with (nil) (0)
0:14:25.157164322 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e00 unref 1->0
0:14:25.157281873 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:406:gst_object_finalize:stream audio 0x7425a4a0, ID , flags 0x0, caps [], tags [] 0x7425a4a0 finalize
0:14:25.157364008 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c5e28 ref 1->2
0:14:25.157527287 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e28 unref 2->1
0:14:25.157618328 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x74090c00 ref 1->2
0:14:25.157737181 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74090c00 unref 2->1
0:14:25.157868586 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:stream audio 0x7425a508, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d52, flags 0x0, caps [audio/mpeg, mpegversion=(int)4, stream-format=(string)loas], tags [taglist, language-code=(string)en, audio-codec=(string)"MPEG-4\ AAC";] 0x7425a508 unref 1->0
0:14:25.157961085 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c5e28 ref 1->2
0:14:25.158080042 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e28 unref 2->1
0:14:25.158165614 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x74090c00 ref 1->2
0:14:25.158279831 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74090c00 unref 2->1
0:14:25.158382330 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:364:gst_object_dispose:stream audio 0x7425a508, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d52, flags 0x0, caps [audio/mpeg, mpegversion=(int)4, stream-format=(string)loas], tags [taglist, language-code=(string)en, audio-codec=(string)"MPEG-4\ AAC";] 0x7425a508 dispose
0:14:25.158458996 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:482:gst_mini_object_replace: replace 0x74090c00 (1) with (nil) (0)
0:14:25.158555766 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x74090c00 unref 1->0
0:14:25.158652744 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:482:gst_mini_object_replace: replace 0x740c5e28 (1) with (nil) (0)
0:14:25.158750503 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e28 unref 1->0
0:14:25.158865711 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:406:gst_object_finalize:stream audio 0x7425a508, ID , flags 0x0, caps [], tags [] 0x7425a508 finalize
0:14:25.158944876 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c5e50 ref 2->3
0:14:25.159037948 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e50 unref 3->2
0:14:25.159120135 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740913b0 ref 1->2
0:14:25.159235551 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740913b0 unref 2->1
0:14:25.159338987 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:stream text 0x7425a570, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d51, flags 0x1, caps [subpicture/x-dvb], tags [taglist, language-code=(string)en, subtitle-codec=(string)"DVB\ subtitles";] 0x7425a570 unref 1->0
0:14:25.159427528 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740c5e50 ref 2->3
0:14:25.159518516 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e50 unref 3->2
0:14:25.159600963 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:349:gst_mini_object_ref: 0x740913b0 ref 1->2
0:14:25.159714296 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740913b0 unref 2->1
0:14:25.159814972 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:364:gst_object_dispose:stream text 0x7425a570, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d51, flags 0x1, caps [subpicture/x-dvb], tags [taglist, language-code=(string)en, subtitle-codec=(string)"DVB\ subtitles";] 0x7425a570 dispose
0:14:25.159888825 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:482:gst_mini_object_replace: replace 0x740913b0 (1) with (nil) (0)
0:14:25.159985074 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740913b0 unref 1->0
0:14:25.160099864 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:482:gst_mini_object_replace: replace 0x740c5e50 (2) with (nil) (0)
0:14:25.160196686 22978 0x74000c00 TRACE        GST_REFCOUNTING gstminiobject.c:429:gst_mini_object_unref: 0x740c5e50 unref 2->1
0:14:25.160294237 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:406:gst_object_finalize:stream text 0x7425a570, ID , flags 0x1, caps [], tags [] 0x7425a570 finalize

(gst-launch-1.0:22978): GStreamer-CRITICAL **: gst_stream_collection_get_size: assertion 'collection->priv->streams' failed

On the following objects, the ID field points at what looks like uninitialised data:

- 0x7425a570
- 0x7425a508
- 0x7425a4a0
- 0x7425a438

Zooming into the 0x7425a570 object, we find this:

minfrin@towerofpi9:~$ cat /mnt/stream/stream23.out | grep 0x7425a570
0:00:03.743320551 22978 0x74091350 TRACE        GST_REFCOUNTING gstobject.c:220:gst_object_init:<GstObject@0x7425a570> 0x7425a570 new
0:00:03.748383519 22978 0x74091350 TRACE        GST_REFCOUNTING gstobject.c:249:gst_object_ref:stream text 0x7425a570, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d51, flags 0x1, caps [subpicture/x-dvb], tags [taglist, language-code=(string)en, subtitle-codec=(string)"DVB\ subtitles";] 0x7425a570 ref 2->3
0:14:25.137106823 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:stream text 0x7425a570, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d51, flags 0x1, caps [subpicture/x-dvb], tags [taglist, language-code=(string)en, subtitle-codec=(string)"DVB\ subtitles";] 0x7425a570 unref 2->1
0:14:25.148977324 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:collection 0x7425ae50 (4 streams) < stream video 0x7425a438, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d4d, flags 0x0, caps [video/x-h264, stream-format=(string)byte-stream, alignment=(string)nal], tags [taglist, video-codec=(string)H.264;], stream audio 0x7425a4a0, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d4e, flags 0x0, caps [audio/mpeg, mpegversion=(int)4, stream-format=(string)loas], tags [taglist, language-code=(string)en, audio-codec=(string)"MPEG-4\ AAC";], stream audio 0x7425a508, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d52, flags 0x0, caps [audio/mpeg, mpegversion=(int)4, stream-format=(string)loas], tags [taglist, language-code=(string)en, audio-codec=(string)"MPEG-4\ AAC";], stream text 0x7425a570, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d51, flags 0x1, caps [subpicture/x-dvb], tags [taglist, language-code=(string)en, subtitle-codec=(string)"DVB\ subtitles";], > 0x7425ae50 unref 1->0
0:14:25.159338987 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:275:gst_object_unref:stream text 0x7425a570, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d51, flags 0x1, caps [subpicture/x-dvb], tags [taglist, language-code=(string)en, subtitle-codec=(string)"DVB\ subtitles";] 0x7425a570 unref 1->0
0:14:25.159814972 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:364:gst_object_dispose:stream text 0x7425a570, ID c05773e29ede60b2192639229d6f79c37840bfcf146a80ec243277440db8f12a/multi-program:20352/00001d51, flags 0x1, caps [subpicture/x-dvb], tags [taglist, language-code=(string)en, subtitle-codec=(string)"DVB\ subtitles";] 0x7425a570 dispose
0:14:25.160294237 22978 0x74000c00 TRACE        GST_REFCOUNTING gstobject.c:406:gst_object_finalize:stream text 0x7425a570, ID , flags 0x1, caps [], tags [] 0x7425a570 finalize

Questions:

- Are we unreffing the objects too many times?
- Why would 0x7425a570 be corrupt at the finalize step?
- What would dispose do that would corrupt the finalize step?
Comment 1 Sebastian Dröge (slomo) 2016-12-20 10:54:32 UTC 
Can you provide a testcase to reproduce this? Please also always put debug logs as attachment into bug reports.

Does valgrind tell you anything meaningful here?
Comment 2 minfrin 2016-12-20 11:07:45 UTC 
This is difficult to reproduce unfortunately, the crash only occurs after many hours of streaming.

This is a Raspberry Pi, so valgrind is not available, however AddressSantizer is not being triggered, I think the assertion is being triggered before AddressSanitizer has a chance to be tripped.

Would it be possible to answer the questions above, specifically the first one? I don't understand the ref values. We start with new, then we go from 2->3, then 2->1 (the 3->2 seems to be missing), then 1->0. Is this normal?

Then there is the dispose, which prints the values fine, and finalize, where the values are now missing with a corrupt ID. Is this normal? What does dispose do, what does finalize do?
Comment 3 Sebastian Dröge (slomo) 2016-12-20 11:17:33 UTC 
That 3->2 is missing suggests that it's just a g_object_unref() somewhere instead of a gst_object_unref(). E.g. in a GValue.

dispose() is called before finalize(), possible multiple times (as such it should be written in a way that allows it to be called safely multiple times). finalize() is the last thing that is called before the object disappears.
Comment 4 Vincent Penquerc'h 2017-03-31 09:40:55 UTC 
Created attachment 349030 [details] [review]
fix racy user-after-free
Comment 5 Tim-Philipp Müller 2017-03-31 10:03:56 UTC 
Could you explain how the patch works and how it fixes this issue? I don't quite see it.
Comment 6 Vincent Penquerc'h 2017-03-31 10:09:23 UTC 
The issue happens when the structure is printed by the logging subsystem: the object is included in the log, and this will cause the full object printout to be done there. However, after dispose, the queue was already cleared, so the access to it (to print the object) would assert, as the queue was already freed. The patch changes it so that the queue is merely empty, and only freed in _finalize.
Comment 7 Vincent Penquerc'h 2017-03-31 10:36:51 UTC 
commit efbacf1931d2f407e7f1c9f8f7dce994504a1188
Author: Vincent Penquerc'h <vincent.penquerch@collabora.co.uk>
Date:   Fri Mar 31 10:38:15 2017 +0100

    streamcollection: fix racy user-after-free
    
    The issue happens when the structure is printed by the logging
    subsystem: the object is included in the log, and this will cause the
    full object printout to be done there. However, after dispose, the queue
    was already cleared, so the access to it (to print the object) would
    assert, as the queue was already freed. The patch changes it so that the
    queue is merely empty, and only freed in _finalize.
    
    https://bugzilla.gnome.org/show_bug.cgi?id=776293
Comment 8 Vincent Penquerc'h 2017-03-31 10:39:22 UTC 
Hrm, mixed up, I got a commit-now mail from slomo, but for another patch, and thought it was this one till I went to change the patch status and saw it was still at none, so this one's merged now. Are you satisfied with the explanation here, or shall I revert it quick ?
Comment 9 Tim-Philipp Müller 2017-03-31 10:49:02 UTC 
We can leave it in for now, it's not harmful, I still just don't see the race :)

Does the print happen from within the dispose somehow, or why does it take place between dispose and finalize?

Someone must be doing an unref() for us to get into dispose. That same someone is not allowed to do anything else with that object afterwards, so unless we do this internally it looks like a refcounting or ordering bug elsewhere to me.

Do we have a stack trace from where the warning is triggered?

Sorry if I'm missing something obvious, I didn't look at the code in detail, it just doesn't seem right at first glance.
Comment 10 Vincent Penquerc'h 2017-03-31 10:55:37 UTC 
The dispose comes from the refcounting calling the logging subsystem, which prints the object:

+ Trace 237304

  • #0 g_logv
  • #1 g_log
  • #2 gst_stream_collection_get_size
    at gststreamcollection.c line 311
  • #3 gst_debug_print_object
    at gstinfo.c line 778
  • #4 gst_debug_print_object
    at gstinfo.c line 876
  • #5 gst_debug_log_default
    at gstinfo.c line 1159
  • #6 gst_debug_log_valist
    at gstinfo.c line 566
  • #7 gst_debug_log
    at gstinfo.c line 498
  • #8 gst_object_dispose
    at gstobject.c line 353
  • #9 g_object_unref
  • #10 mpegts_base_free_program
    at mpegtsbase.c line 484
  • #11 g_hash_table_foreach_remove_or_steal
  • #12 mpegts_base_reset
    at mpegtsbase.c line 210
  • #13 mpegts_base_change_state
    at mpegtsbase.c line 1836
  • #14 gst_element_change_state
    at gstelement.c line 2743
  • #15 gst_element_set_state_func
    at gstelement.c line 2697
  • #16 gst_bin_change_state_func
    at gstbin.c line 2589
  • #17 gst_bin_change_state_func
    at gstbin.c line 2931
  • #18 gst_element_change_state
    at gstelement.c line 2743
  • #19 gst_element_set_state_func
    at gstelement.c line 2697
  • #20 main
    at gst-launch.c line 1216 






Comment 11


Vincent Penquerc'h





          2017-03-31 11:01:12 UTC
        



Well, racy isn't right, actually. With this pipeline, I can get it 100% of the time:

G_DEBUG=fatal_warnings GST_DEBUG_FILE=gst.log GST_DEBUG=9,REFC*:2  gst-launch-1.0 -v filesrc location=/tmp/mpegts.gdp ! gdpdepay ! tsdemux ! identity silent=false ! ac3parse ! gdppay ! filesink location= test.gdp






Comment 12


Tim-Philipp Müller





          2017-03-31 11:04:58 UTC
        



Ok, that makes more sense. Thanks :)