CODEWITHSUNDEEP
connectiontimeoutsignalr
Joris
Joris

Reputation: 341

SignalR client stops the connection due to inactivity

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.

Upvotes: 13

Views: 9234

Answers (1)

Mark
Mark

Reputation: 2071

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.
});

Upvotes: 3

Related Questions