Legend:

Backend at 04:00 (success)Backend at 05:00 (failure)
04:00:00.111 TVRec(1): SwitchLiveTVRingBuffer(discont 0, set_rec 1)
04:00:00.113 TVRec(1): GetProgramRingBufferForLiveTV()
04:00:00.210 TVRec(1): StartedRecording(0x81f92d0) fn(/var/mythtv/storage/TV/13004_20070110040000.mpg)
04:00:00.287 TVRec(1): FinishedRecording(American Casino) in recgroup: LiveTV
04:00:00.291 Chain: Updated endtime for '13004_20070110030000' to 20070110040000
04:00:00.313 Finished recording American Casino: channel 13004
04:00:00.317 Preview: 'myth://127.0.0.1:6543/13004_20070110030000.mpg' is not local, 
             replacing with '/var/mythtv/storage/TV/13004_20070110030000.mpg', which is local.
04:00:00.324 Chain: Appended@11 '13004_20070110040000'
04:00:00.329 DTVRec(1): SetNextRecord(0x81f92d0, 0x8236b60)
[mpegts @ 0xb72b1c38]Parser not found for Codec Id: 94211 !
04:00:01.311 TVRec(1): SetFlags(RingBufferReady,) -> FrontendReady,RunMainLoop,
             CancelNextRecording,AskAllowRecording,RecorderRunning,RingBufferReady,
04:00:01.526 TVRec(1): !has_rec(1) !rec_soon(1) curRec(0xaac34758) starttm(2007-01-10T03:00:00)
04:00:01.537 TVRec(1): Enabling Full LiveTV UI.
0: start_time: 6182.857 duration: 324.012
1: start_time: 6182.944 duration: 323.924
2: start_time: 6182.857 duration: 323.965
stream: start_time: 68698.407 duration: 3600.136 bitrate=3602 kb/s
04:00:01.603 AFD: Opened codec 0x820ee30, id(MPEG2VIDEO) type(Video)
04:00:01.616 AFD: Opened codec 0x820f430, id(MP3) type(Audio)




04:00:01.702 DTVRec(1): ResetForNewFile(void)
04:00:02.186 RecBase(0): SetRingBuffer(0x8236b60) '/var/mythtv/storage/TV/13004_20070110040000.mpg'

04:00:02.293 TVRec(1): RingBufferChanged()
04:00:02.189 NVP: Recording does not have position map.
             Run 'mythcommflag --file 13004_20070110030000.mpg --rebuild' to fix














04:00:02.339 TVRec(1): FinishedRecording(American Casino) in recgroup: LiveTV
04:00:02.363 Chain: Updated endtime for '13004_20070110030000' to 20070110040002
04:00:02.398 Finished recording American Casino: channel 13004

05:00:00.707 TVRec(1): SwitchLiveTVRingBuffer(discont 0, set_rec 1)
05:00:00.734 TVRec(1): GetProgramRingBufferForLiveTV()
05:00:01.012 TVRec(1): StartedRecording(0x8252aa8) fn(/var/mythtv/storage/TV/13004_20070110050000.mpg)
05:00:01.124 TVRec(1): FinishedRecording(Building the Biggest) in recgroup: LiveTV
05:00:01.163 Chain: Updated endtime for '13004_20070110040000' to 20070110050001
05:00:01.191 Finished recording Building the Biggest: channel 13004
05:00:01.194 Preview: 'myth://127.0.0.1:6543/13004_20070110040000.mpg' is not local, 
                        replacing with '/var/mythtv/storage/TV/13004_20070110040000.mpg', which is local.
05:00:01.240 Chain: Appended@12 '13004_20070110050000'
05:00:01.275 DTVRec(1): SetNextRecord(0x8252aa8, 0x81db600)
[mpegts @ 0xb72b1c38]Parser not found for Codec Id: 94211 !
05:00:02.077 TVRec(1): SetFlags(RingBufferReady,) ->FrontendReady,RunMainLoop,
                        CancelNextRecording,AskAllowRecording,RecorderRunning,RingBufferReady,
05:00:02.080 TVRec(1): !has_rec(1) !rec_soon(1) curRec(0xaac09008) starttm(2007-01-10T04:00:00)
05:00:02.081 TVRec(1): Enabling Full LiveTV UI.
0: start_time: 6506.917 duration: 323.930
1: start_time: 6506.944 duration: 323.903
2: start_time: 6506.917 duration: 323.905
stream: start_time: 72299.079 duration: 3599.224 bitrate=3403 kb/s
05:00:02.249 AFD: Opened codec 0x81f6d10, id(MPEG2VIDEO) type(Video)
05:00:02.294 AFD: Opened codec 0x8201cc0, id(MP3) type(Audio)
[mpeg2video @ 0xb71a0d80]00 motion_type at 8 32
[mpeg2video @ 0xb71a0d80]00 motion_type at 6 33
[mpeg2video @ 0xb71a0d80]invalid cbp at 3 34
[mpeg2video @ 0xb71a0d80]ac-tex damaged at 4 35
05:00:02.709 DTVRec(1): ResetForNewFile(void)
05:00:03.204 RecBase(0): SetRingBuffer(0x81db600) '/var/mythtv/storage/TV/13004_20070110050000.mpg'
05:00:03.252 TVRec(1): SwitchLiveTVRingBuffer(discont 0, set_rec 1)
05:00:03.322 TVRec(1): RingBufferChanged()


05:00:03.324 TVRec(1): GetProgramRingBufferForLiveTV()
05:00:03.352 TVRec(1): StartedRecording(0x8250340) fn(/var/mythtv/storage/TV/13004_20070110050003.mpg)
05:00:03.464 TVRec(1): FinishedRecording(One Step Beyond) in recgroup: LiveTV
05:00:03.516 Chain: Updated endtime for '13004_20070110050000' to 20070110050003
05:00:03.644 Finished recording One Step Beyond: channel 13004
05:00:03.667 Preview: 'myth://127.0.0.1:6543/13004_20070110050000.mpg' is not local, 
			replacing with '/var/mythtv/storage/TV/13004_20070110050000.mpg', which is local.
05:00:03.674 Chain: Appended@13 '13004_20070110050003'
05:00:03.676 DTVRec(1): SetNextRecord(0x8250340, 0x81e5b48)
05:00:03.679 Preview Error: Previewer file '/var/mythtv/storage/TV/13004_20070110050000.mpg' is not valid.
05:00:03.803 TVRec(1): SetFlags(RingBufferReady,) -> FrontendReady,RunMainLoop,
                        CancelNextRecording,AskAllowRecording,RecorderRunning,RingBufferReady,
05:00:03.827 TVRec(1): !has_rec(1) !rec_soon(1) curRec(0xaac09008) starttm(2007-01-10T04:00:00)
05:00:03.904 TVRec(1): Enabling Full LiveTV UI.
05:00:03.988 TVRec(1): FinishedRecording(Building the Biggest) in recgroup: LiveTV
05:00:03.990 Chain: Updated endtime for '13004_20070110040000' to 20070110050003
05:00:04.008 Finished recording Building the Biggest: channel 13004
05:00:04.095 DTVRec(1): ResetForNewFile(void)
05:00:04.105 RecBase(0): SetRingBuffer(0x81e5b48) '/var/mythtv/storage/TV/13004_20070110050003.mpg'
05:00:04.106 TVRec(1): RingBufferChanged()
05:00:04.214 TVRec(1): FinishedRecording(One Step Beyond) in recgroup: LiveTV
05:00:04.227 Chain: Updated endtime for '13004_20070110050000' to 20070110050004
05:00:04.258 Finished recording One Step Beyond: channel 13004
05:00:05.688 DVBRec(0): 15 PID filters open.
05:00:07.781 StopLiveTV(void) curRec: 0xaac3cf78 pseudoRec: 0
05:00:07.822 TVRec(1): Changing from WatchingLiveTV to None
05:00:07.823 TVRec(1): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,AskAllowRecording,RecorderRunning,RingBufferReady,
05:00:07.838 TVRec(1): SetFlags(AskAllowRecording,) -> RunMainLoop,AskAllowRecording,RecorderRunning,RingBufferReady,
05:00:07.873 TVRec(1): Request: Program(no) channel() input() flags(KillRec,KillRingBuffer,)
05:00:07.948 DVBRec(0): Close() fd(21) -- begin
05:00:07.978 DVBRec(0): Close() fd(-1) -- end
05:00:08.204 TVRec(1): ClearFlags(RecorderRunning,) -> RunMainLoop,AskAllowRecording,RingBufferReady,
05:00:08.214 DVBRec(0): SetOutputPAT(NULL)
05:00:08.215 DVBRec(0): SetOutputPMT(NULL)
05:00:08.219 TVRec(1): FinishedRecording(One Step Beyond) in recgroup: LiveTV
05:00:08.223 Chain: Updated endtime for '13004_20070110050003' to 20070110050008
05:00:08.261 Finished recording One Step Beyond: channel 13004
05:00:08.265 TVRec(1): ClearFlags(RecorderRunning,) -> RunMainLoop,AskAllowRecording,RingBufferReady,
05:00:08.280 TVRec(1): Tearing down RingBuffer
05:00:08.390 TVRec(1): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,AskAllowRecording,RingBufferReady,
05:02:41.675 Expiring One Step Beyond from Wed Jan 10 05:00:00 2007, 2 MBytes, forced expire (LiveTV recording)

Frontend at 04:00 (success)Frontend at 05:00 (failure)
04:00:00.356 LiveTVChain(live-drevil-2007-01-09T22:52:42): ReloadAll(): Added new recording
04:00:00.356 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
04:00:00.743 LiveTVChain(live-drevil-2007-01-09T22:52:42): SwitchTo(7)
04:00:00.743 LiveTVChain(live-drevil-2007-01-09T22:52:42): Entry@7: '13004_20070110040000'
04:00:00.752 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(379KB) vfl(30) frh(18) ne:0
04:00:00.763 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(379KB) vfl(30) frh(18) ne:0
04:00:00.778 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(379KB) vfl(30) frh(18) ne:0
04:00:00.817 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(379KB) vfl(30) frh(18) ne:0
04:00:00.838 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(379KB) vfl(30) frh(18) ne:0
04:00:00.856 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(346KB) vfl(30) frh(17) ne:0
04:00:00.876 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(313KB) vfl(30) frh(15) ne:0
04:00:00.886 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(313KB) vfl(30) frh(15) ne:0
04:00:00.897 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(313KB) vfl(30) frh(15) ne:0
04:00:00.906 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
04:00:00.912 Position map filled from DB to: 89787
04:00:00.914 SyncPositionMap watchingrecording, from DB: 7586 entries
04:00:00.916 SyncPositionMap watchingrecording no entries from encoder, try DB
04:00:00.917 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
04:00:00.933 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
04:00:00.966 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
04:00:00.976 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
04:00:00.988 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
04:00:00.999 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
04:00:01.007 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(248KB) vfl(30) frh(12) ne:0
04:00:01.026 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
04:00:01.036 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
04:00:01.048 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
04:00:01.059 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
04:00:01.067 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
04:00:01.078 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
04:00:01.089 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
04:00:01.102 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(182KB) vfl(30) frh(9) ne:0
04:00:01.112 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(182KB) vfl(30) frh(9) ne:0
04:00:01.123 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(182KB) vfl(30) frh(9) ne:0
04:00:01.135 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(182KB) vfl(30) frh(9) ne:0
04:00:01.147 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
04:00:01.157 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
04:00:01.168 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
04:00:01.172 Position map filled from DB to: 89853
04:00:01.174 SyncPositionMap watchingrecording total: 7592 entries
04:00:01.185 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
04:00:01.196 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
04:00:01.207 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
04:00:01.220 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(117KB) vfl(30) frh(5) ne:0
04:00:01.231 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(117KB) vfl(30) frh(5) ne:0
04:00:01.242 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(117KB) vfl(30) frh(5) ne:0
04:00:01.253 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(117KB) vfl(30) frh(5) ne:0
04:00:01.261 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(84KB) vfl(30) frh(4) ne:1






04:00:01.261 SwitchToProgram(void)



04:00:01.270 RingBuf(/var/mythtv/storage/TV/13004_20070110030000.mpg):
             OpenFile(myth://127.0.0.1:6543/13004_20070110040000.mpg, 10)
04:00:02.414 NVP: prebuffering pause
04:00:02.415 NVP: Waiting for prebuffer.. 0 AALAAAAAAAAAAAAAaAAAAAAAAAAAuAA
04:00:02.444 RingBuf(/var/mythtv/storage/TV/13004_20070110040000.mpg): CalcReadAheadThresh(4000 KB)
			 -> threshhold(146 KB) min read(32 KB) blk size(64 KB)
XXX - avformatdecoder.cpp : GetFrame : 2624
XXX - decoderbase.cpp : FileChanged : 676
04:00:02.482 FileChangedCallback
04:00:02.512 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(1)
04:00:02.513 Position map filled from DB to: 0
04:00:02.513 SyncPositionMap watchingrecording, from DB: 1 entries
04:00:02.514 Filling position map from 1 to 13
04:00:02.514 Position map filled from Encoder to: 12
04:00:02.514 SyncPositionMap watchingrecording total: 2 entries
04:00:02.515 SyncPositionMap, new totframes: 12, new length: 0, posMap size: 2
[mpeg2video @ 0xb7154d80]ac-tex damaged at 14 21
[mpeg2video @ 0xb7154d80]ac-tex damaged at 0 34
[mpeg2video @ 0xb7154d80]ac-tex damaged at 0 35
04:00:02.576 NVP: Video is 11.1953 frames behind audio (too slow), dropping frame to catch up.
04:00:02.577 NVP: Video is 19.3652 frames behind audio (too slow), dropping frame to catch up.
04:00:02.578 NVP: Video is 25.2489 frames behind audio (too slow), dropping frame to catch up.
04:00:02.579 NVP: Video is 29.4117 frames behind audio (too slow), dropping frame to catch up.
04:00:02.580 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
04:00:02.580 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
04:00:02.581 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
04:00:02.582 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
04:00:02.583 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
04:00:02.584 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
04:00:02.585 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
04:00:02.586 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
04:00:02.587 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
04:00:02.588 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
04:00:02.589 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
04:00:02.589 NVP: prebuffering pause
04:00:02.589 NVP: Waiting for prebuffer.. 0 UAAALAAAAAAAAAAAAAAAAAAAAAAAAAL
04:00:02.751 NVP: Waiting for prebuffer.. 1 UAAAUAAAAAAAAUAAAAAAUuLAAAAAAAu
04:00:02.913 NVP: Waiting for prebuffer.. 2 UAAAUAAAAAAAAUAAAAAAUuLAAAAAAAu
04:00:03.062 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
'video_output' mean = '39680.38', std. dev. = '48046.27', fps = '25.20'
04:00:03.703 NVP: prebuffering pause
04:00:03.704 NVP: Waiting for prebuffer.. 0 AAAAAAAAAAAAaALAAAAAAAAAAuAAAAA
04:00:04.401 NVP: prebuffering pause
04:00:04.401 NVP: Waiting for prebuffer.. 0 AAAALAAAAAAAAAAAAAAAuAAAaAAAAAA
'video_output' mean = '41072.33', std. dev. = '9868.28', fps = '24.35'
'video_output' mean = '39997.42', std. dev. = '7078.93', fps = '25.00'
05:00:01.283 LiveTVChain(live-drevil-2007-01-09T22:52:42): ReloadAll(): Added new recording
05:00:01.284 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
05:00:01.479 LiveTVChain(live-drevil-2007-01-09T22:52:42): SwitchTo(8)
05:00:01.479 LiveTVChain(live-drevil-2007-01-09T22:52:42): Entry@8: '13004_20070110050000'
05:00:01.484 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(512KB) vfl(30) frh(25) ne:0
05:00:01.496 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(512KB) vfl(30) frh(25) ne:0
05:00:01.514 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(480KB) vfl(30) frh(24) ne:0
05:00:01.526 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(480KB) vfl(30) frh(24) ne:0
05:00:01.537 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(480KB) vfl(30) frh(24) ne:0
05:00:01.554 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
05:00:01.566 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
05:00:01.577 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
05:00:01.594 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
05:00:01.606 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
05:00:01.618 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
05:00:01.635 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(414KB) vfl(30) frh(20) ne:0
05:00:01.646 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(414KB) vfl(30) frh(20) ne:0
05:00:01.658 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(414KB) vfl(30) frh(20) ne:0
05:00:01.674 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(381KB) vfl(30) frh(19) ne:0
05:00:01.686 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(381KB) vfl(30) frh(19) ne:0
05:00:01.697 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(381KB) vfl(30) frh(19) ne:0
05:00:01.713 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(349KB) vfl(30) frh(17) ne:0
05:00:01.724 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(349KB) vfl(30) frh(17) ne:0
05:00:01.737 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(349KB) vfl(30) frh(17) ne:0
05:00:01.754 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
05:00:01.766 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
05:00:01.777 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
05:00:01.793 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
05:00:01.804 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
05:00:01.816 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
05:00:01.836 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
05:00:01.876 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(283KB) vfl(30) frh(14) ne:0
05:00:01.897 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(283KB) vfl(30) frh(14) ne:0
05:00:01.925 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(250KB) vfl(30) frh(12) ne:0
05:00:01.937 Position map filled from DB to: 89649
05:00:01.944 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(217KB) vfl(30) frh(10) ne:0
05:00:01.947 SyncPositionMap watchingrecording, from DB: 7556 entries
05:00:01.947 SyncPositionMap watchingrecording no entries from encoder, try DB
05:00:01.958 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(217KB) vfl(30) frh(10) ne:0
05:00:01.970 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(217KB) vfl(30) frh(10) ne:0
05:00:01.981 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(217KB) vfl(30) frh(10) ne:0
05:00:01.996 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(185KB) vfl(30) frh(9) ne:0
05:00:02.010 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(185KB) vfl(30) frh(9) ne:0
05:00:02.022 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(185KB) vfl(30) frh(9) ne:0
05:00:02.035 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
05:00:02.046 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
05:00:02.058 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
05:00:02.078 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
05:00:02.089 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
05:00:02.103 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
05:00:02.123 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
05:00:02.151 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(119KB) vfl(30) frh(5) ne:0
05:00:02.172 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(119KB) vfl(30) frh(5) ne:0
05:00:02.190 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(86KB) vfl(30) frh(4) ne:1
05:00:02.190 SwitchToProgram(void)
05:00:02.243 Position map filled from DB to: 89973
05:00:02.244 SyncPositionMap watchingrecording total: 7584 entries
05:00:02.245 SyncPositionMap, new totframes: 89973, new length: 3598, posMap size: 7584
05:00:02.246 RingBuf(/var/mythtv/storage/TV/13004_20070110040000.mpg):
             OpenFile(myth://127.0.0.1:6543/13004_20070110050000.mpg, 10)
05:00:03.306 NVP: prebuffering pause
05:00:03.307 NVP: Waiting for prebuffer.. 0 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:03.468 NVP: Waiting for prebuffer.. 1 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:03.630 NVP: Waiting for prebuffer.. 2 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:03.683 LiveTVChain(live-drevil-2007-01-09T22:52:42): ReloadAll(): Added new recording
05:00:03.792 NVP: Waiting for prebuffer.. 3 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:03.954 NVP: Waiting for prebuffer.. 4 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:04.116 NVP: Waiting for prebuffer.. 5 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:04.278 NVP: Waiting for prebuffer.. 6 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:04.440 NVP: Waiting for prebuffer.. 7 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:04.602 NVP: Waiting for prebuffer.. 8 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:04.764 NVP: Waiting for prebuffer.. 9 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:04.926 NVP: Prebuffer wait timed out 10 times.
05:00:04.926 NVP: Waiting for prebuffer.. 0 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:05.088 NVP: Waiting for prebuffer.. 1 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:05.250 NVP: Waiting for prebuffer.. 2 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:05.412 NVP: Waiting for prebuffer.. 3 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:05.574 NVP: Waiting for prebuffer.. 4 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:05.736 NVP: Waiting for prebuffer.. 5 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:05.898 NVP: Waiting for prebuffer.. 6 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:06.139 NVP: Waiting for prebuffer.. 7 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:06.301 NVP: Waiting for prebuffer.. 8 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:06.463 NVP: Waiting for prebuffer.. 9 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:06.625 NVP: Prebuffer wait timed out 10 times.
05:00:06.625 NVP: Waiting for prebuffer.. 0 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:06.787 NVP: Waiting for prebuffer.. 1 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:06.949 NVP: Waiting for prebuffer.. 2 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:07.111 NVP: Waiting for prebuffer.. 3 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:07.273 NVP: Waiting for prebuffer.. 4 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:07.435 NVP: Waiting for prebuffer.. 5 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:07.597 NVP: Waiting for prebuffer.. 6 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:07.747 RingBuf(/var/mythtv/storage/TV/13004_20070110050000.mpg): Invalid file (fd -1) when opening '/var/mythtv/storage/TV/13004_20070110050000.mpg'.
05:00:07.747 RingBuf(/var/mythtv/storage/TV/13004_20070110050000.mpg): CalcReadAheadThresh(4000 KB)
			 -> threshhold(146 KB) min read(32 KB) blk size(64 KB)
05:00:07.747 NVP, Error: SwitchToProgram's OpenFile failed.
05:00:07.747 NVP, Error: Unknown error, exiting decoder
05:00:07.747 NVP: Exited decoder loop.
05:00:07.748 TV: Attempting to change from WatchingLiveTV to None
05:00:07.780 TV: StopStuff() -- begin
05:00:07.780 TV: StopStuff(): stopping ring buffer[s]
05:00:07.780 TV: StopStuff(): stopping player[s] (1/2)
05:00:07.780 TV: StopStuff(): stopping recorder[s]
05:00:07.789 VideoOutputXv: dtor
05:00:07.789 VideoOutputXv: DiscardFrames(1)
05:00:07.789 VideoBuffers::DiscardFrames(1): AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
05:00:07.789 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
05:00:07.790 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
05:00:07.790 VideoOutputXv: DiscardFrames() 3: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
05:00:07.790 VideoOutputXv: DiscardFrames(1)
05:00:07.790 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
05:00:07.790 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
05:00:07.791 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
05:00:07.791 VideoOutputXv: DiscardFrames() 3: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
05:00:07.793 VideoOutputXv: Closing XVideo port 240
05:00:08.391 TV: StopStuff(): stopping player[s] (2/2)