I have a signalR hub in a console application and a WPF client. On startup the signalR connection initializes, and should always remain active. Every second a message gets pushed from the server to the client with the current SystemTime (This is what you can see in the logs with 'SystemTimeUpdateNotification')
The behavior I describe now is on a Windows7 device: every once and a while I see that the client loses connection to the server. For some reason the client detects it has been inactive and stops the connection. I have no idea where 'inactive since 4/20/2017 3:04:06 AM' and 'timeout 00:00:50' is coming from. If I check the log on the server around the same time I can see that there are no keepalive messages.
2017-04-20 05:04:04.0728,Trace,Received notification SystemTimeUpdateNotification 2017-04-20 05:04:05.0859,Trace,Received notification SystemTimeUpdateNotification 2017-04-20 05:04:06.0999,Trace,Received notification SystemTimeUpdateNotification 2017-04-20 05:05:13.1020,Trace,Received notification SystemTimeUpdateNotification 2017-04-20 05:05:14.1160,Trace,Received notification SystemTimeUpdateNotification 2017-04-20 05:05:14.5511,Info,The client has been inactive since 4/20/2017 3:04:06 AM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection. 2017-04-20 05:05:14.5871,Info,SignalR connectionstate changed from 'Connected' to 'Disconnected' 2017-04-20 05:05:14.5871,Trace,Received notification NotificationConnectionStateChanged 2017-04-20 05:05:14.5981,Info,Disconnecting... 2017-04-20 05:05:14.5981,Info,Cancel ongoing operations 2017-04-20 05:05:19.6104,Info,SignalR connectionstate changed from 'Disconnected' to 'Connecting' 2017-04-20 05:05:19.6104,Trace,Received notification NotificationConnectionStateChanged 2017-04-20 05:05:19.6104,Info,Disconnecting... 2017-04-20 05:05:19.6454,Info,SignalR connectionstate changed from 'Connecting' to 'Connected' 2017-04-20 05:05:19.6454,Trace,Received notification NotificationConnectionStateChanged 2017-04-20 05:05:19.6454,Info,Connecting... 2017-04-20 05:05:19.6524,Debug,Performing client/server compatibility check 2017-04-20 05:05:19.6524,Debug,Software compatible 2017-04-20 05:05:19.6524,Info,Start retrieving initial data 2017-04-20 05:05:20.0344,Info,initial data retrieved 2017-04-20 05:05:20.2044,Trace,Received notification SystemTimeUpdateNotification 2017-04-20 05:05:21.2144,Trace,Received notification SystemTimeUpdateNotification
Log on the server side:
2017-04-20 05:03:31.6069;Trace;KeepAlive(6a12952a-1cb4-4933-b6b1-db16158958a9) 2017-04-20 05:03:41.6225;Trace;KeepAlive(6a12952a-1cb4-4933-b6b1-db16158958a9) 2017-04-20 05:03:51.6371;Trace;KeepAlive(6a12952a-1cb4-4933-b6b1-db16158958a9) 2017-04-20 05:04:01.6527;Trace;KeepAlive(6a12952a-1cb4-4933-b6b1-db16158958a9) 2017-04-20 05:05:14.5661;Info;Abort(6a12952a-1cb4-4933-b6b1-db16158958a9) 2017-04-20 05:05:14.5661;Info;Removing connection 6a12952a-1cb4-4933-b6b1-db16158958a9 2017-04-20 05:05:14.5661;Info;End(6a12952a-1cb4-4933-b6b1-db16158958a9) 2017-04-20 05:05:14.5841;Trace;DrainWrites(6a12952a-1cb4-4933-b6b1-db16158958a9) 2017-04-20 05:05:14.5841;Info;CompleteRequest (6a12952a-1cb4-4933-b6b1-db16158958a9) 2017-04-20 05:05:19.6344;Info;Connection 9249a8a5-8653-450c-b8da-c5b7a4c7df81 is New. 2017-04-20 05:05:27.6738;Trace;KeepAlive(9249a8a5-8653-450c-b8da-c5b7a4c7df81) 2017-04-20 05:05:37.6874;Trace;KeepAlive(9249a8a5-8653-450c-b8da-c5b7a4c7df81)
Now I get to the really strange part. The 'once and a while' is actually quite fixed. I looked up log entries of the last few days, and it always seems to be around every 11 hours
Inactivity Timestamp Difference with previous LogEntry 17/04/2017 17:59:44 0:00:00 The client has been inactive since 4/17/2017 3:58:35 PM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection. 17/04/2017 17:59:44 11:01:06 The client has been inactive since 4/17/2017 3:58:35 PM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection. 17/04/2017 06:58:38 10:01:01 The client has been inactive since 4/17/2017 4:57:34 AM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection. 16/04/2017 20:57:37 11:01:06 The client has been inactive since 4/16/2017 6:56:29 PM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection. 16/04/2017 09:56:31 11:01:06 The client has been inactive since 4/16/2017 7:55:23 AM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection. 15/04/2017 22:55:25 11:01:06 The client has been inactive since 4/15/2017 8:54:17 PM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection. 15/04/2017 11:54:19 0:00:00 The client has been inactive since 4/15/2017 9:53:09 AM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection. 15/04/2017 11:54:19 11:01:07 The client has been inactive since 4/15/2017 9:53:09 AM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection. 15/04/2017 00:53:12 11:01:06 The client has been inactive since 4/14/2017 10:52:03 PM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection. 14/04/2017 13:52:06 11:01:06 The client has been inactive since 4/14/2017 11:50:58 AM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection. 14/04/2017 02:51:00 The client has been inactive since 4/14/2017 12:49:52 AM and it has exceeded the inactivity timeout of 00:00:50. Stopping the connection.
Is there something like a maximum connection time or what could be causing this behavior?
EDIT 1: if I run the same code on a windows 8, I don't have this problem. I guess it has something to do with the transport method being used on Windows 7 (doesn't support websockets)
EDIT 2:
Server Client Inactivity problem Win 8 Win 8 No Win 7 Win 7 Yes Win 7 Win 8 No Win 8 Win 7 Yes
So it seems related to the operating system of the client.
As stated in the documentation, one way to keep your connection, is to continuously reconnect after its disconnected. Set the disconnected function in your Client
$.connection.hub.disconnected(function() {
setTimeout(function() {
$.connection.hub.start();
}, 5000); // Restart connection after 5 seconds.
});
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With