Unexpected exception in ClientConnectionHandler

[fuzzweed]

Any idea what would cause this? It's started happening two or three times a night. The only thing I can think of that has changed recently is adding a recent patched version of unmanaged.dll - could this be a cause???
From server below. client log attached.


2012-05-03 20:54:49.112 [DEBUG][19] CLIENT-READ: 169200 bytes from offset 458382728
2012-05-03 20:54:49.112 [DEBUG][19] RollingFile.Seek(458382728)
2012-05-03 20:54:49.112 [DEBUG][19] about to read 169200 from location 458382728 (current length = 1406214808)
2012-05-03 20:54:49.112 [DEBUG][19] READafter read
2012-05-03 20:54:49.112 [DEBUG][19] READabout to get length
2012-05-03 20:54:49.112 [DEBUG][19] READafter get length
2012-05-03 20:54:49.112 [DEBUG][19] READ: data read, about to send
2012-05-03 20:54:49.112 [DEBUG][19] READabout to send
2012-05-03 20:54:49.128 [DEBUG][19] READ: complete
2012-05-03 20:54:49.128 [DEBUG][19] File length: 1406214808
2012-05-03 20:54:49.128 [DEBUG][19] CLIENT-READ: 169200 bytes from offset 458551928
2012-05-03 20:54:49.128 [DEBUG][19] RollingFile.Seek(458551928)
2012-05-03 20:54:49.128 [DEBUG][19] about to read 169200 from location 458551928 (current length = 1406214808)
2012-05-03 20:54:49.190 [DEBUG][19] READafter read
2012-05-03 20:54:52.217 [ERROR][19] Unexpected exception in ClientConnectionHandler: System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
at System.Net.Sockets.Socket.Send(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
at System.Net.Sockets.Socket.Send(Byte[] buffer, Int32 size, SocketFlags socketFlags)
at NShared.ClientConnectionHandler.WorkerThread()
2012-05-03 20:54:52.217 [DEBUG][19] CLOSING file (client connection gone)


[ATTACH=CONFIG]33602[/ATTACH]

[sub]

This in itself isnt a problem. It's normal to see that in the log after the client has stopped playback. It just means that the client has disconnected.

[fuzzweed]

Any thoughts on what would cause the client to stop playback? It's entirely random in it's timing, but is happening on two machines. It's also new behaviour either since latest version upgrade or a recent patch.

[sub]

Was there anything particular happening at the time, like skipping or pausing or other activity?

[fuzzweed]

Also if it makes any difference, it's not remembering it's last playback position during these crashes, so I don't get the resume option as I would with a deliberate exit.

[sub]

I just checked your NPVR.log. I assume this was "The Tallest Tower Building The_20120502_22002300.ts"? In the logs it looks like it reached the end of the file and did a orderly stop.

[fuzzweed]

right program, but not an orderly stop (just finished watching the rest of it...). Nothing I can see in common, no skips, not on an ad break, not a particular time into the recording, not a particular channel.... just regularly gives up playing recordings. My other client is doing the same thing so maybe a server or network error????

[sub]

How long should that program be? 62 minutes? It looks like that was where playback was up to.

[fuzzweed]

62 minutes is correct length, but playback was maybe 20 minutes. I watched the remainder between post 5 and 7.

just happened again. 60 minute recording. stopped after 20 minutes or so. had skipped through an ad break if thats a possible cause?

started salvage hunters (60min+2 padding) at 21:56:06.585. Thinks its all over by 10.15.

[ATTACH=CONFIG]33603[/ATTACH]
[ATTACH=CONFIG]33604[/ATTACH]

[fuzzweed]

Any more thoughts on this? I've just been experimenting to see if it was related to skipping at all and don't think it is.

Just watched the same recording three times from the start.
First time skipped forwards 15mins then played normally. Crashed 7 min or so later.
[ATTACH=CONFIG]33606[/ATTACH] (EDIT:cant seem to attach more than 5 files. let me know if the client log for this is needed....)
[ATTACH=CONFIG]33612[/ATTACH]

Next tried it with no skipping at all. Crashed a few minutes in.
[ATTACH=CONFIG]33608[/ATTACH]
[ATTACH=CONFIG]33609[/ATTACH]

Finally tried watching it 'normally' skipping first and middle ad breaks, but then letting it run through to it's full post padding. No crashes at all this time.
[ATTACH=CONFIG]33610[/ATTACH]
[ATTACH=CONFIG]33611[/ATTACH]
Are there any more verbose logging modes I can set to try and identify why the timestamp keeps getting messed up differently with every viewing?

BTW I noticed the client and server clocks seem to be out by a few mins - could this be related?