Internal Data Stream Error
crossan007 opened this issue · 8 comments
crossan007 commented
This is with a Raspi3, and Camera module v2.1
GStreamer 1.10.4
Raspbian Version:
PRETTY_NAME="Raspbian GNU/Linux 9 (stretch)"
NAME="Raspbian GNU/Linux"
VERSION_ID="9"
VERSION="9 (stretch)"
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
First I tried the default pipeline, and received the same errors as below.
Since I'm running this over SSH, and I noticed that the plugin definition mentions that previews are enabled by default, I tried disabling the previews - no avail. I ended up with this pipeline, and still have no success:
Pipeline: gst-launch-1.0 rpicamsrc bitrate=10000 sensor-mode=1 preview=false preview-encoded=false use-stc=false do-timestamp=true ! fakesink
result:
Setting pipeline to PAUSED ...
Pipeline is live and does not need PREROLL ...
Setting pipeline to PLAYING ...
New clock: GstSystemClock
ERROR: from element /GstPipeline:pipeline0/GstRpiCamSrc:rpicamsrc0: Internal data stream error.
Additional debug info:
gstbasesrc.c(2950): gst_base_src_loop (): /GstPipeline:pipeline0/GstRpiCamSrc:rpicamsrc0:
streaming stopped, reason error (-5)
Execution ended after 0:00:00.330214825
Setting pipeline to PAUSED ...
Setting pipeline to READY ...
Setting pipeline to NULL ...
Freeing pipeline ...
with GST_DEBUG=4, the relevant failure output is as follows:
0:00:00.000550203 685 0x181de00 INFO GST_INIT gst.c:510:init_pre: Initializing GStreamer Core Library version 1.10.4
0:00:00.000816191 685 0x181de00 INFO GST_INIT gst.c:511:init_pre: Using library installed in /usr/lib/arm-linux-gnueabihf
0:00:00.000934367 685 0x181de00 INFO GST_INIT gst.c:522:init_pre: Linux raspberrypi 4.9.59-v7+ #1047 SMP Sun Oct 29 12:19:23 GMT 2017 armv7l
0:00:00.002436750 685 0x181de00 INFO GST_INIT gstmessage.c:126:_priv_gst_message_initialize: init messages
0:00:00.005431308 685 0x181de00 INFO GST_INIT gstcontext.c:83:_priv_gst_context_initialize: init contexts
0:00:00.008109931 685 0x181de00 INFO GST_PLUGIN_LOADING gstplugin.c:316:_priv_gst_plugin_initialize: registering 0 static plugins
0:00:00.008763676 685 0x181de00 INFO GST_PLUGIN_LOADING gstplugin.c:224:gst_plugin_register_static: registered static plugin "staticelements"
0:00:00.008842060 685 0x181de00 INFO GST_PLUGIN_LOADING gstplugin.c:226:gst_plugin_register_static: added static plugin "staticelements", result: 1
0:00:00.009010288 685 0x181de00 INFO GST_REGISTRY gstregistry.c:1738:ensure_current_registry: reading registry cache: /root/.cache/gstreamer-1.0/registry.arm.bin
0:00:00.130671186 685 0x181de00 INFO GST_REGISTRY gstregistrybinary.c:619:priv_gst_registry_binary_read_cache: loaded /root/.cache/gstreamer-1.0/registry.arm.bin in 0.121551 seconds
0:00:00.130913944 685 0x181de00 INFO GST_REGISTRY gstregistry.c:1594:scan_and_update_registry: Validating plugins from registry cache: /root/.cache/gstreamer-1.0/registry.arm.bin
0:00:00.134807192 685 0x181de00 INFO GST_REGISTRY gstregistry.c:1696:scan_and_update_registry: Registry cache has not changed
0:00:00.134862192 685 0x181de00 INFO GST_REGISTRY gstregistry.c:1773:ensure_current_registry: registry reading and updating done, result = 1
0:00:00.134900421 685 0x181de00 INFO GST_INIT gst.c:720:init_post: GLib runtime version: 2.50.3
0:00:00.134936670 685 0x181de00 INFO GST_INIT gst.c:722:init_post: GLib headers version: 2.50.3
0:00:00.134968076 685 0x181de00 INFO GST_INIT gst.c:723:init_post: initialized GStreamer successfully
0:00:00.135078180 685 0x181de00 INFO GST_PIPELINE gstparse.c:325:gst_parse_launch_full: parsing pipeline description 'rpicamsrc bitrate=1000000 ! filesink location=test.h264 '
0:00:00.140293552 685 0x181de00 INFO GST_PLUGIN_LOADING gstplugin.c:842:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstrpicamsrc.so" loaded
0:00:00.140374854 685 0x181de00 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "rpicamsrc"
0:00:00.142183015 685 0x181de00 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseSrc@0x197f450> adding pad 'src'
0:00:00.144119874 685 0x181de00 INFO GST_PLUGIN_LOADING gstplugin.c:842:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstcoreelements.so" loaded
0:00:00.144195498 685 0x181de00 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "filesink"
0:00:00.144560599 685 0x181de00 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseSink@0x19843b0> adding pad 'sink'
0:00:00.144723463 685 0x181de00 INFO filesink gstfilesink.c:301:gst_file_sink_set_location:<filesink0> filename : test.h264
0:00:00.144758046 685 0x181de00 INFO filesink gstfilesink.c:302:gst_file_sink_set_location:<filesink0> uri : file:///home/pi/test.h264
0:00:00.144816899 685 0x181de00 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "pipeline"
0:00:00.145101168 685 0x181de00 INFO GST_PIPELINE grammar.y:596:gst_parse_perform_link: linking some pad of GstRpiCamSrc named rpicamsrc0 to some pad of GstFileSink named filesink0 (0/0) with caps "(NULL)"
0:00:00.145168459 685 0x181de00 INFO GST_ELEMENT_PADS gstutils.c:1633:gst_element_link_pads_full: trying to link element rpicamsrc0:(any) to element filesink0:(any)
0:00:00.145214865 685 0x181de00 INFO GST_PADS gstutils.c:933:gst_pad_check_link: trying to link rpicamsrc0:src and filesink0:sink
0:00:00.145308354 685 0x181de00 INFO GST_PADS gstutils.c:1447:prepare_link_maybe_ghosting: rpicamsrc0 and filesink0 in same bin, no need for ghost pads
0:00:00.145370905 685 0x181de00 INFO GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link rpicamsrc0:src and filesink0:sink
0:00:00.145432988 685 0x181de00 INFO GST_PADS gstpad.c:2523:gst_pad_link_full: linked rpicamsrc0:src and filesink0:sink, successful
0:00:00.145472050 685 0x181de00 INFO GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event
0:00:00.145506737 685 0x181de00 INFO GST_EVENT gstpad.c:5652:gst_pad_send_event_unchecked:<rpicamsrc0:src> Received event on flushing pad. Discarding
Setting pipeline to PAUSED ...
0:00:00.145705225 685 0x181de00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<filesink0> current NULL pending VOID_PENDING, desired next READY
0:00:00.145971890 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<filesink0> completed state change to READY
0:00:00.146017150 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<filesink0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.146115899 685 0x181de00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'filesink0' changed state to 2(READY) successfully
0:00:00.146172461 685 0x181de00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current NULL pending VOID_PENDING, desired next READY
0:00:00.146215690 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to READY
0:00:00.146247200 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.146296053 685 0x181de00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 2(READY) successfully
0:00:00.146348084 685 0x181de00 INFO GST_STATES gstelement.c:2394:gst_element_continue_state:<pipeline0> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.146386938 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.146495843 685 0x181de00 INFO GST_STATES gstelement.c:2401:gst_element_continue_state:<pipeline0> continue state change READY to PAUSED, final PAUSED
0:00:00.146565478 685 0x181de00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<filesink0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.146631519 685 0x181de00 INFO GST_STATES gstbin.c:2975:gst_bin_change_state_func:<pipeline0> child 'filesink0' is changing state asynchronously to PAUSED
0:00:00.146672717 685 0x181de00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.153650679 685 0x181de00 INFO basesrc gstbasesrc.c:1343:gst_base_src_do_seek:<rpicamsrc0> seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.153830052 685 0x181de00 INFO task gsttask.c:456:gst_task_set_lock: setting stream lock 0x1980084 on task 0x198d028
0:00:00.153870416 685 0x181de00 INFO GST_PADS gstpad.c:5998:gst_pad_start_task:<rpicamsrc0:src> created task 0x198d028
0:00:00.154106039 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to PAUSED
0:00:00.154179164 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.154245257 685 0x181de00 INFO GST_STATES gstbin.c:3012:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 3(PAUSED) successfully without preroll
0:00:00.154269996 685 0x197b980 INFO GST_ELEMENT_PADS gstelement.c:913:gst_element_get_static_pad: no such pad 'sink' in element "rpicamsrc0"
0:00:00.154312861 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline0> completed state change to PAUSED
0:00:00.154348902 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.154351089 685 0x197b980 FIXME default gstutils.c:3826:gst_pad_create_stream_id_internal:<rpicamsrc0:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
Pipeline is live and does not need PREROLL ...
0:00:00.155116604 685 0x197b980 INFO GST_EVENT gstevent.c:808:gst_event_new_caps: creating caps event video/x-h264, width=(int)1920, height=(int)1080, framerate=(fraction)30/1, stream-format=(string)byte-stream, alignment=(string)nal, profile=(string)baseline
Setting pipeline to PLAYING ...
0:00:00.155557798 685 0x181de00 INFO GST_EVENT gstevent.c:1382:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:00.155657537 685 0x181de00 INFO bin gstbin.c:2798:gst_bin_do_latency_func:<pipeline0> configured latency of 0:00:00.000000000
0:00:00.155730140 685 0x181de00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<filesink0> current READY pending PAUSED, desired next PLAYING
0:00:00.155774775 685 0x181de00 INFO GST_STATES gstbin.c:2975:gst_bin_change_state_func:<pipeline0> child 'filesink0' is changing state asynchronously to PLAYING
0:00:00.155833733 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to PLAYING
0:00:00.155868108 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.155923003 685 0x181de00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 4(PLAYING) successfully
New clock: GstSystemClock
0:00:00.390730541 685 0x197b980 INFO GST_EVENT gstevent.c:889:gst_event_new_segment: creating segment event time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.390911372 685 0x197b980 INFO basesrc gstbasesrc.c:2847:gst_base_src_loop:<rpicamsrc0> marking pending DISCONT
0:00:00.391022257 685 0x197b980 INFO GST_STATES gstbin.c:3450:bin_handle_async_done:<pipeline0> setting state from PAUSED to PAUSED, pending PLAYING
0:00:00.391068663 685 0x197b980 INFO GST_STATES gstbin.c:3470:bin_handle_async_done:<pipeline0> continue state change, pending PLAYING
0:00:00.391288609 685 0x72a02920 INFO GST_STATES gstbin.c:3267:gst_bin_continue_func:<pipeline0> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.391526472 685 0x72a02920 INFO GST_EVENT gstevent.c:1382:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:00.391698449 685 0x72a02920 INFO bin gstbin.c:2798:gst_bin_do_latency_func:<pipeline0> configured latency of 0:00:00.000000000
0:00:00.391849281 685 0x72a02920 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<filesink0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.392003551 685 0x72a02920 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<filesink0> completed state change to PLAYING
0:00:00.392107925 685 0x72a02920 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<filesink0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.392257716 685 0x72a02920 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'filesink0' changed state to 4(PLAYING) successfully
0:00:00.392375840 685 0x72a02920 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:00.392480943 685 0x72a02920 INFO GST_STATES gstbin.c:2638:gst_bin_element_set_state:<rpicamsrc0> skipping transition from PLAYING to PLAYING
0:00:00.392586984 685 0x72a02920 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 4(PLAYING) successfully
0:00:00.392701670 685 0x72a02920 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline0> completed state change to PLAYING
0:00:00.392736462 685 0x72a02920 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.492233714 685 0x197b980 INFO basesrc gstbasesrc.c:2743:gst_base_src_loop:<rpicamsrc0> pausing after gst_base_src_get_range() = error
0:00:00.492303088 685 0x197b980 WARN basesrc gstbasesrc.c:2950:gst_base_src_loop:<rpicamsrc0> error: Internal data stream error.
0:00:00.492333609 685 0x197b980 WARN basesrc gstbasesrc.c:2950:gst_base_src_loop:<rpicamsrc0> error: streaming stopped, reason error (-5)
0:00:00.492423921 685 0x197b980 INFO GST_ERROR_SYSTEM gstelement.c:1890:gst_element_message_full_with_details:<rpicamsrc0> posting message: Internal data stream error.
0:00:00.492537253 685 0x197b980 INFO GST_ERROR_SYSTEM gstelement.c:1917:gst_element_message_full_with_details:<rpicamsrc0> posted error message: Internal data stream error.
0:00:00.492633971 685 0x197b980 INFO task gsttask.c:318:gst_task_func:<rpicamsrc0:src> Task going to paused
ERROR: from element /GstPipeline:pipeline0/GstRpiCamSrc:rpicamsrc0: Internal data stream error.
Additional debug info:
gstbasesrc.c(2950): gst_base_src_loop (): /GstPipeline:pipeline0/GstRpiCamSrc:rpicamsrc0:
streaming stopped, reason error (-5)
Execution ended after 0:00:00.336758936
Setting pipeline to PAUSED ...
0:00:00.492814803 685 0x181de00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<filesink0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:00.492865427 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<filesink0> completed state change to PAUSED
0:00:00.492899073 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<filesink0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:00.492951573 685 0x181de00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'filesink0' changed state to 3(PAUSED) successfully
0:00:00.492995739 685 0x181de00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:00.493040322 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to PAUSED
0:00:00.493071728 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:00.493117821 685 0x181de00 INFO GST_STATES gstbin.c:3012:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 3(PAUSED) successfully without preroll
0:00:00.493167977 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline0> completed state change to PAUSED
0:00:00.493200477 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
Setting pipeline to READY ...
0:00:00.493336569 685 0x181de00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<filesink0> current PAUSED pending VOID_PENDING, desired next READY
0:00:00.493416985 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<filesink0> completed state change to READY
0:00:00.493449798 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<filesink0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.493497141 685 0x181de00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'filesink0' changed state to 2(READY) successfully
0:00:00.493566620 685 0x197b980 INFO task gsttask.c:320:gst_task_func:<rpicamsrc0:src> Task resume from paused
0:00:00.543030378 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to READY
0:00:00.543096523 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.543162252 685 0x181de00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 2(READY) successfully
0:00:00.543223189 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline0> completed state change to READY
0:00:00.543256574 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.543350428 685 0x181de00 INFO GST_STATES gstbin.c:2110:gst_bin_get_state_func:<pipeline0> getting state
Setting pipeline to NULL ...
0:00:00.543452458 685 0x181de00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<filesink0> current READY pending VOID_PENDING, desired next NULL
0:00:00.543668342 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<filesink0> completed state change to NULL
0:00:00.543706675 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<filesink0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.543763653 685 0x181de00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'filesink0' changed state to 1(NULL) successfully
0:00:00.543808809 685 0x181de00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current READY pending VOID_PENDING, desired next NULL
0:00:00.543858757 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to NULL
0:00:00.543891934 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.543940267 685 0x181de00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 1(NULL) successfully
0:00:00.544078130 685 0x181de00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline0> completed state change to NULL
0:00:00.544113286 685 0x181de00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed READY to NULL (VOID_PENDING pending)
Freeing pipeline ...
0:00:00.544214691 685 0x181de00 INFO GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking rpicamsrc0:src(0x1980038) and filesink0:sink(0x1980188)
0:00:00.544278232 685 0x181de00 INFO GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked rpicamsrc0:src and filesink0:sink
0:00:00.544336201 685 0x181de00 INFO GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<pipeline0> removed child "filesink0"
0:00:00.544407763 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<filesink0> 0x19843b0 dispose
0:00:00.544443856 685 0x181de00 INFO GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<filesink0> removing pad 'sink'
0:00:00.544512033 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<filesink0> 0x19843b0 parent class dispose
0:00:00.544551147 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<filesink0> 0x19843b0 finalize
0:00:00.544584949 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<filesink0> 0x19843b0 finalize parent
0:00:00.544637657 685 0x181de00 INFO GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<pipeline0> removed child "rpicamsrc0"
0:00:00.544690052 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<rpicamsrc0> 0x197f450 dispose
0:00:00.544725000 685 0x181de00 INFO GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<rpicamsrc0> removing pad 'src'
0:00:00.544767291 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<rpicamsrc0> 0x197f450 parent class dispose
0:00:00.544816978 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<rpicamsrc0> 0x197f450 finalize
0:00:00.544850572 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<rpicamsrc0> 0x197f450 finalize parent
0:00:00.544886300 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<pipeline0> 0x19860a0 dispose
0:00:00.544977498 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<pipeline0> 0x19860a0 parent class dispose
0:00:00.545016039 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<pipeline0> 0x19860a0 finalize
0:00:00.545049320 685 0x181de00 INFO GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<pipeline0> 0x19860a0 finalize parent
0:00:00.545086976 685 0x181de00 INFO GST_INIT gst.c:989:gst_deinit: deinitializing GStreamer
0:00:00.555445797 685 0x181de00 INFO GST_INIT gst.c:1130:gst_deinit: deinitialized GStreamer
gst-inspect-1.0 rpicamsrc shows the expected output:
gst-inspect-1.0 rpicamsrc
Factory Details:
Rank none (0)
Long-name Raspberry Pi Camera Source
Klass Source/Video
Description Raspberry Pi camera module source
Author Jan Schmidt <jan@centricular.com>
Plugin Details:
Name rpicamsrc
Description Raspberry Pi Camera Source
Filename /usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstrpicamsrc.so
Version 1.0.0
License LGPL
Source module gstrpicamsrc
Binary package GStreamer
Origin URL http://gstreamer.net/
GObject
+----GInitiallyUnowned
+----GstObject
+----GstElement
+----GstBaseSrc
+----GstPushSrc
+----GstRpiCamSrc
crossan007 commented
Execution seems to end after ~ 0:00:00.336200142 +/- 00:00.0001
streaming stopped, reason error (-5)
Execution ended after 0:00:00.336540453
streaming stopped, reason error (-5)
Execution ended after 0:00:00.336652024
streaming stopped, reason error (-5)
Execution ended after 0:00:00.336200142
streaming stopped, reason error (-5)
Execution ended after 0:00:00.336654892
crossan007 commented
4fc608e seems to get stuck at 0:00:00.371406592 3558 0x72a02920 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending) when starting the pipeline:
GST_DEBUG=4 gst-launch-1.0 rpicamsrc bitrate=10000 sensor-mode=1 preview=false preview-encoded=false use-stc=false do-timestamp=true ! fakesink
0:00:00.000372449 3546 0x392e00 INFO GST_INIT gst.c:510:init_pre: Initializing GStreamer Core Library version 1.10.4
0:00:00.000633752 3546 0x392e00 INFO GST_INIT gst.c:511:init_pre: Using library installed in /usr/lib/arm-linux-gnueabihf
0:00:00.001347296 3546 0x392e00 INFO GST_INIT gst.c:522:init_pre: Linux raspberrypi 4.9.59-v7+ #1047 SMP Sun Oct 29 12:19:23 GMT 2017 armv7l
0:00:00.003238292 3546 0x392e00 INFO GST_INIT gstmessage.c:126:_priv_gst_message_initialize: init messages
0:00:00.006548772 3546 0x392e00 INFO GST_INIT gstcontext.c:83:_priv_gst_context_initialize: init contexts
0:00:00.009647167 3546 0x392e00 INFO GST_PLUGIN_LOADING gstplugin.c:316:_priv_gst_plugin_initialize: registering 0 static plugins
0:00:00.010576754 3546 0x392e00 INFO GST_PLUGIN_LOADING gstplugin.c:224:gst_plugin_register_static: registered static plugin "staticelements"
0:00:00.010660556 3546 0x392e00 INFO GST_PLUGIN_LOADING gstplugin.c:226:gst_plugin_register_static: added static plugin "staticelements", result: 1
0:00:00.011438788 3546 0x392e00 INFO GST_REGISTRY gstregistry.c:1738:ensure_current_registry: reading registry cache: /root/.cache/gstreamer-1.0/registry.arm.bin
0:00:00.140828639 3546 0x392e00 INFO GST_REGISTRY gstregistrybinary.c:619:priv_gst_registry_binary_read_cache: loaded /root/.cache/gstreamer-1.0/registry.arm.bin in 0.128548 seconds
0:00:00.141438120 3546 0x392e00 INFO GST_REGISTRY gstregistry.c:1594:scan_and_update_registry: Validating plugins from registry cache: /root/.cache/gstreamer-1.0/registry.arm.bin
0:00:00.145541728 3546 0x392e00 INFO GST_REGISTRY gstregistry.c:1696:scan_and_update_registry: Registry cache has not changed
0:00:00.145896520 3546 0x392e00 INFO GST_REGISTRY gstregistry.c:1773:ensure_current_registry: registry reading and updating done, result = 1
0:00:00.146245167 3546 0x392e00 INFO GST_INIT gst.c:720:init_post: GLib runtime version: 2.50.3
0:00:00.146583502 3546 0x392e00 INFO GST_INIT gst.c:722:init_post: GLib headers version: 2.50.3
0:00:00.146852930 3546 0x392e00 INFO GST_INIT gst.c:723:init_post: initialized GStreamer successfully
0:00:00.147407463 3546 0x392e00 INFO GST_PIPELINE gstparse.c:325:gst_parse_launch_full: parsing pipeline description 'rpicamsrc bitrate=10000 sensor-mode=1 preview=false preview-encoded=false use-stc=false do-timestamp=true ! fakesink '
0:00:00.153413316 3546 0x392e00 INFO GST_PLUGIN_LOADING gstplugin.c:842:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstrpicamsrc.so" loaded
0:00:00.153778473 3546 0x392e00 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "rpicamsrc"
0:00:00.155984522 3546 0x392e00 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseSrc@0x4f4540> adding pad 'src'
0:00:00.158356926 3546 0x392e00 INFO GST_PLUGIN_LOADING gstplugin.c:842:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstcoreelements.so" loaded
0:00:00.158430207 3546 0x392e00 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "fakesink"
0:00:00.159107293 3546 0x392e00 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseSink@0x4f8318> adding pad 'sink'
0:00:00.159334846 3546 0x392e00 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "pipeline"
0:00:00.159780837 3546 0x392e00 INFO GST_PIPELINE grammar.y:596:gst_parse_perform_link: linking some pad of GstRpiCamSrc named rpicamsrc0 to some pad of GstFakeSink named fakesink0 (0/0) with caps "(NULL)"
0:00:00.159846254 3546 0x392e00 INFO GST_ELEMENT_PADS gstutils.c:1633:gst_element_link_pads_full: trying to link element rpicamsrc0:(any) to element fakesink0:(any)
0:00:00.160001410 3546 0x392e00 INFO GST_PADS gstutils.c:933:gst_pad_check_link: trying to link rpicamsrc0:src and fakesink0:sink
0:00:00.160253963 3546 0x392e00 INFO GST_PADS gstutils.c:1447:prepare_link_maybe_ghosting: rpicamsrc0 and fakesink0 in same bin, no need for ghost pads
0:00:00.160400266 3546 0x392e00 INFO GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link rpicamsrc0:src and fakesink0:sink
0:00:00.160618965 3546 0x392e00 INFO GST_PADS gstpad.c:2523:gst_pad_link_full: linked rpicamsrc0:src and fakesink0:sink, successful
0:00:00.160662298 3546 0x392e00 INFO GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event
0:00:00.160696621 3546 0x392e00 INFO GST_EVENT gstpad.c:5652:gst_pad_send_event_unchecked:<rpicamsrc0:src> Received event on flushing pad. Discarding
Setting pipeline to PAUSED ...
0:00:00.161235946 3546 0x392e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fakesink0> current NULL pending VOID_PENDING, desired next READY
0:00:00.161443499 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<fakesink0> completed state change to READY
0:00:00.161479697 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.161712197 3546 0x392e00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 2(READY) successfully
0:00:00.161842302 3546 0x392e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current NULL pending VOID_PENDING, desired next READY
0:00:00.161963552 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to READY
0:00:00.161998865 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.162196105 3546 0x392e00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 2(READY) successfully
0:00:00.162315428 3546 0x392e00 INFO GST_STATES gstelement.c:2394:gst_element_continue_state:<pipeline0> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.162357564 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.162600586 3546 0x392e00 INFO GST_STATES gstelement.c:2401:gst_element_continue_state:<pipeline0> continue state change READY to PAUSED, final PAUSED
0:00:00.162804753 3546 0x392e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fakesink0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.162874076 3546 0x392e00 INFO GST_STATES gstbin.c:2975:gst_bin_change_state_func:<pipeline0> child 'fakesink0' is changing state asynchronously to PAUSED
0:00:00.163056629 3546 0x392e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.166586797 3546 0x392e00 INFO basesrc gstbasesrc.c:1343:gst_base_src_do_seek:<rpicamsrc0> seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.166913464 3546 0x392e00 INFO task gsttask.c:456:gst_task_set_lock: setting stream lock 0x4f5084 on task 0x500828
0:00:00.167049871 3546 0x392e00 INFO GST_PADS gstpad.c:5998:gst_pad_start_task:<rpicamsrc0:src> created task 0x500828
0:00:00.167333934 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to PAUSED
0:00:00.167501852 3546 0x4f0980 INFO GST_ELEMENT_PADS gstelement.c:913:gst_element_get_static_pad: no such pad 'sink' in element "rpicamsrc0"
0:00:00.167580967 3546 0x4f0980 FIXME default gstutils.c:3826:gst_pad_create_stream_id_internal:<rpicamsrc0:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:00:00.167405237 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.167931801 3546 0x392e00 INFO GST_STATES gstbin.c:3012:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 3(PAUSED) successfully without preroll
0:00:00.168228104 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline0> completed state change to PAUSED
0:00:00.168180760 3546 0x4f0980 INFO GST_EVENT gstevent.c:808:gst_event_new_caps: creating caps event video/x-h264, width=(int)1920, height=(int)1080, framerate=(fraction)30/1, stream-format=(string)byte-stream, alignment=(string)nal, profile=(string)baseline
0:00:00.168464303 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
Pipeline is live and does not need PREROLL ...
Setting pipeline to PLAYING ...
0:00:00.170185819 3546 0x392e00 INFO GST_EVENT gstevent.c:1382:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:00.170389726 3546 0x392e00 INFO bin gstbin.c:2798:gst_bin_do_latency_func:<pipeline0> configured latency of 0:00:00.000000000
0:00:00.170546653 3546 0x392e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fakesink0> current READY pending PAUSED, desired next PLAYING
0:00:00.170749362 3546 0x392e00 INFO GST_STATES gstbin.c:2975:gst_bin_change_state_func:<pipeline0> child 'fakesink0' is changing state asynchronously to PLAYING
0:00:00.170966551 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to PLAYING
0:00:00.171082541 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.171432438 3546 0x392e00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 4(PLAYING) successfully
New clock: GstSystemClock
0:00:00.395921664 3546 0x4f0980 INFO GST_EVENT gstevent.c:889:gst_event_new_segment: creating segment event time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.396094945 3546 0x4f0980 INFO basesrc gstbasesrc.c:2847:gst_base_src_loop:<rpicamsrc0> marking pending DISCONT
0:00:00.396208956 3546 0x4f0980 INFO GST_STATES gstbin.c:3450:bin_handle_async_done:<pipeline0> setting state from PAUSED to PAUSED, pending PLAYING
0:00:00.396250623 3546 0x4f0980 INFO GST_STATES gstbin.c:3470:bin_handle_async_done:<pipeline0> continue state change, pending PLAYING
0:00:00.396469947 3546 0x72a02920 INFO GST_STATES gstbin.c:3267:gst_bin_continue_func:<pipeline0> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.396638385 3546 0x72a02920 INFO GST_EVENT gstevent.c:1382:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:00.396743645 3546 0x72a02920 INFO bin gstbin.c:2798:gst_bin_do_latency_func:<pipeline0> configured latency of 0:00:00.000000000
0:00:00.396835052 3546 0x72a02920 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fakesink0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.396888646 3546 0x72a02920 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<fakesink0> completed state change to PLAYING
0:00:00.396924271 3546 0x72a02920 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.397000157 3546 0x72a02920 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 4(PLAYING) successfully
0:00:00.397046719 3546 0x72a02920 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:00.397083699 3546 0x72a02920 INFO GST_STATES gstbin.c:2638:gst_bin_element_set_state:<rpicamsrc0> skipping transition from PLAYING to PLAYING
0:00:00.397116980 3546 0x72a02920 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 4(PLAYING) successfully
0:00:00.397160991 3546 0x72a02920 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline0> completed state change to PLAYING
0:00:00.397192189 3546 0x72a02920 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
^Chandling interrupt.
Interrupt: Stopping pipeline ...
Execution ended after 0:00:18.554330627
Setting pipeline to PAUSED ...
0:00:18.727346716 3546 0x392e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fakesink0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:18.727845467 3546 0x392e00 INFO GST_STATES gstbin.c:2975:gst_bin_change_state_func:<pipeline0> child 'fakesink0' is changing state asynchronously to PAUSED
0:00:18.728283333 3546 0x392e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:18.755758736 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to PAUSED
0:00:18.756341238 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:18.757112074 3546 0x392e00 INFO GST_STATES gstbin.c:3012:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 3(PAUSED) successfully without preroll
0:00:18.757674628 3546 0x392e00 INFO GST_STATES gstbin.c:3441:bin_handle_async_done:<pipeline0> committing state from PLAYING to PAUSED, old pending PAUSED
0:00:18.758346974 3546 0x392e00 INFO GST_STATES gstbin.c:3461:bin_handle_async_done:<pipeline0> completed state change, pending VOID
0:00:18.758862653 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:18.759485832 3546 0x392e00 INFO GST_STATES gstelement.c:2409:gst_element_continue_state:<pipeline0> nothing pending
Setting pipeline to READY ...
0:00:18.760636721 3546 0x392e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fakesink0> current PAUSED pending VOID_PENDING, desired next READY
0:00:18.761239067 3546 0x4f0980 INFO basesrc gstbasesrc.c:2860:gst_base_src_loop:<rpicamsrc0> pausing after gst_pad_push() = flushing
0:00:18.761384745 3546 0x4f0980 INFO task gsttask.c:318:gst_task_func:<rpicamsrc0:src> Task going to paused
0:00:18.761699694 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<fakesink0> completed state change to READY
0:00:18.762148133 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:18.762522561 3546 0x392e00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 2(READY) successfully
0:00:18.762921521 3546 0x4f0980 INFO task gsttask.c:320:gst_task_func:<rpicamsrc0:src> Task resume from paused
0:00:18.824467869 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to READY
0:00:18.825112715 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:18.825763290 3546 0x392e00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 2(READY) successfully
0:00:18.826460428 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline0> completed state change to READY
0:00:18.826915377 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:18.827713713 3546 0x392e00 INFO GST_STATES gstbin.c:2110:gst_bin_get_state_func:<pipeline0> getting state
Setting pipeline to NULL ...
0:00:18.828919134 3546 0x392e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fakesink0> current READY pending VOID_PENDING, desired next NULL
0:00:18.829452938 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<fakesink0> completed state change to NULL
0:00:18.830139867 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:18.830671327 3546 0x392e00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 1(NULL) successfully
0:00:18.831181381 3546 0x392e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current READY pending VOID_PENDING, desired next NULL
0:00:18.831698831 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to NULL
0:00:18.831970342 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:18.832280812 3546 0x392e00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 1(NULL) successfully
0:00:18.833165086 3546 0x392e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline0> completed state change to NULL
0:00:18.833505191 3546 0x392e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed READY to NULL (VOID_PENDING pending)
Freeing pipeline ...
0:00:18.835028894 3546 0x392e00 INFO GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking rpicamsrc0:src(0x4f5038) and fakesink0:sink(0x4f5188)
0:00:18.835730198 3546 0x392e00 INFO GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked rpicamsrc0:src and fakesink0:sink
0:00:18.836525461 3546 0x392e00 INFO GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<pipeline0> removed child "fakesink0"
0:00:18.837595569 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<fakesink0> 0x4f8318 dispose
0:00:18.838206404 3546 0x392e00 INFO GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<fakesink0> removing pad 'sink'
0:00:18.838976667 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<fakesink0> 0x4f8318 parent class dispose
0:00:18.839470367 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<fakesink0> 0x4f8318 finalize
0:00:18.840154692 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<fakesink0> 0x4f8318 finalize parent
0:00:18.840935215 3546 0x392e00 INFO GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<pipeline0> removed child "rpicamsrc0"
0:00:18.841462144 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<rpicamsrc0> 0x4f4540 dispose
0:00:18.842208709 3546 0x392e00 INFO GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<rpicamsrc0> removing pad 'src'
0:00:18.843165483 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<rpicamsrc0> 0x4f4540 parent class dispose
0:00:18.843677881 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<rpicamsrc0> 0x4f4540 finalize
0:00:18.844348872 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<rpicamsrc0> 0x4f4540 finalize parent
0:00:18.845095906 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<pipeline0> 0x4fb0a0 dispose
0:00:18.846101014 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<pipeline0> 0x4fb0a0 parent class dispose
0:00:18.846902162 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<pipeline0> 0x4fb0a0 finalize
0:00:18.847497529 3546 0x392e00 INFO GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<pipeline0> 0x4fb0a0 finalize parent
0:00:18.848202427 3546 0x392e00 INFO GST_INIT gst.c:989:gst_deinit: deinitializing GStreamer
0:00:18.868367806 3546 0x392e00 INFO GST_INIT gst.c:1130:gst_deinit: deinitialized GStreamer
root@raspberrypi:/home/pi/gst-rpicamsrc# GST_DEBUG=4 gst-launch-1.0 rpicamsrc bitrate=10000 preview=false preview-encoded=false use-stc=false do-timestamp=true ! fakesink
0:00:00.000370105 3558 0x303e00 INFO GST_INIT gst.c:510:init_pre: Initializing GStreamer Core Library version 1.10.4
0:00:00.000674846 3558 0x303e00 INFO GST_INIT gst.c:511:init_pre: Using library installed in /usr/lib/arm-linux-gnueabihf
0:00:00.000747971 3558 0x303e00 INFO GST_INIT gst.c:522:init_pre: Linux raspberrypi 4.9.59-v7+ #1047 SMP Sun Oct 29 12:19:23 GMT 2017 armv7l
0:00:00.002442248 3558 0x303e00 INFO GST_INIT gstmessage.c:126:_priv_gst_message_initialize: init messages
0:00:00.005662363 3558 0x303e00 INFO GST_INIT gstcontext.c:83:_priv_gst_context_initialize: init contexts
0:00:00.008360965 3558 0x303e00 INFO GST_PLUGIN_LOADING gstplugin.c:316:_priv_gst_plugin_initialize: registering 0 static plugins
0:00:00.009111332 3558 0x303e00 INFO GST_PLUGIN_LOADING gstplugin.c:224:gst_plugin_register_static: registered static plugin "staticelements"
0:00:00.009193728 3558 0x303e00 INFO GST_PLUGIN_LOADING gstplugin.c:226:gst_plugin_register_static: added static plugin "staticelements", result: 1
0:00:00.009337479 3558 0x303e00 INFO GST_REGISTRY gstregistry.c:1738:ensure_current_registry: reading registry cache: /root/.cache/gstreamer-1.0/registry.arm.bin
0:00:00.120555659 3558 0x303e00 INFO GST_REGISTRY gstregistrybinary.c:619:priv_gst_registry_binary_read_cache: loaded /root/.cache/gstreamer-1.0/registry.arm.bin in 0.111070 seconds
0:00:00.120824931 3558 0x303e00 INFO GST_REGISTRY gstregistry.c:1594:scan_and_update_registry: Validating plugins from registry cache: /root/.cache/gstreamer-1.0/registry.arm.bin
0:00:00.124770985 3558 0x303e00 INFO GST_REGISTRY gstregistry.c:1696:scan_and_update_registry: Registry cache has not changed
0:00:00.124825100 3558 0x303e00 INFO GST_REGISTRY gstregistry.c:1773:ensure_current_registry: registry reading and updating done, result = 1
0:00:00.124859475 3558 0x303e00 INFO GST_INIT gst.c:720:init_post: GLib runtime version: 2.50.3
0:00:00.124894632 3558 0x303e00 INFO GST_INIT gst.c:722:init_post: GLib headers version: 2.50.3
0:00:00.124926351 3558 0x303e00 INFO GST_INIT gst.c:723:init_post: initialized GStreamer successfully
0:00:00.125060674 3558 0x303e00 INFO GST_PIPELINE gstparse.c:325:gst_parse_launch_full: parsing pipeline description 'rpicamsrc bitrate=10000 preview=false preview-encoded=false use-stc=false do-timestamp=true ! fakesink '
0:00:00.130478921 3558 0x303e00 INFO GST_PLUGIN_LOADING gstplugin.c:842:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstrpicamsrc.so" loaded
0:00:00.130562046 3558 0x303e00 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "rpicamsrc"
0:00:00.132372938 3558 0x303e00 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseSrc@0x4654b8> adding pad 'src'
0:00:00.134436694 3558 0x303e00 INFO GST_PLUGIN_LOADING gstplugin.c:842:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstcoreelements.so" loaded
0:00:00.134511955 3558 0x303e00 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "fakesink"
0:00:00.134940082 3558 0x303e00 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseSink@0x46a318> adding pad 'sink'
0:00:00.135046853 3558 0x303e00 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "pipeline"
0:00:00.135411177 3558 0x303e00 INFO GST_PIPELINE grammar.y:596:gst_parse_perform_link: linking some pad of GstRpiCamSrc named rpicamsrc0 to some pad of GstFakeSink named fakesink0 (0/0) with caps "(NULL)"
0:00:00.135488729 3558 0x303e00 INFO GST_ELEMENT_PADS gstutils.c:1633:gst_element_link_pads_full: trying to link element rpicamsrc0:(any) to element fakesink0:(any)
0:00:00.135535188 3558 0x303e00 INFO GST_PADS gstutils.c:933:gst_pad_check_link: trying to link rpicamsrc0:src and fakesink0:sink
0:00:00.135640292 3558 0x303e00 INFO GST_PADS gstutils.c:1447:prepare_link_maybe_ghosting: rpicamsrc0 and fakesink0 in same bin, no need for ghost pads
0:00:00.135714563 3558 0x303e00 INFO GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link rpicamsrc0:src and fakesink0:sink
0:00:00.135818939 3558 0x303e00 INFO GST_PADS gstpad.c:2523:gst_pad_link_full: linked rpicamsrc0:src and fakesink0:sink, successful
0:00:00.135876751 3558 0x303e00 INFO GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event
0:00:00.135957845 3558 0x303e00 INFO GST_EVENT gstpad.c:5652:gst_pad_send_event_unchecked:<rpicamsrc0:src> Received event on flushing pad. Discarding
Setting pipeline to PAUSED ...
0:00:00.136192169 3558 0x303e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fakesink0> current NULL pending VOID_PENDING, desired next READY
0:00:00.136255711 3558 0x303e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<fakesink0> completed state change to READY
0:00:00.136310190 3558 0x303e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.136455139 3558 0x303e00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 2(READY) successfully
0:00:00.136551754 3558 0x303e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current NULL pending VOID_PENDING, desired next READY
0:00:00.136604931 3558 0x303e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to READY
0:00:00.136637118 3558 0x303e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.136685192 3558 0x303e00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 2(READY) successfully
0:00:00.136735296 3558 0x303e00 INFO GST_STATES gstelement.c:2394:gst_element_continue_state:<pipeline0> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.136773108 3558 0x303e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.136910296 3558 0x303e00 INFO GST_STATES gstelement.c:2401:gst_element_continue_state:<pipeline0> continue state change READY to PAUSED, final PAUSED
0:00:00.136991390 3558 0x303e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fakesink0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.137076287 3558 0x303e00 INFO GST_STATES gstbin.c:2975:gst_bin_change_state_func:<pipeline0> child 'fakesink0' is changing state asynchronously to PAUSED
0:00:00.137137172 3558 0x303e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.140816143 3558 0x303e00 INFO basesrc gstbasesrc.c:1343:gst_base_src_do_seek:<rpicamsrc0> seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.141014320 3558 0x303e00 INFO task gsttask.c:456:gst_task_set_lock: setting stream lock 0x466084 on task 0x471828
0:00:00.141115362 3558 0x303e00 INFO GST_PADS gstpad.c:5998:gst_pad_start_task:<rpicamsrc0:src> created task 0x471828
0:00:00.141490416 3558 0x303e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to PAUSED
0:00:00.141568072 3558 0x303e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.141667239 3558 0x461980 INFO GST_ELEMENT_PADS gstelement.c:913:gst_element_get_static_pad: no such pad 'sink' in element "rpicamsrc0"
0:00:00.141769583 3558 0x461980 FIXME default gstutils.c:3826:gst_pad_create_stream_id_internal:<rpicamsrc0:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:00:00.141784167 3558 0x303e00 INFO GST_STATES gstbin.c:3012:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 3(PAUSED) successfully without preroll
0:00:00.141931719 3558 0x303e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline0> completed state change to PAUSED
0:00:00.141984584 3558 0x303e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
Pipeline is live and does not need PREROLL ...
0:00:00.142615472 3558 0x461980 INFO GST_EVENT gstevent.c:808:gst_event_new_caps: creating caps event video/x-h264, width=(int)1920, height=(int)1080, framerate=(fraction)30/1, stream-format=(string)byte-stream, alignment=(string)nal, profile=(string)baseline
Setting pipeline to PLAYING ...
0:00:00.143368026 3558 0x303e00 INFO GST_EVENT gstevent.c:1382:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:00.143465943 3558 0x303e00 INFO bin gstbin.c:2798:gst_bin_do_latency_func:<pipeline0> configured latency of 0:00:00.000000000
0:00:00.143551985 3558 0x303e00 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fakesink0> current READY pending PAUSED, desired next PLAYING
0:00:00.143645944 3558 0x303e00 INFO GST_STATES gstbin.c:2975:gst_bin_change_state_func:<pipeline0> child 'fakesink0' is changing state asynchronously to PLAYING
0:00:00.143713548 3558 0x303e00 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<rpicamsrc0> completed state change to PLAYING
0:00:00.143750892 3558 0x303e00 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<rpicamsrc0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.143841048 3558 0x303e00 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 4(PLAYING) successfully
New clock: GstSystemClock
0:00:00.370039765 3558 0x461980 INFO GST_EVENT gstevent.c:889:gst_event_new_segment: creating segment event time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.370218724 3558 0x461980 INFO basesrc gstbasesrc.c:2847:gst_base_src_loop:<rpicamsrc0> marking pending DISCONT
0:00:00.370346797 3558 0x461980 INFO GST_STATES gstbin.c:3450:bin_handle_async_done:<pipeline0> setting state from PAUSED to PAUSED, pending PLAYING
0:00:00.370415131 3558 0x461980 INFO GST_STATES gstbin.c:3470:bin_handle_async_done:<pipeline0> continue state change, pending PLAYING
0:00:00.370655236 3558 0x72a02920 INFO GST_STATES gstbin.c:3267:gst_bin_continue_func:<pipeline0> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.370866539 3558 0x72a02920 INFO GST_EVENT gstevent.c:1382:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:00.370970966 3558 0x72a02920 INFO bin gstbin.c:2798:gst_bin_do_latency_func:<pipeline0> configured latency of 0:00:00.000000000
0:00:00.371053258 3558 0x72a02920 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fakesink0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.371104977 3558 0x72a02920 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<fakesink0> completed state change to PLAYING
0:00:00.371140758 3558 0x72a02920 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.371214561 3558 0x72a02920 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 4(PLAYING) successfully
0:00:00.371260550 3558 0x72a02920 INFO GST_STATES gstbin.c:2521:gst_bin_element_set_state:<rpicamsrc0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:00.371298311 3558 0x72a02920 INFO GST_STATES gstbin.c:2638:gst_bin_element_set_state:<rpicamsrc0> skipping transition from PLAYING to PLAYING
0:00:00.371331696 3558 0x72a02920 INFO GST_STATES gstbin.c:2969:gst_bin_change_state_func:<pipeline0> child 'rpicamsrc0' changed state to 4(PLAYING) successfully
0:00:00.371374978 3558 0x72a02920 INFO GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline0> completed state change to PLAYING
0:00:00.371406592 3558 0x72a02920 INFO GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
crossan007 commented
currently trying with a "fresh" version of GStreamer from git with steps from @thaytan:
step 1 is 'apt-get build-dep' for all the modules, to get the build dependencies installed
step 2 is use https://cgit.freedesktop.org/gstreamer/gstreamer/plain/scripts/create-uninstalled-setup.sh to compile the GStreamer modules on top
crossan007 commented
This seems to work when using gst-launch-1.0 version 1.13.0 instead of gst-launch-1.0 version 1.10.4
thaytan commented
I don't understand what difference 1.13.0 would make vs 1.10.4. As I mentioned on IRC, I've tried rpicamsrc with lots of versions of GStreamer and not encountered that problem. It definitely works for me against 1.4.4 and git master 1.13.0.1
crossan007 commented
super weird. I'll try it with a fresh raspian image tonight.
crossan007 commented
Not exactly sure what caused my first attempt to fail so miserably, but a clean image of 2017-09-07-raspbian-stretch-lite.zip with the install guide in this repo's README.md worked with only one small hiccup:
The first time I ran it, I got one Internal data stream error:
pi@raspberrypi:~ $ gst-launch-1.0 rpicamsrc bitrate=1000000 ! filesink location=test.h264
Setting pipeline to PAUSED ...
Pipeline is live and does not need PREROLL ...
Setting pipeline to PLAYING ...
New clock: GstSystemClock
ERROR: from element /GstPipeline:pipeline0/GstRpiCamSrc:rpicamsrc0: Internal data stream error.
Additional debug info:
gstbasesrc.c(2950): gst_base_src_loop (): /GstPipeline:pipeline0/GstRpiCamSrc:rpicamsrc0:
streaming stopped, reason error (-5)
Execution ended after 0:00:03.398609582
Setting pipeline to PAUSED ...
Setting pipeline to READY ...
Setting pipeline to NULL ...
Freeing pipeline ...
All subsequent runs seem to be fine.
I'll close the issue.
thaytan commented
I think the generic internal data error is the camera taking too long to start and the new timeout code triggering an error. Perhaps 500ms is still not long enough of a timeout for the first frame. In any case, I need to make it post a more useful and recognisable error when the timeout happens.