Recordings Skipped

[chairmanmao]

I'm having problems with Sage v9, under the Fall Creators Update of Windows 10 64 bit (1709), not reliably waking up to record shows. Meaning some shows are being recorded and some are not.

In trying to diagnose this, I'd like to search the log files for the recording events. But I'm not sure how they are tagged in the log files. Does anyone know what the format of a "recording XXXX" event in the logs?

[wnjj]

Originally Posted by chairmanmao

I'm having problems with Sage v9, under the Fall Creators Update of Windows 10 64 bit (1709), not reliably waking up to record shows. Meaning some shows are being recorded and some are not.

In trying to diagnose this, I'd like to search the log files for the recording events. But I'm not sure how they are tagged in the log files. Does anyone know what the format of a "recording XXXX" event in the logs?

Look for the "Seeker@" lines.

[chairmanmao]

In my ongoing effort to figure out why Sage has suddenly stopped recording shows that its recording schedule says should be recorded, I've been looking over the log file.

Here's an example of what I'm seeing:

Fri 11/3 8:38:27.378 [Seeker@14843fe] Seeker adding new Encoder: DCT-HDHomeRun Prime Tuner 1315E450-0 on 127.0.0.1:9000
Fri 11/3 8:38:27.392 [Seeker@14843fe] Seeker adding new Encoder: DCT-HDHomeRun Prime Tuner 1315E450-1 on 127.0.0.1:9000
Fri 11/3 8:38:27.402 [Seeker@14843fe] Seeker adding new Encoder: DCT-HDHomeRun Prime Tuner 131F5955-0 on 127.0.0.1:9000
Fri 11/3 8:38:27.410 [Seeker@14843fe] Seeker adding new Encoder: DCT-HDHomeRun Prime Tuner 131F5955-2 on 127.0.0.1:9000
Fri 11/3 8:38:27.417 [Seeker@14843fe] Seeker adding new Encoder: DCT-HDHomeRun Prime Tuner 131F5955-1 on 127.0.0.1:9000
Fri 11/3 8:38:27.425 [Seeker@14843fe] Seeker adding new Encoder: DCT-HDHomeRun Prime Tuner 1315E450-2 on 127.0.0.1:9000
Fri 11/3 8:38:27.435 [Seeker@14843fe] MARK 1 currRecord=null enc=DCT-HDHomeRun Prime Tuner 1315E450-0 on 127.0.0.1:9000 clients=[] ir=false

Fri 11/3 8:38:27.442 [Seeker@14843fe] Seeker in AUTOMATIC mode nextRecord=A[45621450,45620123,"House Hunters",87317@1103.12:00,30,T] nextTTA=12092566
Fri 11/3 8:38:27.454 [Seeker@14843fe] newRecord=null
Fri 11/3 8:38:27.460 [Seeker@14843fe] NOTHING TO RECORD FOR NOW...
Fri 11/3 8:38:27.468 [Seeker@14843fe] MARK 1 currRecord=null enc=DCT-HDHomeRun Prime Tuner 1315E450-1 on 127.0.0.1:9000 clients=[] ir=false
Fri 11/3 8:38:27.478 [Seeker@14843fe] Seeker in AUTOMATIC mode nextRecord=A[45511677,45507174,"House Hunters",87317@1103.22:00,30,T] nextTTA=48092566
Fri 11/3 8:38:27.489 [Seeker@14843fe] newRecord=null
Fri 11/3 8:38:27.502 [Seeker@14843fe] NOTHING TO RECORD FOR NOW...
Fri 11/3 8:38:27.510 [Seeker@14843fe] MARK 1 currRecord=null enc=DCT-HDHomeRun Prime Tuner 131F5955-0 on 127.0.0.1:9000 clients=[] ir=false
Fri 11/3 8:38:27.518 [Seeker@14843fe] Seeker in AUTOMATIC mode nextRecord=null nextTTA=9223372036854775807
Fri 11/3 8:38:27.530 [Seeker@14843fe] newRecord=null
Fri 11/3 8:38:27.539 [Seeker@14843fe] NOTHING TO RECORD FOR NOW...
Fri 11/3 8:38:27.545 [Seeker@14843fe] MARK 1 currRecord=null enc=DCT-HDHomeRun Prime Tuner 131F5955-2 on 127.0.0.1:9000 clients=[] ir=false
Fri 11/3 8:38:27.553 [Seeker@14843fe] Seeker in AUTOMATIC mode nextRecord=null nextTTA=9223372036854775807
Fri 11/3 8:38:27.565 [Seeker@14843fe] newRecord=null
Fri 11/3 8:38:27.578 [Seeker@14843fe] NOTHING TO RECORD FOR NOW...
Fri 11/3 8:38:27.591 [Seeker@14843fe] MARK 1 currRecord=null enc=DCT-HDHomeRun Prime Tuner 131F5955-1 on 127.0.0.1:9000 clients=[] ir=false
Fri 11/3 8:38:27.597 [Seeker@14843fe] Seeker in AUTOMATIC mode nextRecord=null nextTTA=9223372036854775807
Fri 11/3 8:38:27.605 [Seeker@14843fe] newRecord=null
Fri 11/3 8:38:27.680 [Seeker@14843fe] NOTHING TO RECORD FOR NOW...
Fri 11/3 8:38:27.688 [Seeker@14843fe] MARK 1 currRecord=null enc=DCT-HDHomeRun Prime Tuner 1315E450-2 on 127.0.0.1:9000 clients=[] ir=false
Fri 11/3 8:38:27.695 [Seeker@14843fe] Seeker in AUTOMATIC mode nextRecord=A[45576942,41341319,"Fixer Upper",87317@1107.21:00,60,T] nextTTA=393692566
Fri 11/3 8:38:27.707 [Seeker@14843fe] newRecord=null
Fri 11/3 8:38:27.715 [Seeker@14843fe] NOTHING TO RECORD FOR NOW...

If I'm reading this correctly, the next two shows scheduled to be recorded are:

- House Hunters on 11/3 at noon
- House Hunters on 11/3 at 10 PM
- Fixer Upper on 11/7 at 9 PM

Yet when I look at the recording schedule through the Sage UI, in addition to those three shows, there are numerous other shows that are targeted to be recorded:

- HGTV Urban Oasis 2017 on 11/3 at 1 PM
- House Hunters on 11/3 at 2:30 PM
- House Hunters on 11/3 at 3:30 PM
- Marvel's Inhumans on 11/3 at 9 PM

and a bunch more.

Any ideas what's going on? Or, better yet, how to fix it?

[JustFred]

Have you tried disabling Sleep mode? That might help to determine whether the issue is "Sage doesn't schedule recordings" vs. "Win10 doesn't wake from sleep".

[chairmanmao]

Worth trying, Fred. But I don't see how Windows not waking would lead to what I saw in the logs, which seems more like whatever part of Sage schedules the recordings not being aware of what it's supposed to record.

But I'll give it a try. Worth burning up a few days of electricity, just to be sure.

[wnjj]

Originally Posted by chairmanmao

Worth trying, Fred. But I don't see how Windows not waking would lead to what I saw in the logs, which seems more like whatever part of Sage schedules the recordings not being aware of what it's supposed to record.

But I'll give it a try. Worth burning up a few days of electricity, just to be sure.

The log segment you showed is only showing the next recording for those tuners. I'm assuming the "missing" ones are scheduled to record on the tuner that is scheduled to record "House Hunters" since it's over at 12:30.

What do you see in the "parallel schedule" for upcoming recordings and which tuners they're on?

[wnjj]

To find the complete schedule in the logs, search for "Scheduler.updateSchedule() called". Depending upon when it last ran, you may have to look in sagetv_1.txt or 2 & 3.

Then inside the brick of airings that you should find "schedules={" followed by each of your tuners and their airings. For each tuner there will be a bunch of candidate shows, followed by a "MustSee=" section which has a list of airings that tuner will record in the future.

[chairmanmao]

Originally Posted by wnjj

The log segment you showed is only showing the next recording for those tuners. I'm assuming the "missing" ones are scheduled to record on the tuner that is scheduled to record "House Hunters" since it's over at 12:30.

What do you see in the "parallel schedule" for upcoming recordings and which tuners they're on?

Good point, thanx. I had assumed, incorrectly, that all tuners would get utilized to cover all the scheduled shows. I appreciate you pointing out the other way they can be, and are, scheduled.

[UgaData]

Sage has its own sleep settings besides the Windows setting. I think the default is to wake the PC up 2 or 3 minutes prior to the start of a recording, I usually set mine to 5 minutes.

In the past, I have had issues with internal tuner cards causing problems when waking Windows from sleep. In my case it was an issue between the tuner card and the motherboard. The setup still worked most of the time but I needed to reboot the system every so often, about a week and a half between reboots.

[chairmanmao]

Originally Posted by wnjj

To find the complete schedule in the logs, search for "Scheduler.updateSchedule() called". Depending upon when it last ran, you may have to look in sagetv_1.txt or 2 & 3.

Then inside the brick of airings that you should find "schedules={" followed by each of your tuners and their airings. For each tuner there will be a bunch of candidate shows, followed by a "MustSee=" section which has a list of airings that tuner will record in the future.

Thanx for the tip. I looked through the block and was wondering if you (or someone else) knew enough about its structure to answer some additional questions:

- There are several ManualRecord entries at the start of the block, but I don't recall ever setting them

- The entry for each HDHomeRun Prime tuner is quite long, and includes a lot of shows that I've never scheduled to be recorded and which, so far as I recall, I've never seen actually recorded. Do you know what those "spurious" shows mean?

[wnjj]

Originally Posted by chairmanmao

Thanx for the tip. I looked through the block and was wondering if you (or someone else) knew enough about its structure to answer some additional questions:

- There are several ManualRecord entries at the start of the block, but I don't recall ever setting them

- The entry for each HDHomeRun Prime tuner is quite long, and includes a lot of shows that I've never scheduled to be recorded and which, so far as I recall, I've never seen actually recorded. Do you know what those "spurious" shows mean?

Mine has the same..extra stuff I never picked and some super old ones I did. I'm guessing the extras are part of the intelligent recording system but with it disabled, they don't actually record. The "MustSee" looks to be the actual list.

[chairmanmao]

Originally Posted by wnjj

Mine has the same..extra stuff I never picked and some super old ones I did. I'm guessing the extras are part of the intelligent recording system but with it disabled, they don't actually record. The "MustSee" looks to be the actual list.

Thanx, that lets me parse that huge block! Which confirms that Sage is correctly forecasting what needs to be recorded.

I also discovered that Sage logs failures to create wait timers (which are done under windows via calls to CreateWaitTimer() and SetWaitTimer()). I don't see any such log messages in my files, which I think pretty much confirms this is a problem with Windows. Or at least outside of Sage