Opened 9 years ago

Closed 9 years ago

#8856 closed defect (fixed)

Failed channel changes fail to stop recording

Reported by: Rob Smith Owned by: jpoet
Priority: minor Milestone: 0.24
Component: MythTV - Recording Version: Master Head
Severity: low Keywords:
Cc: Ticket locked: no

Description (last modified by Rob Smith)

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.

Attachments (2)

StartRecording-WaitForTune.patch (1.7 KB) - added by jpoet 9 years ago.
Wait for tune before setting rsRecording status
StartRecording-WaitForTune-v2.patch (3.0 KB) - added by jpoet 9 years ago.
Works with LiveTV

Download all attachments as: .zip

Change History (10)

comment:1 Changed 9 years ago by Rob Smith

Description: modified (diff)

comment:2 Changed 9 years ago by beirdo

Status: newassigned

Changed 9 years ago by jpoet

Wait for tune before setting rsRecording status

comment:3 Changed 9 years ago by jpoet

Add a patch which waits for the SignalMonitor?(channel change) to finish before setting rsRecording. This allows the status to switch to rsFailed if the tune fails.

I am not committing this (yet) because I want to let it stew for a few days.

Also, this patch does not properly deal with channel change failures during LiveTV.

Changed 9 years ago by jpoet

Works with LiveTV

comment:4 Changed 9 years ago by jpoet

Added a v2 patch which works with LiveTV. Also cleans up some dead code.

comment:5 Changed 9 years ago by jpoet

Resolution: fixed
Status: assignedclosed

(In [26148]) When recording, don't return rsRecording in TVRec::StartRecording? until we know if the SignalMonitor/Channel? Change succeeded.

Also prune some dead code.

Fixes #8856

comment:6 Changed 9 years ago by stuartm

Milestone: unknown0.24

comment:7 Changed 9 years ago by jpoet

Resolution: fixed
Status: closednew

Reverted [26148] since it can cause the scheduler loop to pause. I am working on a new fix, but it will take a day or so.

comment:8 Changed 9 years ago by jpoet

Resolution: fixed
Status: newclosed

(In [26518]) Add a rsTuning state so rsRecording doesn't have to be selected before we know if the tuning succeeded or not.

NOTE: New proto version, so a distclean is needed.

Fixes #8856

Note: See TracTickets for help on using tickets.