Ticket #11262: backlog.3

File backlog.3, 30.2 KB (added by Saul <jaglover@…>, 14 years ago)

Backend log with -v channel,record - with poll time 5000 ms

Line 
12012-12-02 06:31:35.739881 C mythbackend version: fixes/0.26 [v0.26.0] www.mythtv.org
22012-12-02 06:31:35.739914 C Qt version: compile: 4.8.3, runtime: 4.8.3
32012-12-02 06:31:35.739920 N Enabled verbose msgs: general channel record
42012-12-02 06:31:35.739931 N Setting Log Level to LOG_INFO
52012-12-02 06:31:35.740442 I Added logging to the console
62012-12-02 06:31:35.741040 I Setup Interrupt handler
72012-12-02 06:31:35.741054 I Setup Terminated handler
82012-12-02 06:31:35.741065 I Setup Segmentation fault handler
92012-12-02 06:31:35.741088 I Setup Aborted handler
102012-12-02 06:31:35.741098 I Setup Bus error handler
112012-12-02 06:31:35.741108 I Setup Floating point exception handler
122012-12-02 06:31:35.741118 I Setup Illegal instruction handler
132012-12-02 06:31:35.741131 I Setup Real-time signal 0 handler
142012-12-02 06:31:35.741247 N Using runtime prefix = /usr
152012-12-02 06:31:35.741287 N Using configuration directory = /root/.mythtv
162012-12-02 06:31:35.741389 I Assumed character encoding: en_US.UTF-8
172012-12-02 06:31:35.741838 N Empty LocalHostName.
182012-12-02 06:31:35.741848 I Using localhost value of zeus
192012-12-02 06:31:35.754763 N Setting QT default locale to en_US
202012-12-02 06:31:35.754836 I Current locale en_US
212012-12-02 06:31:35.754889 N Reading locale defaults from /usr/share/mythtv//locales/en_us.xml
222012-12-02 06:31:35.763206 I Current MythTV Schema Version (DBSchemaVer): 1307
232012-12-02 06:31:35.763893 I Loading en_us translation for module mythfrontend
242012-12-02 06:31:35.764664 N MythBackend: Starting up as the master server.
252012-12-02 06:31:35.769548 I TVRec(5): Start channel: 2.
262012-12-02 06:31:35.769734 I V4LChannel(/dev/video1): Device name 'Hauppauge WinTV-HVR2250' driver 'saa7164'.
272012-12-02 06:31:35.769758 I V4LChannel(/dev/video1): v4l2: 1 stream io: 0 std io: 1 async io: 0 tuner 1 sliced vbi 0
282012-12-02 06:31:35.777862 I ChannelBase(5): Input #5: 'tuner' schan(2) sourceid(1) ccid(5)
292012-12-02 06:31:35.777875 I ChannelBase(5): Current Input #5: 'tuner'
302012-12-02 06:31:35.778436 I Global TVFormat Setting 'NTSC'
312012-12-02 06:31:35.778480 I V4LChannel(/dev/video1): Input #5: 'tuner' schan(2) tun() v4l1(Unknown) v4l2(NTSC)
322012-12-02 06:31:35.778496 I V4LChannel(/dev/video1): SetFormat(Default) fmt(NTSC) input(5)
332012-12-02 06:31:35.801230 I V4LChannel(/dev/video1): SetInputAndFormat(5, NTSC) (v4l v2) input_switch: 0 mode_switch: 1
342012-12-02 06:31:35.803830 I V4LChannel(/dev/video1): SetFormat(NTSC) fmt(NTSC) input(5)
352012-12-02 06:31:35.804452 I Channel(/dev/video1)::SwitchToInput(in 5, '')
362012-12-02 06:31:35.805374 I V4LChannel(/dev/video1): SetInputAndFormat(5, NTSC) (v4l v2) input_switch: 0 mode_switch: 1
372012-12-02 06:31:35.808471 I DTVChan(/dev/video1): SetChannelByString(2):
382012-12-02 06:31:35.809163 I V4LChannel(/dev/video1): SetFormat(Default) fmt(NTSC) input(5)
392012-12-02 06:31:35.809185 I Channel(/dev/video1)::Tune(2): curList[0].freq(55250)
402012-12-02 06:31:35.809194 I V4LChannel(/dev/video1): Tune(55250000, )
412012-12-02 06:31:35.969940 I Added logging to mythlogserver at TCP:35327
422012-12-02 06:31:36.097501 I Channel(/dev/video1)::Tune(): Frequency is now 55250000
432012-12-02 06:31:36.097509 I DTVChan(/dev/video1): SetChannelByString(2): success
442012-12-02 06:31:36.107715 I TVRec(5): SetFlags(RunMainLoop,) -> RunMainLoop,
452012-12-02 06:31:36.107736 I TVRec(5): ClearFlags(ExitPlayer,FinishRecording,) -> RunMainLoop,
462012-12-02 06:31:36.108552 I TVRec(6): Start channel: 63.
472012-12-02 06:31:36.108621 I V4LChannel(/dev/video2): Device name 'Hauppauge WinTV-HVR2250' driver 'saa7164'.
482012-12-02 06:31:36.108637 I V4LChannel(/dev/video2): v4l2: 1 stream io: 0 std io: 1 async io: 0 tuner 1 sliced vbi 0
492012-12-02 06:31:36.116206 I ChannelBase(6): Input #6: 'tuner' schan(63) sourceid(1) ccid(6)
502012-12-02 06:31:36.116217 I ChannelBase(6): Current Input #6: 'tuner'
512012-12-02 06:31:36.116239 I Global TVFormat Setting 'NTSC'
522012-12-02 06:31:36.116267 I V4LChannel(/dev/video2): Input #6: 'tuner' schan(63) tun() v4l1(Unknown) v4l2(NTSC)
532012-12-02 06:31:36.116281 I V4LChannel(/dev/video2): SetFormat(Default) fmt(NTSC) input(6)
542012-12-02 06:31:36.116964 I V4LChannel(/dev/video2): SetInputAndFormat(6, NTSC) (v4l v2) input_switch: 0 mode_switch: 1
552012-12-02 06:31:36.120030 I V4LChannel(/dev/video2): SetFormat(NTSC) fmt(NTSC) input(6)
562012-12-02 06:31:36.120044 I Channel(/dev/video2)::SwitchToInput(in 6, '')
572012-12-02 06:31:36.120989 I V4LChannel(/dev/video2): SetInputAndFormat(6, NTSC) (v4l v2) input_switch: 0 mode_switch: 1
582012-12-02 06:31:36.123773 I DTVChan(/dev/video2): SetChannelByString(63):
592012-12-02 06:31:36.124391 I V4LChannel(/dev/video2): SetFormat(Default) fmt(NTSC) input(6)
602012-12-02 06:31:36.124411 I Channel(/dev/video2)::Tune(63): curList[61].freq(457250)
612012-12-02 06:31:36.124419 I V4LChannel(/dev/video2): Tune(457250000, )
622012-12-02 06:31:36.417561 I Channel(/dev/video2)::Tune(): Frequency is now 457250000
632012-12-02 06:31:36.417568 I DTVChan(/dev/video2): SetChannelByString(63): success
642012-12-02 06:31:36.423096 I TVRec(6): SetFlags(RunMainLoop,) -> RunMainLoop,
652012-12-02 06:31:36.423116 I TVRec(6): ClearFlags(ExitPlayer,FinishRecording,) -> RunMainLoop,
662012-12-02 06:31:36.423860 I TVRec(7): Start channel: 108-246.
672012-12-02 06:31:36.428012 I DVBChan(7:/dev/dvb/adapter0/frontend0): Opening DVB channel
682012-12-02 06:31:36.430037 I DVBChan(7:/dev/dvb/adapter0/frontend0): Using DVB card /dev/dvb/adapter0/frontend0, with frontend 'LG Electronics LGDT3303 VSB/QAM Frontend'.
692012-12-02 06:31:36.432170 I ChannelBase(7): Input #7: 'DVBInput' schan(108-246) sourceid(4) ccid(7)
702012-12-02 06:31:36.432181 I ChannelBase(7): Current Input #7: 'DVBInput'
712012-12-02 06:31:36.432416 I DTVChan(/dev/dvb/adapter0/frontend0): SetChannelByString(108-246):
722012-12-02 06:31:36.434193 I DVBChan(7:/dev/dvb/adapter0/frontend0): 699000000 qam_256 a auto auto a a auto a v fec: auto msys: UNDEFINED rolloff: 0.35
732012-12-02 06:31:36.434248 I DVBChan(7:/dev/dvb/adapter0/frontend0): Old Params: 0 auto a auto auto a a auto a v fec: auto msys: UNDEFINED rolloff: 0.35
74 DVBChan(7:/dev/dvb/adapter0/frontend0): New Params: 699000000 qam_256 a auto auto a a auto a v fec: auto msys: UNDEFINED rolloff: 0.35
752012-12-02 06:31:36.434260 I DVBChan(7:/dev/dvb/adapter0/frontend0): Tune(): Tuning to 699000000Hz
762012-12-02 06:31:36.438194 I DVBChan: wait_for_backend: Status:
772012-12-02 06:31:36.438203 I DVBChan(7:/dev/dvb/adapter0/frontend0): Tune(): Frequency tuning successful.
782012-12-02 06:31:36.438212 I DTVChan(/dev/dvb/adapter0/frontend0): SetChannelByString(108-246): success
792012-12-02 06:31:36.438224 I DVBChan(7:/dev/dvb/adapter0/frontend0): Closing DVB channel
802012-12-02 06:31:36.438399 I TVRec(7): SetFlags(RunMainLoop,) -> RunMainLoop,
812012-12-02 06:31:36.438415 I TVRec(7): ClearFlags(ExitPlayer,FinishRecording,) -> RunMainLoop,
822012-12-02 06:31:36.440012 I TVRec(8): Start channel: 106-317.
832012-12-02 06:31:36.442074 I DVBChan(8:/dev/dvb/adapter0/frontend0): Opening DVB channel
842012-12-02 06:31:36.442086 I DVBChan(7:/dev/dvb/adapter0/frontend0): Opening DVB channel
852012-12-02 06:31:36.444096 I DVBChan(7:/dev/dvb/adapter0/frontend0): Using DVB card /dev/dvb/adapter0/frontend0, with frontend 'LG Electronics LGDT3303 VSB/QAM Frontend'.
862012-12-02 06:31:36.446228 I ChannelBase(7): Input #7: 'DVBInput' schan(108-246) sourceid(4) ccid(7)
872012-12-02 06:31:36.446239 I ChannelBase(7): Current Input #7: 'DVBInput'
882012-12-02 06:31:36.448301 I ChannelBase(8): Input #8: 'DVBInput' schan(106-317) sourceid(4) ccid(8)
892012-12-02 06:31:36.448312 I ChannelBase(8): Current Input #8: 'DVBInput'
902012-12-02 06:31:36.448540 I DTVChan(/dev/dvb/adapter0/frontend0): SetChannelByString(106-317):
912012-12-02 06:31:36.449941 I DVBChan(8:/dev/dvb/adapter0/frontend0): 687000000 qam_256 a auto auto a a auto a v fec: auto msys: UNDEFINED rolloff: 0.35
922012-12-02 06:31:36.449953 I DVBChan(8:/dev/dvb/adapter0/frontend0): tuning on slave channel
932012-12-02 06:31:36.450000 I DVBChan(7:/dev/dvb/adapter0/frontend0): Old Params: 699000000 qam_256 a auto auto a a auto a v fec: auto msys: UNDEFINED rolloff: 0.35
94 DVBChan(7:/dev/dvb/adapter0/frontend0): New Params: 687000000 qam_256 a auto auto a a auto a v fec: auto msys: UNDEFINED rolloff: 0.35
952012-12-02 06:31:36.450011 I DVBChan(7:/dev/dvb/adapter0/frontend0): Tune(): Tuning to 687000000Hz
962012-12-02 06:31:36.453929 I DVBChan: wait_for_backend: Status:
972012-12-02 06:31:36.453938 I DVBChan(7:/dev/dvb/adapter0/frontend0): Tune(): Frequency tuning successful.
982012-12-02 06:31:36.453945 I DTVChan(/dev/dvb/adapter0/frontend0): SetChannelByString(106-317): success
992012-12-02 06:31:36.453955 I DVBChan(8:/dev/dvb/adapter0/frontend0): Closing DVB channel
1002012-12-02 06:31:36.453963 I DVBChan(7:/dev/dvb/adapter0/frontend0): Closing DVB channel
1012012-12-02 06:31:36.454133 I TVRec(8): SetFlags(RunMainLoop,) -> RunMainLoop,
1022012-12-02 06:31:36.454149 I TVRec(8): ClearFlags(ExitPlayer,FinishRecording,) -> RunMainLoop,
1032012-12-02 06:31:36.524965 I Found 1 distinct programid authorities
1042012-12-02 06:31:36.525247 I New static DB connectionSchedCon
1052012-12-02 06:31:36.528916 I Listening on TCP 127.0.0.1:6544
1062012-12-02 06:31:36.528966 I Listening on TCP 192.168.2.4:6544
1072012-12-02 06:31:36.531065 I Listening on TCP [::1]:6544
1082012-12-02 06:31:36.531144 I Listening on TCP [fe80::21d:60ff:fe40:5a17%eth0]:6544
1092012-12-02 06:31:37.454647 I Main::Registering HttpStatus Extension
1102012-12-02 06:31:37.456288 I Listening on TCP 127.0.0.1:6543
1112012-12-02 06:31:37.456349 I Listening on TCP 192.168.2.4:6543
1122012-12-02 06:31:37.458908 I Listening on TCP [::1]:6543
1132012-12-02 06:31:37.459003 I Listening on TCP [fe80::21d:60ff:fe40:5a17%eth0]:6543
1142012-12-02 06:31:37.460670 N AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
1152012-12-02 06:31:39.529997 I Reschedule requested for MATCH 0 0 0 - SchedulerInit
1162012-12-02 06:31:39.597666 I Scheduled 28 items in 0.0 = 0.01 match + 0.03 check + 0.01 place
1172012-12-02 06:31:39.611258 I Scheduler: Seem to be woken up by USER
1182012-12-02 06:31:46.526501 I Running housekeeping thread
1192012-12-02 06:31:48.365671 I MainServer::ANN Monitor
1202012-12-02 06:31:48.365683 I adding: zeus as a client (events: 0)
1212012-12-02 06:31:48.365980 I MainServer::ANN Monitor
1222012-12-02 06:31:48.365987 I adding: zeus as a client (events: 1)
1232012-12-02 06:31:48.383824 I Getting next free recorder after : -1
1242012-12-02 06:31:48.383841 I Checking card 5. Best card so far -1
1252012-12-02 06:31:48.384282 I Checking card 6. Best card so far 5
1262012-12-02 06:31:48.384687 I Checking card 7. Best card so far 6
1272012-12-02 06:31:48.385436 I Checking card 8. Best card so far 6
1282012-12-02 06:31:48.386159 I Best card is 6
1292012-12-02 06:31:48.388281 I MainServer::ANN Playback
1302012-12-02 06:31:48.388289 I adding: zeus as a client (events: 0)
1312012-12-02 06:31:48.394664 I TVRec(6): Found channel (63) on current card(6).
1322012-12-02 06:31:48.395603 I TVRec(6): Changing from None to WatchingLiveTV
1332012-12-02 06:31:48.395622 I TVRec(6): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,
1342012-12-02 06:31:48.395639 I TVRec(6): HandleTuning Request: Program(NULL) channel() input() flags(LiveTV,)
1352012-12-02 06:31:48.395663 I ChannelBase(6): Looking for startchannel '63' on input 'tuner'
1362012-12-02 06:31:48.397917 I ChannelBase(6): Found startchannel '63' on input 'tuner'
1372012-12-02 06:31:48.397993 I TVRec(6): HW Tuner: 6->6
1382012-12-02 06:31:48.398005 I TVRec(6): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,
1392012-12-02 06:31:48.398019 I TVRec(6): No recorder yet, calling TuningFrequency
1402012-12-02 06:31:48.398304 I V4LChannel(/dev/video2): Device name 'Hauppauge WinTV-HVR2250' driver 'saa7164'.
1412012-12-02 06:31:48.398322 I V4LChannel(/dev/video2): v4l2: 1 stream io: 0 std io: 1 async io: 0 tuner 1 sliced vbi 0
1422012-12-02 06:31:48.406148 I ChannelBase(6): Input #6: 'tuner' schan(63) sourceid(1) ccid(6)
1432012-12-02 06:31:48.406160 I ChannelBase(6): Current Input #6: 'tuner'
1442012-12-02 06:31:48.406187 I Global TVFormat Setting 'NTSC'
1452012-12-02 06:31:48.406217 I V4LChannel(/dev/video2): Input #6: 'tuner' schan(63) tun() v4l1(Unknown) v4l2(NTSC)
1462012-12-02 06:31:48.406230 I V4LChannel(/dev/video2): SetFormat(Default) fmt(NTSC) input(6)
1472012-12-02 06:31:48.406240 I Channel(/dev/video2)::SwitchToInput(in 6, '')
1482012-12-02 06:31:48.428505 I V4LChannel(/dev/video2): SetInputAndFormat(6, NTSC) (v4l v2) input_switch: 0 mode_switch: 1
1492012-12-02 06:31:48.430753 I DTVChan(/dev/video2): SetChannelByString(63):
1502012-12-02 06:31:48.432326 I V4LChannel(/dev/video2): SetFormat(Default) fmt(NTSC) input(6)
1512012-12-02 06:31:48.432344 I Channel(/dev/video2)::Tune(63): curList[61].freq(457250)
1522012-12-02 06:31:48.432353 I V4LChannel(/dev/video2): Tune(457250000, )
1532012-12-02 06:31:48.727691 I Channel(/dev/video2)::Tune(): Frequency is now 457250000
1542012-12-02 06:31:48.727700 I DTVChan(/dev/video2): SetChannelByString(63): success
1552012-12-02 06:31:48.733022 I TVRec(6): CreateLiveTVRingBuffer(63)
1562012-12-02 06:31:48.733405 I TVRec(6): GetProgramRingBufferForLiveTV()
1572012-12-02 06:31:48.736145 N AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min
1582012-12-02 06:31:48.751562 I TVRec(6): StartedRecording(1063_2012-12-02T12:31:48Z) fn(/home/mythtv/rec/1063_20121202123148.mpg)
1592012-12-02 06:31:48.753189 I Chain: Appended@0 '1063_20121202123148'
1602012-12-02 06:31:48.754017 I TVRec(6): Starting Signal Monitor
1612012-12-02 06:31:48.754033 I TVRec(6): SetupSignalMonitor(1, 1)
1622012-12-02 06:31:48.754085 I TVRec(6): Signal monitor successfully created
1632012-12-02 06:31:48.754264 I TVRec(6): SetFlags(SignalMonitorRunning,) -> RunMainLoop,SignalMonitorRunning,
1642012-12-02 06:31:48.754281 I TVRec(6): ClearFlags(WaitingForSignal,) -> RunMainLoop,SignalMonitorRunning,
1652012-12-02 06:31:48.754294 I TVRec(6): SetFlags(WaitingForSignal,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,
1662012-12-02 06:31:48.754307 I TVRec(6): SetFlags(DummyRecorderRunning,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,
1672012-12-02 06:31:48.754313 I DummyDTVRecorder -- started
1682012-12-02 06:31:48.754325 I TVRec(6): SetFlags(RingBufferReady,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
1692012-12-02 06:31:48.754337 I TVRec(6): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
1702012-12-02 06:31:48.754350 I TVRec(6): SetFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
1712012-12-02 06:31:48.754365 I TVRec(6): Got good signal
1722012-12-02 06:31:48.754415 I TVRec(6): TeardownSignalMonitor() -- begin
1732012-12-02 06:31:48.804574 I TVRec(6): TeardownSignalMonitor() -- end
1742012-12-02 06:31:48.804589 I TVRec(6): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
1752012-12-02 06:31:48.804603 I TVRec(6): ClearFlags(WaitingForSignal,) -> RunMainLoop,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
1762012-12-02 06:31:48.804640 I TVRec(6): Starting Recorder
1772012-12-02 06:31:48.805021 I TVRec(6): FinishedRecording(1063_2012-12-02T12:31:48Z)
178 title: Brigadoon
179 in recgroup: LiveTV status: Recording:Recorded is_dummy finished_now
1802012-12-02 06:31:48.805303 I Chain: Updated endtime for '1063_20121202123148' to 20121202123148
1812012-12-02 06:31:48.805799 I TVRec(6): ClearFlags(DummyRecorderRunning,) -> RunMainLoop,NeedToStartRecorder,RingBufferReady,
1822012-12-02 06:31:48.818378 I Using profile 'Live TV' to record
1832012-12-02 06:31:48.818415 I TVRec(6): SwitchLiveTVRingBuffer(discont 1, set_next_rec 0) curRec(1063_2012-12-02T12:31:48Z) curRec.size(0)
1842012-12-02 06:31:48.818828 I TVRec(6): GetProgramRingBufferForLiveTV()
1852012-12-02 06:31:48.821111 N AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min
1862012-12-02 06:31:48.827048 E RecordingInfo::InsertProgram(ProgramInfo(1063_20121202123148.mpg): channame(Turner Classic Movies) startts(Sun Dec 2 11:00:00 2012) endts(Sun Dec 2 13:00:00 2012)
187 recstartts(Sun Dec 2 12:31:48 2012) recendts(Sun Dec 2 13:00:00 2012)
188 title(Brigadoon)): recording already exists...
1892012-12-02 06:31:48.829714 I TVRec(6): StartedRecording(1063_2012-12-02T12:31:49Z) fn(/home/mythtv/rec/1063_20121202123149.mpg)
1902012-12-02 06:31:48.831925 I Chain: Appended@1 '1063_20121202123149'
1912012-12-02 06:31:48.832230 I DTVRec(6): ResetForNewFile(void)
1922012-12-02 06:31:48.833034 I RecBase(6:/dev/video2): SetRingBuffer(0x7fa338031e60) '/home/mythtv/rec/1063_20121202123149.mpg'
1932012-12-02 06:31:48.833054 I RecBase(6:/dev/video2): SetRecording(0x7fa338040450) title(Brigadoon)
1942012-12-02 06:31:48.838857 I TVRec(6): SetFlags(CancelNextRecording,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,RingBufferReady,
1952012-12-02 06:31:48.838889 I DTVRec(6): ResetForNewFile(void)
1962012-12-02 06:31:48.839808 I V4LRec(6:/dev/video2): vbi_format rate: 27000000
197 offset: 0
198 samples_per_line: 1440
199 starts: 10, 274
200 counts: 18, 18
201 flags: 0x0
2022012-12-02 06:31:48.850916 I DevRdB(/dev/video2): buffer size 9400 KB
2032012-12-02 06:31:48.850942 I MPEGRec(/dev/video2): DRB ready
2042012-12-02 06:31:48.851046 I MPEGRec(/dev/video2): Initial startup of recorder
2052012-12-02 06:31:48.851058 I MPEGRec(/dev/video2): StartEncoding
2062012-12-02 06:31:48.851099 I DevRdB(/dev/video2): Start() -- begin
2072012-12-02 06:31:48.851178 I DevRdB(/dev/video2): Start() -- middle
2082012-12-02 06:31:48.851185 I DevRdB(/dev/video2): Start() -- end
2092012-12-02 06:31:48.854047 I TVRec(6): SetFlags(RecorderRunning,RingBufferReady,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,RecorderRunning,RingBufferReady,
2102012-12-02 06:31:48.854066 I TVRec(6): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,CancelNextRecording,RecorderRunning,RingBufferReady,
2112012-12-02 06:31:49.493052 I DTVRec(6): FindPSKeyFrames: frame rate = 29970
2122012-12-02 06:31:49.836213 I TVRec(6): SetFlags(FrontendReady,) -> FrontendReady,RunMainLoop,CancelNextRecording,RecorderRunning,RingBufferReady,
2132012-12-02 06:31:54.756586 I TVRec(6): StopLiveTV(void) curRec: 0x7fa338040450 pseudoRec: 0x0
2142012-12-02 06:31:54.757126 I TVRec(6): Changing from WatchingLiveTV to None
2152012-12-02 06:31:54.757153 I TVRec(6): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RecorderRunning,RingBufferReady,
2162012-12-02 06:31:54.757170 I TVRec(6): HandleTuning Request: Program(NULL) channel() input() flags(KillRec,KillRingBuffer,)
2172012-12-02 06:31:55.003889 I MPEGRec(/dev/video2): run finishing up
2182012-12-02 06:31:55.003899 I MPEGRec(/dev/video2): StopEncoding
2192012-12-02 06:31:55.023984 I DevRdB(/dev/video2): Stop() -- begin
2202012-12-02 06:31:55.024218 I DevRdB(/dev/video2): Stop() -- end
2212012-12-02 06:31:55.311559 I TVRec(6): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady,
2222012-12-02 06:31:55.311664 I RecordingQuality() start(2012-12-02T11:00:00Z) end(2012-12-02T13:00:00Z) score(1)
2232012-12-02 06:31:55.311727 I RecBase(6:/dev/video2): SetRecording(0x0)
2242012-12-02 06:31:55.312765 I TVRec(6): FinishedRecording(1063_2012-12-02T12:31:49Z) good recq:<RecordingQuality overall_score="1" key="1063_2012-12-02T12:31:49Z" />
225
2262012-12-02 06:31:55.312826 I TVRec(6): FinishedRecording(1063_2012-12-02T12:31:49Z)
227 title: Brigadoon
228 in recgroup: LiveTV status: Recorder Failed:Recorder Failed not_dummy finished_now
2292012-12-02 06:31:55.313103 I Chain: Updated endtime for '1063_20121202123149' to 20121202123155
2302012-12-02 06:31:55.313736 I SaveVideoProperties(0x38, 0x20)
2312012-12-02 06:31:55.315045 I TVRec(6): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady,
2322012-12-02 06:31:55.315057 I TVRec(6): Tearing down RingBuffer
2332012-12-02 06:31:55.315422 I TVRec(6): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
2342012-12-02 06:31:55.315771 I TVRec(6): SetFlags(FrontendReady,) -> FrontendReady,RunMainLoop,RingBufferReady,
2352012-12-02 06:31:55.319013 I Getting next free recorder after : -1
2362012-12-02 06:31:55.319023 I Checking card 5. Best card so far -1
2372012-12-02 06:31:55.319557 I Checking card 6. Best card so far 5
2382012-12-02 06:31:55.320007 I Checking card 7. Best card so far 6
2392012-12-02 06:31:55.320712 I Checking card 8. Best card so far 6
2402012-12-02 06:31:55.321402 I Best card is 6
2412012-12-02 06:31:55.323617 I MainServer::ANN Playback
2422012-12-02 06:31:55.323625 I adding: zeus as a client (events: 0)
2432012-12-02 06:31:55.329488 I TVRec(6): Found channel (63) on current card(6).
2442012-12-02 06:31:55.340415 I TVRec(6): Changing from None to WatchingLiveTV
2452012-12-02 06:31:55.340434 I TVRec(6): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RingBufferReady,
2462012-12-02 06:31:55.340448 I TVRec(6): HandleTuning Request: Program(NULL) channel() input() flags(LiveTV,)
2472012-12-02 06:31:55.340461 I ChannelBase(6): Looking for startchannel '63' on input 'tuner'
2482012-12-02 06:31:55.342228 I ChannelBase(6): Found startchannel '63' on input 'tuner'
2492012-12-02 06:31:55.342262 I TVRec(6): HW Tuner: 6->6
2502012-12-02 06:31:55.342273 I TVRec(6): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
2512012-12-02 06:31:55.342281 I TVRec(6): No recorder yet, calling TuningFrequency
2522012-12-02 06:31:55.342551 I V4LChannel(/dev/video2): Device name 'Hauppauge WinTV-HVR2250' driver 'saa7164'.
2532012-12-02 06:31:55.342568 I V4LChannel(/dev/video2): v4l2: 1 stream io: 0 std io: 1 async io: 0 tuner 1 sliced vbi 0
2542012-12-02 06:31:55.350423 I ChannelBase(6): Input #6: 'tuner' schan(63) sourceid(1) ccid(6)
2552012-12-02 06:31:55.350434 I ChannelBase(6): Current Input #6: 'tuner'
2562012-12-02 06:31:55.350461 I Global TVFormat Setting 'NTSC'
2572012-12-02 06:31:55.350491 I V4LChannel(/dev/video2): Input #6: 'tuner' schan(63) tun() v4l1(Unknown) v4l2(NTSC)
2582012-12-02 06:31:55.350503 I V4LChannel(/dev/video2): SetFormat(Default) fmt(NTSC) input(6)
2592012-12-02 06:31:55.350513 I Channel(/dev/video2)::SwitchToInput(in 6, '')
2602012-12-02 06:31:55.352380 I V4LChannel(/dev/video2): SetInputAndFormat(6, NTSC) (v4l v2) input_switch: 0 mode_switch: 1
2612012-12-02 06:31:55.355112 I DTVChan(/dev/video2): SetChannelByString(63):
2622012-12-02 06:31:55.356593 I V4LChannel(/dev/video2): SetFormat(Default) fmt(NTSC) input(6)
2632012-12-02 06:31:55.356609 I Channel(/dev/video2)::Tune(63): curList[61].freq(457250)
2642012-12-02 06:31:55.356618 I V4LChannel(/dev/video2): Tune(457250000, )
2652012-12-02 06:31:55.647919 I Channel(/dev/video2)::Tune(): Frequency is now 457250000
2662012-12-02 06:31:55.647927 I DTVChan(/dev/video2): SetChannelByString(63): success
2672012-12-02 06:31:55.654060 I TVRec(6): CreateLiveTVRingBuffer(63)
2682012-12-02 06:31:55.654434 I TVRec(6): GetProgramRingBufferForLiveTV()
2692012-12-02 06:31:55.656848 N AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min
2702012-12-02 06:31:55.665076 I TVRec(6): StartedRecording(1063_2012-12-02T12:31:55Z) fn(/home/mythtv/rec/1063_20121202123155.mpg)
2712012-12-02 06:31:55.666451 I Chain: Appended@0 '1063_20121202123155'
2722012-12-02 06:31:55.667332 I TVRec(6): Starting Signal Monitor
2732012-12-02 06:31:55.667342 I TVRec(6): SetupSignalMonitor(1, 1)
2742012-12-02 06:31:55.667369 I TVRec(6): Signal monitor successfully created
2752012-12-02 06:31:55.667474 I TVRec(6): SetFlags(SignalMonitorRunning,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady,
2762012-12-02 06:31:55.667489 I TVRec(6): ClearFlags(WaitingForSignal,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady,
2772012-12-02 06:31:55.667502 I TVRec(6): SetFlags(WaitingForSignal,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady,
2782012-12-02 06:31:55.667515 I TVRec(6): SetFlags(DummyRecorderRunning,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2792012-12-02 06:31:55.667520 I DummyDTVRecorder -- started
2802012-12-02 06:31:55.667532 I TVRec(6): SetFlags(RingBufferReady,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2812012-12-02 06:31:55.667545 I TVRec(6): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2822012-12-02 06:31:55.667558 I TVRec(6): SetFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2832012-12-02 06:31:55.667567 I TVRec(6): Got good signal
2842012-12-02 06:31:55.667614 I TVRec(6): TeardownSignalMonitor() -- begin
2852012-12-02 06:31:55.717661 I TVRec(6): TeardownSignalMonitor() -- end
2862012-12-02 06:31:55.717676 I TVRec(6): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
2872012-12-02 06:31:55.717689 I TVRec(6): ClearFlags(WaitingForSignal,) -> RunMainLoop,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
2882012-12-02 06:31:55.717714 I TVRec(6): Starting Recorder
2892012-12-02 06:31:55.718061 I TVRec(6): FinishedRecording(1063_2012-12-02T12:31:55Z)
290 title: Brigadoon
291 in recgroup: LiveTV status: Recording:Recorded is_dummy finished_now
2922012-12-02 06:31:55.718332 I Chain: Updated endtime for '1063_20121202123155' to 20121202123155
2932012-12-02 06:31:55.718774 I TVRec(6): ClearFlags(DummyRecorderRunning,) -> RunMainLoop,NeedToStartRecorder,RingBufferReady,
2942012-12-02 06:31:55.731784 I Using profile 'Live TV' to record
2952012-12-02 06:31:55.731813 I TVRec(6): SwitchLiveTVRingBuffer(discont 1, set_next_rec 0) curRec(1063_2012-12-02T12:31:55Z) curRec.size(0)
2962012-12-02 06:31:55.732218 I TVRec(6): GetProgramRingBufferForLiveTV()
2972012-12-02 06:31:55.734492 N AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min
2982012-12-02 06:31:55.740288 E RecordingInfo::InsertProgram(ProgramInfo(1063_20121202123155.mpg): channame(Turner Classic Movies) startts(Sun Dec 2 11:00:00 2012) endts(Sun Dec 2 13:00:00 2012)
299 recstartts(Sun Dec 2 12:31:55 2012) recendts(Sun Dec 2 13:00:00 2012)
300 title(Brigadoon)): recording already exists...
3012012-12-02 06:31:55.743020 I TVRec(6): StartedRecording(1063_2012-12-02T12:31:56Z) fn(/home/mythtv/rec/1063_20121202123156.mpg)
3022012-12-02 06:31:55.745181 I Chain: Appended@1 '1063_20121202123156'
3032012-12-02 06:31:55.745408 I DTVRec(6): ResetForNewFile(void)
3042012-12-02 06:31:55.745524 I RecBase(6:/dev/video2): SetRingBuffer(0x7fa338019660) '/home/mythtv/rec/1063_20121202123156.mpg'
3052012-12-02 06:31:55.745538 I RecBase(6:/dev/video2): SetRecording(0x7fa3380308a0) title(Brigadoon)
3062012-12-02 06:31:55.751984 I TVRec(6): SetFlags(CancelNextRecording,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,RingBufferReady,
3072012-12-02 06:31:55.752020 I DTVRec(6): ResetForNewFile(void)
3082012-12-02 06:31:55.752906 I V4LRec(6:/dev/video2): vbi_format rate: 27000000
309 offset: 0
310 samples_per_line: 1440
311 starts: 10, 274
312 counts: 18, 18
313 flags: 0x0
3142012-12-02 06:31:55.763008 I DevRdB(/dev/video2): buffer size 9400 KB
3152012-12-02 06:31:55.763023 I MPEGRec(/dev/video2): DRB ready
3162012-12-02 06:31:55.763092 I MPEGRec(/dev/video2): Initial startup of recorder
3172012-12-02 06:31:55.763099 I MPEGRec(/dev/video2): StartEncoding
3182012-12-02 06:31:55.763117 I DevRdB(/dev/video2): Start() -- begin
3192012-12-02 06:31:55.763187 I DevRdB(/dev/video2): Start() -- middle
3202012-12-02 06:31:55.763195 I DevRdB(/dev/video2): Start() -- end
3212012-12-02 06:31:55.767133 I TVRec(6): SetFlags(RecorderRunning,RingBufferReady,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,RecorderRunning,RingBufferReady,
3222012-12-02 06:31:55.767150 I TVRec(6): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,CancelNextRecording,RecorderRunning,RingBufferReady,
3232012-12-02 06:31:56.420091 I DTVRec(6): FindPSKeyFrames: frame rate = 29970
3242012-12-02 06:31:56.430448 I TVRec(6): StopLiveTV(void) curRec: 0x7fa3380308a0 pseudoRec: 0x0
3252012-12-02 06:31:56.430798 I TVRec(6): Changing from WatchingLiveTV to None
3262012-12-02 06:31:56.430818 I TVRec(6): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RecorderRunning,RingBufferReady,
3272012-12-02 06:31:56.430834 I TVRec(6): HandleTuning Request: Program(NULL) channel() input() flags(KillRec,KillRingBuffer,)
3282012-12-02 06:31:56.924254 I MPEGRec(/dev/video2): run finishing up
3292012-12-02 06:31:56.924267 I MPEGRec(/dev/video2): StopEncoding
3302012-12-02 06:31:56.944355 I DevRdB(/dev/video2): Stop() -- begin
3312012-12-02 06:31:56.944586 I DevRdB(/dev/video2): Stop() -- end
3322012-12-02 06:31:57.228324 I TVRec(6): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady,
3332012-12-02 06:31:57.228414 I RecordingQuality() start(2012-12-02T11:00:00Z) end(2012-12-02T13:00:00Z) score(1)
3342012-12-02 06:31:57.228474 I RecBase(6:/dev/video2): SetRecording(0x0)
3352012-12-02 06:31:57.229021 I TVRec(6): FinishedRecording(1063_2012-12-02T12:31:56Z) good recq:<RecordingQuality overall_score="1" key="1063_2012-12-02T12:31:56Z" />
336
3372012-12-02 06:31:57.229074 I TVRec(6): FinishedRecording(1063_2012-12-02T12:31:56Z)
338 title: Brigadoon
339 in recgroup: LiveTV status: Recorder Failed:Recorder Failed not_dummy finished_now
3402012-12-02 06:31:57.229324 I Chain: Updated endtime for '1063_20121202123156' to 20121202123157
3412012-12-02 06:31:57.229957 I SaveVideoProperties(0x38, 0x20)
3422012-12-02 06:31:57.231260 I TVRec(6): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady,
3432012-12-02 06:31:57.231271 I TVRec(6): Tearing down RingBuffer
3442012-12-02 06:31:57.231442 I TVRec(6): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
3452012-12-02 06:32:13.996888 C Received Interrupt: Code 128, PID 0, UID 0, Value 0x00000000
3462012-12-02 06:32:13.997772 N MythBackend exiting
3472012-12-02 06:32:15.647060 I TVRec(5): ClearFlags(RunMainLoop,) -> 0x0
3482012-12-02 06:32:15.647286 I TVRec(5): ClearFlags(RecorderRunning,) -> 0x0
3492012-12-02 06:32:15.647310 I TVRec(6): ClearFlags(RunMainLoop,) -> RingBufferReady,
3502012-12-02 06:32:15.647644 I TVRec(6): ClearFlags(RecorderRunning,) -> RingBufferReady,
3512012-12-02 06:32:15.647678 I TVRec(7): ClearFlags(RunMainLoop,) -> 0x0
3522012-12-02 06:32:15.647771 I DVBChan(7:/dev/dvb/adapter0/frontend0): Closing DVB channel
3532012-12-02 06:32:15.647806 I TVRec(7): ClearFlags(RecorderRunning,) -> 0x0
3542012-12-02 06:32:15.647823 I TVRec(8): ClearFlags(RunMainLoop,) -> 0x0
3552012-12-02 06:32:15.647876 I DVBChan(8:/dev/dvb/adapter0/frontend0): Closing DVB channel
3562012-12-02 06:32:15.647908 I TVRec(8): ClearFlags(RecorderRunning,) -> 0x0
3572012-12-02 06:32:15.647932 I Waiting for threads to exit.