Opened 13 years ago

Closed 13 years ago

#3031 closed patch (fixed)

Recording will not commence until a PMT is set.

Reported by: jppoet Owned by: danielk
Priority: major Milestone: 0.21
Component: mythtv Version: head
Severity: medium Keywords: PMT issue
Cc: mythtrac@…, cymenvig@…, developstuff@…, jakep_82@… Ticket locked: no

Description

Running svn Revision: 12662, but have not seen any changesets since then that says they fix this.

For the last week, about 1/5 of my recordings via any of HD-3000 cards is failing with:

DVBRec(1) Warning: Recording will not commence until a PMT is set.

I have two backends, each with two HD-3000 cards, and this has happened on both of them.

Leading up to the problem:

2007-01-30 18:59:00.672 TVRec(2): SetFlags(AskAllowRecording,) -> RunMainLoop,CancelNextRecording,AskAllowRecording,
2007-01-30 18:59:00.686 TVRec(2): ClearFlags(AskAllowRecording,) -> RunMainLoop,CancelNextRecording,
2007-01-30 18:59:34.521 TVRec(2): StartRecording(Gilmore Girls)
2007-01-30 18:59:34.524 TVRec(2): ClearFlags(AskAllowRecording,) -> RunMainLoop,CancelNextRecording,
2007-01-30 18:59:34.846 TVRec(2): StartedRecording(0x726180) fn(/mythtv/cobalt/1029_20070130190000.mpg)
2007-01-30 18:59:34.865 TVRec(2): ClearFlags(CancelNextRecording,) -> RunMainLoop,
2007-01-30 18:59:34.866 TVRec(2): Changing from None to RecordingOnly
2007-01-30 18:59:34.868 TVRec(2): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,
2007-01-30 18:59:34.868 TVRec(2): SetFlags(AskAllowRecording,) -> RunMainLoop,AskAllowRecording,
2007-01-30 18:59:34.868 TVRec(2): Request: Program(yes) channel() input() flags(Recording,)
2007-01-30 18:59:34.881 TVRec(2): HW Tuner: 2->2
2007-01-30 18:59:34.881 TVRec(2): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,AskAllowRecording,
2007-01-30 18:59:34.902 DVBChan(0): Opening DVB channel
2007-01-30 18:59:34.902 DVBChan(0): Using DVB card 0, with frontend 'Oren OR51132 VSB/QAM Frontend'.
2007-01-30 18:59:34.905 ChannelBase(2): Input #2: 'DVBInput' schan(4-1) sourceid(1) ccid(2)
2007-01-30 18:59:34.912 ChannelBase(2): Current Input #2: 'DVBInput'
2007-01-30 18:59:34.913 DVBChan(0): SetChannelByString(19-1): 
2007-01-30 18:59:34.915 DVBChan(0): 563000000 8vsb a auto auto a a auto a v
2007-01-30 18:59:34.921 DVBChan(0): Old Params: 545000000 8vsb a auto auto a a auto a v
			DVBChan(0): New Params: 563000000 8vsb a auto auto a a auto a v
2007-01-30 18:59:34.921 DVBChan(0): Tune(): Tuning to 563000000Hz
2007-01-30 18:59:34.921 dvbchannel.cpp:wait_for_backend: Status: 
2007-01-30 18:59:34.923 DVBChan(0): Tune(): Frequency tuning successful.
2007-01-30 18:59:34.923 DVBChan(0): SetChannelByString(19-1): Tuned to frequency.
2007-01-30 18:59:34.923 TVRec(2): Starting Signal Monitor
2007-01-30 18:59:34.924 TVRec(2): SetupSignalMonitor(1, 0)
2007-01-30 18:59:34.924 DVBChan(0): Opening DVB channel
2007-01-30 18:59:35.344 SM(0)::AddFlags: Seen() Match() Wait(Sig,)
2007-01-30 18:59:35.352 DVBSM(0)::constructor(): initial flags 0x40000000
2007-01-30 18:59:35.352 TVRec(2): Signal monitor successfully created
2007-01-30 18:59:35.352 TVRec(2): Setting up table monitoring.
2007-01-30 18:59:35.410 Using profile 'Live TV' to record
2007-01-30 18:59:35.411 TVRec(2): ATSC channel: 19_1
2007-01-30 18:59:35.440 DTVSM(0)::SetChannel(19, 1): 
2007-01-30 18:59:35.440 SM(0)::RemoveFlags: Seen(PAT,PMT,VCT,Crypt,) Match(PAT,PMT,VCT,Crypt,) Wait()
2007-01-30 18:59:35.440 SM(0)::AddFlags: Seen() Match() Wait(PAT,VCT,)
2007-01-30 18:59:35.442 SM(0)::AddFlags: Seen() Match() Wait(MGT,)
2007-01-30 18:59:35.442 TVRec(2): Successfully set up ATSC table monitoring.
2007-01-30 18:59:35.443 SM(0)::Start: begin
2007-01-30 18:59:35.447 SM(0)::Start: end
2007-01-30 18:59:35.448 TVRec(2): SetFlags(SignalMonitorRunning,) -> RunMainLoop,AskAllowRecording,SignalMonitorRunning,
2007-01-30 18:59:35.448 TVRec(2): ClearFlags(WaitingForSignal,) -> RunMainLoop,AskAllowRecording,SignalMonitorRunning,
2007-01-30 18:59:35.448 TVRec(2): SetFlags(WaitingForSignal,) -> RunMainLoop,AskAllowRecording,WaitingForSignal,SignalMonitorRunning,
2007-01-30 18:59:35.449 TVRec(2): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,AskAllowRecording,WaitingForSignal,SignalMonitorRunning,
2007-01-30 18:59:35.449 TVRec(2): SetFlags(NeedToStartRecorder,) -> RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,
2007-01-30 18:59:35.804 DVBSM(0)::UpdateValues: Signal Locked
2007-01-30 18:59:35.808 DVBSM(0)::UpdateValues: Waiting for table monitor to start
2007-01-30 18:59:35.812 DVBSM(0)::UpdateValues: Table monitor started
2007-01-30 18:59:35.808 DVBSM(0)::AddPIDFilter(0x0): 
2007-01-30 18:59:35.821 DVBSM(0)::RemovePIDFilter(0x0): 
2007-01-30 18:59:36.143 DVBSM(0): RunTableMonitorTS(): begin (# of pids 2)
2007-01-30 18:59:36.144 DVBSM(0)::AddPIDFilter(0x0): 
2007-01-30 18:59:36.145 DVBSM(0)::AddPIDFilter(0x1ffb): 
2007-01-30 18:59:36.171 SM(0)::AddFlags: Seen(MGT,) Match() Wait()
2007-01-30 18:59:36.172 SM(0)::AddFlags: Seen() Match(MGT,) Wait()
2007-01-30 18:59:36.185 SM(0)::AddFlags: Seen(VCT,TVCT,) Match() Wait()
2007-01-30 18:59:36.195 DTVSM(0)::SetVCT(): tvct->ProgramNumber(idx 0): prog num 3
2007-01-30 18:59:36.196 DTVSM(0)::SetProgramNumber(3): 
2007-01-30 18:59:36.196 SM(0)::RemoveFlags: Seen(PMT,Crypt,) Match(PMT,Crypt,) Wait()
2007-01-30 18:59:36.196 SM(0)::AddFlags: Seen() Match() Wait(PMT,)
2007-01-30 18:59:36.197 SM(0)::AddFlags: Seen() Match(VCT,TVCT,) Wait()
2007-01-30 18:59:36.225 SM(0)::AddFlags: Seen(PAT,) Match() Wait()
2007-01-30 18:59:36.225 SM(0)::AddFlags: Seen() Match(PAT,) Wait()
2007-01-30 18:59:36.225 CreatePATSingleProgram()
2007-01-30 18:59:36.226 PAT in input stream
2007-01-30 18:59:36.226 Program Association Table
 PSIP tableID(0x0) length(21) extension(0x817)
      version(9) current(1) section(0) last_section(0)
         tsid: 2071
 programCount: 3
  program number 3 has PID 0x  30   data  0x 0 0x 3 0xe0 0x30
  program number 19 has PID 0x 130   data  0x 0 0x13 0xe1 0x30
  program number 59 has PID 0x 3b0   data  0x 0 0x3b 0xe3 0xb0

2007-01-30 18:59:36.232 desired_program(3) pid(0x30)
2007-01-30 18:59:36.232 pmt_pid(0x30)
2007-01-30 18:59:36.233 PAT for output stream
2007-01-30 18:59:36.233 Program Association Table
 PSIP tableID(0x0) length(13) extension(0x817)
      version(9) current(1) section(0) last_section(0)
         tsid: 2071
 programCount: 1
  program number 1 has PID 0x  30   data  0x 0 0x 1 0xe0 0x30

2007-01-30 18:59:36.233 DVBSM(0)::AddPIDFilter(0x30): 
2007-01-30 18:59:36.244 SM(0)::AddFlags: Seen(MGT,) Match() Wait()
2007-01-30 18:59:36.245 SM(0)::AddFlags: Seen() Match(MGT,) Wait()
2007-01-30 18:59:36.284 SM(0)::AddFlags: Seen(PMT,) Match() Wait()
2007-01-30 18:59:36.285 SM(0)::AddFlags: Seen() Match(PMT,) Wait()
2007-01-30 18:59:36.290 CreatePMTSingleProgram()
2007-01-30 18:59:36.291 PMT in input stream
2007-01-30 18:59:36.291 Program Map Table ver(9) pid(0x30) pnum(3) len(23)

 Stream #0 pid(0x31) type(video-mpeg2  0x2)
 Stream #1 pid(0x34) type(audio-ac3  0x81)

2007-01-30 18:59:36.291 PMT for output stream
2007-01-30 18:59:36.292 Program Map Table ver(9) pid(0x30) pnum(1) len(23)

 Stream #0 pid(0x31) type(video-mpeg2  0x2)
 Stream #1 pid(0x34) type(audio-ac3  0x81)

2007-01-30 18:59:36.331 TVRec(2): Got good signal
2007-01-30 18:59:36.336 TVRec(2): TeardownSignalMonitor() -- begin
2007-01-30 18:59:36.343 DVBSM(0)::Stop: begin
2007-01-30 18:59:36.348 SM(0)::Stop: begin
2007-01-30 18:59:36.383 SM(0)::Stop: end
2007-01-30 18:59:36.393 DVBSM(0): RunTableMonitorTS(): shutdown
2007-01-30 18:59:36.396 DVBSM(0)::RemovePIDFilter(0x0): 
2007-01-30 18:59:36.396 DVBSM(0)::RemovePIDFilter(0x30): 
2007-01-30 18:59:36.396 DVBSM(0)::RemovePIDFilter(0x1ffb): 
2007-01-30 18:59:36.711 DVBSM(0): RunTableMonitorTS(): end
2007-01-30 18:59:36.712 DVBSM(0)::Stop: end
2007-01-30 18:59:36.716 TVRec(2): TeardownSignalMonitor() -- end
2007-01-30 18:59:36.717 TVRec(2): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,
2007-01-30 18:59:36.717 TVRec(2): ClearFlags(WaitingForSignal,) -> RunMainLoop,AskAllowRecording,NeedToStartRecorder,
2007-01-30 18:59:36.718 TVRec(2): Starting Recorder
2007-01-30 18:59:36.721 Using profile 'Default' to record
2007-01-30 18:59:36.804 RecBase(0): SetRingBuffer(0x2aaaaab340f0) '/mythtv/cobalt/1029_20070130190000.mpg'
2007-01-30 18:59:36.806 RecBase(0): SetRecording(0x726180) title(Gilmore Girls)
2007-01-30 18:59:36.822 DVBRec(0): Card opened successfully fd(15)
2007-01-30 18:59:36.847 TVRec(2): SetFlags(RecorderRunning,RingBufferReady,) -> RunMainLoop,AskAllowRecording,NeedToStartRecorder,RecorderRunning,RingBufferReady,
2007-01-30 18:59:36.853 TVRec(2): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,AskAllowRecording,RecorderRunning,RingBufferReady,
2007-01-30 18:59:36.859 DevRdB(0): buffer size 14100 KB
2007-01-30 18:59:36.873 DVBRec(0) Warning: Recording will not commence until a PMT is set.
2007-01-30 18:59:36.887 DVBRec(0) Warning: Recording will not commence until a PMT is set.
2007-01-30 18:59:36.899 DVBRec(0) Warning: Recording will not commence until a PMT is set.

If I restart the backend, then the program records just fine.

Please let me know if any more information is needed.

John

Attachments (14)

3031-dbg-1.patch (4.0 KB) - added by danielk 13 years ago.
Debugging patch
3031-v1.patch (1.0 KB) - added by danielk 13 years ago.
Possible fix
3031-v2.patch (1.2 KB) - added by danielk 13 years ago.
Possible fix (moved the code to catch a similar failure when initially tuning to an MPEG station and switching to a DVB or ATSC channel).
mythbackend-070210.log (17.1 KB) - added by danielk 13 years ago.
Latest log from John P. Poet
3031_hack.diff (607 bytes) - added by Janne Grunau 13 years ago.
hackish patch, reemits cached PAT and PMT for error condition in dvbrecorder.cpp
3031-dbg-2.patch (30.5 KB) - added by danielk 13 years ago.
Debugging patch 2
3031-dbg-3.patch (27.2 KB) - added by danielk 13 years ago.
Another debugging patch
3031-dbg-4.patch (26.8 KB) - added by danielk 13 years ago.
Another debugging patch
3031-dbg-5.patch (15.6 KB) - added by danielk 13 years ago.
Another debugging patch
3031-dbg-5b.patch (16.1 KB) - added by danielk 13 years ago.
Another debugging patch
3031-dbg-fix.patch (408 bytes) - added by jppoet@… 13 years ago.
Possible fix
3031-dbg-6.patch (6.1 KB) - added by danielk 13 years ago.
Another debugging patch
3031-dbg-7.patch (19.1 KB) - added by danielk 13 years ago.
Another debugging patch
3031-v3.patch (1.9 KB) - added by danielk 13 years ago.
Fix based on 3031-dbg-7.patch

Download all attachments as: .zip

Change History (74)

comment:1 Changed 13 years ago by danielk

Owner: changed from Isaac Richards to danielk
Version: 0.20head

comment:2 Changed 13 years ago by anonymous

Milestone: unknown0.21
Priority: minorcritical
Severity: mediumhigh

Same defect exists and is not repeatable with SkyStar2 DVB

comment:3 Changed 13 years ago by danielk

Priority: criticalminor
Severity: highmedium
Status: newassigned

John, I've been able to reproduce this, I'm looking into it now.

comment:4 Changed 13 years ago by subconsciousrx@…

The Technisat AirStar?-HD5000 also has the same defect with the about the same ratio of 1:5 failed recording. With the same error message.

comment:5 Changed 13 years ago by anonymous

I have also experienced two failures out of about 10 recordings using the HDHomeRun.

Changed 13 years ago by danielk

Attachment: 3031-dbg-1.patch added

Debugging patch

comment:6 Changed 13 years ago by danielk

anon, subconsciousrx, if you can reproduce this failure with the 3031-dbg-1.patch this could help me figure out what the problem is.

This happens *much* more rarely on my system, so this may be a race condition of some kind. The attached patch will print additional debugging information, from what I can tell from the debugging logs I got when I was able to reproduce this the problem is that the recorder is rejecting the PAT/PMT for some reason. The debugging patch prints out these tables when they are seen so I can look at them for oddities; you need to run the backend with "-v record,channel" in order to get the proper debugging with the patch.

comment:7 Changed 13 years ago by Cymen Vig

I am seeing this every couple of days especially on HDTV programs with 12637. I SVN updated and am recompiling with this patch applied. I'm not any of the anonymous people above.

Changed 13 years ago by danielk

Attachment: 3031-v1.patch added

Possible fix

Changed 13 years ago by danielk

Attachment: 3031-v2.patch added

Possible fix (moved the code to catch a similar failure when initially tuning to an MPEG station and switching to a DVB or ATSC channel).

comment:8 Changed 13 years ago by danielk

I got a log from John P. Poet with the debugging patch. Unfortunetly, it looks like the problem on my machine I thought was reproducing this problem is a in fact a different problem. Fortunately, think I know what is causing this problem.

Whenever we create a new recorder instance there is a chance that the PAT/PMT is not set in the recorder until the next PAT/PMT table version update from the broadcaster, because it is already cached in the stream data after the signal monitor sees it. This can also happen if the stream data is changed, say when you first switch from an MPEG to an ATSC channel in LiveTV. I believe we didn't see this with the DVB recorder before the encryption monitor was changed last month because one of the calls we made to initialize the CAM had the side effect of sending these tables to the recorder.

If my analysis is correct, then 3031-v2.patch should fix this problem.

comment:9 in reply to:  8 Changed 13 years ago by subconsciousrx@…

v2 still has the problem. Even more interesting is the ratio of failed recording is the same. I am sending my log to danielk.

comment:10 Changed 13 years ago by jakep_82@…

Cc: jakep_82@… added

Same problem here using a couple Kworld ATSC-110's recording QAM. 12619 is what breaks DVB recordings for me. I've been unable to reproduce with 12618. Easy to reproduce with 12619. Perhaps 12619 should be backed out until this is fixed? It essentially breaks DVB recordings 20% of the time.

Changed 13 years ago by danielk

Attachment: mythbackend-070210.log added

Latest log from John P. Poet

comment:11 Changed 13 years ago by mythtv at webdeck dot com

24 didn't record for me last night. I had the debugging patch applied and logging enabled, but the log is too large to attach. You can download the log here: http://macpro.webdeck.com/mythbackend.log.bz2

I'm the anonomyous user above using the HDHomeRun.

comment:12 in reply to:  description Changed 13 years ago by funaho@…

Also still seeing problems with HDHomeRun here. The log posted in the previous comment has the same thing I'm seeing here when trying to do ATSC recordings, namely this:

2007-02-14 22:00:05.063 HDHRRec(3): SetPAT(): Ignoring PAT not containing our desired program... 2007-02-14 22:00:05.067 HDHRRec(3): Resetting Demux Filters 2007-02-14 22:00:05.067 HDHRRec(3): AdjustFilters?() no pmt or no pat

It happened maybe 25% of the time with rev 12640; with 12770 it is 100% reproducable. Currently I have to manually cancel and restart all ATSC recordings 2-4 times before they will actually start recording. Recordings on regular MPEG channels never fail.

I have 3-4 things set to record off ATSC channels tomorrow night, so if there's anything I can try before then I will recompile and upgrade before the night's recordings start.

comment:13 Changed 13 years ago by anonymous

Cc: mythtrac@… added

comment:14 Changed 13 years ago by larry@…

Just FYI, I'm using an air2pc hd5000 with the 0.20-151.fc6.at install from ATRPMS. After one trip into WatchTV my dvb card produces the PMT error over and over, rendering the dvb card useless. A bt878 based card in the same system works flawlessly.

My system should be adequate: -> P4 3.2GHz 1GB memory, Fedora FC6 with 2.6.19-1.2895.fc6 nvidia FX5950 video card.

What I find interesting is this problem exists for me using this relatively old version. So possibly the problem has exisited for a long time, but only it takes just certain combinations of hardware and software to reproduce it. (How lucky can I get! {;-) )

Larry

comment:15 Changed 13 years ago by DannyCan@…

I am also having this problem for w while, I have a Air2PC .2 and a pcHDTV2000 running KnoppMyth? R5E50 with the latest svn head from a few days ago. This seems to happen once or twice a day for me and on either tuner. I don't know if this info helps any I just wanna see this get fixed.

comment:16 Changed 13 years ago by jakep_82@…

I tried the v2 patch with current svn and had the same results as subconciousrx. In the mean time I'm stuck at 12618.

comment:17 Changed 13 years ago by DannyCan@…

Is there a patch that will allow me to use the latest source code but rollback the changes made in 12619?

comment:18 in reply to:  16 ; Changed 13 years ago by jonner@…

I am also seeing this behavior on Ubuntu Edgy x86_64 with two Air2PC cards (one version 1 and one version 3) and SVN 12904. I am reverting to 12618 to see if that fixes it.

comment:19 Changed 13 years ago by larry@…

Keywords: PMT issue added
Milestone: 0.210.20
Priority: minormajor
Severity: mediumhigh

I decided my AirStarHD5000 card was at fault because I was getting this "Recording will not commence until a PMT is set". So I purchased an KWorld ATSC-110. I was able to "Watch TV" for about five hours this afternoon (I didn't touch the PC or change channels) then nothing...when ever I requested "Watch TV" I got the blue screen and error message. /var/log/mythtv/mythbackend.log is filled with "Recording will not commence until a PMT is set" I'm using the stock ATrpms version 0.20.20060828-3. When the KWorld card starts generating this error, nothing short of powering down the PC will fix it. It has something to do with trying to "Watch TV" Anyway, I've got two cards and multiple computers, they all have this quirk. Just a matter of time before they die.

comment:20 Changed 13 years ago by Janne Grunau

Milestone: 0.200.21
Priority: majorminor
Severity: highmedium

please don't mess with the ticket's properties

comment:21 in reply to:  18 ; Changed 13 years ago by anonymous

Replying to jonner@teegra.net:

I am also seeing this behavior on Ubuntu Edgy x86_64 with two Air2PC cards (one version 1 and one version 3) and SVN 12904. I am reverting to 12618 to see if that fixes it.

I have not seen the PMT problem with 12618. IMHO, this is at least a high severity bug, since it prevents MythTV from performing its primary function reliably.

comment:22 in reply to:  21 Changed 13 years ago by DannyCan@…

Cc: jakep_82@… removed

Replying to anonymous:

Replying to jonner@teegra.net: IMHO, this is at least a high severity bug, since it prevents MythTV from performing its primary function reliably.

I agree, this should be high priority.

comment:23 Changed 13 years ago by anonymous

Priority: minorcritical
Severity: mediumhigh

This creates a major issue with the primary functionality of mythtv.

Changed priority to critical and severity to high to match this. This defect is in multiple DVB cards from differing vendors. Older version of the code do not have this issue.

comment:24 Changed 13 years ago by Isaac Richards

Priority: criticalminor
Severity: highmedium

Unless you are the one fixing the issue, don't play with the priority or severity.

comment:25 Changed 13 years ago by bsjeep

Yea, I'm not crazy! It's a bug! I'm at 12981 svn as of a day or two ago and I'm still having this problem. I initially thought it was related to my HomeRun? and updated to latest firmware, no change. I'm seeing it on HDTV recording only, 20-50% of the time, on a DVICO lite RT 5, and a HDHomeRun.

-Brian

comment:26 Changed 13 years ago by anonymous

It is related to every piece of HDTV hardware. It is relate to all pieces of HDTV hardware related. It is specifically a bug in the code in tuning a channel and reading the PMT. It is related to ALL dvb cards, not a few.

To call this minor is stupidity. It equates to mythtv is unusable with HDTV.

This should be marked critical with high severity. With this bug mythtv in non-functional.

comment:27 Changed 13 years ago by markcov@…

I'm having this problem also. Subscribing to keep track of progress.

comment:28 Changed 13 years ago by wepprop@…

Having same problem also, about 50% of recordings lost over the past 4 days. Am running 12992, Air2Pc cards OTA. Did not have this problem in previous 14 months. Let me know if I can help.

comment:29 Changed 13 years ago by anonymous

Cc: cymenvig@… added

comment:30 Changed 13 years ago by scott@…

I think that this issue should be made more of a priority. I lose 1-2 recordings a week because of this. My DVB cards are a pcHDTV HD-3000 and a HD-2000. I assume you have enough logging on this. If not, I can forward mine to you. Running SVN 12952, Gentoo Linux.

comment:31 Changed 13 years ago by wepprop@…

I took the suggestion on the mailing list and was able to downgrade to 12618 without any difficulty - no db schema incompatibility or anything. Since then, on a somewhat limited sample, no difficulties with recordings.

Sigh of relief...

comment:32 Changed 13 years ago by ken.emerson@…

I also have recently installed an HDHomeRun tuner and have had problems with recordings failing. In the backend log file I will see the message "AdjustFilters?() no pmt or no pat" printed out about every 10-20 mSec for the duration of the recording time. The resulting mpeg file has a size of zero. I have also seen this happen while watching live TV. I was at 12713 and backed up to 12618, but the problem persists. Until the problem is resolved, I will be recording the programs twice to be sure something is recorded; once on an HD tuner and once on an SD (Haupauge) tuner. I am using an Athalon dual core X2 4400+, GeForce? 6600 video (HDMI out), 3 Haupauge tuners (two 150s and one 350 all hooked to cable), and 1 HDHomeRun (over the air only).

Everything was working (mostly) perfectly until going to digital (HDHomeRun).

I'll be glad to run some specific tests or produce debug output if asked.

Changed 13 years ago by Janne Grunau

Attachment: 3031_hack.diff added

hackish patch, reemits cached PAT and PMT for error condition in dvbrecorder.cpp

comment:33 Changed 13 years ago by Janne Grunau

With the 3031_hack.diff applied the dvbrecorder should be able to recover from the "Recording will not commence until a PMT is set." error condition.

This is just a proof of concept hack. If it works I'll work on a more acceptable solution.

This patch doesn't solve the issue but might help to recover from the error.

Anyone who want to test this should just update to revision 12619 and apply the patch.

comment:34 Changed 13 years ago by developstuff@…

I just got the bug behaviour with the patch applied.

comment:35 Changed 13 years ago by anonymous

Cc: developstuff@… added

comment:36 Changed 13 years ago by developstuff@…

Although I tested the patch, I did not go back to 12619 as janne suggested. My test was on HEAD as of one or two days ago. I'm sorry I can't test further; I had to go back to 12618 before I miss an episode of DOOL or Desperate Housewives, causing the WAF to plummet. I did notice that most, if not all, f'ed up recordings were upconverted content (e.g., Last Call, which isn't shot in HD, exhibited this problem two days in a row).

comment:37 Changed 13 years ago by anonymous

For those of you who are using the HDHomeRun tuner and are having problems similar to what I posted earlier, I direct you to the response I got from the manufacturer's technical staff. I have performed the steps recommended less than 24 hours ago and did some testing (certainly not exhaustive) and all recordings took place on schedule.

Please refer to my post on SiliconDust? mythtv forum:

http://www.silicondust.com/forum/viewtopic.php?p=18798#18798

It refers to using the (new) "Quick Tuning" option in mythtv-setup for the HDHomeRun tuners.

--- Ken E.

comment:38 Changed 13 years ago by anonymous

Just wondering if the patch has fixed this for everyone? I haven't been able to upgrade until this bug was fixed.

Changed 13 years ago by danielk

Attachment: 3031-dbg-2.patch added

Debugging patch 2

comment:39 Changed 13 years ago by danielk

Priority: minormajor

Could someone try this patch? It reverts out the changes in #2944. I don't think these changes were really the cause of the underlying problem, but instead triggered it by changing the timing of the tune and triggering a race condition more frequently than it was previously triggered. If this reversion patch works, I'll make a series of patches that should help isolate the problem by gradually reintroducing the changes in #2944. When I figure out what the real problem is, I'll fix it..

comment:40 Changed 13 years ago by mythtv-commits@…

I'm seeing the same or similar behavior with svn 12146
Card is a HD-3000
Sometimes it works, sometimes it doesn't.

2007-04-16 21:00:02.955 TVRec(1): Changing from None to RecordingOnly
2007-04-16 21:00:02.962 TVRec(1): HW Tuner: 1->1
2007-04-16 21:00:03.231 Started recording: 24 "Day 6: 11:00PM - 12:00 Midnight": channel 1021 on cardid 1, sourceid 1
2007-04-16 21:00:04.240 DVBRec(0) Warning: Recording will not commence until a PMT is set.
2007-04-16 21:00:04.248 DVBRec(0) Warning: Recording will not commence until a PMT is set.

..... a bizillion repeats.... one about every 0.6 ms

2007-04-16 22:00:00.548 DVBRec(0) Warning: Recording will not commence until a PMT is set.
2007-04-16 22:00:00.555 DVBRec(0) Warning: Recording will not commence until a PMT is set.
2007-04-16 22:00:00.561 TVRec(1): Changing from RecordingOnly to None
2007-04-16 22:00:00.562 DVBRec(0) Warning: Recording will not commence until a PMT is set.
2007-04-16 22:00:00.570 Finished recording 24 "Day 6: 11:00PM - 12:00 Midnight": channel 1021
2007-04-16 22:00:00.571 Reschedule requested for id 0.
2007-04-16 22:00:00.587 Finished recording 24 "Day 6: 11:00PM - 12:00 Midnight": channel 1021
2007-04-16 22:00:00.640 Scheduled 41 items in 0.1 = 0.01 match + 0.06 place
2007-04-16 22:00:00.645 Preview Error: Previewer file '/myth/tv/1021_20070416210800.mpg' is not valid.

Changed 13 years ago by danielk

Attachment: 3031-dbg-3.patch added

Another debugging patch

Changed 13 years ago by danielk

Attachment: 3031-dbg-4.patch added

Another debugging patch

comment:41 Changed 13 years ago by jakep_82

Cc: jakep_82@… added

Not sure if this helps, but I had been stuck at 12618 because of this bug. A couple days ago I upgraded to 13245 and enabled quicktune per some discussion others have had about the HDHR. I have a couple Kworld ATSC-110 cards. Since the upgrade I've started more than 30 QAM recordings with no failures yet. Previously I would see a failure every 5th or 6th recording.

Changed 13 years ago by danielk

Attachment: 3031-dbg-5.patch added

Another debugging patch

Changed 13 years ago by danielk

Attachment: 3031-dbg-5b.patch added

Another debugging patch

comment:42 Changed 13 years ago by jppoet@…

Type: defectpatch

3031-dbg-fix.patch seems to fix this problem -- for me.

This patch is the difference between Daniel's 3031-dbg-3.patch and 3031-dbg-4.patch.

I applied it to svn r13267, and after 40 attempts, I did not see a failure.

John

Changed 13 years ago by jppoet@…

Attachment: 3031-dbg-fix.patch added

Possible fix

Changed 13 years ago by danielk

Attachment: 3031-dbg-6.patch added

Another debugging patch

comment:43 Changed 13 years ago by danielk

Thanks John, this really narrows it down. Unfortunately the fix patch you posted breaks program number only tuning for some channels. I've added another patch '3031-dbg-6.patch' can you attach the logs for a successful and a failed run with 'mythbackend -v channel,record,siparser'? I've added some additional debugging for Reset() usage which should help be figure out what is different between the failing and successful runs.

comment:44 Changed 13 years ago by Kazan

when you get a final patch to test i can definantly use it :D

Changed 13 years ago by danielk

Attachment: 3031-dbg-7.patch added

Another debugging patch

comment:45 Changed 13 years ago by mythtv-commits@…

Installed with 3031-dbg-6.patch so far looks good 6/6 shows recorded successfully. I'll also try the newest patch and attach logs when I have them. Thanks.

comment:46 Changed 13 years ago by anonymous

can we get a version of the patch that works with mythtv-20-fixes

comment:47 Changed 13 years ago by anonymous

This problem didn't affect 0.20, it was a regression in head.

comment:48 Changed 13 years ago by anonymous

it's affecting me in 0.20-fixes- i'm trying to 3031-dbg-fix.patch right now

comment:49 Changed 13 years ago by anonymous

What's the output of mythbackend --version

comment:50 Changed 13 years ago by anonymous

3031-dbg-fix.patch does not resolve the issue for me on mythtv-0-20-fixes

Library API version: 0.20.20060828-4
Source code version: 13292M
Options compiled in:
 linux release using_xvmcw using_v4l using_oss using_alsa using_ivtv using_dbox2 using_hdhr using_ip_rec using_freebox using_live using_lirc using_joystick_menu using_dvb using_x11 using_xv using_xrandr using_xvmc using_xvmc_vld using_frontend using_backend

comment:51 Changed 13 years ago by anonymous

i think i found a possibility - i haven't had a chance to test it myself and won't until tonight

http://svn.mythtv.org/trac/browser/trunk/mythtv/libs/libmythtv/dvbrecorder.cpp line 737

that continue should probably be removed.

Changed 13 years ago by danielk

Attachment: 3031-v3.patch added

Fix based on 3031-dbg-7.patch

comment:52 Changed 13 years ago by Kazan

i'll try that one when i get home

comment:53 Changed 13 years ago by Kazan

3031-v3.patch resolves on mythtv-20-fixes

comment:54 in reply to:  53 Changed 13 years ago by subconsciousrx@…

Works!

3031-v3.patch tested against head trunk 13303. I recorded 60 shows across 3 dvb cards and 1 hdhomerun without quicktune enable and not one failure.

Thank you, Daniel.

comment:55 Changed 13 years ago by jppoet@…

I can confirm that 3031-v3.patch seems to fix the problem. Thanks Daniel.

comment:56 Changed 13 years ago by mythtv@…

I have had a number of tuning failures with 3031-v3.patch applied. Yes, I have made sure that I have applied it correctly.

I haven't got any logs right now but will collect some soon.

comment:57 Changed 13 years ago by mythtv@…

Here's a log from the failure to tune:

2007-04-23 19:20:19.585 TVRec(1): SetChannel() -- begin
2007-04-23 19:20:19.631 TVRec(1): ClearFlags(RingBufferReady,) -> FrontendReady,RunMainLoop,CancelNextRecording,AskAllowRecording,RecorderRunning,
2007-04-23 19:20:19.698 TVRec(1): Request: Program(no) channel(6) input() flags(LiveTV,)
2007-04-23 19:20:19.780 TVRec(1): ClearFlags(PENDINGACTIONS,) -> FrontendReady,RunMainLoop,CancelNextRecording,AskAllowRecording,RecorderRunning,
2007-04-23 19:20:19.891 TVRec(1): SetFlags(WaitingForRecPause,) -> FrontendReady,RunMainLoop,CancelNextRecording,AskAllowRecording,WaitingForRecPause,RecorderRunning,
2007-04-23 19:20:19.959 TVRec(1): ClearFlags(WaitingForRecPause,) -> FrontendReady,RunMainLoop,CancelNextRecording,AskAllowRecording,RecorderRunning,
2007-04-23 19:20:20.015 DVBRec(0): Close() fd(19) -- begin
2007-04-23 19:20:20.071 DVBRec(0): Close() fd(-1) -- end
2007-04-23 19:20:20.127 RecBase(0): SetRingBuffer(0)
2007-04-23 19:20:20.198 DVBChan(0): Opening DVB channel
2007-04-23 19:20:20.254 DVBChan(0): SetChannelByString(6):
2007-04-23 19:20:20.312 DVBChan(0): 219500000 qam_64 a 3/4 1/2 7 8 1/16 n v
2007-04-23 19:20:20.366 DVBChan(0): Old Params: 219500000 qam_64 a 3/4 1/2 7 8 1/16 n v
      DVBChan(0): New Params: 219500000 qam_64 a 3/4 1/2 7 8 1/16 n v
2007-04-23 19:20:20.422 DVBChan(0): Tune(): Frequency tuning successful.
2007-04-23 19:20:20.478 DVBChan(0): SetChannelByString(6): Tuned to frequency.
2007-04-23 19:20:20.534 TVRec(1): SwitchLiveTVRingBuffer(discont 1, set_rec 0)
2007-04-23 19:20:20.590 TVRec(1): GetProgramRingBufferForLiveTV()
2007-04-23 19:20:20.689 TVRec(1): StartedRecording(0x8230568) fn(/data/recordings/1516_20070423192020.mpg)
2007-04-23 19:20:20.862 TVRec(1): FinishedRecording(Big Brother - Game On) in recgroup: LiveTV
2007-04-23 19:20:20.942 Chain: Updated endtime for '1012_20070423192008' to 20070423192020
2007-04-23 19:20:21.079 Finished recording Big Brother - Game On: channel 1012
2007-04-23 19:20:21.226 Preview: 'myth://10.0.0.36:6543/1012_20070423192008.mpg' is not local,
      replacing with '/data/recordings/1012_20070423192008.mpg', which is local.
[mpegts @ 0xb7692d70]2007-04-23 19:20:21.298 Chain: Appended@2 '1516_20070423192020'
Parser not found for Codec Id: 94211 !
2007-04-23 19:20:21.645 TVRec(1): Starting Signal Monitor
2007-04-23 19:20:21.696 TVRec(1): SetupSignalMonitor(1, 1)
2007-04-23 19:20:21.763 DVBChan(0): Opening DVB channel
2007-04-23 19:20:21.822 SM(0)::AddFlags: Seen() Match() Wait(Sig,)
2007-04-23 19:20:21.875 DVBSM(0)::constructor(): initial flags 0x40000000
2007-04-23 19:20:21.942 TVRec(1): Signal monitor successfully created
2007-04-23 19:20:21.999 TVRec(1): Setting up table monitoring.
2007-04-23 19:20:22.059 Using profile 'Live TV' to record
2007-04-23 19:20:22.111 TVRec(1): DVB service_id 1601 on net_id 0 tsid 0
2007-04-23 19:20:22.167 DTVSM(0)::SetDVBService(transport_id: 0, network_id: 0, service_id: 1601):
2007-04-23 19:20:22.223 SM(0)::RemoveFlags: Seen(PMT,SDT,Crypt,) Match(PMT,SDT,Crypt,) Wait()
2007-04-23 19:20:22.282 SM(0)::AddFlags: Seen() Match() Wait(PMT,SDT,)
2007-04-23 19:20:22.338 SM(0)::AddFlags: Seen() Match() Wait(PMT,SDT,Pos,)
2007-04-23 19:20:22.408 TVRec(1): Successfully set up DVB table monitoring.
2007-04-23 19:20:22.464 SM(0)::Start: begin
2007-04-23 19:20:22.521 SM(0)::Start: end
2007-04-23 19:20:22.576 TVRec(1): SetFlags(SignalMonitorRunning,) -> FrontendReady,RunMainLoop,CancelNextRecording,AskAllowRecording,SignalMonitorRunning,RecorderRunning,
2007-04-23 19:20:22.633 TVRec(1): ClearFlags(WaitingForSignal,) -> FrontendReady,RunMainLoop,CancelNextRecording,AskAllowRecording,SignalMonitorRunning,RecorderRunning,
2007-04-23 19:20:22.700 TVRec(1): SetFlags(WaitingForSignal,) -> FrontendReady,RunMainLoop,CancelNextRecording,AskAllowRecording,WaitingForSignal,SignalMonitorRunning,RecorderRunning,
2007-04-23 19:20:22.520 DVBSM(0)::UpdateValues: Signal Locked
2007-04-23 19:20:22.812 DVBSM(0)::UpdateValues: Waiting for table monitor to start
2007-04-23 19:20:22.756 RecBase(0): SetRingBuffer(0)
2007-04-23 19:20:22.925 TVRec(1): SetFlags(DummyRecorderRunning,) -> FrontendReady,RunMainLoop,CancelNextRecording,AskAllowRecording,WaitingForSignal,SignalMonitorRunning,ANYRECRUNNING,
2007-04-23 19:20:22.869 DVBSM(0)::UpdateValues: Table monitor started
2007-04-23 19:20:22.819 DVBSM(0): RunTableMonitorTS(): begin (# of pids 4)
2007-04-23 19:20:22.981 DummyDTVRecorder -- started
2007-04-23 19:20:23.048 DTVSM(0)::GetStatusList: WaitForPMT seen(0) matching(0)
2007-04-23 19:20:23.182 TVRec(1): SetFlags(RingBufferReady,) -> FrontendReady,RunMainLoop,CancelNextRecording,AskAllowRecording,WaitingForSignal,SignalMonitorRunning,ANYRECRUNNING,RingBufferReady,
2007-04-23 19:20:23.250 DVBSM(0)::AddPIDFilter(0x0):
2007-04-23 19:20:23.323 TVRec(1): ClearFlags(NeedToStartRecorder,) -> FrontendReady,RunMainLoop,CancelNextRecording,AskAllowRecording,WaitingForSignal,SignalMonitorRunning,ANYRECRUNNING,RingBufferReady,
2007-04-23 19:20:23.389 DVBSM(0)::AddPIDFilter(0x10):
2007-04-23 19:20:23.446 TVRec(1): SetFlags(NeedToStartRecorder,) -> FrontendReady,RunMainLoop,CancelNextRecording,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,ANYRECRUNNING,RingBufferReady,
2007-04-23 19:20:23.502 DVBSM(0)::AddPIDFilter(0x11):
2007-04-23 19:20:23.636 DVBSM(0)::AddPIDFilter(0x12):
2007-04-23 19:20:23.693 DVBSM(0)::AddPIDFilter(0x14):
2007-04-23 19:20:23.760 DVBRec(0): SetPAT(1601 on 0x101)
2007-04-23 19:20:23.827 SM(0)::AddFlags: Seen(PAT,) Match() Wait()
2007-04-23 19:20:23.883 SM(0)::AddFlags: Seen() Match(PAT,) Wait()
2007-04-23 19:20:23.939 CreatePATSingleProgram()
2007-04-23 19:20:23.996 PAT in input stream
2007-04-23 19:20:24.052 Program Association Table
 PSIP tableID(0x0) length(33) extension(0x604)
      version(3) current(1) section(0) last_section(0)
         tsid: 1540
 programCount: 6
  program number 0 has PID 0x  10   data  0x 0 0x 0 0xe0 0x10
  program number 1601 has PID 0x 101   data  0x 6 0x41 0xe1 0x 1
  program number 1605 has PID 0x 100   data  0x 6 0x45 0xe1 0x 0
  program number 1607 has PID 0x 106   data  0x 6 0x47 0xe1 0x 6
  program number 1608 has PID 0x 107   data  0x 6 0x48 0xe1 0x 7
  program number 1609 has PID 0x 108   data  0x 6 0x49 0xe1 0x 8

2007-04-23 19:20:23.569 TVRec(1): SetChannel() -- end
2007-04-23 19:20:24.119 desired_program(1601) pid(0x101)
2007-04-23 19:20:24.256 pmt_pid(0x101)
2007-04-23 19:20:24.319 PAT for output stream
2007-04-23 19:20:24.466 Program Association Table
 PSIP tableID(0x0) length(13) extension(0x604)
      version(3) current(1) section(0) last_section(0)
         tsid: 1540
 programCount: 1
  program number 1 has PID 0x 101   data  0x 0 0x 1 0xe1 0x 1

2007-04-23 19:20:24.469 DVBSM(0)::AddPIDFilter(0x101):
0: start_time: 404.156 duration: -9223372036854.775
1: start_time: 404.120 duration: 0.783
2: start_time: 404.115 duration: 0.788
stream: start_time: 4490.162 duration: 8.767 bitrate=13278 kb/s
2007-04-23 19:20:24.629 AFD: Opened codec 0x8328df0, id(MPEG2VIDEO) type(Video)
2007-04-23 19:20:24.645 DVBRec(0): SetPMT(1601)
2007-04-23 19:20:24.785 SM(0)::AddFlags: Seen(PMT,) Match() Wait()
2007-04-23 19:20:24.851 SM(0)::AddFlags: Seen() Match(PMT,) Wait()
2007-04-23 19:20:24.896 DTVSM(0)::GetStatusList: WaitForPMT seen(1) matching(0)
2007-04-23 19:20:24.954 CreatePMTSingleProgram()
2007-04-23 19:20:25.030 PMT in input stream
2007-04-23 19:20:25.010 DTVSM(0)::GetStatusList: WaitForPMT seen(1) matching(1)
2007-04-23 19:20:24.733 AFD: Opened codec 0x8329400, id(AC3) type(Audio)
2007-04-23 19:20:25.088 Program Map Table ver(3) pid(0x101) pnum(1601) len(77)
  System Clock Descriptor (0xb) length(2)
  Smoothing Buffer Descriptor (0x10) length(6)

 Stream #0 pid(0x200) type(video-mpeg2  0x2)
  Video Descriptor (0x2) length(3)
 Stream #1 pid(0x28a) type(audio-mp2-layer[1,2,3]  0x4)
  Audio Descriptor (0x3) length(1)
  ISO-639 Language: code(eng) canonical(eng) eng(English)
 Stream #2 pid(0x28b) type(private-data  0x6)
  AC-3 Descriptor (0x6a) length(3)
  ISO-639 Language: code(eng) canonical(eng) eng(English)
 Stream #3 pid(0x240) type(private-data  0x6)
  Teletext Descriptor (0x56) length(5)

2007-04-23 19:20:25.282 PMT for output stream
2007-04-23 19:20:25.340 Program Map Table ver(3) pid(0x101) pnum(1) len(28)

 Stream #0 pid(0x200) type(video-mpeg2  0x2)
 Stream #1 pid(0x28a) type(audio-mp2-layer[1,2,3]  0x4)
 Stream #2 pid(0x28b) type(audio-ac3  0x81)

2007-04-23 19:20:25.397 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:26.116 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:27.633 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:28.910 DTVSM(0): Time Offset: -1.90999
2007-04-23 19:20:29.020 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:29.673 DTVSM(0)::SetNIT(): net_id = 12841
2007-04-23 19:20:29.722 SM(0)::AddFlags: Seen(NIT,) Match() Wait()
2007-04-23 19:20:30.476 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:31.754 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:33.291 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:34.555 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:36.177 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:37.388 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:38.963 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:40.227 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:41.814 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:43.033 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:44.600 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:45.868 SM(0)::AddFlags: Seen(SDT,) Match() Wait()
2007-04-23 19:20:47.423 SM(0)::AddFlags: Seen(SDT,) Match() Wait()


comment:58 Changed 13 years ago by danielk

Vulturest, it looks like you are experiencing some other problem. Does this only happen with 3031-v3.patch applied, or does it also happen without the patch applied?

comment:59 Changed 13 years ago by Nick Morrott <knowledgejunkie@…>

(cc'd to -dev list)

I've tested the v3 patch on my UK DVB-T master backend, using r13315. (FC4, 2.6.16, V-Stream DVB XPert cards, Sutton Coldfield Tx)

I have watched LiveTV across multiple channels on all 6 UK DVB-T multiplexes and have not encountered any tuning issues.

I have also been successful making a few scheduled recordings, again with no tuning issues.

Nick

comment:60 Changed 13 years ago by danielk

Resolution: fixed
Status: assignedclosed

(In [13316]) Fixes #3031. Fixes the 'Recording will not commence until a PMT is set' bug in ATSC tuning.

Thanks to John P. Poet for doing most of the ATSC testing and Nick Morrott for testing for DVB-X regressions.

Note: See TracTickets for help on using tickets.