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