Opened 12 years ago

Closed 12 years ago

#10212 closed Bug Report - General (fixed)

Transcoded recordings playback broken (stutters, audio failure) during November commits

Reported by: jk90090@… Owned by: Jim Stichnoth
Priority: minor Milestone: 0.25
Component: MythTV - Video Playback Version: Master Head
Severity: medium Keywords: transcoded recordings
Cc: Ticket locked: no

Description (last modified by sphery)

Recently, and accidentally, I updated from mythtv-0.25_pre20111102 to mythtv-0.25_pre20111129, and now I'm having some serious buffering issues with TRANSCODED recordings. Any recording that isn't transcoded is playing back perfectly (720p, 1080i both smooth as silk), and it's pretty much for all transcoded content, so simply newly transcoded recordings.

I transcode by ticking the 'transcode' option for the recording schedule, either with Medium Quality or Low Quality

The settings I use are: (Advanced -> TV Settings -> Recording Profiles -> Transcoders -> ..)

  • Media Quality - Resize video while transcoding, 1280x720, MPEG4, 2200 Bitrate, Max Qual 2, Min Qual 15, Max qual diff between frames 3, Scale bitrate for frame size, Enable High-quality encoding, Enable 4MV encoding; MP3 audio, 32000 sampling rate, qual 7, volume 90%
  • Low Quality - Resize video while transcoding, 960x540, MPEG4, 2200 Bitrate, Max Qual 2, Min Qual 15, Max qual diff between frames 3, Scale bitrate for frame size, Enable High-quality encoding, Enable 4MV encoding; MP3 audio, 32000 sampling rate, qual 5, volume 90%

I am using a Frontend with VPDAU high quality playback (and I have tried without using VPDAU with no different results), and CPU usage for the system is single digits generally when doing playback. Dual Core i5 I think, 6 GB memory.

Some log excerpts from playback:

2011-12-02 10:28:09.198258 N [5764/5764] CoreContext mythplayer.cpp:2090 (PrebufferEnoughFrames) - Player(2): Waited 208ms for video buffers AAAAAffAAAAAAAAAAAAAAAAAAAAA
2011-12-02 10:28:09.247233 I [5764/22424] Decoder ringbuffer.cpp:1093 (WaitForAvail) - RingBuf(myth://mythserver:6543/2041_20111201213000.nuv): Waited 0.2 seconds for data
            to become available... 66599 < 83003
2011-12-02 10:28:09.255258 I [5764/22424] Decoder ringbuffer.cpp:1093 (WaitForAvail) - RingBuf(myth://mythserver:6543/2041_20111201213000.nuv): Waited 0.2 seconds for data
            to become available... 68647 < 83003
2011-12-02 10:28:09.263160 I [5764/22424] Decoder ringbuffer.cpp:1093 (WaitForAvail) - RingBuf(myth://mythserver:6543/2041_20111201213000.nuv): Waited 0.2 seconds for data
            to become available... 70695 < 83003

On the backend, I am not getting any errors.

I copied the nuv to an SMB share that I have mounted for Videos, went into videos, same bad results. I renamed it to avi, and used mplayer for playback which worked flawlessly. Next I copied the file to a frontend local directory, again same failure. Basically the internal player is the one having the trouble, regardless of location.

I pulled down the 1107 commit and after some DB trickery was able to get the frontend up, and entered into the Videos section, and playback of the NUV is back to normal. IF I get more time, I'll try another commit in between 1107 and 1129 to narrow down further where the bug has been introduced.

Help!

Some debug excerpts:

2011-12-18 16:38:27.343942 D [16487/16841] RingBuffer ringbuffer.cpp:858 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1200128, 2048) -- begin
2011-12-18 16:38:27.343987 I [16487/16841] RingBuffer ringbuffer.cpp:879 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1200128, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.344000 D [16487/16841] RingBuffer ringbuffer.cpp:892 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K requested   2K in read
2011-12-18 16:38:27.344007 D [16487/16841] RingBuffer ringbuffer.cpp:943 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read ahead loop
2011-12-18 16:38:27.345563 I [16487/16843] Decoder audio/audiooutputbase.cpp:1095 (SetAudiotime) - AO: SetAudiotime atc=47752884 tc=47752985 f=4096 pfu=-4352 pfs=-512
2011-12-18 16:38:27.345799 I [16487/16843] Decoder audio/audiooutputbase.cpp:1331 (AddData) - AO: AddData frames=1152, bytes=4608, used=25729, free=3046271, timecode=47752985 needsupmix=1
2011-12-18 16:38:27.345818 D [16487/16843] Decoder freesurround.cpp:363 (putFrames) - FreeSurround::putFrames 1152 #ch 2 used 1152 generated 0
2011-12-18 16:38:27.345832 I [16487/16843] Decoder audio/audiooutputbase.cpp:1095 (SetAudiotime) - AO: SetAudiotime atc=47752860 tc=47752985 f=0 pfu=-5504 pfs=-512
2011-12-18 16:38:27.345848 D [16487/16843] Decoder ringbuffer.cpp:1188 (ReadPriv) - RingBuf(/mythtv/video/2041_20111208213000.nuv): ReadPriv(..12, normal) @1198721 -- begin
2011-12-18 16:38:27.345867 D [16487/16843] Decoder ringbuffer.cpp:1272 (ReadPriv) - RingBuf(/mythtv/video/2041_20111208213000.nuv): ReadPriv(..12, normal) -- copying data
2011-12-18 16:38:27.345876 D [16487/16843] Decoder ringbuffer.cpp:1287 (ReadPriv) - RingBuf(/mythtv/video/2041_20111208213000.nuv): ReadPriv(..12, normal) -- checksum 5687
2011-12-18 16:38:27.345890 D [16487/16843] Decoder ringbuffer.cpp:1188 (ReadPriv) - RingBuf(/mythtv/video/2041_20111208213000.nuv): ReadPriv(..34077, normal) @1198733 -- begin
2011-12-18 16:38:27.352057 D [16487/16841] RingBuffer ringbuffer.cpp:858 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1202176, 2048) -- begin
2011-12-18 16:38:27.352068 I [16487/16487] CoreContext mythplayer.cpp:1824 (AVSync) - Player(1): AVSync show
2011-12-18 16:38:27.352118 I [16487/16841] RingBuffer ringbuffer.cpp:879 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1202176, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.352134 D [16487/16841] RingBuffer ringbuffer.cpp:892 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K requested   2K in read
2011-12-18 16:38:27.352143 D [16487/16841] RingBuffer ringbuffer.cpp:943 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read ahead loop
2011-12-18 16:38:27.355434 I [16487/16842] AudioOutputBase audio/audiooutputbase.cpp:1046 (GetAudiotime) - AO: GetAudiotime audt=47752726 atc=47752860 mb=25728 sb=0 tb=25728 sr=48000 obpf=4 bpf=24 sf=1 -1722167296 -89
2011-12-18 16:38:27.355463 I [16487/16842] AudioOutputBase audio/audiooutputalsa.cpp:526 (WriteAudio) - WriteAudio: Preparing 9600 bytes (2400 frames)
2011-12-18 16:38:27.355512 I [16487/16842] AudioOutputBase audio/audiooutputbase.cpp:1046 (GetAudiotime) - AO: GetAudiotime audt=47752726 atc=47752860 mb=16128 sb=19200 tb=35328 sr=48000 obpf=4 bpf=24 sf=1 -762167296 -39
2011-12-18 16:38:27.355527 I [16487/16842] AudioOutputBase audio/audiooutputalsa.cpp:526 (WriteAudio) - WriteAudio: Preparing 9600 bytes (2400 frames)
2011-12-18 16:38:27.355543 I [16487/16842] AudioOutputBase audio/audiooutputbase.cpp:1621 (OutputAudioLoop) - AO: audio waiting for buffer to fill: have 6528 want 9600
2011-12-18 16:38:27.359473 D [16487/16841] RingBuffer ringbuffer.cpp:858 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1204224, 2048) -- begin
2011-12-18 16:38:27.359509 I [16487/16841] RingBuffer ringbuffer.cpp:879 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1204224, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.359523 D [16487/16841] RingBuffer ringbuffer.cpp:892 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K requested   2K in read
2011-12-18 16:38:27.359532 D [16487/16841] RingBuffer ringbuffer.cpp:943 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read ahead loop
2011-12-18 16:38:27.367627 I [16487/16842] AudioOutputBase audio/audiooutputbase.cpp:1621 (OutputAudioLoop) - AO: audio waiting for buffer to fill: have 6528 want 9600
2011-12-18 16:38:27.367649 D [16487/16841] RingBuffer ringbuffer.cpp:858 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1206272, 2048) -- begin
2011-12-18 16:38:27.367689 I [16487/16841] RingBuffer ringbuffer.cpp:879 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1206272, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.367714 D [16487/16841] RingBuffer ringbuffer.cpp:892 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K requested   2K in read
2011-12-18 16:38:27.367723 D [16487/16841] RingBuffer ringbuffer.cpp:943 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read ahead loop
2011-12-18 16:38:27.368724 I [16487/16487] CoreContext audio/audiooutputbase.cpp:1046 (GetAudiotime) - AO: GetAudiotime audt=47752726 atc=47752860 mb=6528 sb=26080 tb=32608 sr=48000 obpf=4 bpf=24 sf=1 -1034167296 -53
2011-12-18 16:38:27.368760 I [16487/16487] CoreContext mythplayer.cpp:1908 (AVSync) - Player(1): A/V timecodes audio 47752726 video 47752773 frameinterval 33367 avdel 47 avg -20082 tcoffset 60 avp 0 avpen 0 avdc 0
2011-12-18 16:38:27.368817 I [16487/16487] CoreContext mythplayer.cpp:2018 (SetBuffering) - Player(1): Waiting for video buffers...
2011-12-18 16:38:27.375767 D [16487/16841] RingBuffer ringbuffer.cpp:858 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1208320, 2048) -- begin
2011-12-18 16:38:27.375803 I [16487/16841] RingBuffer ringbuffer.cpp:879 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1208320, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.375816 D [16487/16841] RingBuffer ringbuffer.cpp:892 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K requested   2K in read
2011-12-18 16:38:27.375824 D [16487/16841] RingBuffer ringbuffer.cpp:943 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read ahead loop
2011-12-18 16:38:27.379866 I [16487/16842] AudioOutputBase audio/audiooutputbase.cpp:1621 (OutputAudioLoop) - AO: audio waiting for buffer to fill: have 6528 want 9600
2011-12-18 16:38:27.383923 D [16487/16841] RingBuffer ringbuffer.cpp:858 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1210368, 2048) -- begin
2011-12-18 16:38:27.383966 I [16487/16841] RingBuffer ringbuffer.cpp:879 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1210368, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.383981 D [16487/16841] RingBuffer ringbuffer.cpp:892 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K requested   2K in read
2011-12-18 16:38:27.383990 D [16487/16841] RingBuffer ringbuffer.cpp:943 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read ahead loop
2011-12-18 16:38:27.392077 I [16487/16842] AudioOutputBase audio/audiooutputbase.cpp:1621 (OutputAudioLoop) - AO: audio waiting for buffer to fill: have 6528 want 9600
2011-12-18 16:38:27.392825 D [16487/16841] RingBuffer ringbuffer.cpp:858 (run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): safe_read(...@1212416, 2048) -- begin

Attachments (5)

mythfrontend.20120201183848.20007-playback-debug-20111114-build.log (164.2 KB) - added by jk90090@… 12 years ago.
mythfrontend.20120201183848.20007-playback-debug-20111114-build.2.log (164.2 KB) - added by jk90090@… 12 years ago.
mythfrontend.20120201184003.20113-playback-audio-debug-20111114-build.log (168.8 KB) - added by jk90090@… 12 years ago.
mythfrontend.20120201131523.28747-playback-debug-20111110-build.log (77.3 KB) - added by jk90090@… 12 years ago.
mythfrontend.20120201131715.28842-playback-audio-debug-20111110-build.log (63.2 KB) - added by jk90090@… 12 years ago.

Download all attachments as: .zip

Change History (36)

comment:1 Changed 12 years ago by jk90090@…

Loaded commit 2011 11 13. Fails.

scripts/mythtv-buildebuild.py -s 4f3b78c3ef2a704c5c74013fa1c6cb870cce4631 --date=20111113 emerge -pv =media-tv/mythtv-0.25_pre20111113

And for tracking, the below commit works:

scripts/mythtv-buildebuild.py -s a2e143f7c77349afcf5cf147a1e4765a2a54db21 --date=20111107 emerge -v =media-tv/mythtv-0.25_pre20111107

comment:2 Changed 12 years ago by jk90090@…

Commit 20111110 works fine.

scripts/mythtv-buildebuild.py -s 94bf2f1eed9b274f33d20028fdec582a2d1f4867 --date=20111110 emerge -v =media-tv/mythtv-0.25_pre20111110

comment:3 Changed 12 years ago by jk90090@…

Ok, narrowed it down to a 1 day window now.

Commit date 20111111 fails to playback properly

scripts/mythtv-buildebuild.py --date=20111111 -s 47d52964f9946e90d9d8edc4392107b338270491 emerge -v =media-tv/mythtv-0.25_pre20111111

comment:4 Changed 12 years ago by jk90090@…

Not entirely sure if the hash actually makes any difference, but I also tried commit hash 836a072d75a21756dc93d014cfd66586f8f67b97 for date 20111111, which also results in failure.

comment:5 Changed 12 years ago by jk90090@…

Additional testting data. My backend, which is still currently running the 20111217 build, plays back the transcoded recordings fine. It is a Quad-core Intel i7 S 860, running a Radeon card (01:00.0 VGA compatible controller: ATI Technologies Inc RV710 [Radeon HD 4550]), audio through Intel chip (00:1b.0 Audio device: Intel Corporation Ibex Peak High Definition Audio (rev 06))

Frontend: Intel Dual Core Duo 6400, Nvidia card (01:00.0 VGA compatible controller: nVidia Corporation G94 9600 GT? (rev a1)), Intel audio (00:1b.0 Audio device: Intel Corporation 82801H (ICH8 Family) HD Audio Controller (rev 02))

comment:6 Changed 12 years ago by jk90090@…

Mark, having any luck?

comment:7 Changed 12 years ago by robertm

Milestone: 0.25unknown
Priority: criticalminor
Severity: highmedium

Please don't bump/ping tickets. Also, please read the ticket howto, do not set severity, milestone, or priority.

comment:8 Changed 12 years ago by amlopezalonso@…

Just having commercials removed (no other transcoding made) makes this issue to happen. The stuttering slots appear scattered along the transcoded recording with no obvious (for me at least) pattern.

comment:9 Changed 12 years ago by jk90090@…

For what it's worth, here's what FFMPEG shows on an transcoded recording:

ffmpeg version 0.7.3, Copyright (c) 2000-2011 the FFmpeg developers

built on Aug 30 2011 16:18:43 with gcc 4.4.4 configuration: --prefix=/usr --libdir=/usr/lib --shlibdir=/usr/lib --mandir=/usr/share/man --enable-shared --cc=i686-pc-linux-gnu-gcc --disable-static --enable-gpl --enable-version3 --enable-postproc --enable-avfilter --disable-stripping --disable-debug --disable-doc --disable-network --disable-vaapi --disable-vdpau --enable-libmp3lame --enable-libvo-aacenc --enable-libvo-amrwbenc --enable-libtheora --enable-libvorbis --enable-libx264 --enable-libxvid --enable-libdc1394 --disable-indev=v4l --disable-indev=oss --disable-indev=jack --enable-x11grab --disable-outdev=oss --enable-libfreetype --enable-pthreads --enable-libopencore-amrwb --enable-libopencore-amrnb --disable-altivec --disable-avx --cpu=i686 --enable-hardcoded-tables libavutil 50. 43. 0 / 50. 43. 0 libavcodec 52.122. 0 / 52.122. 0 libavformat 52.110. 0 / 52.110. 0 libavdevice 52. 5. 0 / 52. 5. 0 libavfilter 1. 80. 0 / 1. 80. 0 libswscale 0. 14. 1 / 0. 14. 1 libpostproc 51. 2. 0 / 51. 2. 0

[nuv @ 0x9ccfe00] Estimating duration from bitrate, this may be inaccurate

Seems stream 0 codec frame rate differs from container frame rate: 1000.00 (1000/1) -> 29.97 (30000/1001) Input #0, nuv, from '2041_20111208213000.avi':

Duration: 13:47:53.70, start: 47746.500000, bitrate: 127 kb/s

Stream #0.0: Video: mpeg4, yuv420p, 960x544, PAR 34:45 DAR 4:3, 29.97 tbr, 1k tbn, 1k tbc Stream #0.1: Audio: mp3, 48000 Hz, stereo, s16, 128 kb/s

At least one output file must be specified

comment:10 Changed 12 years ago by jk90090@…

More data points: It would appear the Mythbuntu 11.10 repository 0.25 builds are suffering the same issue. I loaded it today on the Frontend and experience the same playback issues.

comment:11 Changed 12 years ago by amlopezalonso@…

Yes, that's the one I'm running.

@robertm:

Could you please suggest an option to pass to FE/other in order to generate a proper backtrace?

Thanks, Antonio

comment:12 Changed 12 years ago by sphery

Description: modified (diff)

comment:13 in reply to:  12 Changed 12 years ago by amlopezalonso@…

Replying to mdean:

http://www.mythtv.org/wiki/Debugging

I know how to create a backtrace. What I would like is a suggestion on which app/plugin/option (specially -v <something>) to use in order to shrink the debugging.

comment:14 Changed 12 years ago by amlopezalonso@…

Specifically there should be two debugging points: one somewhere during the transcoding process and another during playback of a transcoded recording. I need some help to perform the former.

comment:15 Changed 12 years ago by jk90090@…

More testing, I used ffmpeg to transcode the recording further in an mkv, and playback in MythVideo? works on the MKV where the original transcoded file does not:

ffmpeg -i 2041_20111208213000.nuv -vcodec copy -sameq -acodec copy -f matroska 2041_2011.mkv

Next I tried dropping the mkv in place of the /mythtv/recordings/2041_20111208213000.nuv file, but playback simply started for a split second and then ended.

mythcommflag --rebuild --starttime 20111208213000 --chanid 2041

Now playback works. So if I manually containerize the transcoded file to Matroska, I'm golden. A bit troublesome but for now I might have a workable workaround.

comment:16 Changed 12 years ago by markk

Can you clarify for me:-

94bf2f1eed9b274f33d20028fdec582a2d1f4867 works fine

next commit

836a072d75a21756dc93d014cfd66586f8f67b97 - doesn't work

If so, then I'm baffled, as that second commit should have no impact on playback (and if it does, it won't matter what container or coded is being played).

Can you confirm this by moving both the frontend AND backend to the first commit (full make distclean and re-compile) and then move forward the one commit.

and please post the full frontend log - cropping logs is a really bad idea, as it invariably leaves out important information.

comment:17 Changed 12 years ago by jk90090@…

When using the Nov 10 2011 commit 94bf2f1eed9b274f33d20028fdec582a2d1f4867 (as best as I can tell by using the python script to pull the git version), playback of transcoded files is fine. If I then pull down the Nov 11 2011 commits (at least the two that I tried), playback is then broken.

From what I can see from a git pull of those two dates, there's quite a few changes:

    git checkout -b 1110 94bf2f1eed9b274f33d20028fdec582a2d1f4867
    git checkout -b 1111 47d52964f9946e90d9d8edc4392107b338270491

diff --git a/mythtv/bindings/python/MythTV/logging.py b/mythtv/bindings/python/MythTV/logging.py
--- a/mythtv/bindings/python/MythTV/logging.py
+++ b/mythtv/bindings/python/MythTV/logging.py
diff --git a/mythtv/html/misc/overview.qsp b/mythtv/html/misc/overview.qsp
--- a/mythtv/html/misc/overview.qsp
+++ b/mythtv/html/misc/overview.qsp
diff --git a/mythtv/html/samples/recorded.qsp b/mythtv/html/samples/recorded.qsp
--- a/mythtv/html/samples/recorded.qsp
+++ b/mythtv/html/samples/recorded.qsp
diff --git a/mythtv/html/setup/js/channeleditor.js b/mythtv/html/setup/js/channeleditor.js
--- a/mythtv/html/setup/js/channeleditor.js
+++ b/mythtv/html/setup/js/channeleditor.js
diff --git a/mythtv/libs/libmythbase/mythversion.h b/mythtv/libs/libmythbase/mythversion.h
--- a/mythtv/libs/libmythbase/mythversion.h
+++ b/mythtv/libs/libmythbase/mythversion.h
diff --git a/mythtv/libs/libmythmetadata/videometadatalistmanager.cpp b/mythtv/libs/libmythmetadata/videometadatalistmanager.cpp
--- a/mythtv/libs/libmythmetadata/videometadatalistmanager.cpp
+++ b/mythtv/libs/libmythmetadata/videometadatalistmanager.cpp
diff --git a/mythtv/libs/libmythmetadata/videometadatalistmanager.h b/mythtv/libs/libmythmetadata/videometadatalistmanager.h
--- a/mythtv/libs/libmythmetadata/videometadatalistmanager.h
+++ b/mythtv/libs/libmythmetadata/videometadatalistmanager.h
diff --git a/mythtv/libs/libmythservicecontracts/datacontracts/frontendActionList.h b/mythtv/libs/libmythservicecontracts/datacontracts/frontendActionList.h
+++ b/mythtv/libs/libmythservicecontracts/datacontracts/frontendActionList.h
diff --git a/mythtv/libs/libmythservicecontracts/datacontracts/frontendStatus.h b/mythtv/libs/libmythservicecontracts/datacontracts/frontendStatus.h
--- a/mythtv/libs/libmythservicecontracts/datacontracts/frontendStatus.h
+++ b/mythtv/libs/libmythservicecontracts/datacontracts/frontendStatus.h
diff --git a/mythtv/libs/libmythservicecontracts/libmythservicecontracts.pro b/mythtv/libs/libmythservicecontracts/libmythservicecontracts.pro
--- a/mythtv/libs/libmythservicecontracts/libmythservicecontracts.pro
+++ b/mythtv/libs/libmythservicecontracts/libmythservicecontracts.pro
diff --git a/mythtv/libs/libmythservicecontracts/services/channelServices.h b/mythtv/libs/libmythservicecontracts/services/channelServices.h
--- a/mythtv/libs/libmythservicecontracts/services/channelServices.h
+++ b/mythtv/libs/libmythservicecontracts/services/channelServices.h
diff --git a/mythtv/libs/libmythservicecontracts/services/dvrServices.h b/mythtv/libs/libmythservicecontracts/services/dvrServices.h
--- a/mythtv/libs/libmythservicecontracts/services/dvrServices.h
+++ b/mythtv/libs/libmythservicecontracts/services/dvrServices.h
diff --git a/mythtv/libs/libmythservicecontracts/services/frontendServices.h b/mythtv/libs/libmythservicecontracts/services/frontendServices.h
--- a/mythtv/libs/libmythservicecontracts/services/frontendServices.h
+++ b/mythtv/libs/libmythservicecontracts/services/frontendServices.h
diff --git a/mythtv/libs/libmythservicecontracts/services/videoServices.h b/mythtv/libs/libmythservicecontracts/services/videoServices.h
--- a/mythtv/libs/libmythservicecontracts/services/videoServices.h
+++ b/mythtv/libs/libmythservicecontracts/services/videoServices.h
diff --git a/mythtv/libs/libmythtv/mpeg/atscstreamdata.cpp b/mythtv/libs/libmythtv/mpeg/atscstreamdata.cpp
--- a/mythtv/libs/libmythtv/mpeg/atscstreamdata.cpp
+++ b/mythtv/libs/libmythtv/mpeg/atscstreamdata.cpp
diff --git a/mythtv/libs/libmythtv/mpeg/atscstreamdata.h b/mythtv/libs/libmythtv/mpeg/atscstreamdata.h
--- a/mythtv/libs/libmythtv/mpeg/atscstreamdata.h
+++ b/mythtv/libs/libmythtv/mpeg/atscstreamdata.h
diff --git a/mythtv/libs/libmythtv/mpeg/atsctables.h b/mythtv/libs/libmythtv/mpeg/atsctables.h
--- a/mythtv/libs/libmythtv/mpeg/atsctables.h
+++ b/mythtv/libs/libmythtv/mpeg/atsctables.h
diff --git a/mythtv/libs/libmythtv/mpeg/mpegdescriptors.cpp b/mythtv/libs/libmythtv/mpeg/mpegdescriptors.cpp
--- a/mythtv/libs/libmythtv/mpeg/mpegdescriptors.cpp
+++ b/mythtv/libs/libmythtv/mpeg/mpegdescriptors.cpp
diff --git a/mythtv/libs/libmythtv/mpeg/mpegdescriptors.h b/mythtv/libs/libmythtv/mpeg/mpegdescriptors.h
--- a/mythtv/libs/libmythtv/mpeg/mpegdescriptors.h
+++ b/mythtv/libs/libmythtv/mpeg/mpegdescriptors.h
diff --git a/mythtv/libs/libmythtv/mpeg/mpegstreamdata.cpp b/mythtv/libs/libmythtv/mpeg/mpegstreamdata.cpp
--- a/mythtv/libs/libmythtv/mpeg/mpegstreamdata.cpp
+++ b/mythtv/libs/libmythtv/mpeg/mpegstreamdata.cpp
diff --git a/mythtv/libs/libmythtv/mpeg/mpegtables.cpp b/mythtv/libs/libmythtv/mpeg/mpegtables.cpp
--- a/mythtv/libs/libmythtv/mpeg/mpegtables.cpp
+++ b/mythtv/libs/libmythtv/mpeg/mpegtables.cpp
diff --git a/mythtv/libs/libmythtv/mpeg/mpegtables.h b/mythtv/libs/libmythtv/mpeg/mpegtables.h
--- a/mythtv/libs/libmythtv/mpeg/mpegtables.h
+++ b/mythtv/libs/libmythtv/mpeg/mpegtables.h
diff --git a/mythtv/libs/libmythtv/mpeg/pespacket.cpp b/mythtv/libs/libmythtv/mpeg/pespacket.cpp
--- a/mythtv/libs/libmythtv/mpeg/pespacket.cpp
+++ b/mythtv/libs/libmythtv/mpeg/pespacket.cpp
diff --git a/mythtv/libs/libmythtv/mpeg/sctedescriptors.cpp b/mythtv/libs/libmythtv/mpeg/sctedescriptors.cpp
--- a/mythtv/libs/libmythtv/mpeg/sctedescriptors.cpp
+++ b/mythtv/libs/libmythtv/mpeg/sctedescriptors.cpp
diff --git a/mythtv/libs/libmythtv/mpeg/sctedescriptors.h b/mythtv/libs/libmythtv/mpeg/sctedescriptors.h
--- a/mythtv/libs/libmythtv/mpeg/sctedescriptors.h
+++ b/mythtv/libs/libmythtv/mpeg/sctedescriptors.h
diff --git a/mythtv/libs/libmythtv/mpeg/sctetables.cpp b/mythtv/libs/libmythtv/mpeg/sctetables.cpp
--- a/mythtv/libs/libmythtv/mpeg/sctetables.cpp
+++ b/mythtv/libs/libmythtv/mpeg/sctetables.cpp
diff --git a/mythtv/libs/libmythtv/mpeg/sctetables.h b/mythtv/libs/libmythtv/mpeg/sctetables.h
--- a/mythtv/libs/libmythtv/mpeg/sctetables.h
+++ b/mythtv/libs/libmythtv/mpeg/sctetables.h
diff --git a/mythtv/libs/libmythtv/mpeg/streamlisteners.h b/mythtv/libs/libmythtv/mpeg/streamlisteners.h
--- a/mythtv/libs/libmythtv/mpeg/streamlisteners.h
+++ b/mythtv/libs/libmythtv/mpeg/streamlisteners.h
diff --git a/mythtv/programs/mythbackend/services/channel.cpp b/mythtv/programs/mythbackend/services/channel.cpp
--- a/mythtv/programs/mythbackend/services/channel.cpp
+++ b/mythtv/programs/mythbackend/services/channel.cpp
diff --git a/mythtv/programs/mythbackend/services/channel.h b/mythtv/programs/mythbackend/services/channel.h
--- a/mythtv/programs/mythbackend/services/channel.h
+++ b/mythtv/programs/mythbackend/services/channel.h
diff --git a/mythtv/programs/mythbackend/services/dvr.cpp b/mythtv/programs/mythbackend/services/dvr.cpp
--- a/mythtv/programs/mythbackend/services/dvr.cpp
+++ b/mythtv/programs/mythbackend/services/dvr.cpp
diff --git a/mythtv/programs/mythbackend/services/dvr.h b/mythtv/programs/mythbackend/services/dvr.h
--- a/mythtv/programs/mythbackend/services/dvr.h
+++ b/mythtv/programs/mythbackend/services/dvr.h
diff --git a/mythtv/programs/mythbackend/services/video.cpp b/mythtv/programs/mythbackend/services/video.cpp
--- a/mythtv/programs/mythbackend/services/video.cpp
+++ b/mythtv/programs/mythbackend/services/video.cpp
diff --git a/mythtv/programs/mythbackend/services/video.h b/mythtv/programs/mythbackend/services/video.h
--- a/mythtv/programs/mythbackend/services/video.h
+++ b/mythtv/programs/mythbackend/services/video.h
diff --git a/mythtv/programs/mythfrontend/mythfexml.cpp b/mythtv/programs/mythfrontend/mythfexml.cpp
--- a/mythtv/programs/mythfrontend/mythfexml.cpp
+++ b/mythtv/programs/mythfrontend/mythfexml.cpp
diff --git a/mythtv/programs/mythfrontend/mythfexml.h b/mythtv/programs/mythfrontend/mythfexml.h
--- a/mythtv/programs/mythfrontend/mythfexml.h
+++ b/mythtv/programs/mythfrontend/mythfexml.h
diff --git a/mythtv/programs/mythfrontend/services/frontend.cpp b/mythtv/programs/mythfrontend/services/frontend.cpp
--- a/mythtv/programs/mythfrontend/services/frontend.cpp
+++ b/mythtv/programs/mythfrontend/services/frontend.cpp
diff --git a/mythtv/programs/mythfrontend/services/frontend.h b/mythtv/programs/mythfrontend/services/frontend.h
--- a/mythtv/programs/mythfrontend/services/frontend.h
+++ b/mythtv/programs/mythfrontend/services/frontend.h
diff --git a/mythtv/programs/mythutil/mpegutils.cpp b/mythtv/programs/mythutil/mpegutils.cpp
--- a/mythtv/programs/mythutil/mpegutils.cpp
+++ b/mythtv/programs/mythutil/mpegutils.cpp

Now, retesting this at this point is going to take some work so I'll need some suggestions. My FE & BE are now sitting at commits from 20120117, which means the database schemas at least have been updated a couple of versions. Should I just perform a manual backup of the DB, remove Myth from both boxes, and change the schema version in the DB to an appropriate # and cross our fingers it doesn't complain too much?

I'll give this a try and if you have any additional suggestions, I'm all ears.

comment:18 Changed 12 years ago by jk90090@…

Mark, what settings do you want for the logs on both the frontend and the backend to help collect the right debugs?

comment:19 Changed 12 years ago by markk

Can you first produce a log with:-

mythfrontend -v playback --loglevel=debug

and a second log with:-

mythfrontend -v playback,audio --loglevel=debug

I think it would also be helpful if you could post a short clip of a problem file - say 60seconds that clearly demonstrate the problem on one of your machines.

thanks.

comment:20 Changed 12 years ago by jk90090@…

Downgraded install to 1110 build, ran playback from beginning of a transcoded recording with playback debug (as noted above), and then again with playback,audio. Also recorded 20 second clip on tv playback. Playback was fine.

Upgrade to 1111 build (hash 47d52964f9946e90d9d8edc4392107b338270491), and repeated. Strangely no issue.

As I've come to find out the hard way, the buildebuild script is not the most robust and may be mixing up versions on me, so now I'm going to the 1113 build to figure out if that is the source of the issue. I know the issue was introduced at some point after 1110, but now I can't tell what actual date it was.

comment:21 Changed 12 years ago by jk90090@…

I know why I have differing results now. The --date option on the python ebuild script doesn't work without the hash also I believe. I had removed the tar.gz for the date 1111 and it pulled down the one specific to the hash I passed it. It must have had a newer hash labeled as the wrong date. I'll dig through until I can recreate the playback issue again.

Changed 12 years ago by jk90090@…

Changed 12 years ago by jk90090@…

Changed 12 years ago by jk90090@…

Changed 12 years ago by jk90090@…

Changed 12 years ago by jk90090@…

comment:22 Changed 12 years ago by jk90090@…

scripts/mythtv-buildebuild.py --date=20111113 -s 4f3b78c3ef2a704c5c74013fa1c6cb870cce4631 --- plays OK

scripts/mythtv-buildebuild.py --date=20111121 -s ffc515395acbf36bc0eec00a98ca9da88bc79ed7 --- plays BAD

scripts/mythtv-buildebuild.py --date=20111116 -s c29389645cb298fd5d2d234c17a6af10639dac04 --- plays BAD

scripts/mythtv-buildebuild.py --date=20111115 -s b6f6916a3a10622ca61e431fbb157ecfbb53c267 --- plays BAD

scripts/mythtv-buildebuild.py --date=20111114 -s e78269ac292429bb494ba3537a47a8061f58a9f3 --- plays BAD

scripts/mythtv-buildebuild.py --date=20111114 -s d207a0bddddac4cb015746e2a4b4e5f841897c8c --- plays BAD

scripts/mythtv-buildebuild.py --date=20111113 -s 4f3b78c3ef2a704c5c74013fa1c6cb870cce4631 -- plays GOOD

Attached the logs (one is a duplicate, the build.2.log one) and trying to setup a location for clips (IMG_1451.mov is working sample, IMG_1452.mov is failing sample).

comment:23 Changed 12 years ago by jk90090@…

Also, debugs for the bad sample are for the d207a0bddddac4cb015746e2a4b4e5f841897c8c hash.

comment:24 Changed 12 years ago by jk90090@…

Well, I've tried a few times to post a link to the 4shared location for the video clips but the system just thinks its spam... http://www.4shared.com/folder/6AAGKJl3/Mythtv.html is the link.

comment:25 Changed 12 years ago by Github

Prefer VDPAU over VAAPI.

Refs #10212

Branch: master Changeset: 1ec824fef8bbf59d84bcbb677d662eb550824b92

comment:26 Changed 12 years ago by markk

Owner: markk deleted
Status: newassigned

Looks like a problem with the ringbuffer optimisations. I'll let someone else deal with that.

comment:27 Changed 12 years ago by danielk

Owner: set to danielk

comment:28 Changed 12 years ago by Andrew Leech <andrew@…>

This sounds like the exact same problem I'm having, with medibuntu daily build (v0.25pre-4564-g1fc5ed1) This appears to happen for me on new recordings (dvb-t) as well as transcoded ones, but get worse once transcoded.

The defining points to me seem to be: "Enabling buffering optimisations for low bitrate stream."

before a lot of consecutive:

"Player(3): Waited 225ms for video buffers AAAAAAAAAAAAAAAAAAAAuAAAAAAAAAAP"

and similar, whenever skipping is going on.

Changing the HD Ringbuffer size makes no difference, nor do realtime threads or the audio buffering setting. I've switched from nvidia vdpau to xvid to opengl to intel vaapi (onboard) and had no change.

The skips always happens at exactly the same point in recordings, usually for ~10 - 20 seconds before being fine for a while. Similarly, I tried moving the file from one hard drive to another and still no change, same skip points.

Crucially, I also found on the new playback stats available through the OSD, the "available video buffer", which normally sits around 80%-90% during playback, drops to 0% during the skips. I haven't found much information about what this stat actually refers to yet, although I'm guessing it's the video buffer that's now automatically sized (optimised)?

Andrew

comment:29 Changed 12 years ago by jk90090@…

Still happening as off mythtv-0.25_pre20120223.

Posted a 70M chunk (out of the full 1.1G transcoded file, used dd bs=1M count=70). I did nothing to correct the shortened file so you might need to.

http://www.4shared.com/file/qCFepIYs/sample.html

comment:30 Changed 12 years ago by Jim Stichnoth

Milestone: unknown0.25
Owner: changed from danielk to Jim Stichnoth
Status: assignedaccepted
Version: UnspecifiedMaster Head

comment:31 Changed 12 years ago by Github

Resolution: fixed
Status: acceptedclosed

Fix RingBuffer? starvation when playing .nuv files.

In the original code, the estimated bitrate for .nuv files was set to 0, and downstream code would figure out a suitable blocksize for ringbuffer fills. After the low-bitrate optimizations in #9824, the blocksize ended up being reduced to 2KB. This may be sufficient for local files, but often causes ringbuffer starvation and stuttering playback for remote files.

Fixes #10212. If similar behavior is seen post-commit, please file a new ticket.

Branch: master Changeset: 083fe59e64d015831ce450e1993e83587935bae5

Note: See TracTickets for help on using tickets.