[mythtv-commits] Ticket #8856: Failed channel changes fail to stop recording
MythTV
mythtv at cvs.mythtv.org
Fri Sep 3 02:34:04 UTC 2010
#8856: Failed channel changes fail to stop recording
--------------------------------+-------------------------------------------
Reporter: kormoc | Owner: jpoet
Type: defect | Status: new
Priority: minor | Milestone: unknown
Component: MythTV - Recording | Version: Trunk Head
Severity: low | Resolution:
Keywords: | Ticket locked: 0
--------------------------------+-------------------------------------------
Description changed by kormoc:
Old description:
> {{{
> 2010-09-02 15:58:30.326 Reschedule requested for id 0.
> 2010-09-02 15:58:30.326 BuildWorkList...
> 2010-09-02 15:58:30.327 AddNewRecords...
> 2010-09-02 15:58:30.508 |-- Start DB Query...
> 2010-09-02 15:58:37.842 |-- 6404 results in 7.33387 sec. Processing...
> 2010-09-02 15:58:38.400 +-- Cleanup...
> 2010-09-02 15:58:38.436 AddNotListed...
> 2010-09-02 15:58:38.443 |-- Start DB Query...
> 2010-09-02 15:58:38.445 |-- 0 results in 0.001064 sec. Processing...
> 2010-09-02 15:58:38.445 Sort by time...
> 2010-09-02 15:58:38.478 PruneOverlaps...
> 2010-09-02 15:58:38.480 Sort by priority...
> 2010-09-02 15:58:39.294 BuildListMaps...
> 2010-09-02 15:58:39.295 SchedNewRecords...
> 2010-09-02 15:58:39.296 Scheduling:
> <SNIP>
> --- print list end ---
> 2010-09-02 15:58:44.295 Scheduled 2884 items in 11.4 = 0.00 match + 11.39
> place
> 2010-09-02 15:58:44.298 scheduler: Scheduled items: Scheduled 2884 items
> in 11.4 = 0.00 match + 11.39 place
> 2010-09-02 15:58:59.329 Scheduler: FillRecordingDir: Starting
> 2010-09-02 15:58:59.330 Scheduler: FillRecordingDir: Finished
> 2010-09-02 15:58:59.330 TVRec(2): RecordPending on inputid 2
> 2010-09-02 15:58:59.469 TVRec(2): ASK_RECORDING 2 29 0 0
> 2010-09-02 15:59:31.404 TVRec(2): StartRecording("The Academy":"Another
> Black Monday")
> 2010-09-02 15:59:31.456 TVRec(2): StartedRecording(0x7f1854c31060)
> fn(/mnt/tv/recordings/1250_20100902160000.mpg)
> 2010-09-02 15:59:31.463 TVRec(2): ClearFlags(CancelNextRecording,) ->
> RunMainLoop,RingBufferReady,
> 2010-09-02 15:59:31.463 TVRec(2): Changing from None to RecordingOnly
> 2010-09-02 15:59:31.464 TVRec(2):
> ClearFlags(FrontendReady,CancelNextRecording,) ->
> RunMainLoop,RingBufferReady,
> 2010-09-02 15:59:31.464 TVRec(2): HandleTuning Request: Program(yes)
> channel() input() flags(Recording,)
> 2010-09-02 15:59:31.475 TVRec(2): HW Tuner: 2->2
> 2010-09-02 15:59:31.480 TVRec(2): ClearFlags(PENDINGACTIONS,) ->
> RunMainLoop,RingBufferReady,
> 2010-09-02 15:59:31.481 TVRec(2): No recorder yet, calling
> TuningFrequency
> 2010-09-02 15:59:31.483 Channel(/dev/video0): Device name 'Hauppauge HD
> PVR' driver 'hdpvr'.
> 2010-09-02 15:59:31.568 ChannelBase(2): Input #2: 'Component' schan(284)
> sourceid(1) ccid(2)
> 2010-09-02 15:59:31.568 ChannelBase(2): Input #4: 'Could not open
> '/dev/video0' to ' schan(3) sourceid(1) ccid(2)
> 2010-09-02 15:59:31.568 ChannelBase(2): Current Input #2: 'Component'
> 2010-09-02 15:59:31.570 Global TVFormat Setting 'NTSC'
> 2010-09-02 15:59:31.570 Channel(/dev/video0): Input #2: 'Component'
> schan(284) tun() v4l1(NTSC) v4l2(NTSC)
> 2010-09-02 15:59:31.570 Channel(/dev/video0): Input #4: 'Could not open
> '/dev/video0' to ' schan(3) tun() v4l1(PAL) v4l2(Unknown)
> 2010-09-02 15:59:31.571 Channel(/dev/video0): SetFormat(Default)
> fmt(NTSC) input(2)
> 2010-09-02 15:59:31.571 Channel(/dev/video0)::SwitchToInput(in 2, '')
> 2010-09-02 15:59:31.575 Channel(/dev/video0): SetInputAndFormat(2, NTSC)
> (v4l v2)
> 2010-09-02 15:59:31.605 ChannelBase(2): SelectChannel 250
> 2010-09-02 15:59:31.605 TVRec(2): Starting Signal Monitor
> 2010-09-02 15:59:31.606 ChannelThread::run
> 2010-09-02 15:59:31.606 TVRec(2): SetupSignalMonitor(1, 0)
> 2010-09-02 15:59:31.606 Channel(/dev/video0): SetChannelByString(250)
> 2010-09-02 15:59:31.607 AnalogSM(/dev/video0): card 'Hauppauge HD PVR'
> driver 'hdpvr' version '512'
> 2010-09-02 15:59:31.607 TVRec(2): Signal monitor successfully created
> 2010-09-02 15:59:31.608 SM(/dev/video0)::Start: begin
> 2010-09-02 15:59:31.610 SM(/dev/video0)::Start: end
> 2010-09-02 15:59:31.610 TVRec(2): SetFlags(SignalMonitorRunning,) ->
> RunMainLoop,SignalMonitorRunning,RingBufferReady,
> 2010-09-02 15:59:31.611 TVRec(2): ClearFlags(WaitingForSignal,) ->
> RunMainLoop,SignalMonitorRunning,RingBufferReady,
> 2010-09-02 15:59:31.611 Channel(/dev/video0): SetFormat(Default)
> fmt(NTSC) input(2)
> 2010-09-02 15:59:31.611 TVRec(2): SetFlags(WaitingForSignal,) ->
> RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady,
> 2010-09-02 15:59:31.612 TVRec(2): ClearFlags(NeedToStartRecorder,) ->
> RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady,
> 2010-09-02 15:59:31.612 Launching: /usr/local/bin/ChangeChannel 250
> 2010-09-02 15:59:31.613 TVRec(2): SetFlags(NeedToStartRecorder,) ->
> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,RingBufferReady,
> 2010-09-02 15:59:31.618 Cleared parent's verbose lock
> 2010-09-02 15:59:31.618 PID 10931: launched
> 2010-09-02 15:59:31.632 AutoExpire: CalcParams(): Max required Free
> Space: 3.0 GB w/freq: 15 min
> 2010-09-02 15:59:31.763 Started recording: "The Academy":"Another Black
> Monday": channel 1250 on cardid 2, sourceid 1
> 2010-09-02 15:59:31.766 scheduler: Started recording: "The
> Academy":"Another Black Monday": channel 1250 on cardid 2, sourceid 1
> 2010-09-02 15:59:31.773 Scheduler: Update next_record for 1
> <SNIP>
>
> 2010-09-02 15:59:32.532 Scheduler: Update next_record for 1174
> 2010-09-02 15:59:32.613 ProgramInfo(1250_20100902160000.mpg), Error:
> GetPlaybackURL: '1250_20100902160000.mpg' should be local, but it can not
> be found.
> 2010-09-02 15:59:34.427 MainServer::HandleVersion - Client speaks
> protocol version 58 but we speak 59!
> 2010-09-02 15:59:34.427 MainServer, Warning: Unknown socket closing
> MythSocket(0x27b7670)
> Excessive channel change retries, commanded 250 got 284
> 2010-09-02 15:59:39.045 PID 10931: exited: status=65280, result=255
> 2010-09-02 15:59:39.049 SignalMonitor: channel change failed
> 2010-09-02 15:59:39.100 SignalMonitor: channel change failed
> 2010-09-02 15:59:39.153 SignalMonitor: channel change failed
> 2010-09-02 15:59:39.205 SignalMonitor: channel change failed
> 2010-09-02 15:59:39.257 SignalMonitor: channel change failed
> 2010-09-02 15:59:39.308 SignalMonitor: channel change failed
> 2010-09-02 15:59:39.360 SignalMonitor: channel change failed
> 2010-09-02 15:59:39.412 SignalMonitor: channel change failed
> 2010-09-02 15:59:39.464 SignalMonitor: channel change failed
>
> 2010-09-02 15:59:39.517 SignalMonitor: channel change failed
> 2010-09-02 15:59:39.568 SignalMonitor: channel change failed
> 2010-09-02 15:59:39.621 SignalMonitor: channel change failed
> 2010-09-02 15:59:39.633 TVRec(2) Error: SignalMonitor failed
> 2010-09-02 15:59:39.653 TVRec(2): ClearFlags(NeedToStartRecorder,) ->
> RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady,
> 2010-09-02 15:59:39.654 TVRec(2): TeardownSignalMonitor() -- begin
> 2010-09-02 15:59:39.654 SM(/dev/video0)::Stop: begin
> 2010-09-02 15:59:39.673 SM(/dev/video0)::Stop: end
> 2010-09-02 15:59:39.673 TVRec(2): TeardownSignalMonitor() -- end
> 2010-09-02 15:59:39.673 TVRec(2): ClearFlags(SignalMonitorRunning,) ->
> RunMainLoop,WaitingForSignal,RingBufferReady,
> 2010-09-02 15:59:39.674 TVRec(2): ClearFlags(WaitingForSignal,) ->
> RunMainLoop,RingBufferReady,
>
> 2010-09-02 16:35:17.894 AutoExpire: CalcParams(): Max required Free
> Space: 3.0 GB w/freq: 15 min
> 2010-09-02 16:35:17.898 Expiring 2449 MB for 1231 at 2010-08-30T21:30:00
> => "The Best Thing I Ever Ate":"Totally Unexpected"
> 2010-09-02 16:35:17.900 autoexpire: Expiring Program: Expiring 2449 MB
> for 1231 at 2010-08-30T21:30:00 => "The Best Thing I Ever Ate":"Totally
> Unexpected"
> 2010-09-02 16:35:18.146 ProgramInfo(1250_20100902160000.mpg), Error:
> GetPlaybackURL: '1250_20100902160000.mpg' should be local, but it can not
> be found.
> 2010-09-02 16:35:22.117 ProgramInfo(1250_20100902160000.mpg), Error:
> GetPlaybackURL: '1250_20100902160000.mpg' should be local, but it can not
> be found.
> }}}
>
> And it leaves behind a 0 byte recording and the tuner shows as being
> used.
New description:
{{{
2010-09-02 15:58:30.326 Reschedule requested for id 0.
2010-09-02 15:58:30.326 BuildWorkList...
2010-09-02 15:58:30.327 AddNewRecords...
2010-09-02 15:58:30.508 |-- Start DB Query...
2010-09-02 15:58:37.842 |-- 6404 results in 7.33387 sec. Processing...
2010-09-02 15:58:38.400 +-- Cleanup...
2010-09-02 15:58:38.436 AddNotListed...
2010-09-02 15:58:38.443 |-- Start DB Query...
2010-09-02 15:58:38.445 |-- 0 results in 0.001064 sec. Processing...
2010-09-02 15:58:38.445 Sort by time...
2010-09-02 15:58:38.478 PruneOverlaps...
2010-09-02 15:58:38.480 Sort by priority...
2010-09-02 15:58:39.294 BuildListMaps...
2010-09-02 15:58:39.295 SchedNewRecords...
2010-09-02 15:58:39.296 Scheduling:
<SNIP>
--- print list end ---
2010-09-02 15:58:44.295 Scheduled 2884 items in 11.4 = 0.00 match + 11.39
place
2010-09-02 15:58:44.298 scheduler: Scheduled items: Scheduled 2884 items
in 11.4 = 0.00 match + 11.39 place
2010-09-02 15:58:59.329 Scheduler: FillRecordingDir: Starting
2010-09-02 15:58:59.330 Scheduler: FillRecordingDir: Finished
2010-09-02 15:58:59.330 TVRec(2): RecordPending on inputid 2
2010-09-02 15:58:59.469 TVRec(2): ASK_RECORDING 2 29 0 0
2010-09-02 15:59:31.404 TVRec(2): StartRecording("The Academy":"Another
Black Monday")
2010-09-02 15:59:31.456 TVRec(2): StartedRecording(0x7f1854c31060)
fn(/mnt/tv/recordings/1250_20100902160000.mpg)
2010-09-02 15:59:31.463 TVRec(2): ClearFlags(CancelNextRecording,) ->
RunMainLoop,RingBufferReady,
2010-09-02 15:59:31.463 TVRec(2): Changing from None to RecordingOnly
2010-09-02 15:59:31.464 TVRec(2):
ClearFlags(FrontendReady,CancelNextRecording,) ->
RunMainLoop,RingBufferReady,
2010-09-02 15:59:31.464 TVRec(2): HandleTuning Request: Program(yes)
channel() input() flags(Recording,)
2010-09-02 15:59:31.475 TVRec(2): HW Tuner: 2->2
2010-09-02 15:59:31.480 TVRec(2): ClearFlags(PENDINGACTIONS,) ->
RunMainLoop,RingBufferReady,
2010-09-02 15:59:31.481 TVRec(2): No recorder yet, calling TuningFrequency
2010-09-02 15:59:31.483 Channel(/dev/video0): Device name 'Hauppauge HD
PVR' driver 'hdpvr'.
2010-09-02 15:59:31.568 ChannelBase(2): Input #2: 'Component' schan(284)
sourceid(1) ccid(2)
2010-09-02 15:59:31.568 ChannelBase(2): Input #4: 'Could not open
'/dev/video0' to ' schan(3) sourceid(1) ccid(2)
2010-09-02 15:59:31.568 ChannelBase(2): Current Input #2: 'Component'
2010-09-02 15:59:31.570 Global TVFormat Setting 'NTSC'
2010-09-02 15:59:31.570 Channel(/dev/video0): Input #2: 'Component'
schan(284) tun() v4l1(NTSC) v4l2(NTSC)
2010-09-02 15:59:31.570 Channel(/dev/video0): Input #4: 'Could not open
'/dev/video0' to ' schan(3) tun() v4l1(PAL) v4l2(Unknown)
2010-09-02 15:59:31.571 Channel(/dev/video0): SetFormat(Default) fmt(NTSC)
input(2)
2010-09-02 15:59:31.571 Channel(/dev/video0)::SwitchToInput(in 2, '')
2010-09-02 15:59:31.575 Channel(/dev/video0): SetInputAndFormat(2, NTSC)
(v4l v2)
2010-09-02 15:59:31.605 ChannelBase(2): SelectChannel 250
2010-09-02 15:59:31.605 TVRec(2): Starting Signal Monitor
2010-09-02 15:59:31.606 ChannelThread::run
2010-09-02 15:59:31.606 TVRec(2): SetupSignalMonitor(1, 0)
2010-09-02 15:59:31.606 Channel(/dev/video0): SetChannelByString(250)
2010-09-02 15:59:31.607 AnalogSM(/dev/video0): card 'Hauppauge HD PVR'
driver 'hdpvr' version '512'
2010-09-02 15:59:31.607 TVRec(2): Signal monitor successfully created
2010-09-02 15:59:31.608 SM(/dev/video0)::Start: begin
2010-09-02 15:59:31.610 SM(/dev/video0)::Start: end
2010-09-02 15:59:31.610 TVRec(2): SetFlags(SignalMonitorRunning,) ->
RunMainLoop,SignalMonitorRunning,RingBufferReady,
2010-09-02 15:59:31.611 TVRec(2): ClearFlags(WaitingForSignal,) ->
RunMainLoop,SignalMonitorRunning,RingBufferReady,
2010-09-02 15:59:31.611 Channel(/dev/video0): SetFormat(Default) fmt(NTSC)
input(2)
2010-09-02 15:59:31.611 TVRec(2): SetFlags(WaitingForSignal,) ->
RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady,
2010-09-02 15:59:31.612 TVRec(2): ClearFlags(NeedToStartRecorder,) ->
RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady,
2010-09-02 15:59:31.612 Launching: /usr/local/bin/ChangeChannel 250
2010-09-02 15:59:31.613 TVRec(2): SetFlags(NeedToStartRecorder,) ->
RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,RingBufferReady,
2010-09-02 15:59:31.618 Cleared parent's verbose lock
2010-09-02 15:59:31.618 PID 10931: launched
2010-09-02 15:59:31.632 AutoExpire: CalcParams(): Max required Free Space:
3.0 GB w/freq: 15 min
2010-09-02 15:59:31.763 Started recording: "The Academy":"Another Black
Monday": channel 1250 on cardid 2, sourceid 1
2010-09-02 15:59:31.766 scheduler: Started recording: "The
Academy":"Another Black Monday": channel 1250 on cardid 2, sourceid 1
2010-09-02 15:59:31.773 Scheduler: Update next_record for 1
<SNIP>
2010-09-02 15:59:32.532 Scheduler: Update next_record for 1174
2010-09-02 15:59:32.613 ProgramInfo(1250_20100902160000.mpg), Error:
GetPlaybackURL: '1250_20100902160000.mpg' should be local, but it can not
be found.
Excessive channel change retries, commanded 250 got 284
2010-09-02 15:59:39.045 PID 10931: exited: status=65280, result=255
2010-09-02 15:59:39.049 SignalMonitor: channel change failed
2010-09-02 15:59:39.100 SignalMonitor: channel change failed
2010-09-02 15:59:39.153 SignalMonitor: channel change failed
2010-09-02 15:59:39.205 SignalMonitor: channel change failed
2010-09-02 15:59:39.257 SignalMonitor: channel change failed
2010-09-02 15:59:39.308 SignalMonitor: channel change failed
2010-09-02 15:59:39.360 SignalMonitor: channel change failed
2010-09-02 15:59:39.412 SignalMonitor: channel change failed
2010-09-02 15:59:39.464 SignalMonitor: channel change failed
2010-09-02 15:59:39.517 SignalMonitor: channel change failed
2010-09-02 15:59:39.568 SignalMonitor: channel change failed
2010-09-02 15:59:39.621 SignalMonitor: channel change failed
2010-09-02 15:59:39.633 TVRec(2) Error: SignalMonitor failed
2010-09-02 15:59:39.653 TVRec(2): ClearFlags(NeedToStartRecorder,) ->
RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady,
2010-09-02 15:59:39.654 TVRec(2): TeardownSignalMonitor() -- begin
2010-09-02 15:59:39.654 SM(/dev/video0)::Stop: begin
2010-09-02 15:59:39.673 SM(/dev/video0)::Stop: end
2010-09-02 15:59:39.673 TVRec(2): TeardownSignalMonitor() -- end
2010-09-02 15:59:39.673 TVRec(2): ClearFlags(SignalMonitorRunning,) ->
RunMainLoop,WaitingForSignal,RingBufferReady,
2010-09-02 15:59:39.674 TVRec(2): ClearFlags(WaitingForSignal,) ->
RunMainLoop,RingBufferReady,
2010-09-02 16:35:17.894 AutoExpire: CalcParams(): Max required Free Space:
3.0 GB w/freq: 15 min
2010-09-02 16:35:17.898 Expiring 2449 MB for 1231 at 2010-08-30T21:30:00
=> "The Best Thing I Ever Ate":"Totally Unexpected"
2010-09-02 16:35:17.900 autoexpire: Expiring Program: Expiring 2449 MB for
1231 at 2010-08-30T21:30:00 => "The Best Thing I Ever Ate":"Totally
Unexpected"
2010-09-02 16:35:18.146 ProgramInfo(1250_20100902160000.mpg), Error:
GetPlaybackURL: '1250_20100902160000.mpg' should be local, but it can not
be found.
2010-09-02 16:35:22.117 ProgramInfo(1250_20100902160000.mpg), Error:
GetPlaybackURL: '1250_20100902160000.mpg' should be local, but it can not
be found.
}}}
And it leaves behind a 0 byte recording and the tuner shows as being used.
--
--
Ticket URL: <http://svn.mythtv.org/trac/ticket/8856#comment:1>
MythTV <http://www.mythtv.org/>
MythTV
More information about the mythtv-commits
mailing list