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:<RecordingQuality overall_score="1" key="6049_2012-03-29T17:41:21" />

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:<RecordingQuality overall_score="1" key="6049_2012-03-29T17:41:42" />

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
