GNOME Bugzilla – Bug 684285
basetransform: allocates from an inactive pool
Last modified: 2012-09-18 19:51:57 UTC
In default_prepare_output_buffer, basetransform tries to allocate from a bufferpool and 99.9% of the time the returned buffer is valid. On transition from PAUSED to READY however, when a basetransform element is before a queue, the element after the queue can deactivate the bufferpool before basetransform has changed state from PAUSED to READY. The buffer returned by the pool will then be invalid. Trace/Log: 0:00:08.457698219 28301 0x617a00 LOG bufferpool gstbufferpool.c:436:gst_buffer_pool_set_active:<xvimagebufferpool0> active 0 0:00:08.457710511 28301 0x617a00 LOG bufferpool gstbufferpool.c:466:gst_buffer_pool_set_active:<xvimagebufferpool0> outstanding buffers 1 0:00:08.457722594 28301 0x617a00 DEBUG GST_STATES gstelement.c:2602:gst_element_change_state:<xvimagesink0> element changed state SUCCESS 0:00:08.457735026 28301 0x617a00 INFO GST_STATES gstelement.c:2295:gst_element_continue_state:<xvimagesink0> completed state change to READY 0:00:08.457747108 28301 0x617a00 INFO GST_STATES gstelement.c:2200:_priv_gst_element_state_changed:<xvimagesink0> notifying about state-changed PLAYING to READY (VOID_PENDING pending) 0:00:08.457760378 28301 0x617a00 TRACE default <snip> 0:00:08.516582455 28301 0x617a00 INFO GST_STATES gstbin.c:2208:gst_bin_element_set_state:<queue0> current PAUSED pending VOID_PENDING, desired next READY 0:00:08.516630716 28301 0x617a00 DEBUG GST_STATES gstelement.c:2445:gst_element_set_state_func:<queue0> set_state to READY 0:00:08.516642798 28301 0x617a00 DEBUG GST_STATES gstelement.c:2470:gst_element_set_state_func:<queue0> setting target state to READY 0:00:08.516654881 28301 0x617a00 DEBUG GST_STATES gstelement.c:2483:gst_element_set_state_func:<queue0> current PAUSED, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS 0:00:08.516668011 28301 0x617a00 DEBUG GST_STATES gstelement.c:2517:gst_element_set_state_func:<queue0> final: setting state from PAUSED to READY 0:00:08.516681211 28301 0x617a00 LOG GST_STATES gstelement.c:2763:gst_element_change_state_func:<queue0> default handler tries setting state from PAUSED to READY (001a) 0:00:08.516694691 28301 0x617a00 DEBUG GST_ELEMENT_PADS gstelement.c:2706:gst_element_pads_activate:<queue0> deactivate pads 0:00:08.516737504 28301 0x617a00 DEBUG GST_PADS gstpad.c:949:gst_pad_set_active:<queue0:src> deactivating pad from push mode 0:00:08.516764532 28301 0x617a00 DEBUG GST_PADS gstpad.c:841:pre_activate:<queue0:src> setting PAD_MODE NONE, set flushing 0:00:08.434238533 28301 0x720190 TRACE gldisplay gstgldisplay.c:558:gst_gl_display_thread_use_fbo: Binding v1 FBO 1 dimensions:320x240 with texture:13 0:00:08.516972589 28301 0x7201e0 LOG queue_dataflow gstqueue.c:1149:gst_queue_loop:<queue0> (queue0:src) received ADD wakeup: 0 of 0-200 buffers, 0 of 0-10485760 bytes, 0 of 0-1000000000 ns, 0 items 0:00:08.516990957 28301 0x7201e0 DEBUG GST_PADS gstpad.c:5200:gst_pad_pause_task:<queue0:src> pause task 0:00:08.517004367 28301 0x7201e0 DEBUG task gsttask.c:662:gst_task_set_state:<queue0:src> Changing task 0x735000 to state 2 0:00:08.517016729 28301 0x7201e0 LOG queue_dataflow gstqueue.c:1178:gst_queue_loop:<queue0> pause task, reason: flushing 0:00:08.546668542 28301 0x7201e0 INFO task gsttask.c:300:gst_task_func:<queue0:src> Task going to paused 0:00:08.517045433 28301 0x617a00 DEBUG GST_PADS gstpad.c:5248:gst_pad_stop_task:<queue0:src> stop task 0:00:08.546710097 28301 0x617a00 DEBUG task gsttask.c:662:gst_task_set_state:<queue0:src> Changing task 0x735000 to state 1 0:00:08.546731888 28301 0x7201e0 INFO task gsttask.c:302:gst_task_func:<queue0:src> Task resume from paused 0:00:08.546745367 28301 0x7201e0 DEBUG GST_PADS gstpad.c:5070:do_stream_status:<queue0:src> doing stream-status 2 0:00:08.546802777 28301 0x7201e0 LOG GST_MESSAGE gstmessage.c:281:gst_message_new_custom: source src: creating new message 0x7fffe0002980 stream-status 0:00:08.546835183 28301 0x7201e0 DEBUG GST_PADS gstpad.c:5099:do_stream_status:<queue0:src> posting stream-status 2 0:00:08.546980103 28301 0x617a00 DEBUG task gsttask.c:789:gst_task_join:<queue0:src> Joining task 0x735000, thread 0x617a00 0:00:08.547115246 28301 0x711e80 DEBUG basesrc gstbasesrc.c:2197:gst_base_src_do_sync:<gltestsrc0> no sync needed 0:00:08.547137805 28301 0x711e80 DEBUG basesrc gstbasesrc.c:2396:gst_base_src_get_range:<gltestsrc0> buffer ok 0:00:08.547163786 28301 0x711e80 LOG GST_SCHEDULING gstpad.c:3616:gst_pad_chain_data_unchecked:<glfilterlaplacian0:sink> calling chainfunction &gst_base_transform_chain with buffer 0x7fffe00090b0, pts 0:00:00.200000000, dts 99:99:99.999999999, dur 0:00:00.033333333, size 115200, offset 6, offset_end 7 0:00:08.547187532 28301 0x711e80 DEBUG basetransform gstbasetransform.c:1932:gst_base_transform_handle_buffer:<glfilterlaplacian0> handling buffer 0x7fffe00090b0 of size 115200 and offset 6 0:00:08.547200243 28301 0x711e80 DEBUG basetransform gstbasetransform.c:2016:gst_base_transform_handle_buffer:<glfilterlaplacian0> calling prepare buffer 0:00:08.547215957 28301 0x711e80 DEBUG basetransform gstbasetransform.c:1545:default_prepare_output_buffer:<glfilterlaplacian0> using pool alloc 0:00:08.547226992 28301 0x711e80 DEBUG bufferpool gstbufferpool.c:1021:default_acquire_buffer:<xvimagebufferpool0> we are flushing 0:00:08.547236979 28301 0x711e80 DEBUG basetransform gstbasetransform.c:1668:default_copy_metadata:<glfilterlaplacian0> copying metadata (gst-launch-1.0:28301): GStreamer-CRITICAL **: gst_mini_object_is_writable: Program received signal SIGTRAP, Trace/breakpoint trap.
+ Trace 230868
Thread 140737103795968 (LWP 28309)
Continuing. 2:02:52.298974593 28301 0x711e80 WARN basetransform gstbasetransform.c:1694:default_copy_metadata:<glfilterlaplacian0> buffer (nil) not writable 2:02:52.299020408 28301 0x711e80 WARN basetransform gstbasetransform.c:1589:default_prepare_output_buffer:<glfilterlaplacian0> warning: could not copy metadata 2:02:52.299275398 28301 0x711e80 INFO GST_ERROR_SYSTEM gstelement.c:1802:gst_element_message_full:<glfilterlaplacian0> posting message: could not copy metadata 2:02:52.299888185 28301 0x711e80 INFO GST_ERROR_SYSTEM gstelement.c:1825:gst_element_message_full:<glfilterlaplacian0> posted warning message: could not copy metadata 2:02:52.299986731 28301 0x711e80 LOG GST_BUFFER gstbuffer.c:492:_gst_buffer_dispose: release 0x7fffe00090b0 to pool 0x70b1e0 2:02:52.300023048 28301 0x711e80 LOG bufferpool gstbufferpool.c:1119:default_release_buffer:<glbufferpool0> released buffer 0x7fffe00090b0 2:02:52.300051892 28301 0x711e80 LOG GST_POLL gstpoll.c:186:raise_wakeup: 0x7fffe0003050: raise 2:02:52.300126622 28301 0x711e80 WARN basetransform gstbasetransform.c:2082:gst_base_transform_handle_buffer:<glfilterlaplacian0> could not get buffer from pool: flushing 2:02:52.300161054 28301 0x711e80 LOG GST_SCHEDULING gstpad.c:3622:gst_pad_chain_data_unchecked:<glfilterlaplacian0:sink> called chainfunction &gst_base_transform_chain with buffer 0x7fffe00090b0, returned flushing 2:02:52.300234317 28301 0x711e80 INFO basesrc gstbasesrc.c:2700:gst_base_src_loop:<gltestsrc0> pausing after gst_pad_push() = flushing 2:02:52.300264489 28301 0x711e80 DEBUG basesrc gstbasesrc.c:2736:gst_base_src_loop:<gltestsrc0> pausing task, reason flushing and the pipeline shuts down properly.
Created attachment 224607 [details] [review] do not copy meta when buffer is null
I commited a slightly more elaborate version that checks and returns the actual return value. commit 0ea3675cf45a16030477184c5203d5c06773f939 Author: Wim Taymans <wim.taymans@collabora.co.uk> Date: Tue Sep 18 21:49:41 2012 +0200 basetransform: check acquire result value Check the result value from _buffer_pool_acquire() and return the value when allocation failed. Fixes https://bugzilla.gnome.org/show_bug.cgi?id=684285