Description of problem: I have a v4l card that outputs a mpeg2 stream to /dev/video0 When opening the device for direct display, after about 30s, the video starts stuttering and (in totem) freezes or (in mplayer) somewhat recovers but with more stuttering and un-synched audio/video Saving the stream on file (cat /dev/video > /tmp/test.mpg) produces a file that plays perfectly. This use case worked perfectly on this hardware before PA was introduced and has been erratic (as in, works two weeks each year) since. The system is not contended and cpu load is very low (since most of the work is done in hardware by the pvr card) Similar bug reports like bug #523066 all point to PA It seems the audio subsystem is doing something stupid that does not work in a direct v4l streaming context, and video players never manage to recover properly while trying to sync audio and video (killing the players and restarting them restores audio and video for another 30s, though it is obviously totally unpractical for real use) Version-Release number of selected component (if applicable): kernel-2.6.32.2-15.fc13.x86_64 alsa-firmware-1.0.20-2.fc12.noarch alsa-lib-1.0.22-1.fc13.x86_64 alsa-plugins-pulseaudio-1.0.21-2.fc12.x86_64 alsa-tools-firmware-1.0.20-4.fc12.x86_64 alsa-utils-1.0.22-1.fc13.x86_64 gstreamer-0.10.25.1-2.fc13.x86_64 gstreamer-ffmpeg-0.10.9-1.fc12.x86_64 gstreamer-java-1.3-1.fc13.x86_64 gstreamer-plugins-base-0.10.25.1-2.fc13.x86_64 gstreamer-plugins-flumpegdemux-0.10.15-8.fc13.x86_64 gstreamer-plugins-good-0.10.17-4.fc13.x86_64 gstreamer-plugins-schroedinger-1.0.8-3.fc13.x86_64 gstreamer-plugins-ugly-0.10.13-1.fc12.x86_64 gstreamer-python-0.10.16-1.fc12.x86_64 gstreamer-tools-0.10.25.1-2.fc13.x86_64 mplayer-1.0-0.111.20091029svn.fc12.x86_64 PackageKit-gstreamer-plugin-0.6.0-1.fc13.x86_64 phonon-backend-gstreamer-4.3.80-2.fc13.x86_64 pulseaudio-0.9.21-3.fc13.x86_64 pulseaudio-gdm-hooks-0.9.21-3.fc13.x86_64 pulseaudio-libs-0.9.21-3.fc13.x86_64 pulseaudio-libs-glib2-0.9.21-3.fc13.x86_64 pulseaudio-libs-zeroconf-0.9.21-3.fc13.x86_64 pulseaudio-module-bluetooth-0.9.21-3.fc13.x86_64 pulseaudio-module-gconf-0.9.21-3.fc13.x86_64 pulseaudio-module-lirc-0.9.21-3.fc13.x86_64 pulseaudio-module-x11-0.9.21-3.fc13.x86_64 pulseaudio-utils-0.9.21-3.fc13.x86_64 totem-2.29.2-1.fc13.x86_64 totem-mozplugin-2.29.2-1.fc13.x86_64 totem-nautilus-2.29.2-1.fc13.x86_64 totem-pl-parser-2.28.2-1.fc13.x86_64 06:01.0 Multimedia video controller: Internext Compression Inc iTVC16 (CX23416) MPEG-2 Encoder (rev 01) Subsystem: Hauppauge computer works Inc. WinTV PVR 150 06:00.0 Multimedia audio controller: Creative Labs SB Audigy (rev 03) Subsystem: Creative Labs E-MU 1010 01:00.1 Audio device: ATI Technologies Inc HD48x0 audio Subsystem: PC Partner Limited Sapphire HD 4850 512MB GDDR3 PCI-E Dual Slot Fansink How reproducible: Always unfortunately Steps to Reproduce: 1. totem /dev/video0 Actual results: Stuttering then freeze Expected results: Smooth video
Created attachment 382099 [details] lspci
Created attachment 382100 [details] dmesg
Created attachment 382101 [details] pamcd ls while video going south
Created attachment 382102 [details] cat /proc/asound/*/pcm*p/sub*/*
Created attachment 382108 [details] mplayer output
gst-launch playbin uri=file:///dev/video0 --gst-debug-level=2 Setting pipeline to PAUSED ... Pipeline is PREROLLING ... Pipeline is PREROLLED ... Setting pipeline to PLAYING ... New clock: GstPulseSinkClock 0:00:21.154391813 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: A lot of buffers are being dropped. 0:00:21.154463051 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: There may be a timestamping problem, or this computer is too slow. WARNING: from element /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: A lot of buffers are being dropped. Additional debug info: gstbasesink.c(2567): gst_base_sink_is_too_late (): /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: There may be a timestamping problem, or this computer is too slow. 0:00:22.283977080 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: A lot of buffers are being dropped. 0:00:22.284031417 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: There may be a timestamping problem, or this computer is too slow. WARNING: from element /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: A lot of buffers are being dropped. Additional debug info: gstbasesink.c(2567): gst_base_sink_is_too_late (): /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: There may be a timestamping problem, or this computer is too slow. 0:00:23.607896062 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: A lot of buffers are being dropped. 0:00:23.607945719 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: There may be a timestamping problem, or this computer is too slow. WARNING: from element /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: A lot of buffers are being dropped. Additional debug info: gstbasesink.c(2567): gst_base_sink_is_too_late (): /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: There may be a timestamping problem, or this computer is too slow. 0:00:24.793323081 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:24.862123681 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:24.926380337 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: A lot of buffers are being dropped. 0:00:24.926431740 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: There may be a timestamping problem, or this computer is too slow. WARNING: from element /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: A lot of buffers are being dropped. Additional debug info: gstbasesink.c(2567): gst_base_sink_is_too_late (): /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: There may be a timestamping problem, or this computer is too slow. 0:00:24.930777057 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:24.999445932 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:25.068111181 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:25.136709729 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:25.527541827 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:25.596345429 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:25.849489676 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:25.918325056 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:26.073943543 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: A lot of buffers are being dropped. 0:00:26.073994528 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: There may be a timestamping problem, or this computer is too slow. WARNING: from element /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: A lot of buffers are being dropped. Additional debug info: gstbasesink.c(2567): gst_base_sink_is_too_late (): /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: There may be a timestamping problem, or this computer is too slow. 0:00:26.124789066 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:26.652493501 15785 0x7f7638003770 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:27.395766008 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: A lot of buffers are being dropped. 0:00:27.395815456 15785 0x7f7645a6e400 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: There may be a timestamping problem, or this computer is too slow. WARNING: from element /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: A lot of buffers are being dropped. Additional debug info: gstbasesink.c(2567): gst_base_sink_is_too_late (): /GstPlayBin:playbin0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: There may be a timestamping problem, or this computer is too slow.
Hmm, I kinda get the feeling that if you do this then there is no element in the pipeline that deals with the deviation of the clocks of the v4l device and the sound card. This will make boom on all devices, sooner or later. If you connect two clocked devices you need some code that does adpative resampling, and from how you describe your setup there is nothing that does that. Or is there?
You should really use "playbin2" in your pipeline. And to answer Lennart's question, it should have a few queues in the middle of the pipeline.
the gst-launch example is only there because I couldn't get totem to output debug info directly. I assume mplayer and totem add all the stuff I missed. They still all fail I you have a particular gst pipeline you want me to test, just post it and I'll run it.
$ gst-launch playbin2 uri=file:///dev/video0 --gst-debug-level=2 Setting pipeline to PAUSED ... Pipeline is PREROLLING ... Pipeline is PREROLLED ... Setting pipeline to PLAYING ... New clock: GstPulseSinkClock 0:00:37.049098483 4043 0x7f9f000045b0 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:37.118294044 4043 0x7f9f000045b0 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:37.186509939 4043 0x7f9f000045b0 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:37.255385626 4043 0x7f9f000045b0 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:37.392570316 4043 0x7f9f000045b0 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:37.529838809 4043 0x7f9f000045b0 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:37.852019244 4043 0x7f9f000045b0 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:37.989419597 4043 0x7f9f000045b0 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:38.381265134 4043 0x7f9f000045b0 WARN pulse pulsesink.c:523:gst_pulsering_stream_underflow_cb:<audiosink-actual-sink-pulse> Got underflow 0:00:42.884316942 4043 0x7f9f1c34b0f0 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: A lot of buffers are being dropped. 0:00:42.884577450 4043 0x7f9f1c34b0f0 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: There may be a timestamping problem, or this computer is too slow. WARNING: from element /GstPlayBin2:playbin20/GstPlaySink:playsink0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: A lot of buffers are being dropped. Additional debug info: gstbasesink.c(2567): gst_base_sink_is_too_late (): /GstPlayBin2:playbin20/GstPlaySink:playsink0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: There may be a timestamping problem, or this computer is too slow. 0:00:43.972660227 4043 0x7f9f1c34b0f0 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: A lot of buffers are being dropped. 0:00:43.972703110 4043 0x7f9f1c34b0f0 WARN basesink gstbasesink.c:2567:gst_base_sink_is_too_late:<videosink-actual-sink-xvimage> warning: There may be a timestamping problem, or this computer is too slow. WARNING: from element /GstPlayBin2:playbin20/GstPlaySink:playsink0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: A lot of buffers are being dropped. Additional debug info: gstbasesink.c(2567): gst_base_sink_is_too_late (): /GstPlayBin2:playbin20/GstPlaySink:playsink0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: There may be a timestamping problem, or this computer is too slow.
i am pretty sure neither mplayer nor playbin or playbin2 would do the resampling. They assume that rate they can read the video stream in is way faster then rate it will be played in. (because they assume they are reading from a hdd where the read space is almost without limit). Since your video input device is clocked in itself and its clock will deviate from the sound card's clock this assumption is not fulfilled. mplayer/playbin/playbin2 can only read the video source data at the rate your video device offers them in. That means that eventually the buffers between the source and the sink in your pipeline *must* either run empty or run over eventually. So really, if you want to play that stream you need some kind of element in the middle that looks at the speed of the source and of the sink and then resamples the stream to compensate the clock deviation. In Gst, if such an element is missing the result will be audio/video being dropped or silence inserted, also called "stuttering". So really, what you try to do *cannot* work. Maybe the time until things go boom change a little without PA and with PA, but that does not change the fact that this *cannot* work.
Without PA the boom time does not happen in hours. Which means it effectively does not happen, since most people need to go to sleep and do not look at video streams for more than a few hours (and even if id did boom after a few hours, which it didn't, that would be perfectly user-acceptable. Adds disrupt video a lot more often than that) With PA problems are tens of seconds away. So in theory, it is broken both ways, but in practice, it is only broken with PA
My guess is that this should be filed against GStreamer upstream, and have playbin2 special case this use case.
http://bugzilla.gnome.org/show_bug.cgi?id=606394
This bug appears to have been reported against 'rawhide' during the Fedora 13 development cycle. Changing version to '13'. More information and reason for this action is here: http://fedoraproject.org/wiki/BugZappers/HouseKeeping
This message is a reminder that Fedora 13 is nearing its end of life. Approximately 30 (thirty) days from now Fedora will stop maintaining and issuing updates for Fedora 13. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as WONTFIX if it remains open with a Fedora 'version' of '13'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version prior to Fedora 13's end of life. Bug Reporter: Thank you for reporting this issue and we are sorry that we may not be able to fix it before Fedora 13 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora please change the 'version' of this bug to the applicable version. If you are unable to change the version, please add a comment here and someone will do it for you. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete. The process we are following is described here: http://fedoraproject.org/wiki/BugZappers/HouseKeeping
Fedora 13 changed to end-of-life (EOL) status on 2011-06-25. Fedora 13 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. Thank you for reporting this bug and we are sorry it could not be fixed.