[mythtv] NVP is not playing after 20000 msec

John P Poet jppoet at gmail.com
Fri Dec 30 22:59:36 EST 2005


Starting a couple of weeks ago (I will track down exactly when, if
necessary), I have had a lot of problems just trying to PLAY a
recording.

The screen will go black for several seconds (this is normal), but
then instead of the show starting, it will kick back to the Recorded
Programs screen with the dialog:

        You have finished watching:
        "Show Name"
        [Delete it, but allow it to re-record]
        [Delete it]
        [Save it so I can watch it again]

My backend log just has:

        adding: jade a remote file transfer

My frontend log has:

2005-12-30 20:45:36.221 Using protocol version 22
2005-12-30 20:45:38.772 TV: Attempting to change from None to
WatchingPreRecorded
2005-12-30 20:45:38.772
RingBuf(myth://192.168.2.50:6543/1014_20050909130000_20050909135800.nuv):
OpenFile(myth://192.168.2.50:6543/1014_20050909130000_20050909135800.nuv,
6)
2005-12-30 20:45:58.856 TV: StartPlayer(): took 20003 ms to start player.
2005-12-30 20:45:58.857 TV Error: StartPlayer(): NVP is not playing
after 20000 msec
2005-12-30 20:45:58.866 TV: Changing from None to WatchingPreRecorded
2005-12-30 20:45:58.872 TV Error: nvp->IsPlaying() timed out
2005-12-30 20:45:58.873 TV: Attempting to change from
WatchingPreRecorded to None
2005-12-30 20:45:58.873 TV: StopStuff() -- begin
2005-12-30 20:45:58.873 TV: StopStuff(): stopping ring buffer[s]
2005-12-30 20:45:59.284 TV: StopStuff(): stopping player[s] (1/2)
2005-12-30 20:45:59.285 TV: StopStuff(): stopping player[s] (2/2)
0: start_time: 111.082 duration: 323.489
1: start_time: 111.040 duration: 323.502
2: start_time: 111.040 duration: 323.502
stream: start_time: 1233.780 duration: 3594.787 bitrate=15818 kb/s
2005-12-30 20:46:02.330 AFD: Stream #0, has id 0x49 codec id
MPEG2VIDEO, type Video at 0x0xb5b00550
2005-12-30 20:46:02.332 detectInterlace(Detect Scan, Detect Scan,
29.97, 1088) ->Interlaced Scan
2005-12-30 20:46:02.332 Interlaced: Interlaced Scan  video_height:
1088  fps: 29.97
2005-12-30 20:46:02.332 AFD: Looking for decoder for MPEG2VIDEO
2005-12-30 20:46:02.332 AFD: Opened codec 0xb5b03d00, id(MPEG2VIDEO) type(Video)
2005-12-30 20:46:02.332 AFD: Stream #1, has id 0x52 codec id AC3, type
Audio at 0x0xb5b03ff0
2005-12-30 20:46:02.333 AFD: Looking for decoder for AC3
2005-12-30 20:46:02.333 AFD: Opened codec 0xb5b040b0, id(AC3) type(Audio)
2005-12-30 20:46:02.333 AFD: Audio Track #1 is A/V stream #1 and has 6
channels in the English language(6647399).
2005-12-30 20:46:02.333 AFD: Stream #2, has id 0x53 codec id AC3, type
Audio at 0x0xb5b04510
2005-12-30 20:46:02.333 AFD: Looking for decoder for AC3
2005-12-30 20:46:02.334 AFD: Opened codec 0xb5b045d0, id(AC3) type(Audio)
2005-12-30 20:46:02.334 AFD: Audio Track #2 is A/V stream #2 and has 2
channels in the English language(6647399).
2005-12-30 20:46:02.334 RingBuf:CalcReadAheadThresh(80768 KB) ->
threshhold(1000 KB) readblocksize(500 KB)
2005-12-30 20:46:02.334 AFD: Trying to select audio track (w/lang)
2005-12-30 20:46:02.334 AFD: Selected track 1: English AC3 5.1ch (A/V Stream #1)
2005-12-30 20:46:02.334 AFD: Initializing audio parms from audio track #1
2005-12-30 20:46:02.334 AFD: Audio format changed
                        from id(NONE)    -1Hz -1ch   0bps    ;
id(NONE)    -1Hz -1ch   0bps
                        to   id( AC3) 48000Hz  6ch  16bps pt ; id(
AC3) 48000Hz  2ch  16bps pt
2005-12-30 20:46:02.335 Opening audio device 'iec958'.
2005-12-30 20:46:02.344 Resyncing position map. posmapStarted = 0
livetv(0) watchingRec(0)
2005-12-30 20:46:02.493 Position map filled from DB to: 107771
2005-12-30 20:46:02.494 SyncPositionMap prerecorded, from DB: 7589 entries
2005-12-30 20:46:02.494 SyncPositionMap, new totframes: 107771, new
length: 3595, posMap size: 7589
2005-12-30 20:46:02.495 AFD: Position map found
2005-12-30 20:46:02.495 AFD: Successfully opened decoder for file:
"myth://192.168.2.50:6543/1014_20050909130000_20050909135800.nuv".
novideo(0)
2005-12-30 20:46:02.498 VideoOutputXv: ctor
2005-12-30 20:46:02.505 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0
2005-12-30 20:46:02.508 Snapping width to avoid scaling: dispwoff
1920, dispxoff: 0
2005-12-30 20:46:02.508 Image size. dispxoff 0, dispyoff: 135,
dispwoff: 1920, disphoff: 810
2005-12-30 20:46:02.508 Image size. imgx 0, imgy: 0, imgw: 1920, imgh: 1080
2005-12-30 20:46:02.508 VideoOutputXv: Pixel dimensions: Screen
1920x1080, window 1920x1080
2005-12-30 20:46:02.508 VideoOutputXv: Estimated display dimensions:
483x272 mm Aspect: 1.77574
2005-12-30 20:46:02.508 VideoOutputXv: Estimated window dimensions:
483x272 mm Aspect: 1.77574
2005-12-30 20:46:02.510 VideoOutputXv: @ j=3 Looking for flag[s]:
XvInputMask XvImageMask
2005-12-30 20:46:02.510 VideoOutputXv: Adaptor: 0 has flag[s]:
XvInputMask XvImageMask
2005-12-30 20:46:02.510 VideoOutputXv: XVideo surface found on port 177
2005-12-30 20:46:02.510 VideoOutputXv: XVideo Format #0 is 'YUY2'
2005-12-30 20:46:02.510 VideoOutputXv: XVideo Format #1 is 'YV12'
2005-12-30 20:46:02.510 VideoOutputXv: XVideo Format #2 is 'UYVY'
2005-12-30 20:46:02.510 VideoOutputXv: XVideo Format #3 is 'I420'
2005-12-30 20:46:02.510 VideoOutputXv: Using XVideo Format 'I420'
2005-12-30 20:46:02.663 Snapping width to avoid scaling: dispwoff
1920, dispxoff: 0
2005-12-30 20:46:02.663 Image size. dispxoff 0, dispyoff: 0, dispwoff:
1920, disphoff: 1080
2005-12-30 20:46:02.663 Image size. imgx 0, imgy: 0, imgw: 1920, imgh: 1080
2005-12-30 20:46:06.460 NVP: ClearAfterSeek()
2005-12-30 20:46:06.461 VideoOutputXv: ClearAfterSeek()
2005-12-30 20:46:06.461 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2005-12-30 20:46:06.461 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2005-12-30 20:46:06.463 Using realtime priority.
2005-12-30 20:46:06.485 Using deinterlace method kerneldeint
2005-12-30 20:46:06.589 nVidiaVideoSync: VBlank ioctl did not work,
unimplemented in this driver?
2005-12-30 20:46:06.589 DRMVideoSync: Could not open device
/dev/dri/card0, No such file or directory
2005-12-30 20:46:06.591 OpenGLVideoSync: GLX extensions:
GLX_EXT_visual_info GLX_EXT_visual_rating GLX_SGIX_fbconfig
GLX_SGIX_pbuffer GLX_SGI_video_sync GLX_
SGI_swap_control GLX_ARB_multisample GLX_NV_float_buffer
GLX_ARB_get_proc_address
2005-12-30 20:46:06.592 OpenGLVideoSync: x,y -> 960, 540
2005-12-30 20:46:06.624 Using OpenGLVideoSync
2005-12-30 20:46:06.645 Using audio as timebase
2005-12-30 20:46:06.645 Video timing method: SGI OpenGL
2005-12-30 20:46:06.645 Refresh rate: 16682, frame interval: 33366
2005-12-30 20:46:06.648 NVP: Waiting for prebuffer.. 0
uLAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2005-12-30 20:46:06.725 AFD: DoFastForward(78600, do flush)
2005-12-30 20:46:06.725 Dec: DoFastForward(78600 (1), do discard frames)
2005-12-30 20:46:06.734 AFD: SeekReset(78611, 0, do flush, do discard)
2005-12-30 20:46:06.734 AFD: SeekReset() flushing
2005-12-30 20:46:06.735 VideoBuffers::DiscardFrames():
UAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2005-12-30 20:46:06.735 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2005-12-30 20:46:06.735 NVP: ClearAfterSeek()
2005-12-30 20:46:06.735 VideoOutputXv: ClearAfterSeek()
2005-12-30 20:46:06.735 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2005-12-30 20:46:06.735 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2005-12-30 20:46:06.753 NVP: Exited decoder loop.
2005-12-30 20:46:06.799 VideoOutputXv: dtor
2005-12-30 20:46:06.799 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2005-12-30 20:46:06.800 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2005-12-30 20:46:06.890 TV: StopStuff() -- end
2005-12-30 20:46:06.891 TV: Changing from WatchingPreRecorded to None

I notice two things in the above log:

        TV Error: StartPlayer(): NVP is not playing after 20000 msec
        TV Error: nvp->IsPlaying() timed out
and
        CalcReadAheadThresh(80768 KB)

When it starts up normally, the CalcReadAheadThresh is closer to 19000.
Does the "nvp->IsPlaying() timed out" mean anything?  Even after that
message, it still seems to be attempting to play the file - but it
fails.

Am I the only one seeing this?  If so, I will have to figure what I
have broken on my system.

Thanks,

John


More information about the mythtv-dev mailing list