[mythtv-users] House (Chicato OTA Fox) failed to record

Matt Garman matthew.garman at gmail.com
Mon Mar 2 15:58:49 UTC 2009 

Bump...


At least a couple (non-consecutive) times now, "House" has failed to
record.  I'm using a HDHomeRun to capture Chicago-area OTA
broadcasts.  Normally everything "just works", but these missed
recordings are getting annoying.

I don't understand all of the log (see below), but one line looks
particularly suspicious:

2009-02-16 18:59:02.280 Could not find channel 32_1 in TVCT

Searching on similar strings in the archives suggests that I should
re-do the channel scan... but will this permanently fix the problem?
The other thing that's odd is that this problem doesn't surface for
every recording; I think all other Fox recordings work, and House
usually records... randomly it doesn't though.

By the way, I'm running Gentoo: mythtv-0.21_p18314-r1.

Any help is much appreciated!

Thanks,
Matt

Here's the complete mythbackend log for the relevant time:

2009-02-16 18:58:00.737 Reschedule requested for id 0.
2009-02-16 18:58:01.102 Scheduled 25 items in 0.4 = 0.00 match + 0.36 place
2009-02-16 18:58:29.112 TVRec(3): RecordPending on inputid 3
2009-02-16 18:58:29.195 TVRec(3): ASK_RECORDING 3 29 0 0
2009-02-16 18:59:01.141 TVRec(3): StartRecording(House)
2009-02-16 18:59:01.696 TVRec(3): StartedRecording(0x2aaab80a6740) fn(/home/mythtv/1321_20090216185900.mpg)
2009-02-16 18:59:01.706 TVRec(3): ClearFlags(CancelNextRecording,) -> RunMainLoop,RingBufferReady,
2009-02-16 18:59:01.707 TVRec(3): Changing from None to RecordingOnly
2009-02-16 18:59:01.710 TVRec(3): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RingBufferReady,
2009-02-16 18:59:01.711 TVRec(3): Request: Program(yes) channel() input() flags(Recording,)
2009-02-16 18:59:01.713 TVRec(3): HW Tuner: 3->3
2009-02-16 18:59:01.714 TVRec(3): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
2009-02-16 18:59:01.715 TVRec(3): No recorder yet, calling TuningFrequency
2009-02-16 18:59:01.717 HDHRChan(ffffffff/0): device found at address 192.168.1.71
2009-02-16 18:59:01.733 ChannelBase(3): Input #3: 'MPEG2TS' schan(32_1) sourceid(1) ccid(3)
2009-02-16 18:59:01.734 ChannelBase(3): Current Input #3: 'MPEG2TS'
2009-02-16 18:59:01.736 HDHRChan(ffffffff/0): Successfully connected to device
2009-02-16 18:59:01.739 HDHRChan(ffffffff/0): SetChannelByString(32_1)
2009-02-16 18:59:01.746 HDHRChan(ffffffff/0): TuneTo(575000000,8vsb)
2009-02-16 18:59:01.748 TVRec(3): Starting Signal Monitor
2009-02-16 18:59:01.748 TVRec(3): SetupSignalMonitor(1, 0)
2009-02-16 18:59:01.749 HDHRSM(ffffffff/0): ctor
2009-02-16 18:59:01.750 DelAllPID()
2009-02-16 18:59:01.752 Filter: ''
2009-02-16 18:59:01.752 SM(ffffffff/0)::AddFlags: Seen() Match() Wait(Sig,)
2009-02-16 18:59:01.753 TVRec(3): Signal monitor successfully created
2009-02-16 18:59:01.754 TVRec(3): Setting up table monitoring.
2009-02-16 18:59:01.820 Using profile 'Live TV' to record
2009-02-16 18:59:01.821 TVRec(3): ATSC channel: 32_1
2009-02-16 18:59:01.822 DTVSM(ffffffff/0)::SetChannel(32, 1): 
2009-02-16 18:59:01.822 SM(ffffffff/0)::RemoveFlags: Seen(PAT,PMT,VCT,Crypt,) Match(PAT,PMT,VCT,Crypt,) Wait()
2009-02-16 18:59:01.823 SM(ffffffff/0)::AddFlags: Seen() Match() Wait(PAT,VCT,)
2009-02-16 18:59:01.824 SM(ffffffff/0)::AddFlags: Seen() Match() Wait(MGT,)
2009-02-16 18:59:01.825 TVRec(3): Successfully set up ATSC table monitoring.
2009-02-16 18:59:01.826 SM(ffffffff/0)::Start: begin
2009-02-16 18:59:01.831 SM(ffffffff/0)::Start: end
2009-02-16 18:59:01.831 TVRec(3): SetFlags(SignalMonitorRunning,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady,
2009-02-16 18:59:01.832 TVRec(3): ClearFlags(WaitingForSignal,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady,
2009-02-16 18:59:01.833 TVRec(3): SetFlags(WaitingForSignal,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady,
2009-02-16 18:59:01.834 TVRec(3): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady,
2009-02-16 18:59:01.835 TVRec(3): SetFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,RingBufferReady,
2009-02-16 18:59:01.834 HDHRSM(ffffffff/0): RunTableMonitor(): begin (# of pids 2)
2009-02-16 18:59:01.833 HDHRSM(ffffffff/0): UpdateValues() -- Waiting for table monitor to start
2009-02-16 18:59:01.862 AddPID(0x0)
2009-02-16 18:59:01.864 HDHRSM(ffffffff/0): UpdateValues() -- Table monitor started
2009-02-16 18:59:01.865 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 15 min
2009-02-16 18:59:01.867 Filter: '0x0000'
2009-02-16 18:59:01.869 Started recording: House "Unfaithful": channel 1321 on cardid 3, sourceid 1
2009-02-16 18:59:01.872 AddPID(0x1ffb)
2009-02-16 18:59:01.875 Filter: '0x0000 0x1ffb'
2009-02-16 18:59:02.278 SM(ffffffff/0)::AddFlags: Seen(PAT,) Match() Wait()
2009-02-16 18:59:02.279 SM(ffffffff/0)::AddFlags: Seen(VCT,TVCT,) Match() Wait()
2009-02-16 18:59:02.280 Could not find channel 32_1 in TVCT
2009-02-16 18:59:02.280 
VCT Terra: channels(3) tsid(0x3eb) seclength(160)
Channel #0 name(WLS-DT) 7-1 mod(ATSC 8-VSB) cTSID(0x3eb)
 pnum(1) ETM_loc(1) access_ctrl(0) hidden(0) hide_guide(1) service_type(2) source_id(1)
 descriptors length(17) count(1)
  Service Location Descriptor (0xa1) length(15)

Channel #1 name(WLS-SD1) 7-2 mod(ATSC 8-VSB) cTSID(0x3eb)
 pnum(2) ETM_loc(0) access_ctrl(0) hidden(0) hide_guide(1) service_type(2) source_id(2)
 descriptors length(17) count(1)
  Service Location Descriptor (0xa1) length(15)

Channel #2 name(WLS-SD2) 7-3 mod(ATSC 8-VSB) cTSID(0x3eb)
 pnum(3) ETM_loc(0) access_ctrl(0) hidden(0) hide_guide(1) service_type(2) source_id(3)
 descriptors length(17) count(1)
  Service Location Descriptor (0xa1) length(15)


2009-02-16 18:59:02.281 SM(ffffffff/0)::AddFlags: Seen(MGT,) Match() Wait()
2009-02-16 18:59:02.282 SM(ffffffff/0)::AddFlags: Seen() Match(MGT,) Wait()
2009-02-16 18:59:02.562 SM(ffffffff/0)::AddFlags: Seen(PAT,) Match() Wait()
2009-02-16 18:59:02.562 SM(ffffffff/0)::AddFlags: Seen(VCT,TVCT,) Match() Wait()
2009-02-16 18:59:02.563 DTVSM(ffffffff/0)::SetVCT(): tvct->ProgramNumber(idx 0): prog num 3
2009-02-16 18:59:02.564 DTVSM(ffffffff/0)::SetProgramNumber(3): 
2009-02-16 18:59:02.564 SM(ffffffff/0)::RemoveFlags: Seen(PMT,Crypt,) Match(PMT,Crypt,) Wait()
2009-02-16 18:59:02.565 SM(ffffffff/0)::AddFlags: Seen(PAT,) Match() Wait()
2009-02-16 18:59:02.566 SM(ffffffff/0)::AddFlags: Seen() Match(PAT,) Wait()
2009-02-16 18:59:02.566 CreatePATSingleProgram()
2009-02-16 18:59:02.567 PAT in input stream
2009-02-16 18:59:02.568 Program Association Table
 PSIP tableID(0x0) length(21) extension(0x3eb)
      version(0) current(1) section(0) last_section(0)
         tsid: 1003
 programCount: 3
  program number     1 has PID 0x  30   data  0x 0 0x 1 0xe0 0x30
  program number     2 has PID 0x  40   data  0x 0 0x 2 0xe0 0x40
  program number     3 has PID 0x  50   data  0x 0 0x 3 0xe0 0x50

2009-02-16 18:59:02.568 desired_program(3) pid(0x50)
2009-02-16 18:59:02.569 pmt_pid(0x50)
2009-02-16 18:59:02.569 PAT for output stream
2009-02-16 18:59:02.570 Program Association Table
 PSIP tableID(0x0) length(13) extension(0x3eb)
      version(0) current(1) section(0) last_section(0)
         tsid: 1003
 programCount: 1
  program number     1 has PID 0x  50   data  0x 0 0x 1 0xe0 0x50

2009-02-16 18:59:02.571 SM(ffffffff/0)::AddFlags: Seen() Match() Wait(PMT,)
2009-02-16 18:59:02.571 SM(ffffffff/0)::AddFlags: Seen() Match(VCT,TVCT,) Wait()
2009-02-16 18:59:02.572 AddPID(0x50)
2009-02-16 18:59:02.574 Filter: '0x0000 0x0050 0x1ffb'
2009-02-16 18:59:02.896 DTVSM(ffffffff/0): Time Offset: 33.1035
    [ above repeats 720 times with slightly different numbers ]
2009-02-16 19:09:52.573 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 15 min
2009-02-16 19:09:52.662 DTVSM(ffffffff/0): Time Offset: 32.9575
    [ above repeats 215 times with slightly different numbers ]
2009-02-16 19:13:06.985 UPnpMedia: BuildMediaMap VIDEO scan starting in :/media/video/myth_video_root:
2009-02-16 19:13:07.257 DTVSM(ffffffff/0): Time Offset: 32.8502
    [ above repeats 15 times with slightly different numbers ]
2009-02-16 19:13:21.604 UPnpMedia: BuildMediaMap Done. Found 1545 objects
2009-02-16 19:13:21.672 DTVSM(ffffffff/0): Time Offset: 32.9597
    [ above repeats 767 times with slightly different numbers ]
2009-02-16 19:24:52.659 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 15 min
2009-02-16 19:24:53.381 DTVSM(ffffffff/0): Time Offset: 32.9712
    [ above repeats 998 times with slightly different numbers ]
2009-02-16 19:39:52.713 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 15 min
2009-02-16 19:39:53.516 DTVSM(ffffffff/0): Time Offset: 32.8535
    [ above repeats 236 times with slightly different numbers ]
2009-02-16 19:43:26.806 UPnpMedia: BuildMediaMap VIDEO scan starting in :/media/video/myth_video_root:
2009-02-16 19:43:26.979 DTVSM(ffffffff/0): Time Offset: 32.8212
    [ above repeats 15 times with slightly different numbers ]
2009-02-16 19:43:41.084 UPnpMedia: BuildMediaMap Done. Found 1545 objects
2009-02-16 19:43:41.359 DTVSM(ffffffff/0): Time Offset: 32.8845
    [ above repeats 745 times with slightly different numbers ]
2009-02-16 19:54:52.770 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 15 min
2009-02-16 19:54:53.634 DTVSM(ffffffff/0): Time Offset: 32.8016
    [ above repeats 407 times with slightly different numbers ]
2009-02-16 20:01:00.141 TVRec(3): ClearFlags(FinishRecording,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,RingBufferReady,
2009-02-16 20:01:00.143 TVRec(3): Changing from RecordingOnly to None
2009-02-16 20:01:00.146 TVRec(3): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,RingBufferReady,
2009-02-16 20:01:00.146 TVRec(3): Request: Program(no) channel() input() flags(CloseRec,KillRingBuffer,)
2009-02-16 20:01:00.147 TVRec(3): TeardownSignalMonitor() -- begin
2009-02-16 20:01:00.148 HDHRSM(ffffffff/0): Stop() -- begin
2009-02-16 20:01:00.148 SM(ffffffff/0)::Stop: begin
2009-02-16 20:01:00.175 SM(ffffffff/0)::Stop: end
2009-02-16 20:01:01.118 HDHRSM(ffffffff/0): RunTableMonitor(): -- shutdown
2009-02-16 20:01:01.120 HDHRSM(ffffffff/0): RunTableMonitor(): -- end
2009-02-16 20:01:01.120 HDHRSM(ffffffff/0): Stop() -- end
2009-02-16 20:01:01.121 HDHRSM(ffffffff/0): Stop() -- begin
2009-02-16 20:01:01.122 SM(ffffffff/0)::Stop: begin
2009-02-16 20:01:01.123 SM(ffffffff/0)::Stop: end
2009-02-16 20:01:01.123 HDHRSM(ffffffff/0): Stop() -- end
2009-02-16 20:01:01.124 TVRec(3): TeardownSignalMonitor() -- end
2009-02-16 20:01:01.124 TVRec(3): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,RingBufferReady,
2009-02-16 20:01:01.125 TVRec(3): ClearFlags(WaitingForSignal,) -> RunMainLoop,NeedToStartRecorder,RingBufferReady,
2009-02-16 20:01:01.124 HDHRSM(ffffffff/0): dtor
2009-02-16 20:01:01.129 HDHRSM(ffffffff/0): Stop() -- begin
2009-02-16 20:01:01.130 SM(ffffffff/0)::Stop: begin
2009-02-16 20:01:01.130 SM(ffffffff/0)::Stop: end
2009-02-16 20:01:01.131 HDHRSM(ffffffff/0): Stop() -- end
2009-02-16 20:01:01.131 SM(ffffffff/0)::Stop: begin
2009-02-16 20:01:01.132 SM(ffffffff/0)::Stop: end
2009-02-16 20:01:01.128 TVRec(3): FinishedRecording(House) in recgroup: Default
2009-02-16 20:01:01.137 Finished recording House "Unfaithful": channel 1321
2009-02-16 20:01:01.151 TVRec(3): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
2009-02-16 20:01:01.148 Reschedule requested for id 0.
2009-02-16 20:01:01.241 Scheduled 24 items in 0.1 = 0.01 match + 0.09 place

More information about the mythtv-users mailing list