No Live TV - "Unable to communicate with recording service"

[tclarsson]

Hi

Did an upgrade to NPVR 3.1.1, and added patches R1A.

When trying to Watch "Live TV", the system responds "Unable to communicate with recording service".

Note that the normal recording is working fine, including even watching delayed TV...

There is a strange error on the logfile, see below (also include the rest.)

Please- Can you point me in the right direction?

Best regards
Thomas


++++
2014-03-24 22:07:14.655 [ERROR][1] Unexpected error calling StartStream(): System.Collections.Generic.KeyNotFoundException: The given key was not present in the dictionary.

Server stack trace:
at System.ThrowHelper.ThrowKeyNotFoundException()
at System.Collections.Generic.Dictionary`2.get_Item(TKey key)
at NShared.RecordingService.StartStream(Int32 channelOID, String target, Int32 previousHandle, ChannelMapping& returnMapping, String& reason)
at NShared.RecordingRemote.StartStream(Int32 channelOID, String target, Int32 previousHandle, ChannelMapping& channelMapping, String& reason)
at System.Runtime.Remoting.Messaging.StackBuilderSink._PrivateProcessMessage(IntPtr md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)
at System.Runtime.Remoting.Messaging.StackBuilderSink.PrivateProcessMessage(RuntimeMethodHandle md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)
at System.Runtime.Remoting.Messaging.StackBuilderSink.SyncProcessMessage(IMessage msg, Int32 methodPtr, Boolean fExecuteInContext)

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 NShared.IRecordingService.StartStream(Int32 channelOID, String target, Int32 previousHandle, ChannelMapping& channelMapping, String& reason)
at NShared.RecordingServiceProxy.StartStream(Int32 channelOID, String target, Int32 previousHandle, ChannelMapping& channelMapping, String& reason)

+++

[sub]

The first problem seems to be the recording service is not starting cleanly, with errors about the web server:

2014-03-24 21:53:07.250 [ERROR][4] Unexpected error starting web server:
System.BadImageFormatException: Could not load file or assembly 'NRecord, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null' or one of its dependencies. This assembly is built by a runtime newer than the currently loaded runtime and cannot be loaded.
File name: 'NRecord, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null'

We've seen people have problems like this with their firewall/antivirus software.

[tclarsson]

Thanks for reply!

Disabled the firewall (and the NPVR web service), also reinstalled 2 times.
Now I get a "Clean recording server start" - but I still get the same problem/symptom - no live tv and the same error message. - same error in the NPVR log!
One can see that when trying LIVE TV - the recording server gets the request: "2014-03-25 18:28:24.010 [DEBUG][15] StartStream(7156:TV4 Stockholm)"

Is "2014-03-25 18:27:26.809 [DEBUG][13] checking if previous capture source can be reused"
and "2014-03-25 18:27:26.809 [DEBUG][13] stopping previous handle"
a indication of a problem or normal?

Given the following background
- Everything worked on version NPVR 2.xxx - failure on 3.1.1 +R1A - no added firewall or antivirus
- exact same error when disabling all firewalls
- signal reaches recording server
- recording server otherwise fine

Perhaps there is another explanation than your initial thought? Anything comes to mind?

Regards
Thomas

++++
[...startup]
2014-03-25 18:26:29.496 [DEBUG][4] OnStart()
2014-03-25 18:26:29.506 [INFO][4] Using local in-process recording service
2014-03-25 18:26:29.616 [DEBUG][4] RecordingServiceProxy@exit
2014-03-25 18:26:29.626 [INFO][4] RecordingService.Startup()
2014-03-25 18:26:29.626 [INFO][4] Starting remoting service
2014-03-25 18:26:29.731 [DEBUG][8] Requesting wake up for 'EPGWAKEUP' at 2014-03-26 02:00
2014-03-25 18:26:29.739 [INFO][7] RecordingService starting...
2014-03-25 18:26:29.753 [DEBUG][7] PurgeOldDeletes()
2014-03-25 18:26:29.753 [DEBUG][7] Loading recording schedule
2014-03-25 18:26:29.764 [DEBUG][7] CancelAllWakeupRequests
2014-03-25 18:26:29.792 [DEBUG][4] OnStart() complete...
2014-03-25 18:26:34.793 [DEBUG][9] Client Listener starting on port 7969
2014-03-25 18:27:26.809 [DEBUG][13] StartStream(7156:TV4 Stockholm)
2014-03-25 18:27:26.809 [DEBUG][13] checking if previous capture source can be reused
2014-03-25 18:27:26.809 [DEBUG][13] stopping previous handle
2014-03-25 18:28:24.010 [DEBUG][15] StartStream(7156:TV4 Stockholm)
2014-03-25 18:28:24.010 [DEBUG][15] checking if previous capture source can be reused
2014-03-25 18:28:24.010 [DEBUG][15] stopping previous handle
++++

[sub]

Can you post a new set of logs showing the problem?

[tclarsson]

Hi Again,

Logs attached (but the same info as before).

I did some network sniffing of the interaction between the NPVR and the recording server. Below is the final message Before recording server sends an error message. As you can see there is a problem with a key....set to "null"???
I include this sniffed file as well in the log package... the recording service has port 8968.

Thanks
Regards
Thomas
(Actually lived in Wellington for 3 years...)

+++++

0000 45 00 00 e1 1b 16 40 00 80 06 00 00 7f 00 00 01 E.....@. ........
0010 7f 00 00 01 dc 55 23 08 5e 49 72 7a 2f 99 d5 8b .....U#. ^Irz/...
0020 50 18 00 1f 60 f6 00 00 00 00 00 00 00 00 00 00 P...`... ........
0030 00 01 00 00 00 00 00 00 00 15 12 00 00 00 12 0b ........ ........
0040 53 74 61 72 74 53 74 72 65 61 6d 12 59 4e 53 68 StartStr eam.YNSh
0050 61 72 65 64 2e 49 52 65 63 6f 72 64 69 6e 67 53 ared.IRe cordingS
0060 65 72 76 69 63 65 2c 20 4e 53 68 61 72 65 64 2c ervice, NShared,
0070 20 56 65 72 73 69 6f 6e 3d 31 2e 30 2e 30 2e 30 Version =1.0.0.0
0080 2c 20 43 75 6c 74 75 72 65 3d 6e 65 75 74 72 61 , Cultur e=neutra
0090 6c 2c 20 50 75 62 6c 69 63 4b 65 79 54 6f 6b 65 l, Publi cKeyToke
00a0 6e 3d 6e 75 6c 6c 05 00 00 00 08 f4 1b 00 00 12 n=null.. ........
00b0 27 4c 49 56 45 26 43 3a 5c 54 65 6d 70 5c 6c 69 'LIVE&C: \Temp\li
00c0 76 65 2d 54 56 34 20 53 74 6f 63 6b 68 6f 6c 6d ve-TV4 S tockholm
00d0 2d 32 30 33 37 2e 74 73 08 00 00 00 20 11 12 00 -2037.ts .... ...
00e0 0b .

[Graham]

A complete stab in the dark ... Is the Live TV buffer file pointing to a missing folder?

http://www.nextpvr.com/nwiki/pmwiki.php?...ation.Misc

[sub]

Its a particularly confusing log. I'm scratching my head a bit. It looks like it's a attempting to reuse the existing device session when it starts live tv, but because it's a new attempt there is no existing device.

Normally I'd offer up a patch with a couple of extra lines of logging and we'd get to the bottom of it pretty quickly, but at the current stage of the release cycle I can't do that. We will be able to next week when the new 3.2.x release is available.

Did you start live tv from the TV Listings plugin? If you start from the 'Live TV' option on the main menu, does it make any difference?

[tclarsson]

A complete stab in the dark ... Is the Live TV buffer file pointing to a missing folder?

http://www.nextpvr.com/nwiki/pmwiki.php?...ation.Misc

no - ref is fine!

Note that watching delayed live TV works fine!

Regards
Thomas

[tclarsson]

Hi
Tried to start live tv from:
- right click menu
- "Live TV" menu item
- "Watch" in TV Guide
- Watch in TV listing

All fails in the same way

Regards
Thomas

[mvallevand]

Did you move the program directory to D: from C: at anytime? This is not the first time I have seen that error when the program directory is not on C:\

Martin