[mythtv] Broken DVB for consecutive programs

Fri Oct 7 12:24:09 UTC 2005

Hi,
   I've just started noticing some DVB tuning broken-ness this week.   
I'm at rev 7394 (although I also saw this with revisions from earlier  
in the week - I didn't notice it last week).  Occasionally programs  
are not being recorded.  They schedule fine, but the recording never  
appears in the list of recorded programs, nor is a .mpg file ever  
generated.  There was a recent commit that stopped programs from  
appearing there if no data coming in from the tuner... so I suspect  
that no data is coming in from the tuner.

   The problem only seems to occur with the later of a series of  
consecutive recordings, even when the later recording is on a  
different tuner.  In the log below there were two recordings from  
6:00pm - 6:30pm and then one missed recording from 6:30pm-7:00pm.   
There was no other program that started recording at 6:30.  The  
program that was missed was:

2005-10-07 18:28:02.613 Started recording World News Australia:  
channel 1003 on cardid 2, sourceid 1

I have three tuners.  My reading of this log is that tuners 0 and 2  
were in use from 6-6:30, tuner 1 was used from 6:30 - 7:00.

Be well,

Will       :-}

2005-10-07 18:25:56.315 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:25:56.316 DVB#2 Rec: PID 512 _continuity_count 7 cc 12
2005-10-07 18:26:11.991 DVB#2 Rec: PID 512 _continuity_count 1 cc 2
2005-10-07 18:27:30.285 TVRec(2): SetFlags(AskAllowRecording,) ->  
RunMainLoop,AskAllowRecording,RingBufferReset,
2005-10-07 18:28:02.426 TVRec(2): ClearFlags(AskAllowRecording,) ->  
RunMainLoop,RingBufferReset,
2005-10-07 18:28:02.434 TVRec(2) Error: HandleStateChange(): Null  
transition None to None
2005-10-07 18:28:02.435 TVRec(2): ClearFlags 
(FrontendReady,CancelNextRecording,) -> RunMainLoop,RingBufferReset,
2005-10-07 18:28:02.436 TVRec(2): SetFlags(AskAllowRecording,) ->  
RunMainLoop,AskAllowRecording,RingBufferReset,
2005-10-07 18:28:02.437 TVRec(2): ClearFlags(CancelNextRecording,) ->  
RunMainLoop,AskAllowRecording,RingBufferReset,
2005-10-07 18:28:02.437 TVRec(2): Changing from None to RecordingOnly
2005-10-07 18:28:02.438 TVRec(2): ClearFlags 
(FrontendReady,CancelNextRecording,) ->  
RunMainLoop,AskAllowRecording,RingBufferReset,
2005-10-07 18:28:02.438 TVRec(2): SetFlags(AskAllowRecording,) ->  
RunMainLoop,AskAllowRecording,RingBufferReset,
2005-10-07 18:28:02.439 TVRec(2): Request: Program(yes) channel()  
input() flags(Recording,)
2005-10-07 18:28:02.439 TVRec(2): ClearFlags 
(WaitingForSIParser,SIParserRunning,) ->  
RunMainLoop,AskAllowRecording,RingBufferReset,
2005-10-07 18:28:02.440 TVRec(2): ClearFlags(WaitingForSignal,) ->  
RunMainLoop,AskAllowRecording,RingBufferReset,
2005-10-07 18:28:02.440 TVRec(2): ClearFlags(PENDINGACTIONS,) ->  
RunMainLoop,AskAllowRecording,RingBufferReset,
2005-10-07 18:28:02.467 DVB#1 Opening DVB channel
2005-10-07 18:28:02.467 DVB#1 SetChannelByString(3)
2005-10-07 18:28:02.481 DVB#1 Frequency: 571500000 BW: 7MHz HP: 2/3  
LP: NoneC: Auto TM: 8K H: None GI: 1/8
2005-10-07 18:28:02.486 DVB#1 Old Params: freq(177500000) type(OFDM)
2005-10-07 18:28:02.486 DVB#1 New Params: freq(571500000) type(OFDM)
2005-10-07 18:28:02.513 dvbchannel.cpp:wait_for_backend: Status:
2005-10-07 18:28:02.514 DVB#1 DVBChannel::Tune: Frequency tuning  
successful.
2005-10-07 18:28:02.514 DVB#1 Tuned to frequency for channel 3.
2005-10-07 18:28:02.517 TVRec(2): Starting Signal Monitor
2005-10-07 18:28:02.520 TVRec(2): SetupSignalMonitor()
2005-10-07 18:28:02.520 DVB#1 Opening DVB channel
2005-10-07 18:28:02.546 SM(1)::AddFlags: Seen() Match() Wait 
(Sig,SNR,BER,UB,)
2005-10-07 18:28:02.546 DVBSM(1)::constructor(): initial flags 0x7400000
2005-10-07 18:28:02.547 TVRec(2): Signal monitor successfully created
2005-10-07 18:28:02.547 TVRec(2): Setting up table monitoring.
2005-10-07 18:28:02.548 TVRec(2): MPEG program number: 769
2005-10-07 18:28:02.550 DTVSM(1)::SetProgramNumber(769):
2005-10-07 18:28:02.550 SM(1)::RemoveFlags: Seen(PMT,) Match(PMT,)  
Wait()
2005-10-07 18:28:02.551 SM(1)::AddFlags: Seen() Match() Wait(PMT,)
2005-10-07 18:28:02.551 SM(1)::AddFlags: Seen() Match() Wait(PAT,PMT,)
2005-10-07 18:28:02.551 TVRec(2): Successfully set up MPEG table  
monitoring.
2005-10-07 18:28:02.552 SM(1)::Start: begin
2005-10-07 18:28:02.554 SM(1)::Start: end
2005-10-07 18:28:02.559 TVRec(2): SetFlags(SignalMonitorRunning,) ->  
RunMainLoop,AskAllowRecording,SignalMonitorRunning,RingBufferReset,
2005-10-07 18:28:02.564 TVRec(2): SetFlags(WaitingForSignal,) ->  
RunMainLoop,AskAllowRecording,WaitingForSignal,SignalMonitorRunning,Ring 
BufferReset,
2005-10-07 18:28:02.566 TVRec(2): SetFlags(NeedToStartRecorder,) ->  
RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,Signa 
lMonitorRunning,RingBufferReset,
2005-10-07 18:28:02.580 DTVSM(1)::GetStatusList: WaitForPMT seen(0)  
matching(0)
2005-10-07 18:28:02.613 Started recording World News Australia:  
channel 1003 on cardid 2, sourceid 1
2005-10-07 18:28:02.816 DVBSM(1)::UpdateValues: Signal Locked
2005-10-07 18:28:02.821 DVBSM(1)::UpdateValues: Waiting for table  
monitor to start
2005-10-07 18:28:02.825 DVBSM(1)::UpdateValues: Table monitor started
2005-10-07 18:28:02.833 scheduler: Last message repeated 3 times
2005-10-07 18:28:02.849 scheduler: Started recording
2005-10-07 18:28:02.856 DVBSM(1)::RunTableMonitor(): begin (# of pids 2)
2005-10-07 18:28:02.857 DVBSM(1)::AddPIDFilter(0x0):
2005-10-07 18:28:02.859 DVBSM(1)::AddPIDFilter(0x1ffb):
2005-10-07 18:31:39.063 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:31:39.086 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:31:39.086 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:31:39.087 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:31:39.087 DVB#2 Rec: PID 512 _continuity_count 0 cc 4
2005-10-07 18:31:44.259 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:31:44.260 DVB#2 Rec: PID 512 _continuity_count 4 cc 5
2005-10-07 18:32:06.744 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:32:06.746 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:32:06.746 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:32:06.747 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:32:06.748 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:32:06.748 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:32:06.749 DVB#2 Rec: PID 512 _continuity_count 10 cc 0
2005-10-07 18:32:15.753 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:32:15.753 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:32:15.754 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:32:15.756 DVB#2 Rec: PID 512 _continuity_count 9 cc 12
2005-10-07 18:33:53.709 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:33:53.719 DVB#2 Rec: PID 512 _continuity_count 3 cc 4
2005-10-07 18:34:00.581 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:34:00.581 DVB#2 Rec: PID 512 _continuity_count 10 cc 11
2005-10-07 18:34:01.089 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:34:01.090 DVB#2 Rec: Packet dropped due to  
uncorrectable error.
2005-10-07 18:34:01.091 DVB#2 Rec: PID 512 _continuity_count 9 cc 11
2005-10-07 18:35:00.248 TVRec(3): Switching to overrecord for 450  
more seconds
2005-10-07 18:35:00.249 TVRec(1): Switching to overrecord for 450  
more seconds
2005-10-07 18:35:00.257 TVRec(1): ClearFlags(FinishRecording,) ->  
RunMainLoop,AskAllowRecording,SIParserRunning,RecorderRunning,RingBuffer 
Reset,
2005-10-07 18:35:00.256 TVRec(3): ClearFlags(FinishRecording,) ->  
RunMainLoop,AskAllowRecording,SIParserRunning,RecorderRunning,RingBuffer 
Reset,
2005-10-07 18:35:07.965 DVB#2 Rec: Packet dropped due to  
uncorrectable error.

[snip - cut till the end of the recording period]

2005-10-07 19:00:00.034 TVRec(2): Switching to overrecord for 450  
more seconds
2005-10-07 19:00:00.034 TVRec(2): ClearFlags(FinishRecording,) ->  
RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,Signa 
lMonitorRunning,RingBufferReset,
2005-10-07 19:07:30.032 TVRec(2): ClearFlags(FinishRecording,) ->  
RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,Signa 
lMonitorRunning,RingBufferReset,
2005-10-07 19:07:30.032 TVRec(2): Changing from RecordingOnly to None
2005-10-07 19:07:30.033 TVRec(2): ClearFlags 
(FrontendReady,CancelNextRecording,) ->  
RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,Signa 
lMonitorRunning,RingBufferReset,
2005-10-07 19:07:30.033 TVRec(2): SetFlags(AskAllowRecording,) ->  
RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,Signa 
lMonitorRunning,RingBufferReset,
2005-10-07 19:07:30.033 TVRec(2): Request: Program(no) channel() input 
() flags(CloseRec,KillRingBuffer,)
2005-10-07 19:07:30.034 TVRec(2): ClearFlags 
(WaitingForSIParser,SIParserRunning,) ->  
RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,Signa 
lMonitorRunning,RingBufferReset,
2005-10-07 19:07:30.034 TVRec(2): TeardownSignalMonitor() -- begin
2005-10-07 19:07:30.034 DVBSM(1)::Stop: begin
2005-10-07 19:07:30.035 SM(1)::Stop: begin
2005-10-07 19:07:30.042 SM(1)::Stop: end
2005-10-07 19:07:30.042 DVBSM(1)::RunTableMonitor(): shutdown
2005-10-07 19:07:30.046 DVBSM(1)::RemovePIDFilter(0x0):
2005-10-07 19:07:30.047 DVBSM(1)::RemovePIDFilter(0x1ffb):
2005-10-07 19:07:30.047 DVBSM(1)::RunTableMonitor(): end
2005-10-07 19:07:30.048 DVBSM(1)::Stop: end
2005-10-07 19:07:30.049 DVBSM(1)::Stop: begin
2005-10-07 19:07:30.049 SM(1)::Stop: begin
2005-10-07 19:07:30.049 SM(1)::Stop: end
2005-10-07 19:07:30.050 DVBSM(1)::Stop: end
2005-10-07 19:07:30.050 DVBSM(1)::Stop: begin
2005-10-07 19:07:30.050 SM(1)::Stop: begin
2005-10-07 19:07:30.050 SM(1)::Stop: end
2005-10-07 19:07:30.051 DVBSM(1)::Stop: end
2005-10-07 19:07:30.051 DVBSM(1)::Stop: begin
2005-10-07 19:07:30.051 SM(1)::Stop: begin
2005-10-07 19:07:30.052 SM(1)::Stop: end
2005-10-07 19:07:30.052 DVBSM(1)::Stop: end
2005-10-07 19:07:30.052 SM(1)::Stop: begin
2005-10-07 19:07:30.053 SM(1)::Stop: end
2005-10-07 19:07:30.051 TVRec(2): TeardownSignalMonitor() -- end
2005-10-07 19:07:30.054 TVRec(2): ClearFlags(SignalMonitorRunning,) - 
 >  
RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,RingB 
ufferReset,
2005-10-07 19:07:30.054 TVRec(2): ClearFlags(WaitingForSignal,) ->  
RunMainLoop,AskAllowRecording,NeedToStartRecorder,RingBufferReset,
2005-10-07 19:07:30.058 Reschedule requested for id 0.
2005-10-07 19:07:30.247 Finished recording World News Australia:  
channel 1003
2005-10-07 19:07:30.254 scheduler: Last message repeated 1 times
2005-10-07 19:07:30.261 scheduler: Finished recording
2005-10-07 19:07:30.262 TVRec(2): ClearFlags(PENDINGACTIONS,) ->  
RunMainLoop,AskAllowRecording,RingBufferReset,
2005-10-07 19:07:30.666 Scheduled 133 items in 0.6 = 0.00 match +  
0.61 place
2005-10-07 19:07:30.677 scheduler: Scheduled items