NRecord.exe fails with exception

[gymshoe]

I have been using NextPVR for about 3 years now - works great! Recently I have experienced a number of crashes for NRecord.exe. The logs do not show an issue, everything looks fine and then the process just seems to stop. Looking at the windows event log I found the following:

Logged 9/25/2017 9:36:03 AM

Faulting application name: NRecord.exe, version: 1.0.0.0, time stamp: 0x59991470
Faulting module name: clr.dll, version: 4.7.2114.0, time stamp: 0x59a639ae
Exception code: 0x80131506
Fault offset: 0x002d388b
Faulting process id: 0x1fe4
Faulting application start time: 0x01d3357c2ba05fae
Faulting application path: C:\Program Files (x86)\NPVR\NRecord.exe
Faulting module path: C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
Report Id: dad27346-a1fe-11e7-8fb5-d850e6db9111

I have the NPVR Recording Service configured to restart after 1 minute on failure - which it did.
I am running version 4.0.4, .Net 4.6.2 Windows 7 Pro, Service Pack 1

Any help would be appreciated!

Jim s

[sub]

If you create a c:\temp directory, do you get a c:\temp\crash.mdmp when it crashes? If so, please supply this file.

[gymshoe]

A c:\temp directory has been there but no .mdmp files are present. I also searched my entire c:\ drive but no .mdmp
Here is a more complete list of the errors found in the windows event log

9/14/2017 5:00:51 AM

Faulting application name: NRecord.exe, version: 1.0.0.0, time stamp: 0x53372694
Faulting module name: ntdll.dll, version: 6.1.7601.23889, time stamp: 0x598d4c81
Exception code: 0xc0000005
Fault offset: 0x000800a4
Faulting process id: 0x8cc
Faulting application start time: 0x01d32c722739cef3
Faulting application path: C:\Program Files (x86)\NPVR\NRecord.exe
Faulting module path: C:\Windows\SysWOW64\ntdll.dll
Report Id: 9645febd-9933-11e7-8489-d850e6db9111

9/16/2017 11:48:55 AM

Faulting application name: NRecord.exe, version: 1.0.0.0, time stamp: 0x53372694
Faulting module name: KERNEL32.dll, version: 6.1.7601.23889, time stamp: 0x598d4d25
Exception code: 0xc0000005
Fault offset: 0x00000000
Faulting process id: 0x1bd0
Faulting application start time: 0x01d32e86d6bb8d87
Faulting application path: C:\Program Files (x86)\NPVR\NRecord.exe
Faulting module path: C:\Windows\syswow64\KERNEL32.dll
Report Id: ecda5da2-9afe-11e7-8489-d850e6db9111

-- enabled auto restart of the service

9/18/2017 2:44:59 AM

Faulting application name: NRecord.exe, version: 1.0.0.0, time stamp: 0x53372694
Faulting module name: ntdll.dll, version: 6.1.7601.23889, time stamp: 0x598d4c81
Exception code: 0xc0000005
Fault offset: 0x000800a4
Faulting process id: 0x1920
Faulting application start time: 0x01d32fc9605d185b
Faulting application path: C:\Program Files (x86)\NPVR\NRecord.exe
Faulting module path: C:\Windows\SysWOW64\ntdll.dll
Report Id: 452e12ea-9c45-11e7-8489-d850e6db9111

9/18/2017 9:24:57 PM

Faulting application name: NRecord.exe, version: 1.0.0.0, time stamp: 0x53372694
Faulting module name: clr.dll, version: 4.7.2114.0, time stamp: 0x59a639ae
Exception code: 0x80131506
Fault offset: 0x002d388b
Faulting process id: 0x1480
Faulting application start time: 0x01d330522fc6efcd
Faulting application path: C:\Program Files (x86)\NPVR\NRecord.exe
Faulting module path: C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
Report Id: ba1fa23e-9ce1-11e7-8489-d850e6db9111

9/19/2017 8:23:41 AM

Faulting application name: NRecord.exe, version: 1.0.0.0, time stamp: 0x53372694
Faulting module name: KERNELBASE.dll, version: 6.1.7601.23889, time stamp: 0x598d4d26
Exception code: 0xe0434352
Fault offset: 0x0000c54f
Faulting process id: 0xbd0
Faulting application start time: 0x01d33148280cd82e
Faulting application path: C:\Program Files (x86)\NPVR\NRecord.exe
Faulting module path: C:\Windows\syswow64\KERNELBASE.dll
Report Id: c0a86bc7-9d3d-11e7-b898-d850e6db9111

-- 9/20 uninstalled .Net 4.7 update (hide the update), uninstalled .net 4.7, installed .Net 4.6.2
-- 9/24 installed 4.0.4 version of NextPvr

9/25/2017 9:36:03 AM

Faulting application name: NRecord.exe, version: 1.0.0.0, time stamp: 0x59991470
Faulting module name: clr.dll, version: 4.7.2114.0, time stamp: 0x59a639ae
Exception code: 0x80131506
Fault offset: 0x002d388b
Faulting process id: 0x1fe4
Faulting application start time: 0x01d3357c2ba05fae
Faulting application path: C:\Program Files (x86)\NPVR\NRecord.exe
Faulting module path: C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
Report Id: dad27346-a1fe-11e7-8fb5-d850e6db9111

There have been a few other cases where the record service fails to start but did not generate an event in the event log.

I started to suspect the .Net 4.7 install that came via windows update so I went back to .net 4.6.2 I then decided to get the latest NextPvr version.

The machine is a media server - that is all it does.

[sub]

Is it doing something in particular at the time? ie, like recording, or live tv, or does it just do it when nothing is happening too?

[gymshoe]

I have seen both. I know that on 9/25 9:36:03 it was in the middle of recording a show. The windows service was automatically restarted after 1 minute and on the restart it picked up where it left off and finished the recording - to another file. Last night it seemed to die in the middle of the night, not much in the logs

9/27/2017 12:47:58 AM

Faulting application name: NRecord.exe, version: 1.0.0.0, time stamp: 0x59991470
Faulting module name: ntdll.dll, version: 6.1.7601.23889, time stamp: 0x598d4c81
Exception code: 0xc0000005
Fault offset: 0x0002e064
Faulting process id: 0x14ac
Faulting application start time: 0x01d336b68e123277
Faulting application path: C:\Program Files (x86)\NPVR\NRecord.exe
Faulting module path: C:\Windows\SysWOW64\ntdll.dll
Report Id: 6a2d1227-a347-11e7-8fb5-d850e6db9111

The only thing I could see from the logs was web.log.1

2017-09-27 00:46:58.168 [DEBUG][121] +++++No entries in VLC Heartbeat Dictionary.
2017-09-27 00:47:28.182 [DEBUG][58] ********** Checking VLC Heartbeat Dictionary
2017-09-27 00:47:28.182 [DEBUG][58] +++++No entries in VLC Heartbeat Dictionary.
2017-09-27 00:47:58.197 [DEBUG][125] ********** Checking VLC Heartbeat Dictionary
2017-09-27 00:47:58.197 [DEBUG][125] +++++No entries in VLC Heartbeat Dictionary.

still no dump file in c:\temp

I have attached a new copy of the logs

[gymshoe]

Had a NRecord.exe failure again tonight - in the middle of a recording

9/27/2017 7:46:28 PM

Faulting application name: NRecord.exe, version: 1.0.0.0, time stamp: 0x59991470
Faulting module name: clr.dll, version: 4.7.2114.0, time stamp: 0x59a639ae
Exception code: 0x80131506
Fault offset: 0x002d388b
Faulting process id: 0x25b4
Faulting application start time: 0x01d33754504f5a86
Faulting application path: C:\Program Files (x86)\NPVR\NRecord.exe
Faulting module path: C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
Report Id: 75e8fe3e-a3e6-11e7-8fb5-d850e6db9111

What is new is that the system had a number of ASP.Net errors leading up the final failure. I have attached a snapshot of the system events and the log files. The ASP.Net errors are of the form

Event code: 3008
Event message: A configuration error has occurred.
Event time: 9/27/2017 7:45:30 PM
Event time (UTC): 9/28/2017 12:45:30 AM
Event ID: a4b2ff6ab7aa41f98dbf67092944bc79
Event sequence: 320
Event occurrence: 71
Event detail code: 0

Application information:
Application domain: aa85f57-1-131509649394430706
Trust level: Full
Application Virtual Path: /
Application Path: C:\Users\Public\NPVR\web\
Machine name: DEFIANT

Process information:
Process ID: 9652
Process name: NRecord.exe
Account name: NT AUTHORITY\SYSTEM

Exception information:
Exception type: ConfigurationErrorsException
Exception message: Exception of type 'System.OutOfMemoryException' was thrown.

Not sure why it is reporting out of memory, the machine has 16 GB and I have never seen any memory pressure - although I was not watching it when this happened.

A little more background on the setup if that helps.

Dedicated media server. Intel I7, 16 GB memory. 15 TB disk space.
3 htpc systems. Running Kodi . Using Kodi plugin to access NextPvr functionality.
NextPvr installed on all htpc machines, configured as a client. Used to examine/alter schedule on server.
All running Windows 7

Problems started recently, within the last 2 weeks.

[sub]

I'm not really sure what might be causing this at this stage. I'm not seeing other reports.

Are you using the web app?

[gymshoe]

I am not using the web app - but I think the web interface is being used heavily by the NextPVR plugin in Kodi. I have Kodi running on my development machine (I am a software developer but don't know the internals of NextPVR) and I am watching the logs, task manager, event viewer on the server. It appears that the NextPVR plugin is doing a frequent refresh of the recording list:

from web.log

2017-09-28 08:28:38.693 [DEBUG][221] Got Web Request (::ffff:192.168.15.50): /service method=recording.list&filter=pending&sid=f00738222b2e4013b3805e42b10994bb
2017-09-28 08:28:38.693 [DEBUG][221] method=recording.list
2017-09-28 08:28:38.693 [DEBUG][221] parameters:
2017-09-28 08:28:38.693 [DEBUG][221] method: recording.list
2017-09-28 08:28:38.693 [DEBUG][221] filter: pending
2017-09-28 08:28:38.693 [DEBUG][221] sid: f00738222b2e4013b3805e42b10994bb
2017-09-28 08:28:38.693 [DEBUG][221] client_ip: 192.168.15.50
2017-09-28 08:28:38.693 [DEBUG][221] host_callback: 192.168.15.20:8866
2017-09-28 08:28:38.693 [DEBUG][221] physical_path: C:\Users\Public\NPVR\web\
2017-09-28 08:28:38.693 [DEBUG][221] user_agent: Kodi/15.1 (Windows NT 6.1; WOW64) App_Bitness/32 Version/15.1-Git:20150816-f4dda26
2017-09-28 08:28:38.693 [DEBUG][221] range: bytes=0-
2017-09-28 08:28:38.693 [DEBUG][221] requested_path: /service
2017-09-28 08:28:38.693 [DEBUG][221] verb: GET
2017-09-28 08:28:38.693 [DEBUG][221] GetRecordingsList
2017-09-28 08:28:38.693 [DEBUG][221] GetRecordingsList@1..(take2)
2017-09-28 08:28:38.693 [DEBUG][221] GetRecordingList@1.1)
2017-09-28 08:28:38.693 [DEBUG][221] GetRecordingList@1.5)
2017-09-28 08:28:38.802 [DEBUG][221] GetRecordingsList@2
2017-09-28 08:28:38.818 [DEBUG][221] GetRecordingsList@exit

I am seeing the web.log files rolling over about every minute while kodi is up. The task manager is showing the cpu for NRecord.exe jumping briefly to 12%, then to 0. Memory is changing but hanging around 120 MB The only other activity I am seeing process wise is a couple of NDigitalHost.exe processes that have a little memory movement but no cpu time to speak of.

My wife is the heavy user of the system (no, I do not watch Little House on the Prairie that you may have seen in the logs) Kodi is running pretty much all day.

We do have a very large list of recordings. There is 15 TB of storage on the server and it is getting full of recordings. Still plenty of breathing room but the list is long. I don't see any options to control how frequently the Kodi NextPVR client polls for the latest list. I am using an older version of Kodi, I will upgrade it to see if that helps.

However, this does not explain some of the NRecord.exe failures that happened in the middle of the night. And I am not sure that all this web traffic is causing the problem.

Are there any debug flags or other switches to flip to help diagnose the problem?

[sub]

It's probably not really to do with out of memory. We've seen this message being a red herring in the past.

You're probably going to need to do some more leg work to narrow down the possible cause. There isn't a lot to go on there. We need to determine what is common between crashes. I'm sure there will be some action in particular causing it to crash. It's unlikely to just crash when nothing is happening.

I am seeing the web.log files rolling over about every minute while kodi is up.

It appears that the NextPVR plugin is doing a frequent refresh of the recording list:

from web.log

2017-09-28 08:28:38.693 [DEBUG][221] Got Web Request (::ffff:192.168.15.50): /service method=recording.list&filter=pending&sid=f00738222 b2e4013b3805e42b10994bb

Is it really? I wouldn't expect to see Kodi continually making that call.

If you restart the recording service, and only start one Kodi client, and keep and eye on the log, is it continually making that call? It should make these types of calls when a Kodi client starts, or when certain activities cause it to reload the recording list. The rest of the time I would expect to see fairly regular /service?method=recording.lastupdated calls, which is it polling the backend to see if their is changes it needs to load.

[sub]

It is odd that it claims to be dying in ntdll.dll, which is unmanaged code. Are you running any firewall / antivirus / netnanny software that could be causing this process to crash? These types of apps hook calls to ntdll.dll etc.