[mythtv-users] Debugging mythfrontend video freeze

[Scott D. Davilla]

>I'd like to get some help in debugging a frontend video freeze. I'm
>using svn version 14938 trunk builds. Setup is as follows;
>
>backend:
>	Dedicated backend w/ two PVR-150 and a dual channel
>HDHomeRun. So 4 encoders. This is all mpeg2 encoding. Backend has
>plenty of resources (core2 du0 at 1.83 GHz with four SATA 500GB
>drives for video storage and 320GB boot. Runs same svn version.
>
>frontend:
>	1GHz Pentium-M with nvidia 7300 for mpeg2 hardware decoding.
>
>
>This setup works quite well in handling HD content from the
>HDHomeRun, video is nice and smooth and cpu percent is 60-70 when
>displaying 1080i or 720p ATSC HD content. The frontend has no problem
>displaying HD content besides the below problem. I do have other
>frontends (both x86 linux and x86 OSX) that don't have the below
>problem.
>

I've made some significant progress on this problem that I'd like to 
share with others that might be having similar problems. First the 
symptoms from the logs;

NVP: Waiting for prebuffer.. 0 ALAADAdL
NVP: prebuffering pause

If you see these, that means the thread filling the video buffer on 
the frontend has tripped some fill threshold and is has sped up 
getting video data from the backend. Normally you will only see 
sporatic bursts this in the log when the video content changes like a 
change to a dark background. The reason is that the  mpeg2 
decompression rate has changed and the video buffer is emptying 
faster than before. The thread filling the video buffer re-fills 
according to the decompressed video rate rather than the actual 
buffer in use. This keeps network traffic throttled to the video 
consumption rate.

If you see lot's of these -- you have a problem.

AO: Broadcasting free space avail
audio waiting for buffer to fill: have 2048 want 4096

If you see these, that means that the thread filling the audio codec 
is waiting for the audio codec to empty it's buffer so the thread can 
transfer more audio data.

If you see lot's of these -- you have a problem.


I was seening both, then sometime later a hang as either the thread 
handling the audi codec or the thread handling the video buffer 
stalled. The threads were basically fighting each other in an attempt 
to keep the video and audio in sync. There were several little 
problems which added up to hang.

1) cat /proc/sys/dev/rtc/max-user-freq. If you get 64, then bad. It 
needs to be 1024 or the audio/video timing gets wrong because the 
frontend cannot use the rtc for timing. To change this (for Ubuntu) 
add the following to /etc/sysctl.conf and "sudo /etc/init.d/procps.sh 
restart" to take effect.

dev.rtc.max-user-freq=1024

since I also have HPET I added

dev.hpet.max-user-freq=1024

2) patch using http://svn.mythtv.org/trac/ticket/4159. This is really 
important in that if the HD video glitches (Mine is ATSC OTA coming 
from an antenna), the glitch can cause XvMC to drop a frame, the 
frame should be recycled but gets held forever. If this happens 
several times, you can end up holding all 8 frame buffers and stall.

3) For HDHomeRun users, patch using 
http://svn.mythtv.org/trac/ticket/4213. The comment is correct in 
that the buffer size is decreased but more important is now the 
network recv size is a multiple of the HDHomeRun UDP transfer size. 
This keeps the TS packets in sync in case of network glitches. That 
was my real issue with 3), the HDHomeRun was sending periodic bad 
packets and needed to be rebooted. It had been continuously powered 
for six months since the last reboot.

4) Request -- It would be nice if 
http://svn.mythtv.org/trac/ticket/3963 was applied to trunk. Since 
the HDHomeRun is inherited from DTVRecorder, it's also going that 
have similar problems as mentioned in the ticket.

I have one last hang point to find, I do have a symptom. ATSC 1080i 
is not always interlaced, the content changes from interlaced to 
de-interlaced and back. This is typically seen rapidly during 
commercials. For example;

2007-12-06 21:06:55.943 NVP: interlaced frame seen after 9 progressive frames
2007-12-06 21:06:55.943 Set video sync frame interval to 33366
2007-12-06 21:06:55.943 Enabled deinterlacing
2007-12-06 21:06:56.126 NVP: progressive frame seen after 6 interlaced  frames
2007-12-06 21:06:56.192 Set video sync frame interval to 33366
2007-12-06 21:06:56.193 Disabled deinterlacing
2007-12-06 21:06:56.210 NVP: interlaced frame seen after 3 progressive frames
2007-12-06 21:06:56.210 Set video sync frame interval to 33366
2007-12-06 21:06:56.210 Enabled deinterlacing
2007-12-06 21:06:56.359 NVP: progressive frame seen after 6 interlaced  frames
2007-12-06 21:06:56.427 Set video sync frame interval to 33366
2007-12-06 21:06:56.427 Disabled deinterlacing
2007-12-06 21:06:56.526 NVP: interlaced frame seen after 5 progressive frames
2007-12-06 21:06:56.527 Set video sync frame interval to 33366
2007-12-06 21:06:56.527 Enabled deinterlacing


The "Enabled deinterlacing" is always the last line in the log.

Scott