[mythtv-users] live tv "jump program file buffer" error

Rob Hodge hodgespeed at gmail.com
Tue Jan 1 11:55:16 UTC 2013 

hello.

hiting an error that seems to be a very non-specific 'you've got a
problem' type of error.

first off, hardware.

i have a core 2 duo 1.83 dell paviliaon d4560 computer.
video card is a nvidia 7300 LE (nvidia proprietary drivers) only
display currently used is on the S-video port.
video tuner is a Winfast HD cinema card; this has been tricked into
working with the hack described here:
http://www.linuxtv.org/wiki/index.php/Leadtek_WinFast_HDTV_Cinema
only signal in is a digital comcast feed.

(not the newest/latest/ greatest, but, eh.)

frontend and backend on one machine.

running on a copy of ubuntu server 12.10 that has had lubuntu-core
overlaid, and the mythbuntu packages overlaid on top of it.
the mythbuntu repos are enabled, and i'm running version .26

when i bring up 'watch live TV' it works, untill i change the channel.
then i get the 'error opening jump program file buffer' message and
mythtvfront end hangs, to the point of the clock displayed in the
front end app stays frozen.

 to get my screen back i have to ssh in and kill the process not once
but twice.

this is 100% repeatable on my setup; i've never managed to change a
channel successfully.

here's my logs, from my last crash. screen on the front end frozen at 3:29 AM

first, frontend:

Jan  1 03:28:37 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:405 (StartTV) TV: Exiting main playback loop.
Jan  1 03:28:37 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythmainwindow.cpp:2606 (PauseIdleTimer) Resuming idle
timer
Jan  1 03:28:43 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:1017 (TV) TV: Creating TV object
Jan  1 03:28:43 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythmainwindow.cpp:2606 (PauseIdleTimer) Resuming idle
timer
Jan  1 03:28:43 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythmainwindow.cpp:2601 (PauseIdleTimer) Suspending idle
timer
Jan  1 03:28:43 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:1232 (Init) TV: Created TvPlayWindow.
Jan  1 03:28:43 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2155 (HandleStateChange) TV: Attempting to
change from None to WatchingLiveTV
Jan  1 03:28:43 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythcorecontext.cpp:375 (ConnectCommandSocket)
MythCoreContext: Connecting to backend server: 10.0.0.59:6543 (try 1
of 1)
Jan  1 03:28:43 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythcorecontext.cpp:1191 (CheckProtoVersion) Using
protocol version 75
Jan  1 03:28:43 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext tv_play.cpp:2222 (HandleStateChange) TV: Spawning LiveTV
Recorder -- begin
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext tv_play.cpp:2229 (HandleStateChange) TV: Spawning LiveTV
Recorder -- end
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2250 (HandleStateChange) TV:
playbackURL(/home/mythtv/livetv/1512_20130101112845.mpg)
cardtype(DUMMY)
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: E
CoreContext audio/audiooutputalsa.cpp:172 (GetPCMInfo) ALSA:
snd_pcm_info_get_card: Operation not permitted
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext audioplayer.cpp:167 (ReinitAudio) AudioPlayer: Enabling
Audio
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythrender_opengl.cpp:76 (Create) OpenGL: Sync to VBlank
is enabled (good!)
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythrender_opengl1.cpp:77 (InitFeatures) OpenGL1: Fragment
program support available
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythrender_opengl.cpp:953 (InitFeatures) OpenGL:
PixelBufferObject support available
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythrender_opengl.cpp:128 (Init) OpenGL: Initialised
MythRenderOpenGL
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext videoout_opengl.cpp:322 (SetupContext) VidOutGL: Created
MythRenderOpenGL device.
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythpainter_ogl.cpp:27 (MythOpenGLPainter) OpenGL painter
using existing OpenGL context.
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythpainter_ogl.cpp:29 (MythOpenGLPainter) OpenGL painter
using existing QGLWidget.
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythplayer.cpp:1750 (InitAVSync) Player(1): Video timing
method: USleep with busy wait
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:5240 (StartPlayer) TV: Created player.
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2394 (HandleStateChange) TV: Changing from
None to WatchingLiveTV
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2406 (HandleStateChange) TV: State is LiveTV &
mctx == ctx
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2408 (HandleStateChange) TV: UpdateOSDInput
done
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2410 (HandleStateChange) TV: UpdateLCD done
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2412 (HandleStateChange) TV: ITVRestart done
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2485 (HandleStateChange) TV: Main UI disabled.
Jan  1 03:28:45 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:403 (StartTV) TV: Entering main playback loop.
Jan  1 03:28:48 Entertainment mythlogserver: mythfrontend[3546]: W
CoreContext ringbuffer.cpp:1035 (WaitForReadsAllowed)
RingBuf(/home/mythtv/livetv/1512_20130101112847.mpg): Taking too long
to be allowed to read..
Jan  1 03:28:49  mythlogserver: last message repeated 3 times
Jan  1 03:28:49 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythpainter_ogl.cpp:62 (ClearCache) Clearing OpenGL
painter cache.
Jan  1 03:28:49 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythpainter_ogl.cpp:27 (MythOpenGLPainter) OpenGL painter
using existing OpenGL context.
Jan  1 03:28:49 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythpainter_ogl.cpp:29 (MythOpenGLPainter) OpenGL painter
using existing QGLWidget.
Jan  1 03:28:49 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext openglvideo.cpp:230 (Init) GLVid: Using custom UYVY input
textures.
Jan  1 03:28:49 Entertainment mythlogserver: mythfrontend[3546]: E
CoreContext videooutbase.cpp:625 (SetupDeinterlace) VideoOutput:
Couldn't load deinterlace filter opengldoubleratekerneldeint
Jan  1 03:28:49 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext osd.cpp:228 (OverrideUIScale) OSD: Base theme size:
800x600
Jan  1 03:28:49 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext osd.cpp:233 (OverrideUIScale) OSD: Scaling factors:
0.25x0.216667
Jan  1 03:28:49 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext avformatdecoder.cpp:2145 (ScanStreams) AFD: Opened codec
0x25bf9c0, id(MPEG2VIDEO) type(Video)
Jan  1 03:28:49 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext avformatdecoder.cpp:2003 (ScanStreams) AFD: codec AC3 has
6 channels
Jan  1 03:28:49 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext avformatdecoder.cpp:2145 (ScanStreams) AFD: Opened codec
0x2347980, id(AC3) type(Audio)
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext audio/audiooutputbase.cpp:791 (Reconfigure) AO: Opening
audio device 'default' ch 2(6) sr 48000 sf 32 bit floating point reenc
0
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: E
CoreContext audio/audiooutputalsa.cpp:961 (OpenMixer) ALSA: no
playback control PCM found on mixer device default
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: E
CoreContext audio/audiooutputalsa.cpp:497 (OpenDevice) ALSA: Unable to
open audio mixer. Volume control disabled
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext avformatdecoder.cpp:783 (SetEof) AFD: Resetting byte
context eof (livetv 1 was eof 0)
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 101ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 204ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 306ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 409ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 512ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 614ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 717ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:50 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 820ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:51 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 922ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:51 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 1025ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:51 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 1127ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:51 Entertainment mythlogserver: mythfrontend[3546]: W
Decoder ringbuffer.cpp:1035 (WaitForReadsAllowed)
RingBuf(/home/mythtv/livetv/1512_20130101112847.mpg): Taking too long
to be allowed to read..
Jan  1 03:28:51 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 1230ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:51 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 1333ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:51 Entertainment mythlogserver: mythfrontend[3546]: W
Decoder ringbuffer.cpp:1035 (WaitForReadsAllowed)
RingBuf(/home/mythtv/livetv/1512_20130101112847.mpg): Taking too long
to be allowed to read..
Jan  1 03:28:51 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 1435ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:51 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 1538ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAuLP
Jan  1 03:28:55 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 103ms for video buffers AAUAAUAAuAALUUAUUAUUAUuAAAAAAAAP
Jan  1 03:28:55 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 205ms for video buffers AAUAAUAAuAALUUAUUAUUAUuAAAAAAAAP
Jan  1 03:28:55 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 308ms for video buffers AAUAAUAAuAALUUAUUAUUAUuAAAAAAAAP
Jan  1 03:28:55 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 410ms for video buffers AAUAAUAAuAALUUAUUAUUAUuAAAAAAAAP
Jan  1 03:28:55 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 513ms for video buffers AAUAAUAAuAALUUAUUAUUAUuAAAAAAAAP
Jan  1 03:28:56 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 103ms for video buffers uAAAAUAAUAAUAAuAALAAAUUAUUAUUAAP
Jan  1 03:28:57 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 205ms for video buffers uAAAAUAAUAAUAAuAALAAAUUAUUAUUAAP
Jan  1 03:28:57 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 308ms for video buffers uAAAAUAAUAAUAAuAALAAAUUAUUAUUAAP
Jan  1 03:28:57 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 411ms for video buffers uAAAAUAAUAAUAAuAALAAAUUAUUAUUAAP
Jan  1 03:28:57 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 513ms for video buffers uAAAAUAAUAAUAAuAALAAAUUAUUAUUAAP
Jan  1 03:28:58 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 102ms for video buffers UUAUUAUUAAAUAAUAAUAAuAALAAAAUAAP
Jan  1 03:28:58 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 205ms for video buffers UUAUUAUUAAAUAAUAAUAAuAALAAAAUAAP
Jan  1 03:28:58 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 307ms for video buffers UUAUUAUUAAAUAAUAAUAAuAALAAAAUAAP
Jan  1 03:28:58 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 410ms for video buffers UUAUUAUUAAAUAAUAAUAAuAALAAAAUAAP
Jan  1 03:28:58 Entertainment mythlogserver: mythfrontend[3546]: W
Decoder ringbuffer.cpp:1035 (WaitForReadsAllowed)
RingBuf(/home/mythtv/livetv/1512_20130101112847.mpg): Taking too long
to be allowed to read..
Jan  1 03:28:58 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 513ms for video buffers UUAUUAUUAAAUAAUAAUAAuAALAAAAUAAP
Jan  1 03:28:59 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 615ms for video buffers UUAUUAUUAAAUAAUAAUAAuAALAAAAUAAP
Jan  1 03:28:59 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 718ms for video buffers UUAUUAUUAAAUAAUAAUAAuAALAAAAUAAP
Jan  1 03:29:00 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 103ms for video buffers AAAAAAAUAUUAUUAUUUAAUAAUAAuAALAP
Jan  1 03:29:00 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 206ms for video buffers AAAAAAAUAUUAUUAUUUAAUAAUAAuAALAP
Jan  1 03:29:00 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 309ms for video buffers AAAAAAAUAUUAUUAUUUAAUAAUAAuAALAP
Jan  1 03:29:00 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 412ms for video buffers AAAAAAAUAUUAUUAUUUAAUAAUAAuAALAP
Jan  1 03:29:00 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 514ms for video buffers AAAAAAAUAUUAUUAUUUAAUAAUAAuAALAP
Jan  1 03:29:01 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythplayer.cpp:2091 (PrebufferEnoughFrames) Player(1):
Waited 103ms for video buffers AAAAAAAAAAAAAAAUUAUUAUUUUuUAAuLP
Jan  1 03:29:21 Entertainment mythlogserver: mythfrontend[3546]: E
CoreContext fileringbuffer.cpp:290 (OpenFile)
FileRingBuf(/home/mythtv/livetv/1041_20130101112911.mpg): OpenFile():
File too small (0B).
Jan  1 03:29:21 Entertainment mythlogserver: mythfrontend[3546]: E
CoreContext mythplayer.cpp:2627 (JumpToProgram) Player(1):
JumpToProgram's OpenFile failed (card type: DVB).
Jan  1 03:29:21 Entertainment mythlogserver: mythfrontend[3546]: E
CoreContext mythplayer.cpp:2628 (JumpToProgram) LiveTVChain has 4
entries#012   DUMMY: 1512 (11:28:45 to 11:28:47)#012     DVB: 1512
(11:28:47 to 11:29:09) discontinuous#012   DUMMY: 1041 (11:29:09 to
11:29:11) discontinuous#012*    DVB: 1041 (11:29:11 to 12:30:15)
discontinuous
Jan  1 03:29:21 Entertainment mythlogserver: mythfrontend[3546]: E
CoreContext mythplayer.cpp:2839 (EventLoop) Player(1): Unknown
recorder error, exiting decoder
Jan  1 03:29:21 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2155 (HandleStateChange) TV: Attempting to
change from WatchingLiveTV to None
Jan  1 03:29:21 Entertainment mythlogserver: mythfrontend[3546]: W
CoreContext mythpainter.cpp:34 (Teardown) MythPainter: 3 images not
yet de-allocated.
Jan  1 03:29:21 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythpainter_ogl.cpp:62 (ClearCache) Clearing OpenGL
painter cache.
Jan  1 03:29:21 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythrender_opengl1.cpp:280 (DeleteOpenGLResources)
OpenGL1: Deleting OpenGL Resources
Jan  1 03:29:21 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythrender_opengl.cpp:1042 (DeleteOpenGLResources) OpenGL:
Deleting OpenGL Resources
Jan  1 03:29:22 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2394 (HandleStateChange) TV: Changing from
WatchingLiveTV to None
Jan  1 03:29:22 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:405 (StartTV) TV: Exiting main playback loop.
Jan  1 03:29:22 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2155 (HandleStateChange) TV: Attempting to
change from None to WatchingLiveTV
Jan  1 03:29:22 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythcorecontext.cpp:375 (ConnectCommandSocket)
MythCoreContext: Connecting to backend server: 10.0.0.59:6543 (try 1
of 1)
Jan  1 03:29:22 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext mythcorecontext.cpp:1191 (CheckProtoVersion) Using
protocol version 75
Jan  1 03:29:22 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext tv_play.cpp:2222 (HandleStateChange) TV: Spawning LiveTV
Recorder -- begin
Jan  1 03:29:24 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext tv_play.cpp:2229 (HandleStateChange) TV: Spawning LiveTV
Recorder -- end
Jan  1 03:29:24 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2250 (HandleStateChange) TV:
playbackURL(/home/mythtv/livetv/1512_20130101112922.mpg)
cardtype(DUMMY)
Jan  1 03:29:24 Entertainment mythlogserver: mythfrontend[3546]: E
CoreContext tv_play.cpp:2267 (HandleStateChange) TV: LiveTV not
successfully started
Jan  1 03:29:24 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:2485 (HandleStateChange) TV: Main UI disabled.
Jan  1 03:29:24 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:403 (StartTV) TV: Entering main playback loop.
Jan  1 03:29:24 Entertainment mythlogserver: mythfrontend[3546]: I
CoreContext tv_play.cpp:405 (StartTV) TV: Exiting main playback loop.
Jan  1 03:29:24 Entertainment mythlogserver: mythfrontend[3546]: N
CoreContext mythmainwindow.cpp:2606 (PauseIdleTimer) Resuming idle
timer


now, backend.

Jan  1 03:28:24 Entertainment mythlogserver: mythbackend[1859]: I
HouseKeeping housekeeper.cpp:221 (RunHouseKeeping) Running
housekeeping thread
Jan  1 03:28:33 Entertainment mythlogserver: mythbackend[1859]: I
ProcessRequest mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN
Monitor
Jan  1 03:28:33 Entertainment mythlogserver: mythbackend[1859]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding:
Entertainment as a client (events: 0)
Jan  1 03:28:42 Entertainment mythlogserver: mythbackend[1859]: I
ProcessRequest mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN
Playback
Jan  1 03:28:42 Entertainment mythlogserver: mythbackend[1859]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding:
Entertainment as a client (events: 0)
Jan  1 03:28:42 Entertainment mythlogserver: mythbackend[1859]: I
TVRecEvent tv_rec.cpp:1043 (HandleStateChange) TVRec(1): Changing from
None to WatchingLiveTV
Jan  1 03:28:43 Entertainment mythlogserver: mythbackend[1859]: I
TVRecEvent tv_rec.cpp:3562 (TuningCheckForHWChange) TVRec(1): HW
Tuner: 1->1
Jan  1 03:28:45 Entertainment mythlogserver: mythbackend[1859]: N
CoreContext autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams():
Max required Free Space: 3.0 GB w/freq: 14 min
Jan  1 03:28:47 Entertainment mythlogserver: mythbackend[1859]: N
CoreContext autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams():
Max required Free Space: 3.0 GB w/freq: 14 min
Jan  1 03:28:49 Entertainment mythlogserver: mythbackend[1859]: I
ProcessRequest recorderbase.cpp:395 (GetKeyframePositions)
RecBase(1:/dev/dvb/adapter0/frontend0):
GetKeyframePositions(1,9223372036854775807,#1) out of 2
Jan  1 03:28:50 Entertainment mythlogserver: mythbackend[1859]: I
ProcessRequest recorderbase.cpp:395 (GetKeyframePositions)
RecBase(1:/dev/dvb/adapter0/frontend0):
GetKeyframePositions(1,9223372036854775807,#1) out of 2
Jan  1 03:29:07 Entertainment mythlogserver: mythbackend[1859]: I
TVRecEvent tv_rec.cpp:3562 (TuningCheckForHWChange) TVRec(1): HW
Tuner: 1->1
Jan  1 03:29:09 Entertainment mythlogserver: mythbackend[1859]: N
CoreContext autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams():
Max required Free Space: 3.0 GB w/freq: 14 min
Jan  1 03:29:10 Entertainment mythlogserver: mythbackend[1859]: E
DVBRead dtvsignalmonitor.cpp:347 (HandlePMT)
DTVSM(/dev/dvb/adapter0/frontend0): Wrong PMT; pmt->pn(3) desired(4)
Jan  1 03:29:10 Entertainment mythlogserver: mythbackend[1859]: E
DVBRead dtvsignalmonitor.cpp:347 (HandlePMT)
DTVSM(/dev/dvb/adapter0/frontend0): Wrong PMT; pmt->pn(5) desired(4)
Jan  1 03:29:10 Entertainment mythlogserver: mythbackend[1859]: E
DVBRead dtvsignalmonitor.cpp:347 (HandlePMT)
DTVSM(/dev/dvb/adapter0/frontend0): Wrong PMT; pmt->pn(2) desired(4)
Jan  1 03:29:10 Entertainment mythlogserver: mythbackend[1859]: E
DVBRead dtvsignalmonitor.cpp:347 (HandlePMT)
DTVSM(/dev/dvb/adapter0/frontend0): Wrong PMT; pmt->pn(1) desired(4)
Jan  1 03:29:11 Entertainment mythlogserver: mythbackend[1859]: N
CoreContext autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams():
Max required Free Space: 3.0 GB w/freq: 14 min
Jan  1 03:29:21 Entertainment mythlogserver: mythbackend[1859]: I
TVRecEvent tv_rec.cpp:1043 (HandleStateChange) TVRec(1): Changing from
WatchingLiveTV to None
Jan  1 03:29:23 Entertainment mythlogserver: mythbackend[1859]: I
TVRecEvent tv_rec.cpp:830 (FinishedRecording) TVRec(1):
FinishedRecording(1041_2013-01-01T11:29:11Z) damaged
recq:<RecordingQuality overall_score="0"
key="1041_2013-01-01T11:29:11Z">#012    <Gap
start="2013-01-01T10:15:15Z" end="2013-01-01T12:30:15Z"
duration="8100" />#012</RecordingQuality>
Jan  1 03:29:23 Entertainment mythJan  1 03:29:23 Entertainment
mythlogserver: mythbackend[1859]: I ProcessRequest mainserver.cpp:1395
(HandleAnnounce) MainServer::ANN Playback
Jan  1 03:29:23 Entertainment mythlogserver: mythbackend[1859]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding:
Entertainment as a client (events: 0)
Jan  1 03:29:23 Entertainment mythlogserver: mythbackend[1859]: I
TVRecEvent tv_rec.cpp:1043 (HandleStateChange) TVRec(1): Changing from
None to WatchingLiveTV
Jan  1 03:29:23 Entertainment mythlogserver: mythbackend[1859]: I
TVRecEvent tv_rec.cpp:3562 (TuningCheckForHWChange) TVRec(1): HW
Tuner: 1->1
Jan  1 03:29:23 Entertainment mythlogserver: mythbackend[1859]: N
CoreContext autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams():
Max required Free Space: 3.0 GB w/freq: 14 min
Jan  1 03:29:24 Entertainment mythlogserver: mythbackend[1859]: I
TVRecEvent tv_rec.cpp:1043 (HandleStateChange) TVRec(1): Changing from
WatchingLiveTV to None
Jan  1 03:30:07 Entertainment mythlogserver: mythbackend[1859]: N
Expire autoexpire.cpp:641 (SendDeleteMessages) Expiring 0 MB for 1512
at 2013-01-01T11:28:45Z => Unknown

so far, i have tried:
running frontend sudo'd (to check for permission problems)
i've verified 'quick channel change' is set to never.
i've tried increasing the delay on changing channels to 250ms
re-scanning channels

anyone have any ideas, or anything to point me in the right direction?

More information about the mythtv-users mailing list