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 779053 - gstplayer: Meet seek hang when trying to seek http streaming clips
gstplayer: Meet seek hang when trying to seek http streaming clips
Status: RESOLVED NOTGNOME
Product: GStreamer
Classification: Platform
Component: gst-plugins-bad
1.10.x
Other Linux
: Normal major
: git master
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2017-02-22 07:21 UTC by Lyon
Modified: 2017-03-14 10:19 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
log_gstplayer with GST_DEBUG=gst-player:6 (85.29 KB, application/octet-stream)
2017-02-22 10:56 UTC, Lyon
Details
log_without_gstplayer with GST_DEBUG=4 (294.60 KB, application/octet-stream)
2017-02-22 11:10 UTC, Lyon
Details
log without gstplayer with GST_DEBUG=6 (2.67 MB, application/x-gzip)
2017-02-24 09:01 UTC, Lyon
Details
log with gstplayer export GST_DEBUG=6 (1.88 MB, application/x-gzip)
2017-02-27 03:49 UTC, Lyon
Details
tread backtrace (13.93 KB, text/plain)
2017-02-27 10:14 UTC, Lyon
Details
thread apply all bt with gst-play (33.09 KB, text/plain)
2017-02-28 02:17 UTC, Lyon
Details
thread apply all bt with gst-play (35.74 KB, text/plain)
2017-02-28 06:30 UTC, Lyon
Details

Description Lyon 2017-02-22 07:21:03 UTC
Hi, Slomo,
     I met some seek issue when I am using new gstplayer high level API.
     When I tried to seek some http streaming clips, it will hang and seems gstreamer state change failed somewhere.
     I also tried with your gst-play application (which using the new gstplayer API), using command line: ./gst-play http://10.192.225.205/streaming/http/H264_BP11_352x288_25_1536_AAC_11_64_1_friendsr.mp4 --interactive

and using right-arrow to seek,  it will hang after gst_player_seek_interal_locked seek rate is set.

the log as below:
 0:00:03.791108727 12364  0x15b0800 DEBUG             gst-player gstplayer.c:1572:state_changed_cb:<player0> Changed state old: PLAYING new: PAUSED pending: VOID_PENDING
0:00:03.791881105 12364  0x15b0800 DEBUG             gst-player gstplayer.c:1644:state_changed_cb:<player0> Seeking now that we reached PAUSED state
0:00:03.793672206 12364  0x15b0800 DEBUG             gst-player gstplayer.c:3045:gst_player_seek_internal_locked:<player0> Seek with rate 1.00 to 0:00:04.557188000

if I play the clips locally, these clips can seek successfully.

Do you happen to meet such kind of issue?


Besides, when I tried to set rate with some local clips with text tracks involved, if we set rate to 4 and then set to 2 quickly, it will also meet the hang issue.

Thanks
Lyon
Comment 1 Sebastian Dröge (slomo) 2017-02-22 09:22:15 UTC
The stream you provide is not accessible here.

Does seeking work without GstPlayer, e.g. with the gst-play-1.0 from gst-plugins-base? Do you use any proprietary elements in your pipeline here?
Comment 2 Lyon 2017-02-22 10:06:31 UTC
(In reply to Sebastian Dröge (slomo) from comment #1)
> The stream you provide is not accessible here.
> 
> Does seeking work without GstPlayer, e.g. with the gst-play-1.0 from
> gst-plugins-base? Do you use any proprietary elements in your pipeline here?

If I use gst-play-1.0 that without GstPlayer, the seek works fine.

Actually I do use our own demux plugin, but if without GstPlayer, the http streaming seek works fine. Is there anything I should pay attention by using GstPlayer
Comment 3 Sebastian Dröge (slomo) 2017-02-22 10:09:25 UTC
Not really. Can you provide a debug log? With GST_DEBUG=gstplayer:6 and another with GST_DEBUG=6?
Comment 4 Lyon 2017-02-22 10:56:51 UTC
Created attachment 346426 [details]
log_gstplayer with GST_DEBUG=gst-player:6
Comment 5 Lyon 2017-02-22 11:10:14 UTC
Created attachment 346427 [details]
log_without_gstplayer with GST_DEBUG=4

Please see attached log, Thanks
Comment 6 Sebastian Dröge (slomo) 2017-02-23 19:07:06 UTC
(In reply to Lyon from comment #5)
> Created attachment 346427 [details]
> log_without_gstplayer with GST_DEBUG=4
> 
> Please see attached log, Thanks

This should also be with 6, not 4.
Comment 7 Lyon 2017-02-24 09:01:24 UTC
Created attachment 346617 [details]
log without gstplayer with GST_DEBUG=6

Sorry, the previous GST_DEBUG=6 log size is too large to upload.
I created a tar ball and uploaded again, please see attached file
Thanks
Lyon
Comment 8 Sebastian Dröge (slomo) 2017-02-25 10:48:21 UTC
The GST_DEBUG=6 log does not contain any debug output from GstPlayer. Are you using something else in there?

Please provide a full log with GstPlayer and everything at debug level 6.
Comment 9 Lyon 2017-02-27 03:49:36 UTC
Created attachment 346786 [details]
log with gstplayer export GST_DEBUG=6

Please see attched file for GST_DEBUG=6 with gstplayer.
previous one is without gstplayer.
Comment 10 Lyon 2017-02-27 03:50:31 UTC
 it seems somehow related to mutex issue.
Comment 11 Sebastian Dröge (slomo) 2017-02-27 08:08:17 UTC
If you think so, please also provide a backtrace of all threads when it breaks.
Comment 12 Lyon 2017-02-27 10:14:15 UTC
Created attachment 346804 [details]
tread backtrace

Please see attached file for the thread backtrace
Comment 13 Sebastian Dröge (slomo) 2017-02-27 10:41:58 UTC
This is not with gst-play but your own application. Also it seems like not all threads are included. Please do "thread apply all bt"
Comment 14 Lyon 2017-02-28 02:17:23 UTC
Created attachment 346878 [details]
thread apply all bt with gst-play

Hi, Slomo,
Sorry for my previous log and hanks for your patience 
please see attached file for thread all gst-play

Thanks
Lyon
Comment 15 Lyon 2017-02-28 06:30:57 UTC
Created attachment 346885 [details]
thread apply all bt with gst-play
Comment 16 Lyon 2017-02-28 06:59:52 UTC
From thread 2 (gstplayer)
it hangs at g_mutex_lock() in aiurdemux
  • #0 syscall
    at ../sysdeps/unix/sysv/linux/arm/syscall.S line 37
  • #1 g_mutex_lock_slowpath
    at /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/glib/gthread-posix.c line 1312
  • #2 g_mutex_lock
    at /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/glib/gthread-posix.c line 1336
  • #3 gst_aiurdemux_handle_src_event
    at aiurdemux.c line 3701
  • #4 gst_aiurdemux_handle_src_event
    at aiurdemux.c line 690
  • #5 gst_pad_send_event_unchecked

aiurdemux is the demux plugin we used in the pipeline.
Here is the situation, in http streaming mode.
There is one thread aiur_push, a loop to process the data got and push to downstream. and there is one mutex lock in this thread. when unlock the mutex when quit the loop.
When seeking, in handle src seek event, it will set the push loop to false and make it quit, meanwhile lock mutex to wait the streaming finished, and then do flush and seek.
however, seems the aiur_push thread loop is never quit and the mutex is never been released, so it locked in waiting for streaming finished.


I'm still trying to figure out why the aiur_push loop not quit.
when not using gstplayer, the loop is quit successfully and the unlock the mutex, which will not meet the deadlock issue.


I'm still trying to figure out why the aiur_push loop not quit.
when not using gstplayer, the loop quit successfully and will unlock the mutex, which will not meet the deadlock issue.
Comment 17 Lyon 2017-02-28 10:14:26 UTC
seems after seek, demux gst_pad_push() hang
Comment 18 Lyon 2017-02-28 13:13:45 UTC
I got some clue: 
to wait for streaming data push finishing, it will lock the mutex before flush and seek event. in data processing and push thread, same mutex is used.
However in gstplayer implementation, in seek process, it will first set GST state to PAUSED, therefore, when the queue is full, it will block the pipeline and gst_pad_push never get change to return. and then. the mutex not released and cause deadlock before it can flush and seek.

Here might be my resolution: flush data before the mutex lock and then seek, after flush, it will have chance to push the data and the seek can get the mutex to continue seek, and use another mutex to lock before the flush to avoid continuously seeking event.
Comment 19 Lyon 2017-02-28 13:15:39 UTC
in our previous implementation without gstplay, seeking operation needn't wait state changed to PAUSED, So when playing , the pipeline will not block, and will quit the push_data loop successfully and release the mutex.
Comment 20 Sebastian Dröge (slomo) 2017-02-28 14:48:08 UTC
That looks very much like a bug in your aiurdemux, where it handles threading wrong. Please take a look at other demuxer implement things like this.


The reason why the push function of your demuxer is not unlocked is because it's blocked downstream. Your demuxer is supposed to unblock downstream (but *only* for flushing seeks) by sending a flush-start event downstream when it handles the seek. It can then wait on the stream-lock afterwards to know when downstream is unblocked.

But look at existing demuxer implementations, their seek handlers are all handling this more or less the same way. In any case, generally don't hold a (especially non-recursive) mutex while pushing events/buffers upstream/downstream, posting messages or emitting signals, this is always a potential place for deadlocks.
Comment 21 Lyon 2017-03-01 02:03:27 UTC
Thanks slomo, I think it is exactly what you mentioned. will fix this bug in our aiurdemux for this threading issue.

Really thanks again ~
Comment 22 Lyon 2017-03-14 09:17:29 UTC
One more question: In gstplayer API, when seeking, it will first change state t PAUSED, then do seek operation, we are wondering why doing so?,  as it could seek without change it to PAUSED state first.
Comment 23 Sebastian Dröge (slomo) 2017-03-14 10:19:44 UTC
Because the order of state changes is not deterministic then