Ticket #2335: comp.html

File comp.html, 23.9 KB (added by david@…, 20 years ago)

Comparison of frontend and backend log for successful and unsuccessful program transitions

Line 
1<html>
2
3<head>
4<style type="text/css">
5.blue { background-color: #00f; }
6.lgreen { background-color: #afa; }
7.dgreen { background-color: #8d8; }
8.red { background-color: #d33; }
9.orange { background-color: #aa0; }
10td { vertical-align: top; font-family: monospace; font-size: x-small; border: 1px solid black; }
11</style>
12</head>
13
14<body>
15
16<p>
17Legend:
18<ul>
19<li><span class="lgreen">First (successful) SwitchLiveTVRingBuffer run lines</li>
20<li><span class="dgreen">First (unsuccessful) SwitchLiveTVRingBuffer run matching lines</li>
21<li><span class="orange">Second (unsuccessful) SwitchLiveTVRingBuffer run lines</li>
22<li><span class="red">Unmatched lines (probably irrelevant)</li>
23</ul>
24</p>
25
26<table>
27
28
29<tr>
30<td>Backend at 04:00 (success)</td><td>Backend at 05:00 (failure)</td>
31</tr>
32
33
34
35<tr>
36
37<td>
38<pre>
39<span class="lgreen">04:00:00.111 TVRec(1): SwitchLiveTVRingBuffer(discont 0, set_rec 1)
4004:00:00.113 TVRec(1): GetProgramRingBufferForLiveTV()
4104:00:00.210 TVRec(1): StartedRecording(0x81f92d0) fn(/var/mythtv/storage/TV/13004_20070110040000.mpg)
4204:00:00.287 TVRec(1): FinishedRecording(American Casino) in recgroup: LiveTV
4304:00:00.291 Chain: Updated endtime for '13004_20070110030000' to 20070110040000
4404:00:00.313 Finished recording American Casino: channel 13004
4504:00:00.317 Preview: 'myth://127.0.0.1:6543/13004_20070110030000.mpg' is not local,
46 replacing with '/var/mythtv/storage/TV/13004_20070110030000.mpg', which is local.
4704:00:00.324 Chain: Appended@11 '13004_20070110040000'
4804:00:00.329 DTVRec(1): SetNextRecord(0x81f92d0, 0x8236b60)
49[mpegts @ 0xb72b1c38]Parser not found for Codec Id: 94211 !
5004:00:01.311 TVRec(1): SetFlags(RingBufferReady,) -> FrontendReady,RunMainLoop,
51 CancelNextRecording,AskAllowRecording,RecorderRunning,RingBufferReady,
5204:00:01.526 TVRec(1): !has_rec(1) !rec_soon(1) curRec(0xaac34758) starttm(2007-01-10T03:00:00)
5304:00:01.537 TVRec(1): Enabling Full LiveTV UI.
540: start_time: 6182.857 duration: 324.012
551: start_time: 6182.944 duration: 323.924
562: start_time: 6182.857 duration: 323.965
57stream: start_time: 68698.407 duration: 3600.136 bitrate=3602 kb/s
5804:00:01.603 AFD: Opened codec 0x820ee30, id(MPEG2VIDEO) type(Video)
5904:00:01.616 AFD: Opened codec 0x820f430, id(MP3) type(Audio)
60
61
62
63
6404:00:01.702 DTVRec(1): ResetForNewFile(void)
6504:00:02.186 RecBase(0): SetRingBuffer(0x8236b60) '/var/mythtv/storage/TV/13004_20070110040000.mpg'
66
6704:00:02.293 TVRec(1): RingBufferChanged()</span>
68<span class="red">04:00:02.189 NVP: Recording does not have position map.
69 Run 'mythcommflag --file 13004_20070110030000.mpg --rebuild' to fix</span>
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84<span class="lgreen">04:00:02.339 TVRec(1): FinishedRecording(American Casino) in recgroup: LiveTV
8504:00:02.363 Chain: Updated endtime for '13004_20070110030000' to 20070110040002
8604:00:02.398 Finished recording American Casino: channel 13004
87</span>
88</pre>
89</td>
90
91<td>
92<pre>
93<span class="dgreen">05:00:00.707 TVRec(1): SwitchLiveTVRingBuffer(discont 0, set_rec 1)
9405:00:00.734 TVRec(1): GetProgramRingBufferForLiveTV()
9505:00:01.012 TVRec(1): StartedRecording(0x8252aa8) fn(/var/mythtv/storage/TV/13004_20070110050000.mpg)
9605:00:01.124 TVRec(1): FinishedRecording(Building the Biggest) in recgroup: LiveTV
9705:00:01.163 Chain: Updated endtime for '13004_20070110040000' to 20070110050001
9805:00:01.191 Finished recording Building the Biggest: channel 13004
9905:00:01.194 Preview: 'myth://127.0.0.1:6543/13004_20070110040000.mpg' is not local,
100 replacing with '/var/mythtv/storage/TV/13004_20070110040000.mpg', which is local.
10105:00:01.240 Chain: Appended@12 '13004_20070110050000'
10205:00:01.275 DTVRec(1): SetNextRecord(0x8252aa8, 0x81db600)
103[mpegts @ 0xb72b1c38]Parser not found for Codec Id: 94211 !
10405:00:02.077 TVRec(1): SetFlags(RingBufferReady,) ->FrontendReady,RunMainLoop,
105 CancelNextRecording,AskAllowRecording,RecorderRunning,RingBufferReady,
10605:00:02.080 TVRec(1): !has_rec(1) !rec_soon(1) curRec(0xaac09008) starttm(2007-01-10T04:00:00)
10705:00:02.081 TVRec(1): Enabling Full LiveTV UI.
1080: start_time: 6506.917 duration: 323.930
1091: start_time: 6506.944 duration: 323.903
1102: start_time: 6506.917 duration: 323.905
111stream: start_time: 72299.079 duration: 3599.224 bitrate=3403 kb/s
11205:00:02.249 AFD: Opened codec 0x81f6d10, id(MPEG2VIDEO) type(Video)
11305:00:02.294 AFD: Opened codec 0x8201cc0, id(MP3) type(Audio)</span>
114<span class="red">[mpeg2video @ 0xb71a0d80]00 motion_type at 8 32
115[mpeg2video @ 0xb71a0d80]00 motion_type at 6 33
116[mpeg2video @ 0xb71a0d80]invalid cbp at 3 34
117[mpeg2video @ 0xb71a0d80]ac-tex damaged at 4 35</span><span class="dgreen">
11805:00:02.709 DTVRec(1): ResetForNewFile(void)
11905:00:03.204 RecBase(0): SetRingBuffer(0x81db600) '/var/mythtv/storage/TV/13004_20070110050000.mpg'</span>
120<span class="orange">05:00:03.252 TVRec(1): SwitchLiveTVRingBuffer(discont 0, set_rec 1)</span>
121<span class="dgreen">05:00:03.322 TVRec(1): RingBufferChanged()</span>
122
123
124<span class="orange">05:00:03.324 TVRec(1): GetProgramRingBufferForLiveTV()
12505:00:03.352 TVRec(1): StartedRecording(0x8250340) fn(/var/mythtv/storage/TV/13004_20070110050003.mpg)
12605:00:03.464 TVRec(1): FinishedRecording(One Step Beyond) in recgroup: LiveTV
12705:00:03.516 Chain: Updated endtime for '13004_20070110050000' to 20070110050003
12805:00:03.644 Finished recording One Step Beyond: channel 13004
12905:00:03.667 Preview: 'myth://127.0.0.1:6543/13004_20070110050000.mpg' is not local,
130 replacing with '/var/mythtv/storage/TV/13004_20070110050000.mpg', which is local.
13105:00:03.674 Chain: Appended@13 '13004_20070110050003'
13205:00:03.676 DTVRec(1): SetNextRecord(0x8250340, 0x81e5b48)
13305:00:03.679 Preview Error: Previewer file '/var/mythtv/storage/TV/13004_20070110050000.mpg' is not valid.
13405:00:03.803 TVRec(1): SetFlags(RingBufferReady,) -> FrontendReady,RunMainLoop,
135 CancelNextRecording,AskAllowRecording,RecorderRunning,RingBufferReady,
13605:00:03.827 TVRec(1): !has_rec(1) !rec_soon(1) curRec(0xaac09008) starttm(2007-01-10T04:00:00)
13705:00:03.904 TVRec(1): Enabling Full LiveTV UI.</span>
138<span class="dgreen">05:00:03.988 TVRec(1): FinishedRecording(Building the Biggest) in recgroup: LiveTV
13905:00:03.990 Chain: Updated endtime for '13004_20070110040000' to 20070110050003
14005:00:04.008 Finished recording Building the Biggest: channel 13004</span><span class="orange">
14105:00:04.095 DTVRec(1): ResetForNewFile(void)
14205:00:04.105 RecBase(0): SetRingBuffer(0x81e5b48) '/var/mythtv/storage/TV/13004_20070110050003.mpg'
14305:00:04.106 TVRec(1): RingBufferChanged()
14405:00:04.214 TVRec(1): FinishedRecording(One Step Beyond) in recgroup: LiveTV
14505:00:04.227 Chain: Updated endtime for '13004_20070110050000' to 20070110050004
14605:00:04.258 Finished recording One Step Beyond: channel 13004
14705:00:05.688 DVBRec(0): 15 PID filters open.
14805:00:07.781 StopLiveTV(void) curRec: 0xaac3cf78 pseudoRec: 0
14905:00:07.822 TVRec(1): Changing from WatchingLiveTV to None
15005:00:07.823 TVRec(1): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,AskAllowRecording,RecorderRunning,RingBufferReady,
15105:00:07.838 TVRec(1): SetFlags(AskAllowRecording,) -> RunMainLoop,AskAllowRecording,RecorderRunning,RingBufferReady,
15205:00:07.873 TVRec(1): Request: Program(no) channel() input() flags(KillRec,KillRingBuffer,)
15305:00:07.948 DVBRec(0): Close() fd(21) -- begin
15405:00:07.978 DVBRec(0): Close() fd(-1) -- end
15505:00:08.204 TVRec(1): ClearFlags(RecorderRunning,) -> RunMainLoop,AskAllowRecording,RingBufferReady,
15605:00:08.214 DVBRec(0): SetOutputPAT(NULL)
15705:00:08.215 DVBRec(0): SetOutputPMT(NULL)
15805:00:08.219 TVRec(1): FinishedRecording(One Step Beyond) in recgroup: LiveTV
15905:00:08.223 Chain: Updated endtime for '13004_20070110050003' to 20070110050008
16005:00:08.261 Finished recording One Step Beyond: channel 13004
16105:00:08.265 TVRec(1): ClearFlags(RecorderRunning,) -> RunMainLoop,AskAllowRecording,RingBufferReady,
16205:00:08.280 TVRec(1): Tearing down RingBuffer
16305:00:08.390 TVRec(1): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,AskAllowRecording,RingBufferReady,
16405:02:41.675 Expiring One Step Beyond from Wed Jan 10 05:00:00 2007, 2 MBytes, forced expire (LiveTV recording)
165</span>
166</pre>
167</td>
168
169</tr>
170<tr>
171<td>Frontend at 04:00 (success)</td><td>Frontend at 05:00 (failure)</td>
172</tr>
173<tr>
174
175<td>
176<pre>
17704:00:00.356 LiveTVChain(live-drevil-2007-01-09T22:52:42): ReloadAll(): Added new recording
17804:00:00.356 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
17904:00:00.743 LiveTVChain(live-drevil-2007-01-09T22:52:42): SwitchTo(7)
18004:00:00.743 LiveTVChain(live-drevil-2007-01-09T22:52:42): Entry@7: '13004_20070110040000'
18104:00:00.752 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(379KB) vfl(30) frh(18) ne:0
18204:00:00.763 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(379KB) vfl(30) frh(18) ne:0
18304:00:00.778 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(379KB) vfl(30) frh(18) ne:0
18404:00:00.817 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(379KB) vfl(30) frh(18) ne:0
18504:00:00.838 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(379KB) vfl(30) frh(18) ne:0
18604:00:00.856 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(346KB) vfl(30) frh(17) ne:0
18704:00:00.876 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(313KB) vfl(30) frh(15) ne:0
18804:00:00.886 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(313KB) vfl(30) frh(15) ne:0
18904:00:00.897 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(313KB) vfl(30) frh(15) ne:0
19004:00:00.906 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
19104:00:00.912 Position map filled from DB to: 89787
19204:00:00.914 SyncPositionMap watchingrecording, from DB: 7586 entries
19304:00:00.916 SyncPositionMap watchingrecording no entries from encoder, try DB
19404:00:00.917 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
19504:00:00.933 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
19604:00:00.966 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
19704:00:00.976 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
19804:00:00.988 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
19904:00:00.999 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(281KB) vfl(30) frh(14) ne:0
20004:00:01.007 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(248KB) vfl(30) frh(12) ne:0
20104:00:01.026 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
20204:00:01.036 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
20304:00:01.048 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
20404:00:01.059 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
20504:00:01.067 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
20604:00:01.078 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
20704:00:01.089 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(215KB) vfl(30) frh(10) ne:0
20804:00:01.102 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(182KB) vfl(30) frh(9) ne:0
20904:00:01.112 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(182KB) vfl(30) frh(9) ne:0
21004:00:01.123 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(182KB) vfl(30) frh(9) ne:0
21104:00:01.135 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(182KB) vfl(30) frh(9) ne:0
21204:00:01.147 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
21304:00:01.157 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
21404:00:01.168 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
21504:00:01.172 Position map filled from DB to: 89853
21604:00:01.174 SyncPositionMap watchingrecording total: 7592 entries
21704:00:01.185 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
21804:00:01.196 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
21904:00:01.207 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(149KB) vfl(30) frh(7) ne:0
22004:00:01.220 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(117KB) vfl(30) frh(5) ne:0
22104:00:01.231 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(117KB) vfl(30) frh(5) ne:0
22204:00:01.242 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(117KB) vfl(30) frh(5) ne:0
22304:00:01.253 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(117KB) vfl(30) frh(5) ne:0
22404:00:01.261 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(84KB) vfl(30) frh(4) ne:1
225
226
227
228
229
230
23104:00:01.261 SwitchToProgram(void)
232
233
234
23504:00:01.270 RingBuf(/var/mythtv/storage/TV/13004_20070110030000.mpg):
236 OpenFile(myth://127.0.0.1:6543/13004_20070110040000.mpg, 10)
23704:00:02.414 NVP: prebuffering pause
23804:00:02.415 NVP: Waiting for prebuffer.. 0 AALAAAAAAAAAAAAAaAAAAAAAAAAAuAA
23904:00:02.444 RingBuf(/var/mythtv/storage/TV/13004_20070110040000.mpg): CalcReadAheadThresh(4000 KB)
240 -> threshhold(146 KB) min read(32 KB) blk size(64 KB)
241XXX - avformatdecoder.cpp : GetFrame : 2624
242XXX - decoderbase.cpp : FileChanged : 676
24304:00:02.482 FileChangedCallback
24404:00:02.512 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(1)
24504:00:02.513 Position map filled from DB to: 0
24604:00:02.513 SyncPositionMap watchingrecording, from DB: 1 entries
24704:00:02.514 Filling position map from 1 to 13
24804:00:02.514 Position map filled from Encoder to: 12
24904:00:02.514 SyncPositionMap watchingrecording total: 2 entries
25004:00:02.515 SyncPositionMap, new totframes: 12, new length: 0, posMap size: 2
251[mpeg2video @ 0xb7154d80]ac-tex damaged at 14 21
252[mpeg2video @ 0xb7154d80]ac-tex damaged at 0 34
253[mpeg2video @ 0xb7154d80]ac-tex damaged at 0 35
25404:00:02.576 NVP: Video is 11.1953 frames behind audio (too slow), dropping frame to catch up.
25504:00:02.577 NVP: Video is 19.3652 frames behind audio (too slow), dropping frame to catch up.
25604:00:02.578 NVP: Video is 25.2489 frames behind audio (too slow), dropping frame to catch up.
25704:00:02.579 NVP: Video is 29.4117 frames behind audio (too slow), dropping frame to catch up.
25804:00:02.580 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
25904:00:02.580 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
26004:00:02.581 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
26104:00:02.582 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
26204:00:02.583 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
26304:00:02.584 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
26404:00:02.585 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
26504:00:02.586 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
26604:00:02.587 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
26704:00:02.588 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
26804:00:02.589 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
26904:00:02.589 NVP: prebuffering pause
27004:00:02.589 NVP: Waiting for prebuffer.. 0 UAAALAAAAAAAAAAAAAAAAAAAAAAAAAL
27104:00:02.751 NVP: Waiting for prebuffer.. 1 UAAAUAAAAAAAAUAAAAAAUuLAAAAAAAu
27204:00:02.913 NVP: Waiting for prebuffer.. 2 UAAAUAAAAAAAAUAAAAAAUuLAAAAAAAu
27304:00:03.062 NVP: Video is 30 frames behind audio (too slow), dropping frame to catch up.
274'video_output' mean = '39680.38', std. dev. = '48046.27', fps = '25.20'
27504:00:03.703 NVP: prebuffering pause
27604:00:03.704 NVP: Waiting for prebuffer.. 0 AAAAAAAAAAAAaALAAAAAAAAAAuAAAAA
27704:00:04.401 NVP: prebuffering pause
27804:00:04.401 NVP: Waiting for prebuffer.. 0 AAAALAAAAAAAAAAAAAAAuAAAaAAAAAA
279'video_output' mean = '41072.33', std. dev. = '9868.28', fps = '24.35'
280'video_output' mean = '39997.42', std. dev. = '7078.93', fps = '25.00'
281</pre>
282</td>
283<td>
284<pre>
28505:00:01.283 LiveTVChain(live-drevil-2007-01-09T22:52:42): ReloadAll(): Added new recording
28605:00:01.284 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
28705:00:01.479 LiveTVChain(live-drevil-2007-01-09T22:52:42): SwitchTo(8)
28805:00:01.479 LiveTVChain(live-drevil-2007-01-09T22:52:42): Entry@8: '13004_20070110050000'
28905:00:01.484 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(512KB) vfl(30) frh(25) ne:0
29005:00:01.496 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(512KB) vfl(30) frh(25) ne:0
29105:00:01.514 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(480KB) vfl(30) frh(24) ne:0
29205:00:01.526 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(480KB) vfl(30) frh(24) ne:0
29305:00:01.537 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(480KB) vfl(30) frh(24) ne:0
29405:00:01.554 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
29505:00:01.566 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
29605:00:01.577 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
29705:00:01.594 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
29805:00:01.606 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
29905:00:01.618 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(447KB) vfl(30) frh(22) ne:0
30005:00:01.635 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(414KB) vfl(30) frh(20) ne:0
30105:00:01.646 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(414KB) vfl(30) frh(20) ne:0
30205:00:01.658 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(414KB) vfl(30) frh(20) ne:0
30305:00:01.674 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(381KB) vfl(30) frh(19) ne:0
30405:00:01.686 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(381KB) vfl(30) frh(19) ne:0
30505:00:01.697 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(381KB) vfl(30) frh(19) ne:0
30605:00:01.713 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(349KB) vfl(30) frh(17) ne:0
30705:00:01.724 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(349KB) vfl(30) frh(17) ne:0
30805:00:01.737 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(349KB) vfl(30) frh(17) ne:0
30905:00:01.754 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
31005:00:01.766 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
31105:00:01.777 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
31205:00:01.793 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
31305:00:01.804 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
31405:00:01.816 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
31505:00:01.836 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(316KB) vfl(30) frh(15) ne:0
31605:00:01.876 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(283KB) vfl(30) frh(14) ne:0
31705:00:01.897 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(283KB) vfl(30) frh(14) ne:0
31805:00:01.925 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(250KB) vfl(30) frh(12) ne:0
31905:00:01.937 Position map filled from DB to: 89649
32005:00:01.944 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(217KB) vfl(30) frh(10) ne:0
32105:00:01.947 SyncPositionMap watchingrecording, from DB: 7556 entries
32205:00:01.947 SyncPositionMap watchingrecording no entries from encoder, try DB
32305:00:01.958 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(217KB) vfl(30) frh(10) ne:0
32405:00:01.970 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(217KB) vfl(30) frh(10) ne:0
32505:00:01.981 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(217KB) vfl(30) frh(10) ne:0
32605:00:01.996 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(185KB) vfl(30) frh(9) ne:0
32705:00:02.010 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(185KB) vfl(30) frh(9) ne:0
32805:00:02.022 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(185KB) vfl(30) frh(9) ne:0
32905:00:02.035 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
33005:00:02.046 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
33105:00:02.058 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
33205:00:02.078 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
33305:00:02.089 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
33405:00:02.103 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
33505:00:02.123 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(152KB) vfl(30) frh(7) ne:0
33605:00:02.151 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(119KB) vfl(30) frh(5) ne:0
33705:00:02.172 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(119KB) vfl(30) frh(5) ne:0
33805:00:02.190 NVP: IsReallyNearEnd() br(500KB) fps(24) sz(86KB) vfl(30) frh(4) ne:1
33905:00:02.190 SwitchToProgram(void)
34005:00:02.243 Position map filled from DB to: 89973
34105:00:02.244 SyncPositionMap watchingrecording total: 7584 entries
34205:00:02.245 SyncPositionMap, new totframes: 89973, new length: 3598, posMap size: 7584
34305:00:02.246 RingBuf(/var/mythtv/storage/TV/13004_20070110040000.mpg):
344 OpenFile(myth://127.0.0.1:6543/13004_20070110050000.mpg, 10)
34505:00:03.306 NVP: prebuffering pause
34605:00:03.307 NVP: Waiting for prebuffer.. 0 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
34705:00:03.468 NVP: Waiting for prebuffer.. 1 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
34805:00:03.630 NVP: Waiting for prebuffer.. 2 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
34905:00:03.683 LiveTVChain(live-drevil-2007-01-09T22:52:42): ReloadAll(): Added new recording
35005:00:03.792 NVP: Waiting for prebuffer.. 3 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
35105:00:03.954 NVP: Waiting for prebuffer.. 4 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
35205:00:04.116 NVP: Waiting for prebuffer.. 5 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
35305:00:04.278 NVP: Waiting for prebuffer.. 6 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
35405:00:04.440 NVP: Waiting for prebuffer.. 7 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
35505:00:04.602 NVP: Waiting for prebuffer.. 8 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
35605:00:04.764 NVP: Waiting for prebuffer.. 9 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
35705:00:04.926 NVP: Prebuffer wait timed out 10 times.
35805:00:04.926 NVP: Waiting for prebuffer.. 0 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
35905:00:05.088 NVP: Waiting for prebuffer.. 1 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
36005:00:05.250 NVP: Waiting for prebuffer.. 2 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
36105:00:05.412 NVP: Waiting for prebuffer.. 3 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
36205:00:05.574 NVP: Waiting for prebuffer.. 4 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
36305:00:05.736 NVP: Waiting for prebuffer.. 5 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
36405:00:05.898 NVP: Waiting for prebuffer.. 6 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
36505:00:06.139 NVP: Waiting for prebuffer.. 7 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
36605:00:06.301 NVP: Waiting for prebuffer.. 8 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
36705:00:06.463 NVP: Waiting for prebuffer.. 9 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
36805:00:06.625 NVP: Prebuffer wait timed out 10 times.
36905:00:06.625 NVP: Waiting for prebuffer.. 0 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
37005:00:06.787 NVP: Waiting for prebuffer.. 1 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
37105:00:06.949 NVP: Waiting for prebuffer.. 2 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
37205:00:07.111 NVP: Waiting for prebuffer.. 3 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
37305:00:07.273 NVP: Waiting for prebuffer.. 4 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
37405:00:07.435 NVP: Waiting for prebuffer.. 5 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
37505:00:07.597 NVP: Waiting for prebuffer.. 6 AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
37605:00:07.747 RingBuf(/var/mythtv/storage/TV/13004_20070110050000.mpg): Invalid file (fd -1) when opening '/var/mythtv/storage/TV/13004_20070110050000.mpg'.
37705:00:07.747 RingBuf(/var/mythtv/storage/TV/13004_20070110050000.mpg): CalcReadAheadThresh(4000 KB)
378 -> threshhold(146 KB) min read(32 KB) blk size(64 KB)
37905:00:07.747 NVP, Error: SwitchToProgram's OpenFile failed.
38005:00:07.747 NVP, Error: Unknown error, exiting decoder
38105:00:07.747 NVP: Exited decoder loop.
38205:00:07.748 TV: Attempting to change from WatchingLiveTV to None
38305:00:07.780 TV: StopStuff() -- begin
38405:00:07.780 TV: StopStuff(): stopping ring buffer[s]
38505:00:07.780 TV: StopStuff(): stopping player[s] (1/2)
38605:00:07.780 TV: StopStuff(): stopping recorder[s]
38705:00:07.789 VideoOutputXv: dtor
38805:00:07.789 VideoOutputXv: DiscardFrames(1)
38905:00:07.789 VideoBuffers::DiscardFrames(1): AAAuAAAAAAAAAAAAAAAAAALAAAAAAAa
39005:00:07.789 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
39105:00:07.790 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
39205:00:07.790 VideoOutputXv: DiscardFrames() 3: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
39305:00:07.790 VideoOutputXv: DiscardFrames(1)
39405:00:07.790 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
39505:00:07.790 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
39605:00:07.791 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
39705:00:07.791 VideoOutputXv: DiscardFrames() 3: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
39805:00:07.793 VideoOutputXv: Closing XVideo port 240
39905:00:08.391 TV: StopStuff(): stopping player[s] (2/2)
400</pre>
401</td>
402
403
404
405</tr>
406</table>
407</body>
408</html>