Problems with overlapping recordings

[johnsta]

*** Problems with overlapping recordings

About a year ago, I was in this forum reporting a bug where npvr was
creating defective recordings. Although the records could play black
within npvr itself, they could not play using wmplayer. With vlc they
do play, but the time fields were all zero and the hotkeys don't work,
although the progress bar still works.

This bug started happening when I switched from Windows media center
to npvr in 2016. It continued when I switched from a Ceton tuner card
to an HDHomerun. In the last year, there have been several new
versions of npvr, but the problem has not disappeared.

In the last month, I changed from a Windows 7 system to a new computer
running Windows ten, and the problem persisted.

So that eliminated almost all the variables. The bug did not occur
with media center, but it did with npvr in numerous configurations --
ceton vs hdhomerun, Windows 7 vs windows 10.

The only possibility left is that this is a bug in npvr.

During the last month I started looking at specific situations when it
happens and when it doesn't, and this has led me to find exactly what
the bug is in npvr.

Here are two scheduled programs:

21:29:00+0:31: 4 25 REC Fam [Fam.S01E09.Ocean.View.ts]
22:00:00+0:30: 61 25 REC Broad City [Broad.City.S05E07.Shenanigans.ts]

Fam was recorded from 21:29 for 31 minutes on tuner 25, while Broad
City was recorded from 22:00 for 30 minutes on tuner 25. Fam is on
channel 4, and Broad City is on channel 61. So, theoretically, tuner
25 switches from channel 4 to channel 61 at exactly 10 pm.

Here's the NPVR status as of about 30 seconds past 10 pm:



This state of affairs goes on for two minutes.

Notice that BOTH programs are recording, even though they're on
different channels using the same tuner. There is no planet on which
that make sense.

The result is that the meta-data for BOTH recordings is wiped out.
This is the bug that's been occurring for years.

This is due to pre-padding (defaults to one minute) and post-padding
(defaults to two minutes). Pre- and post-padding is a GOOD thing when
you're recording the same channel, but is a BAD thing when you're
changing channels.

To fix this bug in npvr requires a new "overlap algorithm":

• If one recording is overlapping the next recording on the same
  tuner on the same channel, then overlapping is wonderful.
  
  
  
• But if they're on different channels, then the end time of the
  first recording and the start time of the second recording must be
  adjusted so that there's a gap of a few seconds between them, to
  give the tuner a chance to reset. This has to override the pre-
  and post- settings, since it never makes sense to record two
  different channels on the same tuner at the same time.

This should fix the bug in npvr that creates defective recordings.

I'm providing this information to you in the hope that it will be
useful to you.

Have a nice day!

[Graham]

Notice that BOTH programs are recording, even though they're on
different channels using the same tuner. There is no planet on which
that make sense.

There is one such planet in my living room

NextPVR is able to simultaneously record two channels on a single tuner when both channels are on a single mux/frequency.

I am receiving TV via a rooftop aerial. I am receiving more than 50 TV channels that arrive on one of about 10 frequencies. There are between about 5 and 10 channels on each frequency. NextPVR is able to simultaneously record all of the channels on one frequency using a single tuner.

I don't know whether this is relevant in your situation.

[johnsta]

That sort of multiplexing would not work with a Comcast cablecard.

[BrettB]

Notice that BOTH programs are recording, even though they're on
different channels using the same tuner. There is no planet on which
that make sense.

First thing: You didn't post your logs (be sure to post ALL of the logs) nor even tell us what version of NextPVR you're running. So we really can't effectively help you.

However, sub has repeatedly stated that when (during post-padding) a tuner is "taken away" for another recording, the original recording will continue "recording" until the end of the post-padding time. However, it doesn't actually receive any new data, so doesn't actually write anything to the .ts file. Personally, I think that this behavior is sort of bogus--if the tuner gets taken away, then the recording should stop and proceed to execute the post-processing.bat file immediately rather than wait for the rest of the post-padding time period to pass. But, that's the way the system currently works.

Now, that being said, there was a time (for several versions as I recall) where (at least with CableCard devices), the original recording would continue receiving the stream from the tuner (now tuned to a new channel) and would write that to the end of the .ts file. This situation would often cause strange behavior when playing these .ts files. But that bug has been fixed for a while now.

If you are running the latest version of NPVR, you could repeat your test and see if the original .ts file continues growing in size after the tuner is reallocated.

[johnsta]

NPVR 4.2.3 (181112)

It will be a couple of weeks before I'll be ready to install 4.2.4.

As for logs, I'll have to wait until I catch it at the right time,
which may be a couple of days.

I'm actually not looking for help, since I gave up after all the
hassle a year ago, and now I just live with the problem and work
around it. But I felt that the information that I've uncovered is
valuable enough so that I wanted to pass it on to you.

[HollyCairns]

First thing: You didn't post your logs (be sure to post ALL of the logs) nor even tell us what version of NextPVR you're running. So we really can't effectively help you.

...dosn't actually write anything to the .ts file. Personally, I think that this behavior is sort of bogus--if the tuner gets taken away, then the recording should stop But, that's the way the system currently works.

The post padding seems really inconsistent for me. Most of the time I get the post padding but 10% of the time I don't which results in not getting a complete show. I've done multiple tests, looking at the logs, having no shows recorded after the post padding, having shows recorded during the post padding and it just seems fluky. Right now I'm recording two sequential shows on the same channel and it looks like show #1 is getting post padding as the file size keeps increasing and the show ended 7 minutes ago ( I have 10 mins post padding). I'm going to do alot of test recordings on the weekend just to see if I should move on to something else. Really frustrating trying to complete a season when I loose a show due to post padding.

Using NextPVR 4.2.4 (190307) on Windows 7, using HD Homerun 2 tuners.

[mvallevand]

Most of the time I get the post padding but 10% of the time I don't which results in not getting a complete show.

That's really odd I use no-padding because here in Ottawa the times are so good based on the EPG that it just isn't necessary for me. What network is bad for you?

Martin

[HollyCairns]

Today my problem was with Antenna TV (Buffalo) (3 times) and City Tv (1 time). One of shows on Antenna TV although it had no post padding I got the whole show. City TV (Toronto) wasn't a post padding problem it was odd in that Dr. TS showed no errors but I couldn't open it in Avidemux. Since I didn't need the file I was only testing I didn't spend too much time to figure out the problem. The post padding problem is rather random like I said about 10% of the time there is a problem. Seems there is no rhyme or reason why I get the post padding or not. Its not based on time of day, channel, signal strength or whether the tuner will be use after the post padding. Plan to do some more tests over the weekend.

[johnsta]

Best wishes to everyone in New Zealand after last week's tragedy
in Christchurch.

In order to obtain the requested log files, I waited until Thursday
evening, since the same programs were being scheduled in the same way
as on the previous Thursday.

Here's a summary produced by a script I've written
to show the status at any given time. Each row shows:
Start time, length, channel, tuner, status, program name, file name
The following snapshot was taken around 10:15pm:

Code:

Thu-3/14-20:00:04+0:31:  10 25 DONE Superstore [Superstore.S04E11.Steps.Challenge.ts]
Thu-3/14-20:00:06+1:02:   5 27 DONE Grey's Anatomy [Greys.Anatomy.S15E17.And.Dream.of.Sheep.ts]
Thu-3/14-20:29:01+0:32:  10 26 DONE A.P. Bio [A.P..Bio.S02E02.Nuns.ts]
Thu-3/14-20:31:00+0:32:   4 25 DONE Fam [Fam.S01E10.Dance.Dance.Resolution.ts]
Thu-3/14-20:59:00+0:33:  10 26 DONE Brooklyn Nine-Nine [Brooklyn.Nine-Nine.S06E10.Gintars.ts]
Thu-3/14-21:00:00+1:02:   5 27 DONE Station 19 [Station.19.S02E09.I.Fought.the.Law.ts]
Thu-3/14-21:29:01+0:32:   4 25 DONE Fam [Fam.S01E11.Party.Girl.ts]
Thu-3/14-21:29:02+0:32:  10 26 DONE Will & Grace [Will.&.Grace.S02E15.Bad.Blood.ts]
Thu-3/14-21:59:00+1:01:  10 26  REC Law & Order: Special Victims Unit [Law.&.Order.Special.Victims.Unit.S20E17.Missing.ts]
Thu-3/14-21:59:00+1:01:   5 27  REC For the People [For.the.People.S02E02.This.Is.America.ts]
Thu-3/14-22:00:00+0:30:  61 25  REC Broad City [Broad.City.S05E08.Sleep.No.More.ts]
Thu-3/14-22:34:00+0:33:  30 25      Better Things - Conflict Alternative Airing
Thu-3/14-23:07:00+0:34:  30 26      Better Things - Conflict Alternative Airing
Thu-3/14-23:34:00+1:03:  10 25      The Tonight Show Starring Jimmy Fallon

The two programs of interest are Fam (at 21:29) and Broad City
(at 22:00). Fam shows a length of 32 minutes because NPVR adds two
minutes for padding. This means that from 22:00-22:01, tuner 25
is theoretically recording two different shows on the same tuner,
which makes no sense at all, and is the problem.

This is the source of the bug that's causing the program metadata to
be wiped out. The bug, as I've previously said, is that although the
Fam recording could play back within npvr itself, it could not play
using wmplayer. With vlc it does play, but the time fields are all
zero and the hotkeys don't work, although the progress bar still
works.

On Thursday evening, I watched what happened as it happened:

• Between 21:29-22:00, when Fam was recording, I was able
  to watch the recording using VLC. The time fields were shown, and
  the hotkeys worked.
  
  
• At 22:00, when Broad City started recording, VLC went POOF. The
  time fields were zeroes, and the hotkeys suddenly stopped working.
  
  
• The final Fam recording has a minute or two of something at the
  end (according to the VLC progress bar), but when I try to see what it
  is, VLC just stops.

Here's the log from HDhomerun. Keep in mind that these
times are GMT, so 10 pm=22:00 ET equals 02:00 GMT.

Code:

20190315-00:00:03 Tuner: tuner0 tuning 10 WBTSLP (auto:135MHz-11)
20190315-00:00:03 Tuner: tuner0 rtp stream ended (new request)
20190315-00:00:03 Tuner: tuner0 streaming rtp to 192.168.1.139:36312
20190315-00:00:03 CableCARD: tuner0 10 WBTSLP (auto:135MHz-11) access = subscribed
20190315-00:00:05 Tuner: tuner2 tuning 5 WCVB (auto:135MHz-4)
20190315-00:00:05 Tuner: tuner2 rtp stream ended (new request)
20190315-00:00:05 Tuner: tuner2 streaming rtp to 192.168.1.139:36313
20190315-00:00:05 CableCARD: tuner2 5 WCVB (auto:135MHz-4) access = subscribed
20190315-00:02:34 Tuner: tuner1 rtp stream ended (usage timeout)

20190315-00:29:00 Tuner: tuner1 tuning 10 WBTSLP (auto:135MHz-11)
20190315-00:29:00 Tuner: tuner1 streaming rtp to 192.168.1.139:36314
20190315-00:29:00 CableCARD: tuner1 10 WBTSLP (auto:135MHz-11) access = subscribed
20190315-00:30:59 Tuner: tuner0 tuning 4 WBZ (auto:135MHz-3)
20190315-00:30:59 Tuner: tuner0 rtp stream ended (new request)
20190315-00:30:59 Tuner: tuner0 streaming rtp to 192.168.1.139:36315
20190315-00:30:59 CableCARD: tuner0 4 WBZ (auto:135MHz-3) access = subscribed

20190315-01:03:34 Tuner: tuner0 rtp stream ended (usage timeout)
20190315-01:29:00 Tuner: tuner0 tuning 4 WBZ (auto:135MHz-3)
20190315-01:29:00 Tuner: tuner0 streaming rtp to 192.168.1.139:36316
20190315-01:29:01 CableCARD: tuner0 4 WBZ (auto:135MHz-3) access = subscribed

20190315-01:59:59 Tuner: tuner0 tuning 61 COMEDY (auto:147MHz-2503)
20190315-01:59:59 Tuner: tuner0 rtp stream ended (new request)
20190315-01:59:59 Tuner: tuner0 streaming rtp to 192.168.1.139:36317
20190315-01:59:59 CableCARD: tuner0 61 COMEDY (auto:147MHz-2503) access = subscribed
20190315-01:59:59 Tuner: tuner0 tuning 61 COMEDY (auto:147MHz-2503)
20190315-01:59:59 Tuner: tuner0 rtp stream ended (new request)
20190315-01:59:59 Tuner: tuner0 streaming rtp to 192.168.1.139:36317
20190315-01:59:59 CableCARD: tuner0 61 COMEDY (auto:147MHz-2503) access = subscribed

20190315-02:32:34 Tuner: tuner0 rtp stream ended (usage timeout)
20190315-02:33:00 Tuner: tuner0 tuning 30 FX (auto:159MHz-2712)
20190315-02:33:00 Tuner: tuner0 streaming rtp to 192.168.1.139:36318
20190315-02:33:00 CableCARD: tuner0 30 FX (auto:159MHz-2712) access = subscribed

I'm not including npvr.log, because there had been no entries
for two days.

Finally, the following is the listing of nrecord.log between
8:30pm and 10:02pm.

http://generationaldynamics.com/gdgraphi...190314.txt

Note the following group of lines:

> Recording due to start pre-padding, but tuner not available
> Scheduled Recording about to start maybe a candidate for moving to another tuner (different locator than another recording on same device)
> Existing:
> irc</map><chan>16</chan>
> Required:
> rc</map><chan>16</chan>
> Was allocated to capture source: 25
> Checking possible candidate: 35
> Checking possible candidate: 34
> Checking possible candidate: 33
> Checking possible candidate: 32
> Checking possible candidate: 25
> Checking possible candidate: 26
> Checking if multi-record possible...
> Checking possible candidate: 27
> Checking if multi-record possible...
> Checking possible candidate: 20
> Recording not moved. No other available tuner could be found.

This group of lines appeared hundreds of times within a one minute
period at 8:30 pm and again at 9:59 pm. Apparently this had to do
with trying to accommodate the one-minute pre-padding for Broad City
and, upon failing, kept trying almost 200 times within one minute. I
don't know whether that's a bug or a feature, but my gut reaction is
"that can't be right."

So apparently NPVR handles the pre-padding right, but the bug is that
it doesn't handle the post-padding right. The fix would have to be
that when npvr starts tuner 25 recording on channel 61 at 10pm, it
must first stop recording on channel 4.

In case anyone is wondering why I'm recording all these shows, it's
not because I'm running a business. I started recording some shows in
the 1990s on vcr tapes. In those days, I could always watch the shows
within a few days or weeks. If the VCR tapes started piling up, I
could always catch up during the summer rerun period. As time went
by, I moved to Beyond TV, Windows Media Center, and then NPVR. As
time has gone by, I've gotten farther and farther behind in watching
the recordings. I'm currently watching an episode of Quantico from
23-Oct-2016, which means that I'm almost three years behind. At my
age it's very unlikely that I'll ever watch what I'm recording now, so
this is truly the act of an obsessive compulsive mind. And once
again, I point out that I donated $80. However, I'm not looking for
help, since I've gotten used to the bug and I just work around the
bug. I'm just providing information so that you can fix the bug if
you want to.

[sub]

Johnsta, can you please supply your npvr.db3 file? I want to check some of the tuning strings.