Emby doesn't record after it wakes from sleep.

[Noel-M 11]

My server sleeps in the daytime, and records TV at night.
Often, the first scheduled record of the evening is missing or starts late.

I have captured such an event - log files attached.

The first scheduled record is 'Mastermind' at 18:00.  The log shows ...

• 2021-05-25 16:21:51.760 Info LiveTV: Creating recording timer for 14c0223c0b13b68a699f3ed4c7e40c1f, Mastermind Australia. Timer will fire in 93.137321125 minutes

That is, it will record at 17:55.  The machine goes to sleep and does wake at 17:50.  In the log we see ...

• 2021-05-25 17:50:10.477 Debug NetworkManager: Detected local ip addresses: 192.168.0.5, 127.0.0.1, fe80::3d74:d41:c15f:3386%14, ::1

So, Emby is active but does not record.  The next entries are at 18:21 and the program has been missed.

Eventually it logs ...

• 2021-05-25 18:21:42.508 Info LiveTV: Recording timer fired for Mastermind Australia.

This recording was missed.  All further recordings for the evening are perfect.

embyserver.txt hardware_detection-63757556519.txt embyserver-63757556374.txt

[Noel-M 11]

This is still a problem for me.  It seems crazy that I need to manually use WIndows Task Scheduler to wake the server and fire up Emby 30 minutes before by first scheduled recording.  My other choice is to leave the server running 24 hours a day - and that's not my preference.  It's only required for about 8 hours.  Did I log this problem in the correct area ?

[Luke 42080]

Hi there, apologies for the delay. We're looking into this.

[Noel-M 11]

This is still a problem for me.   Here are extracts from a recent Emby log ...

* A recording is scheduled

2021-10-26 11:40:48.901 Info LiveTV: Creating recording timer for 942e4cc94374460bb2731385e1e4e2fc, PBS Newshour. Timer will fire in 74.18498152333333 minutes

* that is, timer will fire at 12:55
* the machine goes to sleep

* Then a single line as the machine wakes 5 minutes before recording is due to start ...  (so Emby is alive)

2021-10-26 12:50:16.497 Debug NetworkManager: Detected local ip addresses: 192.168.0.5, 127.0.0.1, fe80::3d74:d41:c15f:3386%14, ::1

* but no recording starts, and no other logging.  The machine goes back to sleep
* It is manually woken at 16:16, and Emby realises that it missed the program.

2021-10-26 16:16:36.603 Info LiveTV: Recording timer fired for PBS Newshour.
2021-10-26 16:16:36.603 Warn LiveTV: Recording timer fired for updatedTimer PBS Newshour, Id: 942e4cc94374460bb2731385e1e4e2fc, but the program has already ended.

[ebr 16185]

7 hours ago, Noel-M said:

but no recording starts, and no other logging.  The machine goes back to sleep

Hi.  Exactly when did it go back to sleep?

[Noel-M 11]

From system event log:   1:00:11 PM

TV program started at 1:00 PM and I should have started recording 5 minutes before that.

I think the only time Emby gets it correct is if it refreshes the timers in the 10 minutes after wake up and before program start.  That is, the procedure that logs this line ...

2021-10-26 11:40:48.901 Info LiveTV: Creating recording timer for 942e4cc94374460bb2731385e1e4e2fc, PBS Newshour. Timer will fire in 74.18498152333333 minutes

If that procedure occurs during the program that should have been recorded, the recording will start and I may have a fraction of the program recorded.

PS:  I have win10 System unattended sleep timeout set to 10 minutes, which is larger that the default value.  All recordings should begin 5 minutes after wake up.

[ebr 16185]

3 minutes ago, Noel-M said:

From system event log:   1:00:11 PM

So your sleep timer is 5 minutes?  I would try setting that to 10 and see if this issue clears up.

[Noel-M 11]

No my sleep timer is 30 minutes.

My unattended sleep timer is 10 minutes (this one introduced in windows 10 - the machine sleeps in 10 minutes instead of 30 if nothing happens after it wakes up.)

I have Emby set to start recording 5 minutes before program start - and Emby creates a windows scheduler item 5 minutes before that.  So, something should happen 5 minutes after wake up.  If nothing happens in 10 minutes the machine resumes sleep.

 

[Noel-M 11]

I suspect that Emby needs to perform a Refresh Guide Data after it wakes to get back in sync.   My guide provider only updates the guide once a day.  I have a refresh sheduled every 60 minutes.  Of course, the refresh interval needs to be greater than the sleep timeout else the machine would never sleep.

Summary:

* At 12:50 an Emby scheduled task runs which wakes the machine.

C:\Users\Noel\AppData\Roaming\Emby-Server\system\EmbyServer.exe  C:\Users\Noel\AppData\Roaming\Emby-Server\system\EmbyServer.dll -noautorunwebapp

*Emby logs the following  line, but does nothing else ... 

2021-10-26 12:50:16.497 Debug NetworkManager: Detected local ip addresses: 192.168.0.5, 127.0.0.1, fe80::3d74:d41:c15f:3386%14, ::1

( I suspect it needs to refresh guide data and reset recored timers)

* After 10 minutes of nothingness, at 1:00 PM the unattended sleep timout fires and the machine returns to sleep state.

[Luke 42080]

Hi, when the machine wakes, Emby Server needs to adjust all of it's internal timers to ensure they fire at the correct time. The issue is that when the machine wakes, Emby Server is not being notified of the wake by the .net core runtime like it should be. We're going to be updating to a newer major version of the runtime soon so I'm hoping that will help with this. If not then we'll have to explore workarounds.

[Luke 42080]

@Noel-M if you wouldn't mind trying this with the beta server, it has the .net core 6.0 runtime, which could make a difference. Thanks !

[Noel-M 11]

Sorry, still doesn't work.  Logfile attached but here are the highlights ...

* Request recording of 'Parliament Question Time'.  Program starts at 14:00, recording starts at 13:55, task manager task fires at 13:50

2021-11-23 11:33:33.405 Info LiveTV: Creating recording timer for 38b5c0ef715a1fc91f2cf821a9bac271, Media Watch. Timer will fire in 9234.44324204 minutes
2021-11-23 11:33:33.434 Info LiveTV: Creating recording timer for ca74633395d3416ba89459a4b5d41c8a, Parliament Question Time - Live. Timer will fire in 141.44275824666667 minutes

* Machine goes to sleep at 13:29.  Emby logs it.

2021-11-23 13:29:22.723 Info SystemEvents: SystemEvents_PowerModeChanged Suspend

* Machine wakes at 13:50.  Emby logs it.

2021-11-23 13:50:21.208 Debug NetworkManager: Detected local ip addresses: 192.168.0.5, 127.0.0.1, fe80::3d74:d41:c15f:3386%14, ::1

* Program starts at 14:00, but Emby is not recording.

* Emby notes the machine is awake at 14:13 and starts recording, but has missed the first 15 minutes of the show.

2021-11-23 14:13:48.463 Info SystemEvents: SystemEvents_PowerModeChanged Resume

2021-11-23 14:13:48.463 Info LibraryMonitor: Stopping directory watching for path F:\RecordedTV

2021-11-23 14:13:48.467 Info LiveTV: Getting media sources for recording from channel 84423 84423
2021-11-23 14:13:48.471 Info LiveTV: Opening live stream for recording from channel 84423 84423
2021-11-23 14:13:48.471 Info LiveTvManager: Opening channel stream from Emby, external channel Id: hauppauge_48
2021-11-23 14:13:48.471 Info LiveTV: Streaming Channel hauppauge_48
 

embyserver - Copy.txt

[Noel-M 11]

Another attempt with the beta.  I tried  to record "ABC News at Noon".  The program starts at noon, recording should start at 11:55, wake event should occur at 11:50
Log file attached, here are the highlights ...

* Machine goes to sleep at 11:00
2021-11-24 11:00:37.881 Info SystemEvents: SystemEvents_PowerModeChanged Suspend

* Machine wakes correctly at 11:50, Emby logs but does nothing else
2021-11-24 11:50:10.718 Debug NetworkManager: Detected local ip addresses: 192.168.0.5, 127.0.0.1, fe80::3d74:d41:c15f:3386%14, ::1

* At 12:43 Emby recognises the record timer for 'News At Noon' (which is now over)
2021-11-24 12:43:44.808 Info LiveTV: Recording timer fired for ABC News At Noon.

* At 13:03 Emby finally processes the System Resume Event notification (the machine has been awake for 73 minutes)
2021-11-24 13:03:19.315 Info SystemEvents: SystemEvents_PowerModeChanged Resume
2021-11-24 13:03:19.318 Warn LiveTV: Recording timer fired for updatedTimer ABC News At Noon, Id: a6fe8e808e264597bbb9ab280cc17a50, but the program has already ended.

embyserver - Copy.txt

[rbjtech 5284]

In the Windows scheduler - you should see the recordings listed as 'Emby Recording X' - is it worth posting screen shots from those tabs to see if there is anything obviously wrong ?

My machine never sleeps, so I don't have this issue - but I was looking into what it actually does using the schedule....

a) - My 'General' section is set to only Run when a user is logged in - I presume when your machine 'wakes' it is still logged in ?  Try setting to use a service account instead ?

b) - My 'Actions' section is an interesting one - It works but it looks very odd -

program is embyserver.exe - that's fine - but arguments are -

"C:\Emby-Server\system\EmbyServer.dll C:\Emby-Server\system\EmbyServer.dll C:\Emby-Server\system\EmbyServer.dll C:\Emby-Server\system\EmbyServer.dll C:\Emby-Server\system\EmbyServer.dll C:\Emby-Server\system\EmbyServer.dll C:\Emby-Server\system\EmbyServer.dll C:\Emby-Server\system\EmbyServer.dll -noautorunwebapp"

is that correct ?  Why all the same arguments ?

c) My 'Conditions' are - Power, all 3 ticked

d) My 'Settings' - Run task as soon as possible after a schedule is missed (should be yes?), retry should probably be yes as well ?

 

Maybe worth having a play to modify this yourself, and if it solves the issue - then emby may need to change some of it's wake settings ..

 

Edited November 24, 2021 by rbjtech

[Noel-M 11]

There is no problem with the machine waking. Attached is a report from System Power State.

Emby always logs something after the wake 
2021-11-24 11:50:10.718 Debug NetworkManager: Detected local ip addresses: 192.168.0.5, 127.0.0.1, fe80::3d74:d41:c15f:3386%14, ::1

.. but does not acknowledge the PowerModeChanged event immediately.  Ofter it handles the event after the program that was to be recorded has finished.

My user is always logged in.  That's not my preference, but Emby generates the scheduled task with the "Run when user logged in" checked.  This prevents me from waking Emby as a system service.

[Luke 42080]

@Noel-M there has never actually been an issue with the system waking. The issue is that Emby Server does not get notified of the wake by the .net core runtime, and therefore never adjusts it's internal recording schedules.

I do have an idea for a workaround though. Would you mind repeating the same test you've done, but first enabling debug logging under the server Logs menu? Thanks !

[Noel-M 11]

Debug enabled.

The machine goes to sleep at 01:30 am.  I have scheduled a recording of "Home Shopping" at 03:00 am on 8th dec.
My log file rotates at 0:00 - so I have included the log file for 7th as well.

I haven't seen this behaviour before.  In the log file from the 7th I see the recording scheduled.
2021-12-07 23:58:18.680 Info LiveTV: Creating recording timer for a2cbf4f0b70e4730bf311291b582a902, Home Shopping. Timer will fire in 176.68865920666667 minutes

The system power report shows the machine sleeping and waking (and the reason for waking)

The logfile from the 8th has no mention of 'Home Shopping'.
The program was not recorded.

embyserver-63774518400.txt embyserver.txt

[Luke 42080]

OK I see a workaround. As you can see, we're getting notified of the Resume event much later than expected, and this is the reason for the problem.

But when the system actually wakes, there are also network change events firing, so we can also listen to those. Thanks.

[Noel-M 11]

4.7.0.19 looks good.   No misses so far.  Thanks for the effort.

[Luke 42080]

Thanks for the feedback.