NPVR "Recording Service Not Running at Recording Time"

[andrewj]

Hi,

I am still having problems with missed recordings. The latest instance was a program scheduled to record last night (2018-02-08) at 21:00. If I look in the "What's New" page it reports "Recording Service Not Running at Recording Time" for that program and one scheduled earlier in the day. The last successful recording was on the 7th at 21:57-23:00 which seemed to have recorded OK (the output file is fine) but against which NPVR shows "Recording service was stopped during recording".

Obviously something happened towards the end of that program which caused the recording service to crash, and it didn't restart until I rebooted the PC last night.

I have had a look in the logs but I can't make sense of the cause. The only error I can see in the timeslot for the program on 2018-02-07 is in NRecord.log.1, and seems to relate to downloading FanArt, but that shouldn't have stopped the recording and there are other similar instances earlier:

Code:

2018-02-07 21:57:08.406    [ERROR][60]    Unexpected error in FanArtTVHelper: System.Net.WebException: The remote server returned an error: (404) Not Found.
   at System.Net.WebClient.DownloadDataInternal(Uri address, WebRequest& request)
   at System.Net.WebClient.DownloadString(Uri address)
   at System.Net.WebClient.DownloadString(String address)
   at NShared.Metadata.FanArtTVHelper.LookupMetadata(String seriesID, MetadataEntity entity)

There is an error a couple of hours earlier in the log which looks a bit more serious, but I can't understand what it's saying:

Code:

2018-02-07 21:04:01.910    [DEBUG][9]    Stopping recording (15322 on 22). Past end time of recording. 12
2018-02-07 21:04:01.921    [DEBUG][9]    StopStream(C)
2018-02-07 21:04:01.931    [ERROR][9]    Unexpected stopping remote stream: System.Runtime.Remoting.RemotingException: Failed to read from an IPC Port: The pipe has been ended.


Server stack trace:
   at System.Runtime.Remoting.Channels.Ipc.IpcPort.Read(Byte[] data, Int32 offset, Int32 length)
   at System.Runtime.Remoting.Channels.Ipc.PipeStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   at System.Runtime.Remoting.Channels.SocketHandler.ReadFromSocket(Byte[] buffer, Int32 offset, Int32 count)
   at System.Runtime.Remoting.Channels.SocketHandler.Read(Byte[] buffer, Int32 offset, Int32 count)
   at System.Runtime.Remoting.Channels.SocketHandler.ReadAndMatchFourBytes(Byte[] buffer)
   at System.Runtime.Remoting.Channels.Tcp.TcpSocketHandler.ReadAndMatchPreamble()
   at System.Runtime.Remoting.Channels.Tcp.TcpSocketHandler.ReadVersionAndOperation(UInt16& operation)
   at System.Runtime.Remoting.Channels.Ipc.IpcClientHandler.ReadHeaders()
   at System.Runtime.Remoting.Channels.Ipc.IpcClientTransportSink.ProcessMessage(IMessage msg, ITransportHeaders requestHeaders, Stream requestStream, ITransportHeaders& responseHeaders, Stream& responseStream)
   at System.Runtime.Remoting.Channels.BinaryClientFormatterSink.SyncProcessMessage(IMessage msg)

Exception rethrown at [0]:
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at NUtility.IRecorder.StopStream(Int32 streamHandle)
   at NShared.DigitalRecorder.StopStream(Int32 streamHandle)
2018-02-07 21:04:01.931    [ERROR][9]    Trying to force restart of NDigitalHost on next stream request...

Please can someone advise on what's happening?

Logs attached, and many thanks,
Andrew

[HarryH3]

I had a problem with the recording service crashing a few years ago. After installing a PostUpdateEPG.bat file that reboots the system every night, after the EPG update completes in the wee hours of the morning. I didn't write it, it came from someone else here in the forum. I haven't seen a recording service problem since.

echo off
REM Reboot if not recording
set NSHelper=c:"program files (x86)"\npvr\nscripthelper.exe

:check
FOR /F "tokens=*" %%i in ('%NSHelper% -isinuse') do SET condition=%%i
echo %condition%
IF %condition% =="NOT RECORDING" goto reboot

:delay
timeout 60
goto check

:reboot

echo "About to reboot"
shutdown /r

[andrewj]

Thanks. It would be great if we could understand the root cause, but that looks like a decent work-around.
How do you run it? Do you install it somewhere and it runs automatically?

[sub]

Create a c:\temp directory, and if it crashes again, please supply the c:\temp\crash.mdmp file. Hopefully I'll be able to tell the cause from this.

[HarryH3]

Thanks. It would be great if we could understand the root cause, but that looks like a decent work-around.
How do you run it? Do you install it somewhere and it runs automatically?

The file goes in C:\Users\Public\NPVR\Scripts and must be named PostUpdateEPG.bat

[andrewj]

Hi Sub,
I already have a C:\Temp directory but I can't see that file there. Does it get deleted when the system is restarted?
Andrew

[sub]

In the Windows Event Viewer, is there a error stating the recording service crashed? There is no sign of any critical error in those logs (including those errors you quoted above).

Those event messages can sometimes give the name of a different dump file that windows has collected.

[jcjefferies]

I think I was the one who wrote the script some years ago! I wanted to do a regular reboot as I was getting occasional miscellaneous problems which would prevent recordings taking place sometimes for several days. A reboot means that any problems in the evening that you don't notice doesn't carry over into the next day. I asked Sub if there was a way to detect if NextPVR was recording so he added the "-isinuse" function so the reboot only takes place when NextPVR is not recording.

However if its just the Recording Service which is stopping then it should automatically restart as that seems to be the "recovery" setting in Services for the first & second crash. The third instance is not set but it could be worth trying the "Reboot" option as long as you remember that it has been set when it seems to reboot for no reason!!

[andrewj]

Hi,
There's nothing at all in the windows event logs, which is odd.
Andrew

[andrewj]

A complete system reboot seems a bit drastic, and could cause problems with other things running on my system. I have an idea for a better solution, but I may need a bit of help.

I wrote a Windows service which restarts the Serviio process early in the morning, which helps to unlock files which serviio can sometimes leave locked. I could easily extend that code to do something to the NPVR recording service. I can detect if the service is stopped and start it, and I could also just do a service restart on a regular basis (e.g. early in the morning when I restart Serviio).

Would that work?