Errors in NRecord.log

[BrettB]

While I was looking through my NRecord.log for info on the archiving problem, I also saw a couple of messages and errors that I'm curious about. None of these are critical, but when you have a chance, if you could look at them, it might help a bit with troubleshooting in the future.

Here's the section of the log file for a recording starting (the full logfiles are attached to my message about archiving):

Code:

2017-09-23 18:59:01.392    [DEBUG][10]    DefaultDirectoryChoice: first
2017-09-23 18:59:01.392    [DEBUG][10]    Advanced manual recurring recording is using name: Series Premiers
2017-09-23 18:59:01.392    [DEBUG][10]    Preferred filename is 'Live PD Police Patrol Overtime.S01E01.Police Patrol'
2017-09-23 18:59:01.393    [DEBUG][10]    allocating recording target filename: E:\NPVR Recordings2\Live PD Police Patrol Overtime\Live PD Police Patrol Overtime.S01E01.Police Patrol.ts
2017-09-23 18:59:01.393    [DEBUG][10]    About to start recording (213803 on 1566): E:\NPVR Recordings2\Live PD Police Patrol Overtime\Live PD Police Patrol Overtime.S01E01.Police Patrol.ts...
2017-09-23 18:59:01.393    [DEBUG][10]    Free space 1130492379136  (E:\)
2017-09-23 18:59:01.393    [DEBUG][10]    HDHomeRunRecorder.StartStream()
2017-09-23 18:59:01.393    [DEBUG][10]    HDHomeRunRecorder@2.0
2017-09-23 18:59:01.393    [DEBUG][10]    HDHomeRunRecorder@2.1
2017-09-23 18:59:01.393    [DEBUG][10]    HDHomeRunRecorder@2.2 nextPort=36316
2017-09-23 18:59:01.393    [DEBUG][10]    HDHomeRunRecorder@2.2.0
2017-09-23 18:59:01.393    [DEBUG][10]    HDHomeRunRecorder@2.2.0@allocated
2017-09-23 18:59:01.393    [DEBUG][10]    HDHomeRunRecorder@2.3
2017-09-23 18:59:01.393    [DEBUG][10]    Allocated port: 36316
2017-09-23 18:59:01.393    [DEBUG][10]    HDHomeRunRecorder@3
2017-09-23 18:59:01.393    [DEBUG][10]    HDHR 'Model': hdhomerun3_cablecard
2017-09-23 18:59:01.393    [DEBUG][10]    HDHR 'Application': Default
2017-09-23 18:59:01.393    [DEBUG][10]    About to start HDHR device. Checking status for information sake... (could tell if it's already in use elsewhere)
2017-09-23 18:59:01.393    [DEBUG][10]    Executing: C:\Program Files\Silicondust\HDHomeRun\hdhomerun_config.exe 131EA0C1 get /tuner1/status
2017-09-23 18:59:01.430    [DEBUG][10]    Status: ch=none lock=none ss=0 snq=0 seq=0 bps=0 pps=0

2017-09-23 18:59:01.561    [ERROR][89]    Unexpected error looking up metadata: System.NullReferenceException: Object reference not set to an instance of an object.
   at NShared.TheTVDBMetadataPlugin.LookupMetadata(MetadataEntity entity)
2017-09-23 18:59:01.784    [DEBUG][71]    Using URL: https://json.schedulesdirect.org/20141201
2017-09-23 18:59:01.877    [DEBUG][71]    
{"account":{"expires":"2018-06-20T02:23:17Z","messages":[],"maxLineups":4},"lineups":[{"lineup":"USA-MN58526-X","modified":"2017-09-13T01:58:19Z","uri":"\/20141201\/lineups\/USA-MN58526-X"},{"lineup":"USA-OTA-55106","modified":"2017-08-27T00:39:56Z","uri":"\/20141201\/lineups\/USA-OTA-55106"}],"lastDataUpdate":"2017-09-23T20:55:20Z","notifications":[],"systemStatus":[{"date":"2015-09-08T00:00:00Z","status":"Online","message":"No known issues."}],"serverID":"20141201.web.1","datetime":"2017-09-23T23:59:01Z","code":0}
2017-09-23 18:59:02.347    [DEBUG][71]    Got poster
2017-09-23 18:59:02.430    [DEBUG][10]    Executing: C:\Program Files\Silicondust\HDHomeRun\hdhomerun_config.exe 131EA0C1 set /tuner1/lockkey 100566
2017-09-23 18:59:02.494    [DEBUG][10]    SetIncomingPort@2
2017-09-23 18:59:02.494    [DEBUG][10]    SetIncomingPort@exit
2017-09-23 18:59:02.494    [DEBUG][10]    Executing: C:\Program Files\Silicondust\HDHomeRun\hdhomerun_config.exe 131EA0C1 key 100566 set /tuner1/vchannel 829
2017-09-23 18:59:02.546    [DEBUG][10]    ForcedIP.xml does not exists
2017-09-23 18:59:02.570    [DEBUG][10]    131EA0C1 can be found via adapter with ip address: 192.168.143.10
2017-09-23 18:59:02.570    [DEBUG][10]    Executing: C:\Program Files\Silicondust\HDHomeRun\hdhomerun_config.exe 131EA0C1 key 100566 set /tuner1/target rtp://192.168.143.10:36316
2017-09-23 18:59:02.574    [DEBUG][10]    SetIncomingPort@2
2017-09-23 18:59:02.574    [DEBUG][10]    SetIncomingPort@exit
2017-09-23 18:59:02.575    [DEBUG][10]    StartStream() returned handle=46
2017-09-23 18:59:02.575    [DEBUG][10]    Allocated Handle: 46
2017-09-23 18:59:02.575    [DEBUG][10]    Temp at 9/23/2017 6:59:12 PM
2017-09-23 18:59:02.575    [DEBUG][10]    Started recording (213803:46:E:\NPVR Recordings2\Live PD Police Patrol Overtime\Live PD Police Patrol Overtime.S01E01.Police Patrol.ts)
2017-09-23 18:59:02.582    [DEBUG][75]    cached catalog does not exist
2017-09-23 18:59:02.586    [DEBUG][10]    Starting: C:\Users\Public\NPVR\Scripts\ParallelProcessing.bat "E:\NPVR Recordings2\Live PD Police Patrol Overtime\Live PD Police Patrol Overtime.S01E01.Police Patrol.ts" 829 213803 1566 "Live PD: Police Patrol: Overtime"
2017-09-23 18:59:02.630    [DEBUG][80]    Got fanart
2017-09-23 18:59:02.694    [DEBUG][102]    Got landscape
2017-09-23 18:59:02.695    [DEBUG][113]    Downloading metadata and artwork took + 1316ms
2017-09-23 18:59:02.986    [ERROR][89]    Unexpected error looking up metadata: System.NullReferenceException: Object reference not set to an instance of an object.
   at NShared.TheTVDBMetadataPlugin.LookupMetadata(MetadataEntity entity)
2017-09-23 18:59:03.134    [DEBUG][89]    Got poster
2017-09-23 18:59:03.789    [DEBUG][116]    Got fanart
2017-09-23 18:59:03.943    [DEBUG][100]    Got landscape
2017-09-23 18:59:03.945    [DEBUG][75]    Downloading metadata and artwork took + 1363ms

1. There are a couple of Unexpected errors which I don't think are important, but can be confusing when looking for "real errors":

Code:

2017-09-23 18:59:01.561    [ERROR][89]    Unexpected error looking up metadata: System.NullReferenceException: Object reference not set to an instance of an object.
   at NShared.TheTVDBMetadataPlugin.LookupMetadata(MetadataEntity entity)
...
2017-09-23 18:59:02.986    [ERROR][89]    Unexpected error looking up metadata: System.NullReferenceException: Object reference not set to an instance of an object.
   at NShared.TheTVDBMetadataPlugin.LookupMetadata(MetadataEntity entity)

2. There is a message which says "cached catalog does not exist". What does that message mean?

Code:

2017-09-23 18:59:02.582    [DEBUG][75]    cached catalog does not exist

3. Finally, can you eliminate the extra blank line when checking the HDHR status? I thought that you had done that before, but I'm still seeing it.

Code:

2017-09-23 18:59:01.393    [DEBUG][10]    Executing: C:\Program Files\Silicondust\HDHomeRun\hdhomerun_config.exe 131EA0C1 get /tuner1/status
2017-09-23 18:59:01.430    [DEBUG][10]    Status: ch=none lock=none ss=0 snq=0 seq=0 bps=0 pps=0

2017-09-23 18:59:01.561...