Recording will not commence until a PMT is set.

[jppoet]

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

[anonymous]

Same defect exists and is not repeatable with SkyStar2 DVB

[danielk]

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

[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.

[anonymous]

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

[danielk]

Debugging patch

[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.

[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.

[danielk]

Possible fix

[danielk]

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).

[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.

[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.

[jakep_82@…]

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.

[danielk]

Latest log from John P. Poet

[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.

[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.

[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

[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.

[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.

[DannyCan@…]

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

[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.

[larry@…]

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.

[janne]

please don't mess with the ticket's properties

[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.

[DannyCan@…]

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.

[anonymous]

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.

[ijr]

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

[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

[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.

[markcov@…]

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

[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.

[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.

[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...

[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.

[janne]

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

[janne]

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.

[developstuff@…]

I just got the bug behaviour with the patch applied.

[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).

[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.

[anonymous]

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

[danielk]

Debugging patch 2

[danielk]

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..

[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.

[danielk]

Another debugging patch

[danielk]

Another debugging patch

[jakep_82]

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.

[danielk]

Another debugging patch

[danielk]

Another debugging patch

[jppoet@…]

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

[jppoet@…]

Possible fix

[danielk]

Another debugging patch

[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.

[Kazan]

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

[danielk]

Another debugging patch

[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.

[anonymous]

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

[anonymous]

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

[anonymous]

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

[anonymous]

What's the output of mythbackend --version

[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

[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.

[danielk]

Fix based on 3031-dbg-7.patch

[Kazan]

i'll try that one when i get home

[Kazan]

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

[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.

[jppoet@…]

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

[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.

[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()

[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?

[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

[danielk]

(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.