DVR Schedule Optimization Frequency & Incorrect Recordings

Server Version#: 1.21.2.3918
Player Version#: 4.50.1
Tuner Make/Model: HDHomeRun Quatro
Guide/Lineup name:
Using XMLTV?:
Channel number/Name:

I’ve been using Plex DVR for about a month now and have been recording quite a bit. In general, things have been working great except for the random posters being applied to recorded episodes but it seems like that’s been an issue for a while and is yet to be fixed.

I’ve noticed several failed recordings around the times where I have conflicts identified in the DVR Schedule (due to more than 4 tuners required). I’ve been looking through the logs and noticed that the DVR Schedule Optimizer Routine (DVR:NewSchedule) is running several times an hour. Is this normal and is there any way to adjust this?

Jan 21, 2021 19:26:32.758 [10200] DEBUG - DVR:NewSchedule: Partitioning, step one, let's compute an absolute ordering.
Jan 21, 2021 19:30:30.661 [9240] DEBUG - DVR:NewSchedule: Partitioning, step one, let's compute an absolute ordering.
Jan 21, 2021 19:31:31.012 [8744] DEBUG - DVR:NewSchedule: Partitioning, step one, let's compute an absolute ordering.
Jan 21, 2021 19:56:02.520 [10436] DEBUG - DVR:NewSchedule: Partitioning, step one, let's compute an absolute ordering.

Sometimes it will optimize 6-10 times every hour. It seems to be doing everything right with finding conflicts before the shows actually run by assigning “Tuner -1” and throwing a warning:

Jan 21, 2021 19:56:02.520 [10436] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:00:00 and 2021-01-21 21:00:00 on channel 7.3: 'Chicago P.D. - E1 - Stepping Stone'
Jan 21, 2021 19:56:02.520 [10436] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:00:00 and 2021-01-21 20:30:00 on channel 4.1: 'Mr. Mayor - E4 - The Sac'
Jan 21, 2021 19:56:02.520 [10436] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:00:00 and 2021-01-21 20:30:00 on channel 7.1: 'Young Sheldon - E6 - Freshman Orientation and the Inventor of the Zipper'
Jan 21, 2021 19:56:02.520 [10436] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:00:00 and 2021-01-21 21:00:00 on channel 40.2: 'Quantum Leap - E16 - Freedom: November 22, 1970'
Jan 21, 2021 19:56:02.520 [10436] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:00:00 and 2021-01-21 21:00:00 on channel 31.5: 'Star Trek - E9 - The Tholian Web'
Jan 21, 2021 19:56:02.520 [10436] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:00:00 and 2021-01-21 20:30:00 on channel 21.2: 'Frasier - E20 - Cheerful Goodbyes'
Jan 21, 2021 19:56:02.520 [10436] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:30:00 and 2021-01-21 21:00:00 on channel 4.1: 'Superstore - E6 - Biscuit'
Jan 21, 2021 19:56:02.520 [10436] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:30:00 and 2021-01-21 21:00:00 on channel 21.2: 'Frasier - E21 - Frasier Has Spokane'

Jan 21, 2021 19:56:03.641 [10436] DEBUG -  DVR:NewSchedule: device 0 tuner 3 airing 0 between 2021-01-21 20:30:00 and 2021-01-21 21:00:00 on channel 4.1: 'Superstore - E6 - Biscuit'
Jan 21, 2021 19:56:03.641 [10436] DEBUG -  DVR:NewSchedule: device 0 tuner 2 airing 0 between 2021-01-21 20:00:00 and 2021-01-21 21:00:00 on channel 7.3: 'Chicago P.D. - E1 - Stepping Stone'
Jan 21, 2021 19:56:03.641 [10436] DEBUG -  DVR:NewSchedule: device 0 tuner 3 airing 0 between 2021-01-21 20:00:00 and 2021-01-21 20:30:00 on channel 4.1: 'Mr. Mayor - E4 - The Sac'
Jan 21, 2021 19:56:03.641 [10436] DEBUG -  DVR:NewSchedule: device 0 tuner 1 airing 0 between 2021-01-21 20:00:00 and 2021-01-21 20:30:00 on channel 7.1: 'Young Sheldon - E6 - Freshman Orientation and the Inventor of the Zipper'
Jan 21, 2021 19:56:03.641 [10436] DEBUG -  DVR:NewSchedule: device 0 tuner 0 airing 0 between 2021-01-21 20:00:00 and 2021-01-21 21:00:00 on channel 40.2: 'Quantum Leap - E16 - Freedom: November 22, 1970'
Jan 21, 2021 19:56:03.641 [10436] DEBUG -  DVR:NewSchedule: device -1 tuner -1 airing -1 between 2021-01-21 20:00:00 and 2021-01-21 21:00:00 on channel : 'Star Trek - E9 - The Tholian Web'
Jan 21, 2021 19:56:03.641 [10436] DEBUG -  DVR:NewSchedule: device -1 tuner -1 airing -1 between 2021-01-21 20:00:00 and 2021-01-21 20:30:00 on channel : 'Frasier - E20 - Cheerful Goodbyes'
Jan 21, 2021 19:56:03.641 [10436] DEBUG -  DVR:NewSchedule: device 0 tuner 1 airing 0 between 2021-01-21 20:30:00 and 2021-01-21 21:00:00 on channel 21.2: 'Frasier - E21 - Frasier Has Spokane'

Jan 21, 2021 19:56:03.646 [10436] DEBUG - [Grabber/c1a474876fdf2ce7506362b2df35bdf2a6f7195a] Scheduling 'Superstore - E6 - Biscuit' for timed grab at 2021-01-21 20:30:00 (in 2037 seconds)
Jan 21, 2021 19:56:03.646 [10436] DEBUG - [Grabber/4bb16d6a0922e5a84393c556a2a160a214c44967] Scheduling 'Chicago P.D. - E1 - Stepping Stone' for timed grab at 2021-01-21 20:00:00 (in 237 seconds)
Jan 21, 2021 19:56:03.646 [10436] DEBUG - [Grabber/e1447ca476c641fc3c7a5d80b6169dfc5514d45d] Scheduling 'Mr. Mayor - E4 - The Sac' for timed grab at 2021-01-21 20:00:00 (in 237 seconds)
Jan 21, 2021 19:56:03.646 [10436] DEBUG - [Grabber/efc2b418c38a23f7dea91f80d57507ff154b2807] Scheduling 'Young Sheldon - E6 - Freshman Orientation and the Inventor of the Zipper' for timed grab at 2021-01-21 20:00:00 (in 237 seconds)
Jan 21, 2021 19:56:03.646 [10436] DEBUG - [Grabber/ebde1fd024b5ebedd0568515e7a24f65ff55e305] Scheduling 'Quantum Leap - E16 - Freedom: November 22, 1970' for timed grab at 2021-01-21 20:00:00 (in 237 seconds)
Jan 21, 2021 19:56:03.646 [10436] DEBUG - Grabber: Operation for 'Star Trek - E9 - The Tholian Web' on channel 31.5 completed with status error (The recording conflicts with other recordings)
Jan 21, 2021 19:56:03.646 [10436] WARN - DVR:NewSchedule: Couldn't schedule recording (error: The recording conflicts with other recordings).
Jan 21, 2021 19:56:03.646 [10436] DEBUG - Grabber: Operation for 'Frasier - E20 - Cheerful Goodbyes' on channel 21.2 completed with status error (The recording conflicts with other recordings)
Jan 21, 2021 19:56:03.646 [10436] WARN - DVR:NewSchedule: Couldn't schedule recording (error: The recording conflicts with other recordings).

Screenshot 2021-01-21 135714

Young Sheldon has a -1 minute modifier which is why it doesn’t find a conflict Quantum Leap, Chicago PD, Frasier and Superstore…so that’s all good

I’ve noticed, however, that sometimes the optimize routine will run after the block of shows start (After 8PM in this case) and it will then try to record the conflicting shows even though there are no tuners left (it just records nothing)…the .grab folders are empty.

Jan 21, 2021 20:09:36.811 [8036] DEBUG - DVR:NewSchedule: Partitioning, step one, let's compute an absolute ordering.

Jan 21, 2021 20:09:36.811 [8036] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:00:00 and 2021-01-21 21:00:00 on channel 31.5: 'Star Trek - E9 - The Tholian Web'
Jan 21, 2021 20:09:36.811 [8036] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:00:00 and 2021-01-21 20:30:00 on channel 21.2: 'Frasier - E20 - Cheerful Goodbyes'
Jan 21, 2021 20:09:36.811 [8036] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:30:00 and 2021-01-21 21:00:00 on channel 4.1: 'Superstore - E6 - Biscuit'
Jan 21, 2021 20:09:36.811 [8036] DEBUG -  DVR:NewSchedule: Between 2021-01-21 20:30:00 and 2021-01-21 21:00:00 on channel 21.2: 'Frasier - E21 - Frasier Has Spokane'

Jan 21, 2021 20:09:37.829 [8036] DEBUG -  DVR:NewSchedule: device 0 tuner 3 airing 0 between 2021-01-21 20:30:00 and 2021-01-21 21:00:00 on channel 4.1: 'Superstore - E6 - Biscuit'
Jan 21, 2021 20:09:37.829 [8036] DEBUG -  DVR:NewSchedule: device 0 tuner 2 airing 0 between 2021-01-21 20:00:00 and 2021-01-21 21:00:00 on channel 31.5: 'Star Trek - E9 - The Tholian Web'
Jan 21, 2021 20:09:37.829 [8036] DEBUG -  DVR:NewSchedule: device 0 tuner 3 airing 0 between 2021-01-21 20:00:00 and 2021-01-21 20:30:00 on channel 21.2: 'Frasier - E20 - Cheerful Goodbyes'
Jan 21, 2021 20:09:37.829 [8036] DEBUG -  DVR:NewSchedule: device 0 tuner 1 airing 0 between 2021-01-21 20:30:00 and 2021-01-21 21:00:00 on channel 21.2: 'Frasier - E21 - Frasier Has Spokane'

Jan 21, 2021 20:09:37.834 [8036] DEBUG - [Grabber/c1a474876fdf2ce7506362b2df35bdf2a6f7195a] Scheduling 'Superstore - E6 - Biscuit' for timed grab at 2021-01-21 20:30:00 (in 1223 seconds)
Jan 21, 2021 20:09:37.834 [8036] DEBUG - [Grabber/e64a7d2bff8597397bdcd15e6e2350b862bfe2c5] Starting grab immediately for 'Star Trek - E9 - The Tholian Web' on channel 31.5 and we're 577 seconds in already.
Jan 21, 2021 20:09:37.834 [8036] DEBUG - [Grabber/36b286d41a7b44af2a3d4502c64936c2267c87b5] Starting grab immediately for 'Frasier - E20 - Cheerful Goodbyes' on channel 21.2 and we're 577 seconds in already.
Jan 21, 2021 20:09:37.834 [8036] DEBUG - [Grabber/348c3ea74773a034b6bebf9dc232925425cb4d1f] Scheduling 'Frasier - E21 - Frasier Has Spokane' for timed grab at 2021-01-21 20:30:00 (in 1223 seconds)

It thinks there are tuners available because it’s not taking into account that there are 4 tuners already in use from 8:00 - 8:30 and tries to record Star Trek and Frasier from 8:00-8:30 as well.

Screenshot 2021-01-21 201243

Then it tries to record Superstore at 8:30 but all of the tuners are taken and I get the last 30 minutes of Star Trek instead…which shouldn’t have recorded in the first place.

Jan 21, 2021 20:30:09.267 [9820] DEBUG - DVR:NewSchedule: Scheduled an operation 'Superstore - E6 - Biscuit' on channel 4.1 on device 0 tuner 0 between 2021-01-21 20:30:00 and 2021-01-21 21:00:00

And it thinks it’s recording:
Screenshot 2021-01-21 203631

But it’s really recording the last half of Star Trek on 31.5 and nothing on 4.1.

Screenshot 2021-01-21 204201

Is there any way to keep the DVR:NewSchedule routine from running so often? I’d be fine with it running only when the EPG is updated or when I add a show to the DVR queue. Or the routine needs be to modified to take into account tuners currently in use. But either way, I’m not sure why it’s running so often.

If the DVR scheduler is redoing the logic regularly and its conclusions change as some programs scheduled time completes, this would mean that you would never know for sure in advance what shows are really going to record. If you’re really onto something here, it could possibly explain a lot of posts about scheduling frustrations that I’ve seen for the past 2 years.

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.