2012-03-29 17:41:16.862775 C mythbackend version: master [v0.25-rc-91-g55cd239-dirty] www.mythtv.org 2012-03-29 17:41:16.862803 N Enabled verbose msgs: general record channel 2012-03-29 17:41:16.862831 N Setting Log Level to LOG_INFO 2012-03-29 17:41:16.862887 I Added logging to the console 2012-03-29 17:41:16.862892 I Added database logging to table logging 2012-03-29 17:41:16.862971 N Setting up SIGHUP handler 2012-03-29 17:41:16.863081 N Using runtime prefix = /usr/local 2012-03-29 17:41:16.863095 N Using configuration directory = /home/eric/.mythtv 2012-03-29 17:41:16.863191 I Assumed character encoding: en_US.UTF-8 2012-03-29 17:41:16.863682 N Empty LocalHostName. 2012-03-29 17:41:16.863694 I Using localhost value of bugs 2012-03-29 17:41:16.863824 I Testing network connectivity to '192.168.0.11' 2012-03-29 17:41:16.863959 I Starting process manager 2012-03-29 17:41:16.864059 I Starting process signal handler 2012-03-29 17:41:16.864138 I Starting IO manager (read) 2012-03-29 17:41:16.864373 I Starting IO manager (write) 2012-03-29 17:41:17.015423 I Current locale en_US 2012-03-29 17:41:17.015540 N Reading locale defaults from /usr/local/share/mythtv//locales/en_us.xml 2012-03-29 17:41:17.043684 I Current MythTV Schema Version (DBSchemaVer): 1299 2012-03-29 17:41:17.044969 I Loading en_us translation for module mythfrontend 2012-03-29 17:41:17.047197 N MythBackend: Starting up as the master server. 2012-03-29 17:41:17.068315 I TVRec(1): Start channel: 1130. 2012-03-29 17:41:17.068452 I HDHRChan(1310209E-0): Opening HDHR channel 2012-03-29 17:41:17.079084 I HDHRSH(1310209E-0): Successfully connected to device 2012-03-29 17:41:17.079344 I HDHRSH: Creating new stream handler 1310209E-0 for 1310209E-0 2012-03-29 17:41:17.101075 I ChannelBase(1): Input #1: 'MPEG2TS' schan(1130) sourceid(12) ccid(1) 2012-03-29 17:41:17.101091 I ChannelBase(1): Current Input #1: 'MPEG2TS' 2012-03-29 17:41:17.105674 I DTVChan(1310209E-0): SetChannelByString(1130): 2012-03-29 17:41:17.109415 I HDHRSH(1310209E-0): Tuning vchannel 1130 2012-03-29 17:41:17.114507 I DTVChan(1310209E-0): SetChannelByString(1130): success 2012-03-29 17:41:17.114757 I HDHRSH(1310209E-0): Not Re-Tuning channel none 2012-03-29 17:41:17.133831 I TVRec(1): SetFlags(RunMainLoop,) -> RunMainLoop, 2012-03-29 17:41:17.133862 I TVRec(1): ClearFlags(ExitPlayer,FinishRecording,) -> RunMainLoop, 2012-03-29 17:41:17.170847 I TVRec(3): Start channel: 1110. 2012-03-29 17:41:17.170920 I HDHRChan(1310209E-1): Opening HDHR channel 2012-03-29 17:41:17.181345 I HDHRSH(1310209E-1): Successfully connected to device 2012-03-29 17:41:17.181551 I HDHRSH: Creating new stream handler 1310209E-1 for 1310209E-1 2012-03-29 17:41:17.200307 I ChannelBase(3): Input #2: 'MPEG2TS' schan(1110) sourceid(12) ccid(3) 2012-03-29 17:41:17.200321 I ChannelBase(3): Current Input #2: 'MPEG2TS' 2012-03-29 17:41:17.202677 I DTVChan(1310209E-1): SetChannelByString(1110): 2012-03-29 17:41:17.205184 I HDHRSH(1310209E-1): Tuning vchannel 1110 2012-03-29 17:41:17.205635 I DTVChan(1310209E-1): SetChannelByString(1110): success 2012-03-29 17:41:17.205831 I HDHRSH(1310209E-1): Not Re-Tuning channel none 2012-03-29 17:41:17.206024 I TVRec(3): SetFlags(RunMainLoop,) -> RunMainLoop, 2012-03-29 17:41:17.206045 I TVRec(3): ClearFlags(ExitPlayer,FinishRecording,) -> RunMainLoop, 2012-03-29 17:41:17.229935 I TVRec(5): Start channel: 135. 2012-03-29 17:41:17.230010 I HDHRChan(1310209E-2): Opening HDHR channel 2012-03-29 17:41:17.243571 I HDHRSH(1310209E-2): Successfully connected to device 2012-03-29 17:41:17.243880 I HDHRSH: Creating new stream handler 1310209E-2 for 1310209E-2 2012-03-29 17:41:17.266755 I ChannelBase(5): Input #3: 'MPEG2TS' schan(135) sourceid(12) ccid(5) 2012-03-29 17:41:17.266769 I ChannelBase(5): Current Input #3: 'MPEG2TS' 2012-03-29 17:41:17.268927 I DTVChan(1310209E-2): SetChannelByString(135): 2012-03-29 17:41:17.271226 I HDHRSH(1310209E-2): Tuning vchannel 135 2012-03-29 17:41:17.271787 I DTVChan(1310209E-2): SetChannelByString(135): success 2012-03-29 17:41:17.271985 I HDHRSH(1310209E-2): Not Re-Tuning channel none 2012-03-29 17:41:17.272154 I TVRec(5): SetFlags(RunMainLoop,) -> RunMainLoop, 2012-03-29 17:41:17.272165 I TVRec(5): ClearFlags(ExitPlayer,FinishRecording,) -> RunMainLoop, 2012-03-29 17:41:17.293883 I TVRec(9): Start channel: 34. 2012-03-29 17:41:17.294124 I V4LChannel(/dev/video0): Device name 'Pinnacle PCTV HD 800i' driver 'cx8800'. 2012-03-29 17:41:17.294150 I V4LChannel(/dev/video0): v4l2: 1 stream io: 0 std io: 1 async io: 0 tuner 1 sliced vbi 0 2012-03-29 17:41:17.301459 I ChannelBase(9): Input #6: 'Television' schan(34) sourceid(6) ccid(9) 2012-03-29 17:41:17.301473 I ChannelBase(9): Current Input #6: 'Television' 2012-03-29 17:41:17.303634 I Global TVFormat Setting 'NTSC' 2012-03-29 17:41:17.303689 I V4LChannel(/dev/video0): Input #6: 'Television' schan(34) tun() v4l1(NTSC) v4l2(NTSC) 2012-03-29 17:41:17.303711 I V4LChannel(/dev/video0): SetFormat(Default) fmt(NTSC) input(6) 2012-03-29 17:41:17.303732 I V4LChannel(/dev/video0): SetInputAndFormat(6, NTSC) (v4l v2) input_switch: 0 mode_switch: 1 2012-03-29 17:41:17.428153 I V4LChannel(/dev/video0): SetFormat(NTSC) fmt(NTSC) input(6) 2012-03-29 17:41:17.430258 I Channel(/dev/video0)::SwitchToInput(in 6, '') 2012-03-29 17:41:17.431332 I V4LChannel(/dev/video0): SetInputAndFormat(6, NTSC) (v4l v2) input_switch: 0 mode_switch: 1 2012-03-29 17:41:17.575851 I DTVChan(/dev/video0): SetChannelByString(34): 2012-03-29 17:41:17.578360 I V4LChannel(/dev/video0): SetFormat(Default) fmt(NTSC) input(6) 2012-03-29 17:41:17.578393 I Channel(/dev/video0)::Tune(34): curList[32].freq(283250) 2012-03-29 17:41:17.578404 I V4LChannel(/dev/video0): Tune(283250000, ) 2012-03-29 17:41:17.735554 I Channel(/dev/video0)::Tune(): Frequency is now 283250000 2012-03-29 17:41:17.735566 I DTVChan(/dev/video0): SetChannelByString(34): success 2012-03-29 17:41:17.746355 I TVRec(9): SetFlags(RunMainLoop,) -> RunMainLoop, 2012-03-29 17:41:17.746377 I TVRec(9): ClearFlags(ExitPlayer,FinishRecording,) -> RunMainLoop, 2012-03-29 17:41:17.750689 W Scheduler: Listings source 'HD-OTA' is defined, but is not attached to a card input. 2012-03-29 17:41:17.751649 W Scheduler: Listings source 'HD-Cable' is defined, but is not attached to a card input. 2012-03-29 17:41:17.752601 W Scheduler: Listings source 'no_grab' is defined, but is not attached to a card input. 2012-03-29 17:41:17.778497 I Found 1 distinct programid authorities 2012-03-29 17:41:17.778862 I New static DB connectionSchedCon 2012-03-29 17:41:17.787912 I Listening on TCP 127.0.0.1:6544 2012-03-29 17:41:17.788006 I Listening on TCP 192.168.0.14:6544 2012-03-29 17:41:17.788148 I Listening on TCP [0:0:0:0:0:0:0:1]:6544 2012-03-29 17:41:18.742664 I Main::Registering HttpStatus Extension 2012-03-29 17:41:18.748151 I Listening on TCP 127.0.0.1:6543 2012-03-29 17:41:18.748239 I Listening on TCP 192.168.0.14:6543 2012-03-29 17:41:18.748363 I Listening on TCP [0:0:0:0:0:0:0:1]:6543 2012-03-29 17:41:18.753685 N AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min 2012-03-29 17:41:20.197263 I MainServer::ANN Monitor 2012-03-29 17:41:20.197274 I adding: bugs as a client (events: 0) 2012-03-29 17:41:20.197665 I MainServer::ANN Monitor 2012-03-29 17:41:20.197675 I adding: bugs as a client (events: 1) 2012-03-29 17:41:20.273553 I Getting next free recorder after : -1 2012-03-29 17:41:20.273562 I Checking card 1. Best card so far -1 2012-03-29 17:41:20.275696 I Checking card 3. Best card so far 1 2012-03-29 17:41:20.277870 I Checking card 5. Best card so far 3 2012-03-29 17:41:20.280051 I Checking card 9. Best card so far 5 2012-03-29 17:41:20.282270 I Best card is 5 2012-03-29 17:41:20.288073 I MainServer::ANN Playback 2012-03-29 17:41:20.288082 I adding: bugs as a client (events: 0) 2012-03-29 17:41:20.309728 I TVRec(5): Found channel (49) on different card(9). 2012-03-29 17:41:20.324122 I MainServer::ANN Playback 2012-03-29 17:41:20.324133 I adding: bugs as a client (events: 0) 2012-03-29 17:41:20.327549 I TVRec(9): Changing from None to WatchingLiveTV 2012-03-29 17:41:20.327575 I TVRec(9): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop, 2012-03-29 17:41:20.327595 I TVRec(9): HandleTuning Request: Program(NULL) channel() input() flags(LiveTV,) 2012-03-29 17:41:20.327616 I ChannelBase(9): Looking for startchannel '49' on input 'Television' 2012-03-29 17:41:20.350691 I ChannelBase(9): Found startchannel '49' on input 'Television' 2012-03-29 17:41:20.350735 I TVRec(9): HW Tuner: 9->9 2012-03-29 17:41:20.350748 I TVRec(9): ClearFlags(PENDINGACTIONS,) -> RunMainLoop, 2012-03-29 17:41:20.350758 I TVRec(9): No recorder yet, calling TuningFrequency 2012-03-29 17:41:20.351909 I V4LChannel(/dev/video0): Device name 'Pinnacle PCTV HD 800i' driver 'cx8800'. 2012-03-29 17:41:20.351930 I V4LChannel(/dev/video0): v4l2: 1 stream io: 0 std io: 1 async io: 0 tuner 1 sliced vbi 0 2012-03-29 17:41:20.359499 I ChannelBase(9): Input #6: 'Television' schan(34) sourceid(6) ccid(9) 2012-03-29 17:41:20.359512 I ChannelBase(9): Current Input #6: 'Television' 2012-03-29 17:41:20.359590 I Global TVFormat Setting 'NTSC' 2012-03-29 17:41:20.359623 I V4LChannel(/dev/video0): Input #6: 'Television' schan(34) tun() v4l1(NTSC) v4l2(NTSC) 2012-03-29 17:41:20.359638 I V4LChannel(/dev/video0): SetFormat(Default) fmt(NTSC) input(6) 2012-03-29 17:41:20.359649 I Channel(/dev/video0)::SwitchToInput(in 6, '') 2012-03-29 17:41:20.365028 I V4LChannel(/dev/video0): SetInputAndFormat(6, NTSC) (v4l v2) input_switch: 0 mode_switch: 1 2012-03-29 17:41:20.505856 I DTVChan(/dev/video0): SetChannelByString(49): 2012-03-29 17:41:20.513296 I V4LChannel(/dev/video0): SetFormat(Default) fmt(NTSC) input(6) 2012-03-29 17:41:20.513316 I Channel(/dev/video0)::Tune(49): curList[47].freq(373250) 2012-03-29 17:41:20.513327 I V4LChannel(/dev/video0): Tune(373250000, ) 2012-03-29 17:41:20.656798 I Channel(/dev/video0)::Tune(): Frequency is now 373250000 2012-03-29 17:41:20.656809 I DTVChan(/dev/video0): SetChannelByString(49): success 2012-03-29 17:41:20.666743 I TVRec(9): CreateLiveTVRingBuffer(49) 2012-03-29 17:41:20.668086 I TVRec(9): GetProgramRingBufferForLiveTV() 2012-03-29 17:41:20.677808 N AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min 2012-03-29 17:41:20.729593 I TVRec(9): StartedRecording(0x7fc7380466f0) fn(/share/TV/recordings/6049_20120329174120.mpg) 2012-03-29 17:41:20.735665 I Chain: Appended@0 '6049_20120329174120' 2012-03-29 17:41:20.739998 I TVRec(9): Starting Signal Monitor 2012-03-29 17:41:20.740020 I TVRec(9): SetupSignalMonitor(1, 1) 2012-03-29 17:41:20.740143 I TVRec(9): Signal monitor successfully created 2012-03-29 17:41:20.740332 I TVRec(9): SetFlags(SignalMonitorRunning,) -> RunMainLoop,SignalMonitorRunning, 2012-03-29 17:41:20.740347 I TVRec(9): ClearFlags(WaitingForSignal,) -> RunMainLoop,SignalMonitorRunning, 2012-03-29 17:41:20.740361 I TVRec(9): SetFlags(WaitingForSignal,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning, 2012-03-29 17:41:20.740375 I TVRec(9): SetFlags(DummyRecorderRunning,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning, 2012-03-29 17:41:20.740381 I DummyDTVRecorder -- started 2012-03-29 17:41:20.740395 I TVRec(9): SetFlags(RingBufferReady,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2012-03-29 17:41:20.740409 I TVRec(9): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2012-03-29 17:41:20.740425 I TVRec(9): SetFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2012-03-29 17:41:20.740441 I TVRec(9): Got good signal 2012-03-29 17:41:20.740705 I TVRec(9): TeardownSignalMonitor() -- begin 2012-03-29 17:41:20.791040 I TVRec(9): TeardownSignalMonitor() -- end 2012-03-29 17:41:20.791062 I TVRec(9): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady, 2012-03-29 17:41:20.791078 I TVRec(9): ClearFlags(WaitingForSignal,) -> RunMainLoop,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady, 2012-03-29 17:41:20.791153 I TVRec(9): Starting Recorder 2012-03-29 17:41:20.793070 I TVRec(9): FinishedRecording(The Waltons) key: 6049_2012-03-29T17:41:20 in recgroup: LiveTV status: Recording:Recorded is_dummy finished_now 2012-03-29 17:41:20.794616 I Chain: Updated endtime for '6049_20120329174120' to 20120329174120 2012-03-29 17:41:20.796842 I TVRec(9): ClearFlags(DummyRecorderRunning,) -> RunMainLoop,NeedToStartRecorder,RingBufferReady, 2012-03-29 17:41:20.864972 I Using profile 'Live TV' to record 2012-03-29 17:41:20.864991 I TVRec(9): SwitchLiveTVRingBuffer(discont 1, set_rec 0 2012-03-29 17:41:20.866556 I TVRec(9): GetProgramRingBufferForLiveTV() 2012-03-29 17:41:20.867204 I Reschedule requested for id -1. 2012-03-29 17:41:20.879292 N AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min 2012-03-29 17:41:20.886351 E RecordingInfo::InsertProgram(ProgramInfo(6049_20120329174120.mpg): channame(Hallmark Channel) startts(Thu Mar 29 17:00:00 2012) endts(Thu Mar 29 18:00:00 2012) recstartts(Thu Mar 29 17:41:20 2012) recendts(Thu Mar 29 18:00:00 2012) title(The Waltons)): recording already exists... 2012-03-29 17:41:20.912585 I TVRec(9): StartedRecording(0x11c4620) fn(/share/TV/recordings/6049_20120329174121.mpg) 2012-03-29 17:41:20.921784 I TVRec(9): FinishedRecording(The Waltons) key: 6049_2012-03-29T17:41:20 in recgroup: LiveTV status: Recorded:Recorded not_dummy already_finished 2012-03-29 17:41:20.931001 I Chain: Appended@1 '6049_20120329174121' 2012-03-29 17:41:20.933049 I DTVRec(9): ResetForNewFile(void) 2012-03-29 17:41:20.935473 I RecBase(9:/dev/video0): SetRingBuffer(0x1200450) '/share/TV/recordings/6049_20120329174121.mpg' 2012-03-29 17:41:20.935500 I RecBase(9:/dev/video0): SetRecording(0x11c4620) title(The Waltons) 2012-03-29 17:41:20.946939 I TVRec(9): SetFlags(CancelNextRecording,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,RingBufferReady, 2012-03-29 17:41:20.947162 I DTVRec(9): ResetForNewFile(void) 2012-03-29 17:41:20.947419 E mpegrecorder.cpp:set_ctrls(): Could not set Audio Sampling Frequency to 2 eno: Invalid argument (22) 2012-03-29 17:41:20.947441 E mpegrecorder.cpp:set_ctrls(): Could not set Audio Encoding to 1 eno: Invalid argument (22) 2012-03-29 17:41:20.947460 E mpegrecorder.cpp:set_ctrls(): Could not set Audio L2 Bitrate to 13 eno: Invalid argument (22) 2012-03-29 17:41:20.947478 E mpegrecorder.cpp:set_ctrls(): Could not set Video Aspect ratio to 1 eno: Invalid argument (22) 2012-03-29 17:41:20.947497 E mpegrecorder.cpp:set_ctrls(): Could not set MPEG Stream type to 0 eno: Invalid argument (22) 2012-03-29 17:41:20.947516 E mpegrecorder.cpp:set_ctrls(): Could not set Video Average Bitrate to 4500000 eno: Invalid argument (22) 2012-03-29 17:41:20.947534 E mpegrecorder.cpp:set_ctrls(): Could not set Video Peak Bitrate to 6000000 eno: Invalid argument (22) 2012-03-29 17:41:20.983492 I DevRdB(/dev/video0): buffer size 9400 KB 2012-03-29 17:41:20.983508 I MPEGRec(/dev/video0): DRB ready 2012-03-29 17:41:20.983560 I MPEGRec(/dev/video0): Initial startup of recorder 2012-03-29 17:41:20.983571 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:20.983592 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:20.983643 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:20.983649 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:20.987473 I TVRec(9): SetFlags(RecorderRunning,RingBufferReady,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,RecorderRunning,RingBufferReady, 2012-03-29 17:41:20.987502 I TVRec(9): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,CancelNextRecording,RecorderRunning,RingBufferReady, 2012-03-29 17:41:23.483021 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:23.483039 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:23.483067 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:23.483072 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:23.483078 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:23.483098 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:23.483115 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:23.483142 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:23.483145 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:25.983020 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:25.983028 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:25.983050 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:25.983058 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:25.983062 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:25.983088 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:25.983105 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:25.983133 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:25.983136 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:26.616088 I Scheduled 530 items in 5.7 = 2.44 match + 3.31 place 2012-03-29 17:41:26.817627 I Scheduler: Seem to be woken up by USER 2012-03-29 17:41:27.798398 I Running housekeeping thread 2012-03-29 17:41:28.483018 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:28.483027 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:28.483050 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:28.483055 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:28.483059 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:28.483084 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:28.483101 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:28.483129 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:28.483133 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:30.983027 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:30.983041 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:30.983200 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:30.983206 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:30.983209 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:30.983226 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:30.983247 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:30.983281 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:30.983284 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:31.159803 I TVRec(9): SetFlags(FrontendReady,) -> FrontendReady,RunMainLoop,CancelNextRecording,RecorderRunning,RingBufferReady, 2012-03-29 17:41:33.483019 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:33.483027 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:33.483062 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:33.483066 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:33.483069 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:33.483084 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:33.483099 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:33.483128 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:33.483131 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:35.983015 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:35.983024 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:35.983055 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:35.983060 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:35.983064 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:35.983080 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:35.983096 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:35.983125 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:35.983128 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:38.483018 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:38.483026 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:38.483049 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:38.483053 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:38.483058 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:38.483082 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:38.483098 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:38.483124 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:38.483128 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:40.983015 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:40.983024 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:40.983047 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:40.983052 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:40.983056 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:40.983081 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:40.983099 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:40.983126 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:40.983129 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:41.402323 I TVRec(9): StopLiveTV(void) curRec: 0x11c4620 pseudoRec: 0x0 2012-03-29 17:41:41.403841 I TVRec(9): Changing from WatchingLiveTV to None 2012-03-29 17:41:41.403866 I TVRec(9): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RecorderRunning,RingBufferReady, 2012-03-29 17:41:41.403885 I TVRec(9): HandleTuning Request: Program(NULL) channel() input() flags(KillRec,KillRingBuffer,) 2012-03-29 17:41:41.403896 I DevRdB(/dev/video0): Stop() -- begin 2012-03-29 17:41:41.403936 E DevRdB(/dev/video0): WakePoll failed. 2012-03-29 17:41:41.403974 I DevRdB(/dev/video0): Stop() -- end 2012-03-29 17:41:41.403991 I MPEGRec(/dev/video0): run finishing up 2012-03-29 17:41:41.403996 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:41.414002 I TVRec(9): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady, 2012-03-29 17:41:41.415368 I RecBase(9:/dev/video0): SetRecording(0x0) 2012-03-29 17:41:41.418691 I TVRec::FinishedRecording(The Waltons) good recq: 2012-03-29 17:41:41.418775 I TVRec(9): FinishedRecording(The Waltons) key: 6049_2012-03-29T17:41:21 in recgroup: LiveTV status: Recorder Failed:Recorder Failed not_dummy finished_now 2012-03-29 17:41:41.420110 I Chain: Updated endtime for '6049_20120329174121' to 20120329174141 2012-03-29 17:41:41.422524 I SaveVideoProperties(0x38, 0x20) 2012-03-29 17:41:41.429599 I TVRec(9): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady, 2012-03-29 17:41:41.429612 I TVRec(9): Tearing down RingBuffer 2012-03-29 17:41:41.429843 I TVRec(9): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady, 2012-03-29 17:41:41.430202 I TVRec(9): SetFlags(FrontendReady,) -> FrontendReady,RunMainLoop,RingBufferReady, 2012-03-29 17:41:41.431571 I TVRec(9): SetFlags(FrontendReady,) -> FrontendReady,RunMainLoop,RingBufferReady, 2012-03-29 17:41:41.440835 I Getting next free recorder after : -1 2012-03-29 17:41:41.440848 I Checking card 1. Best card so far -1 2012-03-29 17:41:41.461963 I Checking card 3. Best card so far 1 2012-03-29 17:41:41.464013 I Checking card 5. Best card so far 3 2012-03-29 17:41:41.466147 I Checking card 9. Best card so far 5 2012-03-29 17:41:41.468257 I Best card is 5 2012-03-29 17:41:41.475356 I MainServer::ANN Playback 2012-03-29 17:41:41.475367 I adding: bugs as a client (events: 0) 2012-03-29 17:41:41.497488 I TVRec(5): Found channel (49) on different card(9). 2012-03-29 17:41:41.508593 I MainServer::ANN Playback 2012-03-29 17:41:41.508603 I adding: bugs as a client (events: 0) 2012-03-29 17:41:41.511648 I TVRec(9): Changing from None to WatchingLiveTV 2012-03-29 17:41:41.511675 I TVRec(9): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RingBufferReady, 2012-03-29 17:41:41.511692 I TVRec(9): HandleTuning Request: Program(NULL) channel() input() flags(LiveTV,) 2012-03-29 17:41:41.511707 I ChannelBase(9): Looking for startchannel '49' on input 'Television' 2012-03-29 17:41:41.518406 I ChannelBase(9): Found startchannel '49' on input 'Television' 2012-03-29 17:41:41.518436 I TVRec(9): HW Tuner: 9->9 2012-03-29 17:41:41.518449 I TVRec(9): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady, 2012-03-29 17:41:41.518459 I TVRec(9): No recorder yet, calling TuningFrequency 2012-03-29 17:41:41.519594 I V4LChannel(/dev/video0): Device name 'Pinnacle PCTV HD 800i' driver 'cx8800'. 2012-03-29 17:41:41.519615 I V4LChannel(/dev/video0): v4l2: 1 stream io: 0 std io: 1 async io: 0 tuner 1 sliced vbi 0 2012-03-29 17:41:41.528030 I ChannelBase(9): Input #6: 'Television' schan(34) sourceid(6) ccid(9) 2012-03-29 17:41:41.528043 I ChannelBase(9): Current Input #6: 'Television' 2012-03-29 17:41:41.528121 I Global TVFormat Setting 'NTSC' 2012-03-29 17:41:41.528154 I V4LChannel(/dev/video0): Input #6: 'Television' schan(34) tun() v4l1(NTSC) v4l2(NTSC) 2012-03-29 17:41:41.528170 I V4LChannel(/dev/video0): SetFormat(Default) fmt(NTSC) input(6) 2012-03-29 17:41:41.528180 I Channel(/dev/video0)::SwitchToInput(in 6, '') 2012-03-29 17:41:41.534668 I V4LChannel(/dev/video0): SetInputAndFormat(6, NTSC) (v4l v2) input_switch: 0 mode_switch: 1 2012-03-29 17:41:41.677178 I DTVChan(/dev/video0): SetChannelByString(49): 2012-03-29 17:41:41.685016 I V4LChannel(/dev/video0): SetFormat(Default) fmt(NTSC) input(6) 2012-03-29 17:41:41.685036 I Channel(/dev/video0)::Tune(49): curList[47].freq(373250) 2012-03-29 17:41:41.685047 I V4LChannel(/dev/video0): Tune(373250000, ) 2012-03-29 17:41:41.826850 I Channel(/dev/video0)::Tune(): Frequency is now 373250000 2012-03-29 17:41:41.826864 I DTVChan(/dev/video0): SetChannelByString(49): success 2012-03-29 17:41:41.835655 I TVRec(9): CreateLiveTVRingBuffer(49) 2012-03-29 17:41:41.836956 I TVRec(9): GetProgramRingBufferForLiveTV() 2012-03-29 17:41:41.846679 N AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min 2012-03-29 17:41:41.905939 I TVRec(9): StartedRecording(0x7fc7401adac0) fn(/share/TV/recordings/6049_20120329174141.mpg) 2012-03-29 17:41:41.910700 I Chain: Appended@0 '6049_20120329174141' 2012-03-29 17:41:41.915402 I TVRec(9): Starting Signal Monitor 2012-03-29 17:41:41.915415 I TVRec(9): SetupSignalMonitor(1, 1) 2012-03-29 17:41:41.915466 I TVRec(9): Signal monitor successfully created 2012-03-29 17:41:41.915591 I TVRec(9): SetFlags(SignalMonitorRunning,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady, 2012-03-29 17:41:41.915608 I TVRec(9): ClearFlags(WaitingForSignal,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady, 2012-03-29 17:41:41.915622 I TVRec(9): SetFlags(WaitingForSignal,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady, 2012-03-29 17:41:41.915637 I TVRec(9): SetFlags(DummyRecorderRunning,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2012-03-29 17:41:41.915643 I DummyDTVRecorder -- started 2012-03-29 17:41:41.915656 I TVRec(9): SetFlags(RingBufferReady,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2012-03-29 17:41:41.915670 I TVRec(9): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2012-03-29 17:41:41.915685 I TVRec(9): SetFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2012-03-29 17:41:41.915695 I TVRec(9): Got good signal 2012-03-29 17:41:41.915955 I TVRec(9): TeardownSignalMonitor() -- begin 2012-03-29 17:41:41.966207 I TVRec(9): TeardownSignalMonitor() -- end 2012-03-29 17:41:41.966227 I TVRec(9): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady, 2012-03-29 17:41:41.966243 I TVRec(9): ClearFlags(WaitingForSignal,) -> RunMainLoop,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady, 2012-03-29 17:41:41.966297 I TVRec(9): Starting Recorder 2012-03-29 17:41:41.967860 I TVRec(9): FinishedRecording(The Waltons) key: 6049_2012-03-29T17:41:41 in recgroup: LiveTV status: Recording:Recorded is_dummy finished_now 2012-03-29 17:41:41.969219 I Chain: Updated endtime for '6049_20120329174141' to 20120329174141 2012-03-29 17:41:41.971197 I TVRec(9): ClearFlags(DummyRecorderRunning,) -> RunMainLoop,NeedToStartRecorder,RingBufferReady, 2012-03-29 17:41:42.037680 I Using profile 'Live TV' to record 2012-03-29 17:41:42.037697 I TVRec(9): SwitchLiveTVRingBuffer(discont 1, set_rec 0 2012-03-29 17:41:42.038918 I TVRec(9): GetProgramRingBufferForLiveTV() 2012-03-29 17:41:42.048094 N AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min 2012-03-29 17:41:42.100778 I TVRec(9): StartedRecording(0x7fc7400b9610) fn(/share/TV/recordings/6049_20120329174142.mpg) 2012-03-29 17:41:42.106272 I TVRec(9): FinishedRecording(The Waltons) key: 6049_2012-03-29T17:41:41 in recgroup: LiveTV status: Recorded:Recorded not_dummy already_finished 2012-03-29 17:41:42.115924 I Chain: Appended@1 '6049_20120329174142' 2012-03-29 17:41:42.117671 I DTVRec(9): ResetForNewFile(void) 2012-03-29 17:41:42.117803 I RecBase(9:/dev/video0): SetRingBuffer(0x1230e00) '/share/TV/recordings/6049_20120329174142.mpg' 2012-03-29 17:41:42.117820 I RecBase(9:/dev/video0): SetRecording(0x7fc7400b9610) title(The Waltons) 2012-03-29 17:41:42.129027 I TVRec(9): SetFlags(CancelNextRecording,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,RingBufferReady, 2012-03-29 17:41:42.129254 I DTVRec(9): ResetForNewFile(void) 2012-03-29 17:41:42.129405 E mpegrecorder.cpp:set_ctrls(): Could not set Audio Sampling Frequency to 2 eno: Invalid argument (22) 2012-03-29 17:41:42.129427 E mpegrecorder.cpp:set_ctrls(): Could not set Audio Encoding to 1 eno: Invalid argument (22) 2012-03-29 17:41:42.129446 E mpegrecorder.cpp:set_ctrls(): Could not set Audio L2 Bitrate to 13 eno: Invalid argument (22) 2012-03-29 17:41:42.129464 E mpegrecorder.cpp:set_ctrls(): Could not set Video Aspect ratio to 1 eno: Invalid argument (22) 2012-03-29 17:41:42.129482 E mpegrecorder.cpp:set_ctrls(): Could not set MPEG Stream type to 0 eno: Invalid argument (22) 2012-03-29 17:41:42.129501 E mpegrecorder.cpp:set_ctrls(): Could not set Video Average Bitrate to 4500000 eno: Invalid argument (22) 2012-03-29 17:41:42.129520 E mpegrecorder.cpp:set_ctrls(): Could not set Video Peak Bitrate to 6000000 eno: Invalid argument (22) 2012-03-29 17:41:42.142726 I DevRdB(/dev/video0): buffer size 9400 KB 2012-03-29 17:41:42.142738 I MPEGRec(/dev/video0): DRB ready 2012-03-29 17:41:42.142751 I MPEGRec(/dev/video0): Initial startup of recorder 2012-03-29 17:41:42.142759 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:42.142774 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:42.142821 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:42.142828 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:42.144401 I TVRec(9): SetFlags(RecorderRunning,RingBufferReady,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,RecorderRunning,RingBufferReady, 2012-03-29 17:41:42.144425 I TVRec(9): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,CancelNextRecording,RecorderRunning,RingBufferReady, 2012-03-29 17:41:44.643019 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:44.643035 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:44.643066 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:44.643072 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:44.643075 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:44.643102 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:44.643119 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:44.643145 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:44.643148 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:47.143016 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:47.143027 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:47.143057 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:47.143065 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:47.143069 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:47.143096 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:47.143116 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:47.143143 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:47.143146 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:49.643016 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:49.643026 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:49.643059 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:49.643066 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:49.643070 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:49.643096 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:49.643113 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:49.643141 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:49.643144 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:52.143018 E DevRdB(/dev/video0): Poll giving up 2 2012-03-29 17:41:52.143028 E DevRdB(/dev/video0): fill_ringbuffer: error state 2012-03-29 17:41:52.143051 E MPEGRec(/dev/video0): Device error detected 2012-03-29 17:41:52.143057 I MPEGRec(/dev/video0): RestartEncoding 2012-03-29 17:41:52.143061 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:52.143086 I MPEGRec(/dev/video0): StartEncoding 2012-03-29 17:41:52.143103 I DevRdB(/dev/video0): Start() -- begin 2012-03-29 17:41:52.143131 I DevRdB(/dev/video0): Start() -- middle 2012-03-29 17:41:52.143134 I DevRdB(/dev/video0): Start() -- end 2012-03-29 17:41:52.171683 I TVRec(9): StopLiveTV(void) curRec: 0x7fc7400b9610 pseudoRec: 0x0 2012-03-29 17:41:52.173032 I TVRec(9): Changing from WatchingLiveTV to None 2012-03-29 17:41:52.173062 I TVRec(9): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RecorderRunning,RingBufferReady, 2012-03-29 17:41:52.173074 I TVRec(9): HandleTuning Request: Program(NULL) channel() input() flags(KillRec,KillRingBuffer,) 2012-03-29 17:41:52.173092 I DevRdB(/dev/video0): Stop() -- begin 2012-03-29 17:41:52.173164 I DevRdB(/dev/video0): Stop() -- end 2012-03-29 17:41:52.173178 I MPEGRec(/dev/video0): run finishing up 2012-03-29 17:41:52.173182 I MPEGRec(/dev/video0): StopEncoding 2012-03-29 17:41:52.192349 I TVRec(9): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady, 2012-03-29 17:41:52.193775 I RecBase(9:/dev/video0): SetRecording(0x0) 2012-03-29 17:41:52.195045 I TVRec::FinishedRecording(The Waltons) good recq: 2012-03-29 17:41:52.195131 I TVRec(9): FinishedRecording(The Waltons) key: 6049_2012-03-29T17:41:42 in recgroup: LiveTV status: Recorder Failed:Recorder Failed not_dummy finished_now 2012-03-29 17:41:52.196294 I Chain: Updated endtime for '6049_20120329174142' to 20120329174152 2012-03-29 17:41:52.198341 I SaveVideoProperties(0x38, 0x20) 2012-03-29 17:41:52.204908 I TVRec(9): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady, 2012-03-29 17:41:52.204923 I TVRec(9): Tearing down RingBuffer 2012-03-29 17:41:52.205156 I TVRec(9): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady, 2012-03-29 17:41:54.366723 N MythBackend exiting