[mythtv-commits] Re: Ticket #288: Myth DVB-T sometimes fails to get lock when starting recording on second card

MythTV mythtv at cvs.mythtv.org
Wed Sep 7 02:04:24 UTC 2005


#288: Myth DVB-T sometimes fails to get lock when starting recording on second
card
----------------------------------+-----------------------------------------
 Reporter:  mythtv at opencraft.org  |        Owner:  danielk 
     Type:  defect                |       Status:  assigned
 Priority:  minor                 |    Milestone:  0.19    
Component:  mythtv                |      Version:  head    
 Severity:  medium                |   Resolution:          
       Cc:                        |  
----------------------------------+-----------------------------------------
Changes (by danielk):

  * milestone:  => 0.19
  * status:  new => assigned
  * owner:  ijr => danielk

Old description:

> 50% of the time when starting a second recording just after a first
> recording has started successfully, it times out waiting for a lock. This
> has happenned since around SVN 7050.
>
> The cards are both identical Nova-T cards. The failure is not channel
> specific.
>
> The following log was taken usnig latest SVN. It starts just after the
> first card starts recording.
>
> I had a problem with the BER being out of range stopping recording on
> card 0 which Daniel kindly fixed last week.
>
> David.
>
> 2005-09-02 19:17:55.614 Recorder to started
> 2005-09-02 19:17:55.615 DVB#0 Rec: Adding pid 770 (0x302)
> 2005-09-02 19:17:55.618 DVB#0 Rec: Adding pid 772 (0x304)
> 2005-09-02 19:17:55.619 DVB#0 Rec: Adding pid 769 (0x301)
> 2005-09-02 19:17:55.643 DVB#0 Data read from DMX - This is for debugging
> with transform.c
> 2005-09-02 19:17:56.916 DVB#0 Rec: Found first keyframe
> 2005-09-02 19:17:56.919 DVB#0 Rec: Found Payload Start for PID 769
> 2005-09-02 19:17:56.941 DVB#0 Rec: Found Payload Start for PID 772
> 2005-09-02 19:17:56.943 DVB#0 Rec: Found Payload Start for PID 770
> 2005-09-02 19:17:59.645 Reschedule requested for id 1382.
> 2005-09-02 19:18:01.953 Scheduled 37 items in 2.3 = 0.30 match + 2.00
> place
> 2005-09-02 19:18:01.961 DVB#1 Trying to tune to channel 13.
> 2005-09-02 19:18:02.057 Started recording "Everybody Loves Raymond" on
> channel: 1010 on cardid: 2, sourceid 1
> 2005-09-02 19:18:02.058 DVB#1 Frequency: 219500000 BW: 7MHz HP: 3/4 LP:
> 1/2C: QAM-64 TM: 8K H: None GI: 1/16
> 2005-09-02 19:18:02.061 DVBEvents: Flushing Event Status()
> frequency(226500000 Hz)
> 2005-09-02 19:18:02.062 DVBEvents: Flushing Event
> Status(Signal,Carrier,FEC Stable,Sync,Lock,) frequency(226500000 Hz)
> 2005-09-02 19:18:02.063 DVB#1 Waiting for event
> 2005-09-02 19:18:02.196 DVB#1 Event Status() frequency(219500000 Hz)
> 2005-09-02 19:18:02.199 DVB#1 Waiting for frontend event after tune.
> 2005-09-02 19:18:02.200 DVB#1 Frequency tuning successful.
> 2005-09-02 19:18:02.201 DVB#1 Tuned to frequency for channel 13.
> 2005-09-02 19:18:02.241 Changing from None to RecordingOnly
> 2005-09-02 19:18:02.256 Using profile 'Default' to record
> 2005-09-02 19:18:02.264 SetRecording(0x0x8229c68)
> 2005-09-02 19:18:02.270 Prog title: Everybody Loves Raymond
> 2005-09-02 19:18:02.277 SetSignalMonitoringRate(50, 0)
> 2005-09-02 19:18:02.284 SetupSignalMonitor()
> 2005-09-02 19:18:02.289 DVB#1 Opening DVB channel
> 2005-09-02 19:18:02.295 SetupSignalMonitor() -- DVB hack begin
> 2005-09-02 19:18:02.299 SetupSignalMonitor() -- DVB hack end
> 2005-09-02 19:18:02.379 SM:    AddFlags: Seen() Match()
> Wait(Sig,SNR,BER,UB,)
> 2005-09-02 19:18:02.381 DVBSM(1)::constructor(): initial flags 0x7400000
> 2005-09-02 19:18:02.382 signal monitor successfully created
> 2005-09-02 19:18:02.383 Setting up table monitoring.
> 2005-09-02 19:18:02.384 Not ATSC channel: major(-1) minor(-1).
> 2005-09-02 19:18:02.385 mpeg program number: 1586
> 2005-09-02 19:18:02.386 DTVSM(1)::SetProgramNumber(1586):
> 2005-09-02 19:18:02.387 SM: RemoveFlags: Seen(PMT,) Match(PMT,) Wait()
> 2005-09-02 19:18:02.388 SM:    AddFlags: Seen() Match() Wait(PMT,)
> 2005-09-02 19:18:02.389 SM:    AddFlags: Seen() Match() Wait(PAT,PMT,)
> 2005-09-02 19:18:02.391 Successfully set up MPEG table monitoring.
> 2005-09-02 19:18:02.392 SM(1)::Start: begin
> 2005-09-02 19:18:02.394 SM(1)::Start: end
> 2005-09-02 19:18:02.396 DTVSM(1)::GetStatusList: WaitForPMT seen(0)
> matching(0)
> 2005-09-02 19:18:05.411 SigMon Flags are: Seen() Match()
> Wait(PAT,PMT,Sig,SNR,BER,UB,)
> 2005-09-02 19:18:05.413 SML[0]: Name(slock) Val(0) thr(>=1) range(0,1)
> timeout(3000 ms) is set. Is NOT good.
> 2005-09-02 19:18:05.414 SML[1]: Name(signal) Val(32767) thr(>=-32768)
> range(-32768,32767) timeout(3000 ms) is set. Is good.
> 2005-09-02 19:18:05.416 SML[2]: Name(seen_pat) Val(0) thr(>=1) range(0,1)
> timeout(0 ms) is set. Is NOT good.
> 2005-09-02 19:18:05.416 SML[3]: Name(matching_pat) Val(0) thr(>=1)
> range(0,1) timeout(0 ms) is set. Is NOT good.
> 2005-09-02 19:18:05.417 SML[4]: Name(seen_pmt) Val(0) thr(>=1) range(0,1)
> timeout(0 ms) is set. Is NOT good.
> 2005-09-02 19:18:05.419 SML[5]: Name(matching_pmt) Val(0) thr(>=1)
> range(0,1) timeout(0 ms) is set. Is NOT good.
> 2005-09-02 19:18:05.419 SML[6]: Name(snr) Val(32767) thr(>=-32768)
> range(-32768,32767) timeout(0 ms) is set. Is good.
> 2005-09-02 19:18:05.421 SML[7]: Name(ber) Val(65535) thr(<=65535)
> range(0,65535) timeout(0 ms) is set. Is good.
> 2005-09-02 19:18:05.421 SML[8]: Name(ucb) Val(0) thr(<=65535)
> range(0,65535) timeout(0 ms) is set. Is good.
> 2005-09-02 19:18:05.422 TVRec: Timed out waiting for lock -- aborting
> recording
> 2005-09-02 19:18:05.424 SetSignalMonitoringRate(0, 0)
> 2005-09-02 19:18:05.424 TeardownSignalMonitor() -- begin
> 2005-09-02 19:18:05.425 DVBSM(1)::Stop: begin
> 2005-09-02 19:18:05.426 SM(1)::Stop: begin
> 2005-09-02 19:18:05.489 SM(1)::Stop: end
> 2005-09-02 19:18:05.491 DVBSM(1)::Stop: end
> 2005-09-02 19:18:05.493 DVBSM(1)::Stop: begin
> 2005-09-02 19:18:05.495 SM(1)::Stop: begin
> 2005-09-02 19:18:05.496 SM(1)::Stop: end
> 2005-09-02 19:18:05.497 DVBSM(1)::Stop: end
> 2005-09-02 19:18:05.498 SM(1)::Stop: begin
> 2005-09-02 19:18:05.500 SM(1)::Stop: end
> 2005-09-02 19:18:05.500 TeardownSignalMonitor() -- end
> 2005-09-02 19:18:05.502 TVRec: StartRecorderPost(): aborting recording
> 2005-09-02 19:18:05.503 StartRecorderPost()::closeRecorder -- begin
> 2005-09-02 19:18:05.506 StartRecorderPost()::closeRecorder -- end

New description:

 50% of the time when starting a second recording just after a first
 recording has started successfully, it times out waiting for a lock. This
 has happenned since around SVN 7050.

 The cards are both identical Nova-T cards. The failure is not channel
 specific.

 The following log was taken usnig latest SVN. It starts just after the
 first card starts recording.

 I had a problem with the BER being out of range stopping recording on card
 0 which Daniel kindly fixed last week.

 David.
 {{{
 2005-09-02 19:17:55.614 Recorder to started
 2005-09-02 19:17:55.615 DVB#0 Rec: Adding pid 770 (0x302)
 2005-09-02 19:17:55.618 DVB#0 Rec: Adding pid 772 (0x304)
 2005-09-02 19:17:55.619 DVB#0 Rec: Adding pid 769 (0x301)
 2005-09-02 19:17:55.643 DVB#0 Data read from DMX - This is for debugging
 with transform.c
 2005-09-02 19:17:56.916 DVB#0 Rec: Found first keyframe
 2005-09-02 19:17:56.919 DVB#0 Rec: Found Payload Start for PID 769
 2005-09-02 19:17:56.941 DVB#0 Rec: Found Payload Start for PID 772
 2005-09-02 19:17:56.943 DVB#0 Rec: Found Payload Start for PID 770
 2005-09-02 19:17:59.645 Reschedule requested for id 1382.
 2005-09-02 19:18:01.953 Scheduled 37 items in 2.3 = 0.30 match + 2.00
 place
 2005-09-02 19:18:01.961 DVB#1 Trying to tune to channel 13.
 2005-09-02 19:18:02.057 Started recording "Everybody Loves Raymond" on
 channel: 1010 on cardid: 2, sourceid 1
 2005-09-02 19:18:02.058 DVB#1 Frequency: 219500000 BW: 7MHz HP: 3/4 LP:
 1/2C: QAM-64 TM: 8K H: None GI: 1/16
 2005-09-02 19:18:02.061 DVBEvents: Flushing Event Status()
 frequency(226500000 Hz)
 2005-09-02 19:18:02.062 DVBEvents: Flushing Event
 Status(Signal,Carrier,FEC Stable,Sync,Lock,) frequency(226500000 Hz)
 2005-09-02 19:18:02.063 DVB#1 Waiting for event
 2005-09-02 19:18:02.196 DVB#1 Event Status() frequency(219500000 Hz)
 2005-09-02 19:18:02.199 DVB#1 Waiting for frontend event after tune.
 2005-09-02 19:18:02.200 DVB#1 Frequency tuning successful.
 2005-09-02 19:18:02.201 DVB#1 Tuned to frequency for channel 13.
 2005-09-02 19:18:02.241 Changing from None to RecordingOnly
 2005-09-02 19:18:02.256 Using profile 'Default' to record
 2005-09-02 19:18:02.264 SetRecording(0x0x8229c68)
 2005-09-02 19:18:02.270 Prog title: Everybody Loves Raymond
 2005-09-02 19:18:02.277 SetSignalMonitoringRate(50, 0)
 2005-09-02 19:18:02.284 SetupSignalMonitor()
 2005-09-02 19:18:02.289 DVB#1 Opening DVB channel
 2005-09-02 19:18:02.295 SetupSignalMonitor() -- DVB hack begin
 2005-09-02 19:18:02.299 SetupSignalMonitor() -- DVB hack end
 2005-09-02 19:18:02.379 SM:    AddFlags: Seen() Match()
 Wait(Sig,SNR,BER,UB,)
 2005-09-02 19:18:02.381 DVBSM(1)::constructor(): initial flags 0x7400000
 2005-09-02 19:18:02.382 signal monitor successfully created
 2005-09-02 19:18:02.383 Setting up table monitoring.
 2005-09-02 19:18:02.384 Not ATSC channel: major(-1) minor(-1).
 2005-09-02 19:18:02.385 mpeg program number: 1586
 2005-09-02 19:18:02.386 DTVSM(1)::SetProgramNumber(1586):
 2005-09-02 19:18:02.387 SM: RemoveFlags: Seen(PMT,) Match(PMT,) Wait()
 2005-09-02 19:18:02.388 SM:    AddFlags: Seen() Match() Wait(PMT,)
 2005-09-02 19:18:02.389 SM:    AddFlags: Seen() Match() Wait(PAT,PMT,)
 2005-09-02 19:18:02.391 Successfully set up MPEG table monitoring.
 2005-09-02 19:18:02.392 SM(1)::Start: begin
 2005-09-02 19:18:02.394 SM(1)::Start: end
 2005-09-02 19:18:02.396 DTVSM(1)::GetStatusList: WaitForPMT seen(0)
 matching(0)
 2005-09-02 19:18:05.411 SigMon Flags are: Seen() Match()
 Wait(PAT,PMT,Sig,SNR,BER,UB,)
 2005-09-02 19:18:05.413 SML[0]: Name(slock) Val(0) thr(>=1) range(0,1)
 timeout(3000 ms) is set. Is NOT good.
 2005-09-02 19:18:05.414 SML[1]: Name(signal) Val(32767) thr(>=-32768)
 range(-32768,32767) timeout(3000 ms) is set. Is good.
 2005-09-02 19:18:05.416 SML[2]: Name(seen_pat) Val(0) thr(>=1) range(0,1)
 timeout(0 ms) is set. Is NOT good.
 2005-09-02 19:18:05.416 SML[3]: Name(matching_pat) Val(0) thr(>=1)
 range(0,1) timeout(0 ms) is set. Is NOT good.
 2005-09-02 19:18:05.417 SML[4]: Name(seen_pmt) Val(0) thr(>=1) range(0,1)
 timeout(0 ms) is set. Is NOT good.
 2005-09-02 19:18:05.419 SML[5]: Name(matching_pmt) Val(0) thr(>=1)
 range(0,1) timeout(0 ms) is set. Is NOT good.
 2005-09-02 19:18:05.419 SML[6]: Name(snr) Val(32767) thr(>=-32768)
 range(-32768,32767) timeout(0 ms) is set. Is good.
 2005-09-02 19:18:05.421 SML[7]: Name(ber) Val(65535) thr(<=65535)
 range(0,65535) timeout(0 ms) is set. Is good.
 2005-09-02 19:18:05.421 SML[8]: Name(ucb) Val(0) thr(<=65535)
 range(0,65535) timeout(0 ms) is set. Is good.
 2005-09-02 19:18:05.422 TVRec: Timed out waiting for lock -- aborting
 recording
 2005-09-02 19:18:05.424 SetSignalMonitoringRate(0, 0)
 2005-09-02 19:18:05.424 TeardownSignalMonitor() -- begin
 2005-09-02 19:18:05.425 DVBSM(1)::Stop: begin
 2005-09-02 19:18:05.426 SM(1)::Stop: begin
 2005-09-02 19:18:05.489 SM(1)::Stop: end
 2005-09-02 19:18:05.491 DVBSM(1)::Stop: end
 2005-09-02 19:18:05.493 DVBSM(1)::Stop: begin
 2005-09-02 19:18:05.495 SM(1)::Stop: begin
 2005-09-02 19:18:05.496 SM(1)::Stop: end
 2005-09-02 19:18:05.497 DVBSM(1)::Stop: end
 2005-09-02 19:18:05.498 SM(1)::Stop: begin
 2005-09-02 19:18:05.500 SM(1)::Stop: end
 2005-09-02 19:18:05.500 TeardownSignalMonitor() -- end
 2005-09-02 19:18:05.502 TVRec: StartRecorderPost(): aborting recording
 2005-09-02 19:18:05.503 StartRecorderPost()::closeRecorder -- begin
 2005-09-02 19:18:05.506 StartRecorderPost()::closeRecorder -- end
 }}}

Comment:

 I don't know what is happening here.

 If anyone has more info please attach it to this ticket.

-- 
Ticket URL: <http://cvs.mythtv.org/trac/ticket/288>
MythTV <http://www.mythtv.org/>
MythTV


More information about the mythtv-commits mailing list