Understanding how Nrecord.exe controls sleep / wake?

[jksmurf]

I'm trying to troubleshoot my PC waking up immediately after going to sleep (after 1 hr 5mins).

I looked at the Event Viewer logs filtered on "Power Troubleshooter" (in logs) and there are a number of events (example below) referring to NRecord.exe which occur after the completion of the wake to record. I also know that PostProcessing.bat calls comskip.exe.

Code:

The system has returned from a low power state.


Sleep Time: ‎2015‎-‎10‎-‎03T22:09:32.453496600Z
Wake Time: ‎2015‎-‎10‎-‎03T22:10:33.966870600Z


Wake Source: Timer - NRecord.exe

Is it likely that what is logged as NRecord.exe is actually comskip.exe, called from NRecord.exe via PostProcessing.bat but logged as coming from NRecord.exe in EventViewer?

If not then any suggestions why NRecord.exe would keep waking the PC every 3 or 4 mins, after it has finished recording?
Finally, what can I do to avoid this behaviour (Server is in the bedroom so is quite sensitive to WAF...).

k.

[sub]

If you search the nrecord.log for "Requesting wake up for", you'll see the list of times NextPVR has requested that Windows be awake, and what it is waking for.

2015-10-04 20:31:02.248 [DEBUG][11] Requesting wake up for 'EPGWAKEUP' at 10/5/2015 9:30 AM
...
2015-10-04 20:31:02.467 [DEBUG][10] Requesting wake up for 'RecordingOID7587' at 10/4/2015 11:28 PM

[jksmurf]

OK, I'll have a look at that when I get home and get back to you. The thing is that there were only two recordings (IIRC) and the last was a wake-up request at around 2:45 am, so I was wondering why NRecord would still be logged as the program asking for wake events, well after theevent (so to speak).

k.

[sub]

You'll have to check the logs for info about what times NextPVR has asked Windows to be awake.

After each EPG update, it'll schedule the wake up for the next night, and for any recordings scheduled.

[jksmurf]

sub

OK I looked at the logs, there is no way there is as many wake events scheduled as there are wake events attributed to NRecord.exe in the Windows System logs.
Something calls the Wakeup.bat script after "Recording service noted the system was resuming..." and it cycles around that and keeps waking the PC, which promptly falls asleep ~3 mins later, it seems?

Code:

2015-10-05 01:47:00.492    [DEBUG][10]    Starting: C:\Users\Public\NPVR\Scripts\PostProcessing.bat "D:\GBPVRVids\Rugby World Cup 2015\Rugby World Cup 2015_20151004_23300145.ts" 671 7587 1531 "Rugby World Cup 2015"
2015-10-05 02:52:45.893    [DEBUG][17]    Resuming...
2015-10-05 02:52:46.401    [DEBUG][6]    cycling MVP servers
2015-10-05 02:52:52.339    [DEBUG][10]    Recording service noted the system was resuming...
2015-10-05 02:52:56.483    [DEBUG][10]    Starting: C:\Users\Public\NPVR\Scripts\Wakeup.bat
2015-10-05 02:52:56.541    [DEBUG][6]    Starting MVP server 0
2015-10-05 02:52:57.418    [DEBUG][10]    C:\Users\Public\NPVR\Scripts\Wakeup.bat has exited
2015-10-05 02:56:12.889    [DEBUG][17]    Resuming...
2015-10-05 02:56:13.772    [DEBUG][6]    cycling MVP servers
2015-10-05 02:56:13.773    [DEBUG][6]    Starting MVP server 0
2015-10-05 02:56:20.315    [DEBUG][10]    Recording service noted the system was resuming...
2015-10-05 02:56:20.315    [DEBUG][10]    Starting: C:\Users\Public\NPVR\Scripts\Wakeup.bat
2015-10-05 02:56:23.704    [DEBUG][10]    C:\Users\Public\NPVR\Scripts\Wakeup.bat has exited
2015-10-05 02:59:41.896    [DEBUG][37]    Resuming...
2015-10-05 02:59:42.771    [DEBUG][6]    cycling MVP servers
2015-10-05 02:59:42.772    [DEBUG][6]    Starting MVP server 0
2015-10-05 02:59:49.257    [DEBUG][10]    Recording service noted the system was resuming...
2015-10-05 02:59:49.257    [DEBUG][10]    Starting: C:\Users\Public\NPVR\Scripts\Wakeup.bat
2015-10-05 02:59:52.837    [DEBUG][10]    C:\Users\Public\NPVR\Scripts\Wakeup.bat has exited
2015-10-05 03:03:10.891    [DEBUG][17]    Resuming...
2015-10-05 03:03:11.978    [DEBUG][6]    cycling MVP servers
2015-10-05 03:03:11.978    [DEBUG][6]    Starting MVP server 0
2015-10-05 03:03:18.255    [DEBUG][10]    Recording service noted the system was resuming...
2015-10-05 03:03:18.255    [DEBUG][10]    Starting: C:\Users\Public\NPVR\Scripts\Wakeup.bat
2015-10-05 03:03:21.639    [DEBUG][10]    C:\Users\Public\NPVR\Scripts\Wakeup.bat has exited
2015-10-05 03:06:39.908    [DEBUG][17]    Resuming...
2015-10-05 03:06:40.859    [DEBUG][6]    cycling MVP servers
2015-10-05 03:06:40.859    [DEBUG][6]    Starting MVP server 0
2015-10-05 03:06:47.136    [DEBUG][10]    Recording service noted the system was resuming...
2015-10-05 03:06:47.136    [DEBUG][10]    Starting: C:\Users\Public\NPVR\Scripts\Wakeup.bat
2015-10-05 03:06:50.732    [DEBUG][10]    C:\Users\Public\NPVR\Scripts\Wakeup.bat has exited
2015-10-05 03:10:07.910    [DEBUG][9]    Resuming...
2015-10-05 03:10:09.114    [DEBUG][6]    cycling MVP servers
2015-10-05 03:10:09.114    [DEBUG][6]    Starting MVP server 0
2015-10-05 03:10:15.299    [DEBUG][10]    Recording service noted the system was resuming...
2015-10-05 03:10:15.299    [DEBUG][10]    Starting: C:\Users\Public\NPVR\Scripts\Wakeup.bat
2015-10-05 03:10:18.805    [DEBUG][10]    C:\Users\Public\NPVR\Scripts\Wakeup.bat has exited
2015-10-05 03:13:36.892    [DEBUG][9]    Resuming...
2015-10-05 03:13:37.769    [DEBUG][6]    cycling MVP servers
2015-10-05 03:13:37.770    [DEBUG][6]    Starting MVP server 0
2015-10-05 03:13:43.986    [DEBUG][10]    Recording service noted the system was resuming...
2015-10-05 03:13:43.986    [DEBUG][10]    Starting: C:\Users\Public\NPVR\Scripts\Wakeup.bat
2015-10-05 03:13:47.845    [DEBUG][10]    C:\Users\Public\NPVR\Scripts\Wakeup.bat has exited
2015-10-05 03:17:04.894    [DEBUG][39]    Resuming...
2015-10-05 03:17:06.175    [DEBUG][6]    cycling MVP servers
2015-10-05 03:17:06.175    [DEBUG][6]    Starting MVP server 0
2015-10-05 03:17:12.260    [DEBUG][10]    Recording service noted the system was resuming...
2015-10-05 03:17:12.260    [DEBUG][10]    Starting: C:\Users\Public\NPVR\Scripts\Wakeup.bat
2015-10-05 03:17:15.711    [DEBUG][10]    C:\Users\Public\NPVR\Scripts\Wakeup.bat has exited
2015-10-05 03:20:33.906    [DEBUG][41]    Resuming...
2015-10-05 03:20:35.148    [DEBUG][6]    cycling MVP servers
2015-10-05 03:20:35.148    [DEBUG][6]    Starting MVP server 0
2015-10-05 03:20:40.989    [DEBUG][10]    Recording service noted the system was resuming...
2015-10-05 03:20:40.989    [DEBUG][10]    Starting: C:\Users\Public\NPVR\Scripts\Wakeup.bat
2015-10-05 03:20:44.606    [DEBUG][10]    C:\Users\Public\NPVR\Scripts\Wakeup.bat has exited
2015-10-05 03:24:01.891    [DEBUG][23]    Resuming...

btw I also noted a backup WakeUp request for every OID, I assume this by design?

k.

[sub]

Something calls the Wakeup.bat script after "Recording service noted the system was resuming..." and it cycles around that and keeps waking the PC, which promptly falls asleep ~3 mins later, it seems?

Whenever the application gets a 'resume' power event, then it logs this message, and looks for a Wakeup.bat to run. It has no idea what triggered the wakeup.

Going back to sleep isn't something NextPVR does. Your windows settings mush be set to auto sleep after a couple of minutes of inactivity.

btw I also noted a backup WakeUp request for every OID, I assume this by design?

Correct.

[jksmurf]

Whenever the application gets a 'resume' power event, then it logs this message, and looks for a Wakeup.bat to run. It has no idea what triggered the wakeup.

Going back to sleep isn't something NextPVR does. Your windows settings mush be set to auto sleep after a couple of minutes of inactivity.

Hmm. OK. This must be where I am confused :confused:
To me, the Power Troubleshooter suggests that NRecord.exe is the initiator of the Wake Event.
My sleep settings are pretty simple - Go to sleep after 1hr 5mins. That's it (apart from Allow Wake Timers). :confused:

I agree it seems to try to nod off again, but I cannot see any settings which tell it do that (unless this is a default action once it sleeps after 1hr 5mins has passed), as I am assume if NPVR wakes it to run a recording it does so (and it does do so), and the logs suggest it does so, until the recording is done.

The bit that I can't get my head around is what is waking it up after it does so. You are pretty sure that it is not Nrecord.exe, but e Power Troubleshooter says it is :confused:

What am I missing?
Alternatively, where should I look for other sleep settings - I've tried to find some, I really have.

k.

[EDIT] OK I am looking at http://www.sevenforums.com/tutorials/357...ke-up.html
Whilst my sleep time is 65mins, I don't actually have a setting for "System Unattended Sleep Timeout" in my Power Options, but I see from a registry hunt that is is around 2 mins. Need to do some more reading.

I see I can add the options using these http://www.sevenforums.com/tutorials/246...meout.html

[sub]

I agree it seems to try to nod off again, but I cannot see any settings which tell it do that (unless this is a default action once it sleeps after 1hr 5mins has passed), as I am assume if NPVR wakes it to run a recording it does so (and it does do so), and the logs suggest it does so, until the recording is done.

NextPVR never askes it to go to sleep. It tells Windows what time it needs to be awake to initiate a recording. When a recording is in-progress, every minute or so it tells windows "I'm using the machine, so don't go to sleep). Once the recording has stopped, it stops tell Windows the machine is in use, then Windows is free to go back to sleep if it wants.

I seem to remember Windows has some other rules about how long it takes to go back to sleep if it was woken for a system process, rather than a user waking it.

The bit that I can't get my head around is what is waking it up after it does so. You are pretty sure that it is not Nrecord.exe, but e Power Troubleshooter says it is :confused:

Yeah, I'm not sure either. There is only one bit of code in NextPVR that makes this SetWaitableTimer() call to wake windows, and it always logs one of these "Requesting wake up for...." log messages. So those times listed in the logs are the only times it's requested wake for.

[2leftfeet]

I seem to remember Windows has some other rules about how long it takes to go back to sleep if it was woken for a system process, rather than a user waking it.

you are referring to the System_Unattended_Sleep_Timeout control in windows Power setting. In some PC's it is set to the sleep timeout, in others it has to be set independently.
See http://www.tenforums.com/general-discuss...8-1-a.html - has a download for a registry key that makes this control visible in power settings.


As for what is waking it up - from administrator command prompt, try powercfg -lastwake ; powercfg -requests ; and powercfg -waketimers to see if some other process is demanding that the PC wakes and/or stays awake.

[jksmurf]

See http://www.tenforums.com/general-discuss...8-1-a.html - has a download for a registry key that makes this control visible in power settings..

Yup the site I noted above has a similar registry key, so I enabled that and changed it to 1hr from the 2min default to see what happens.

As for what is waking it up - from administrator command prompt, try powercfg -lastwake ; powercfg -requests ; and powercfg -waketimers to see if some other process is demanding that the PC wakes and/or stays awake.

As above, I already used the EventViewer Power Troubleshooter which does a similar thing. It shows NRecord.exe as the waker-upper and the timing of the events corresponds to the Nrecord.log.

It seems from the log that (chicken and the egg?) that the wake-event came first and that Nrecord.exe is reacting to the resume, sending its own little wakeup.bat command via the script.

@sub:

Yeah, I'm not sure either. There is only one bit of code in NextPVR that makes this SetWaitableTimer() call to wake windows, and it always logs one of these "Requesting wake up for...." log messages. So those times listed in the logs are the only times it's requested wake for..

I'm pretty sure that in this instance (and others) the game that Nrecord was asked to wake up for had long completed; hence, coming full circle (above original post), I was querying what ELSE Nrecord.exe could be controlling - which is why I was wondering if it was Nrecord.exe calling PostProcessing.bat which in turns calls comskip.exe, but Nrecord.exe is fingered as the initiating Wake event for that comskip.exe process. Possible?