GNOME Bugzilla – Bug 784510
HLS/playbin: bus receives EOS on potential re-buffering
Last modified: 2017-07-13 12:46:58 UTC
I think this is a regression compared to 1.10. It seems like playbin for a HLS URI sends an EOS instead of potential buffering. Sample app I tested with is here: https://github.com/fzwoch/twit-twat Try "./twit-twat --channel rocketbeanstv" for testing. This is a live channel that usually is online 24/7. Any other channel should show the issue as well though. It works fine with GStreamer 1.10 (needs 1.10.5 or higher due to a .m3u8 parsing fix). On GStreamer 1.12 The application reports an EOS pretty quickly. When comparing the behavior it feels like 1.10 pauses the stream for re-buffering, or in general runs out of data for a short period of time but then recovers and continues. 1.12 simply stops and reports an EOS. I assume it occurs on buffer under runs as the behavior on 1.12 can be impacted by adding a "latency" option to the playbin. For example setting a latency of 4 seconds makes the stream to run pretty consistently - I guess because buffering will be less likely in this case.
Here is the some playbin debug output for GStreamer 1.12.1: 0:00:13.684339933 4234 0x55c372b40a30 DEBUG playbin gstplaybin2.c:3269:notify_tags_cb:<playbin0> Tags on pad <inputselector1:sink_0> with stream id 0 and type 0 have changed 0:00:13.755361506 4234 0x55c372b40a30 DEBUG playbin gstplaybin2.c:3269:notify_tags_cb:<playbin0> Tags on pad <inputselector1:sink_0> with stream id 0 and type 0 have changed 0:00:14.682746016 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:3269:notify_tags_cb:<playbin0> Tags on pad <inputselector0:sink_0> with stream id 0 and type 2 have changed 0:00:16.317433925 4234 0x55c372b40a30 DEBUG playbin gstplaybin2.c:3269:notify_tags_cb:<playbin0> Tags on pad <inputselector1:sink_0> with stream id 0 and type 0 have changed 0:00:17.243068434 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:3269:notify_tags_cb:<playbin0> Tags on pad <inputselector0:sink_0> with stream id 0 and type 2 have changed 0:00:18.273241547 4234 0x55c372b40a30 DEBUG playbin gstplaybin2.c:3269:notify_tags_cb:<playbin0> Tags on pad <inputselector1:sink_0> with stream id 0 and type 0 have changed 0:00:19.242496401 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:3269:notify_tags_cb:<playbin0> Tags on pad <inputselector0:sink_0> with stream id 0 and type 2 have changed 0:00:19.482316592 4234 0x55c372b40a30 DEBUG playbin gstplaybin2.c:3269:notify_tags_cb:<playbin0> Tags on pad <inputselector1:sink_0> with stream id 0 and type 0 have changed 0:00:20.692801158 4234 0x55c372b40a30 DEBUG playbin gstplaybin2.c:3269:notify_tags_cb:<playbin0> Tags on pad <inputselector1:sink_0> with stream id 0 and type 0 have changed 0:00:21.642926388 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:3269:notify_tags_cb:<playbin0> Tags on pad <inputselector0:sink_0> with stream id 0 and type 2 have changed 0:00:22.682860160 4234 0x55c372b40a30 DEBUG playbin gstplaybin2.c:3846:drained_cb:<playbin0> about to finish in group 0x55c3731b60c8 0:00:22.682907775 4234 0x55c372b40a30 DEBUG playbin gstplaybin2.c:5597:setup_next_source:<playbin0> setup sources 0:00:22.682925829 4234 0x55c372b40a30 DEBUG playbin gstplaybin2.c:5633:setup_next_source:<playbin0> no next group 0:00:23.682677740 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:3846:drained_cb:<playbin0> about to finish in group 0x55c3731b60c8 0:00:23.682702206 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:5597:setup_next_source:<playbin0> setup sources 0:00:23.682708458 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:5633:setup_next_source:<playbin0> no next group 0:00:23.682716704 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:3846:drained_cb:<playbin0> about to finish in group 0x55c3731b60c8 0:00:23.682725235 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:5597:setup_next_source:<playbin0> setup sources 0:00:23.682733468 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:5633:setup_next_source:<playbin0> no next group 0:00:23.682745311 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:3846:drained_cb:<playbin0> about to finish in group 0x55c3731b60c8 0:00:23.682752799 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:5597:setup_next_source:<playbin0> setup sources 0:00:23.682760095 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:5633:setup_next_source:<playbin0> no next group 0:00:23.682770527 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:3846:drained_cb:<playbin0> about to finish in group 0x55c3731b60c8 0:00:23.682777551 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:5597:setup_next_source:<playbin0> setup sources 0:00:23.682785158 4234 0x55c372b40c00 DEBUG playbin gstplaybin2.c:5633:setup_next_source:<playbin0> no next group 0:00:23.931527190 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:3579:pad_removed_cb:<playbin0> pad uridecodebin0:src_0 removed from group 0x55c3731b60c8 0:00:23.931551139 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:3622:pad_removed_cb:<playbin0> pad 0x7f7a90098030 removed from array 0:00:23.931555114 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:3642:pad_removed_cb:<playbin0> all combiner sinkpads removed 0:00:23.931558762 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:3643:pad_removed_cb:<playbin0> removing combiner 0x55c37325c5b0 0:00:23.931635857 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:3579:pad_removed_cb:<playbin0> pad uridecodebin0:src_1 removed from group 0x55c3731b60c8 0:00:23.931645969 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:3622:pad_removed_cb:<playbin0> pad 0x7f7a90098320 removed from array 0:00:23.931648952 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:3642:pad_removed_cb:<playbin0> all combiner sinkpads removed 0:00:23.931651462 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:3643:pad_removed_cb:<playbin0> removing combiner 0x55c37325c710 0:00:23.931976999 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:5657:save_current_group:<playbin0> save current group 0:00:23.931983423 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:5499:deactivate_group:<playbin0> unlinking group 0x55c3731b60c8 0:00:23.931986852 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:5506:deactivate_group:<playbin0> unlinking combiner audio/ 0:00:23.931989674 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:5506:deactivate_group:<playbin0> unlinking combiner video/ 0:00:23.931992272 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:5506:deactivate_group:<playbin0> unlinking combiner text/ 0:00:23.932012745 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:5680:groups_set_locked_state:<playbin0> setting locked state to 0 on all groups 0:00:23.932017473 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:5166:group_set_locked_state_unlocked:<playbin0> locked_state 0 on group 0x55c3731b5e08 0:00:23.932021014 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:5166:group_set_locked_state_unlocked:<playbin0> locked_state 0 on group 0x55c3731b60c8 0:00:23.932227143 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:5680:groups_set_locked_state:<playbin0> setting locked state to 1 on all groups 0:00:23.932233010 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:5166:group_set_locked_state_unlocked:<playbin0> locked_state 1 on group 0x55c3731b5e08 0:00:23.932236239 4234 0x55c372868f90 DEBUG playbin gstplaybin2.c:5166:group_set_locked_state_unlocked:<playbin0> locked_state 1 on group 0x55c3731b60c8 On GStreamer 1.10.x the log simply shows the inputselector messages and eventually some buffering messages.
Fixed in upstream bug.