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 751508 - tsdemux: jerky sound on some multicast streams (regression)
tsdemux: jerky sound on some multicast streams (regression)
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gst-plugins-bad
1.x
Other Linux
: Normal blocker
: 1.5.91
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2015-06-25 17:33 UTC by Jan ONDREJ (SAL)
Modified: 2015-08-28 18:27 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
gst-play log with GST_DEBUG=*:INFO (35.19 KB, application/x-gzip)
2015-06-26 04:38 UTC, Jan ONDREJ (SAL)
  Details
tsdemux: fix latency handling again (1.38 KB, patch)
2015-08-23 22:43 UTC, Tim-Philipp Müller
accepted-commit_now Details | Review

Description Jan ONDREJ (SAL) 2015-06-25 17:33:10 UTC
With gstreamer 1.5.2 and 1.5.1, when playing some multicast channels, sound is playing jerky (or halting, sorry for my english). Other multicast channels are working well.

Downgrade to 1.4.5 works well for all channels.

Recorded stream is playing well, so unable to reproduce this way.

Tell me, which DEBUG leves are required to debug this or how to add more information.
Comment 1 Jan ONDREJ (SAL) 2015-06-25 17:54:40 UTC
I see these messages with debug:

0:00:05.052650201  7189 0xaf9d2460 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:00:05.053111153  7189 0xaf9d2460 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:00:05.053437731  7189 0xaf9d2460 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:00:05.053809985  7189 0xaf9d2460 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:00:08.374285236  7298  0x942e400 FIXME                    bin gstbin.c:4052:gst_bin_query: implement duration caching in GstBin again

Same messages for OK streams.
For wrong stream debug output is jerking/halting too.

Trying to also record audio with:
  gst-play-1.0 udp://232.232.64.119:5004 --audiosink='lamemp3enc ! filesink location=/tmp/test.mp3'
but resulting mp3 is OK.
Comment 2 Nicolas Dufresne (ndufresne) 2015-06-25 18:41:18 UTC
Would it be possible to provide a bit of information about your multi-cast stream ? Is there a way we could reproduce your issue ?
Comment 3 Jan ONDREJ (SAL) 2015-06-26 04:38:51 UTC
Created attachment 306137 [details]
gst-play log with GST_DEBUG=*:INFO

Unable to reproduce on different stream. I don't know, how this stream differs from others except it's IP address.

Attaching log file, may be you can find more info. Tell me if I should add more debugging.
Comment 4 Nicolas Dufresne (ndufresne) 2015-06-26 13:04:20 UTC
So you are transmitting mp3 straight over UDP ? (We can't help if we can't figure-out what your are trying to do, what kind of server and network protocol this is).
Comment 5 Jan ONDREJ (SAL) 2015-06-26 15:01:47 UTC
(In reply to Nicolas Dufresne (stormer) from comment #4)
> So you are transmitting mp3 straight over UDP ? (We can't help if we can't
> figure-out what your are trying to do, what kind of server and network
> protocol this is).

This is TV channel from my internet provider. It's an IPTV stream, but I don't know more about their server and so. Curious, that same server, same provider, just different IP (or channel) works well. All channel except this one works.

Example of gst-play commands:

working: gst-play-1.0 udp://232.232.64.120:5004

jamming: gst-play-1.0 udp://232.232.64.119:5004

How can I compare them?

I am on IRC as SALstar. If you need more info, just contact me.
Comment 6 Jan ONDREJ (SAL) 2015-06-28 11:34:01 UTC
May be this helps:
  same stream using udpxy works, but direct multicast playing don't
Comment 7 Nicolas Dufresne (ndufresne) 2015-06-30 01:36:27 UTC
To be honest, I think your streamer introduce jitter and there might not be enough buffer by default to handle it. I'm also starting to think you are looking for help with your project, rather then reporting a GStreamer bug. 

Please provide everything that could let us reproduce the issue (like all the details about the stream, if server is free, name it, explain how you configured it, if not, provide us access to a stream or a WireShark pcap dump, something we can use to reproduce). Otherwise it's not useful and you can close this bug. For general help and discussions there is a mailing list.
Comment 8 Jan ONDREJ (SAL) 2015-06-30 11:04:12 UTC
I don't know anything about server. I get this stream from my internet provider and unable to get more information. I can record it with wireshark later, but I don't know if this helps. Stream converted to http stream using udpxy project is playing normally. Looks like there is something with combination of multicast source and audio sink. Using gst-discover I found some differences in my streams (working and jamming). There is only one difference which is different for from all streams. This jamming stream has "channel mode: joint-stereo". Other streams has "channel mode: stereo".

Does this helps? Can you try to reproduce on multicast stream with joint-stereo channel mode?

Here is gst-discover output for jamming stream:

Analyzing udp://232.232.64.119:5004
Done discovering udp://232.232.64.119:5004
Missing plugins

Topology:
  container: MPEG-2 Transport Stream
    unknown: Teletext
    audio: MPEG-1 Layer 2 (MP2)
    video: MPEG-2 Video (Main Profile)

Properties:
  Duration: 99:99:99.999999999
  Seekable: no
  Tags: 
      language code: cs
      audio codec: MPEG-1 Layer 2 (MP2)
      nominal bitrate: 192000
      has crc: false
      channel mode: joint-stereo
      minimum bitrate: 192000
      bitrate: 192000
      maximum bitrate: 192000
      video codec: MPEG-2 Video (Main Profile)

Please tell me, if you still need pcap dump.
Comment 9 Tim-Philipp Müller 2015-06-30 11:16:37 UTC
Yes, please make a pcap capture (old pcap format, not -ng one) and put it somewhere.
Comment 10 Jan ONDREJ (SAL) 2015-06-30 14:25:40 UTC
OK, here is my pcap dump:

http://work.salstar.sk/public/gstreamer/stream.pcap

Recorded with this command:

tshark -p -F pcap -w /tmp/stream.pcap port 5004

Unable to reproduce using gst-play-1.0 /tmp/stream.pcap. 
Trying to reproduce using tcpreplay, but gst-play can't join multicast group.
Comment 11 Nicolas Dufresne (ndufresne) 2015-06-30 15:40:57 UTC
I believe I can reproduce, could you confirm:

gst-launch-1.0 filesrc location=stream.pcap ! pcapparse ! identity sync=1 ! decodebin name=dec dec. ! queue ! pulsesink dec. ! queue ! glimagesink
Comment 12 Nicolas Dufresne (ndufresne) 2015-06-30 15:50:49 UTC
And as I suspected, increasing the buffering fixes it:

gst-launch-1.0 filesrc location=stream.pcap ! pcapparse ! identity sync=1 ! queue min-threshold-time=5000000000 ! decodebin name=dec dec. ! queue ! pulsesink dec. ! queue ! glimagesink

It looks like if audio is late on the video. Clearly you can't fix the stream. You should try setting "buffer-duration" on playbin, if I remember correctly it should have the same effect as the above pipeline. I believe this is not a GStreamer bug, outside the fact that this stream surpass GStreamer default buffering capacity.
Comment 13 Jan ONDREJ (SAL) 2015-06-30 16:07:02 UTC
Confirming reproduction with you gst-launch command.

Trying to experience with min-threshold-time directly on my udp stream:

gst-launch-1.0 udpsrc address=232.232.64.119 port=5004 ! queue min-threshold-time=1 ! decodebin name=dec dec. ! queue ! pulsesink dec. ! queue ! xvimagesink

Here are results for different threshold times:

0 - jamming
1 - 500000 - playing well, it's enough to set it to 1
>5000000 - nothing happens, no video/audio opened, waited more than 10 seconds

Trying to set buffering (flag 0x100), buffer-duration, but doesn't help (python):

      self.playbin.set_property("flags",
        0x001 # render video
        | 0x002 # render audio
        | 0x004 * int(bool(self.subtitle_files)) # render subtitles
        | 0x008 # audio visualization
        #| 0x010 # soft volume
        | 0x080 # progressive download buffering
        # buffering will break playing of large mkv files
        | 0x100 # buffering
        | 0x200 # deinterlace
        #| 0x400 # soft-colorbalance
      )
      #self.playbin.set_property("buffer-size", 100*1048576) # 100 MB
      self.playbin.set_property("buffer-duration", 10*nanosecond) # 10s

Because this worked well with gst-1.4.5, I think this should work with newer versions too.
Comment 14 Jan ONDREJ (SAL) 2015-08-23 19:47:51 UTC
Same problem with:
gstreamer1-plugins-ugly-1.5.90-1.fc22.i686
gstreamer1-libav-1.5.90-1.fc22.i686
gstreamer1-plugins-base-tools-1.5.90-1.fc22.i686
gstreamer1-1.5.90-1.fc22.i686
gstreamer1-plugins-bad-free-1.5.90-1.fc22.i686
gstreamer1-plugins-good-1.5.90-1.fc22.i686
gstreamer1-plugins-base-1.5.90-1.fc22.i686
gstreamer1-plugins-bad-free-extras-1.5.90-1.fc22.i686

Because there was no problem with gst-1.4, I think this should be fixed before an stable release.

Also there is no workaround for this problem and playbin.
Comment 15 Tim-Philipp Müller 2015-08-23 20:04:27 UTC
Jan, you could help narrow it down by bisecting the various git modules to figure out what commit introduced the problem.
Comment 16 Tim-Philipp Müller 2015-08-23 20:19:48 UTC
It looks like multiqueue for some reason now has a max-size-buffers limit in 1.5 (of 5 and 13 buffers), and reaches the buffer limit a few times. In the 1.4 log the multiqueue often contains many more buffers than the limits in 1.5
Comment 17 Tim-Philipp Müller 2015-08-23 20:20:22 UTC
Marking as blocker for now since it's a regression. Doesn't necessarily mean it'll get fixed in time though.
Comment 18 Jan ONDREJ (SAL) 2015-08-23 22:27:56 UTC
(In reply to Tim-Philipp Müller from comment #15)
> Jan, you could help narrow it down by bisecting the various git modules to
> figure out what commit introduced the problem.

Here is git bisect result:

a1f709c2935860585dcddfdb2e7d40541db423a5 is the first bad commit
commit a1f709c2935860585dcddfdb2e7d40541db423a5
Author: Olivier Crête <olivier.crete@collabora.com>
Date:   Fri Apr 17 13:55:26 2015 -0600

    tsdemux: Cleanup latency query handling
    
    The minimum latency is always 0 or more. And we should
    requery upstream as it may have changed.

:040000 040000 cce6f3e7187389cfa940f9c35afc99803c75eb5e e4c02662f8a9b6d3a35777033334254053691091 M      gst
Comment 19 Tim-Philipp Müller 2015-08-23 22:43:05 UTC
Created attachment 309897 [details] [review]
tsdemux: fix latency handling again

http://cgit.freedesktop.org/gstreamer/gst-plugins-bad/commit/gst/mpegtsdemux?id=a1f709c2935860585dcddfdb2e7d40541db423a5

It looks like after the change it won't add TS_LATENCY to the minimum latency any more if the minimum latency is 0 (as in the case of udpsrc). I don't think that's right.

I'm not sure if this behavioural change was intentional or not (I would guess not since it was labelled as 'cleanup').