Recordings cut-off due to improper use of multiple tuners

[Reddwarf]

Tuner allocation at scheduling/epg-update time is done without regard to padding. Padding is accomodated on-the-fly at recording time on an "if possible" basis. That logic all seems fine. It's just that when the recording was moved to another tuner to accomodate the padding, NRecord ended up choosing a tuner that was already in use on another channel; NRecord appeared to think it was doing a multi-record on the same frequency, but in fact it changed channels and ended the prior recording a minute early.

Since Sub added logic to make a second attempt if a tuner device don't start when it is supposed to, the need for conflict handling/recording priority gets more urgent. I have a tuner that is failing to start sometimes, and when it fails to start a scheduled recording Nrecord will try another tuner. The other tuner may have a recording scheduled a little later, so when the time comes Nrecord cuts the first recording short and starts the second on that tuner instead. If I could set priority for the recordings Nrecord would know that the first one was more important and cancel the second one.

[fluffykeith]

When I read this http://www.nextpvr.com/nwiki/pmwiki.php?...dings#toc9 it impies that you can set the priority for which recordings are important. I've not tried it.

Also wouldn't it be easier to schedule for the whole time show plus padding rather than trying to fix it on the fly. oh well I'm sure there is good reason - just needs tweeking by the sound of it.

[totallhavoc]

Logs are attached. The issue happened Monday night. It was recording like like this with pre and post at 2 and 4 minutes:

8:00 PM
tuner 1: Bones on Fox

9:00 PM
Tuner 2: The Following on Fox (why it didn't use tuner 1 I still don't understand)
Tuner 3: 90210 on CW

10:00 PM
Tuner 3: Hawaii Five-O on CBS

90210 gets cut off by Hawaii Five-O, which isn't a problem for me but try to explain it to others in the house.

FYI: I have 4 tuners

[johnsonx42]

Yep, exactly the same problem as the OP:

Code:

2013-02-18 21:58:00.159    [DEBUG][7]    Recording due to start pre-padding, but tuner not available
2013-02-18 21:58:00.160    [DEBUG][7]    Scheduled Recording about to start maybe a candidate for moving to another tuner (different locator than another recording on same device)
2013-02-18 21:58:00.160    [DEBUG][7]    Existing:
<physical_channel>49</physical_channel>
2013-02-18 21:58:00.160    [DEBUG][7]    Required:
<physical_channel>48</physical_channel>
2013-02-18 21:58:00.160    [DEBUG][7]    Was allocated to capture source20
2013-02-18 21:58:00.166    [DEBUG][7]    Checking if multi-record possible...
2013-02-18 21:58:00.168    [DEBUG][7]    Found another available tuner for new recording. Now allocated to 30
2013-02-18 21:58:00.174    [DEBUG][7]    Recording successfully moved.

NRecord seems to understand that tuner 20 is busy on a different physical frequency, and moves the recording to tuner 30... except tuner 30 is busy recording 90210. I can't tell from the logs whether NRecord thinks tuner 30 isn't busy, just doesn't check, or if it thinks it's starting a multi-record on the same physical frequency (which it isn't). For it's part, NDigitalHost just does what NRecord tells it to do.

Clearly a bug.

[Handy.Man]

It may depends on the tuner driver not answering in time or not giving the correct response or not handling the request etc.

[sub]

I spent time today looking closely at these logs and trying to identify the cause, but I was unable to. In the attached update though, I've added more logging around the process of moving recordings to different tuners. This should hopefully help us pinpoint the cause of the problem.

Install the patch, and post the logs when the problem strikes again.

[johnsonx42]

ok, I was able to re-produce this fairly easily. I don't see much extra logging, just a note about which tuners it's checking. Perhaps log lines you don't see will tell you something.

(ignore everything in the log before 14:16:45.271; I got mixed up and my first attempt failed)

To make it happen, at 14:16:45.271 I started a recording "Cyberchase" on physical channel 92 and tuner 1534, then another recording "Baggage" on physical channel 91 and tuner 1536. Both recordings were set to end at 14:30. I then scheduled another recording "Divorce Court" at 14:30, on physical channel 89, which was provisionally set for tuner 1534 (verified using SQLite Spy). I set one minute pre- and post-padding on all recordings.

At 14:29, it wanted to start the recording "Divorce Court" on 1534, but correctly found that 1534 was busy. It looked for another tuner, and immediately decided that 1536 was available so it started the recording there on channel 89. 1536 of course was still busy recording "Baggage" on channel 91, so the "Baggage" recording was cut short by 2 minutes (1 minute of actual show, and 1 minute of requested padding). I have two other tuners capable of recording that show - analog tuner 1532 and digital tuner 1524.

edit: and just for reference, the "Baggage" recording is listed as being 14 minutes long in the Recordings list, but the actual recording is only 12 minutes long when played.

[totallhavoc]

I've installed the patch and will up some logs as soon as the issue happens again

[sub]

ok, I was able to re-produce this fairly easily. I don't see much extra logging, just a note about which tuners it's checking. Perhaps log lines you don't see will tell you something.

Yep, missing lines have helped point me to the potential problem area.

[sub]

I think I see what's happening. See if this patch helps.