SignalR keep-alive options is not working

wmmihaa commented 4 years ago

Describe the bug

I'd like to extend the keep-alive settings to every three minutes, but event thought I follow the recommended configuration on both server and client, the client will disconnect and reconnect every 30 seconds.

To Reproduce

Middleware

services.AddSignalR(hubOptions =>
{
    hubOptions.EnableDetailedErrors = true;
    hubOptions.KeepAliveInterval = TimeSpan.FromMinutes(3);
    hubOptions.ClientTimeoutInterval = TimeSpan.FromMinutes(6);
})
    .AddJsonProtocol(options =>
    {
        options.PayloadSerializerOptions.PropertyNamingPolicy = null;
    });

Client (JavaScript)

    const signalR = require("@microsoft/signalr");
    const connection = new signalR.HubConnectionBuilder()
        .withUrl(`${uri}/nodeHub`)
        .withAutomaticReconnect() 
        .configureLogging(signalR.LogLevel.Debug)
        .build();
    connection.keepAliveIntervalInMilliseconds = 1000 * 60 * 3; // Three minutes
    connection.serverTimeoutInMilliseconds = 1000 * 60 * 6; // Six minutes

Client output

[2020-03-25T19:59:39.489Z] Debug: HttpConnection.stopConnection(undefined) called while in state Disconnecting.
[2020-03-25T19:59:39.491Z] Error: Connection disconnected with error 'Error: Server timeout elapsed without receiving a message from the server.'.
[2020-03-25T19:59:39.494Z] Debug: HubConnection.connectionClosed(Error: Server timeout elapsed without receiving a message from the server.) called while in state Connected.
[2020-03-25T19:59:39.496Z] Information: Connection reconnecting because of error 'Error: Server timeout elapsed without receiving a message from the server.'.
mSB: Connection: Retrying to connect (undefined)
[2020-03-25T19:59:39.502Z] Information: Reconnect attempt number 1 will start in 0 ms.
[2020-03-25T19:59:39.504Z] Debug: Starting connection with transfer format 'Text'.
[2020-03-25T19:59:39.505Z] Debug: Sending negotiation request: https://localhost:44390/nodeHub/negotiate?negotiateVersion=1.
[2020-03-25T19:59:39.519Z] Debug: Selecting transport 'WebSockets'.
[2020-03-25T19:59:39.533Z] Information: WebSocket connected to wss://localhost:44390/nodeHub?id=M7XNHGMAk7eqbMTHVoi47Q.
[2020-03-25T19:59:39.534Z] Debug: The HttpConnection connected successfully.
[2020-03-25T19:59:39.535Z] Debug: Sending handshake request.
[2020-03-25T19:59:39.536Z] Information: Using HubProtocol 'json'.
[2020-03-25T19:59:39.539Z] Debug: Server handshake complete.
[2020-03-25T19:59:39.540Z] Information: HubConnection reconnected successfully.
mSB: Connection: Reconnected
[2020-03-25T20:00:09.540Z] Debug: HttpConnection.stopConnection(undefined) called while in state Disconnecting.
[2020-03-25T20:00:09.540Z] Error: Connection disconnected with error 'Error: Server timeout elapsed without receiving a message from the server.'.
[2020-03-25T20:00:09.541Z] Debug: HubConnection.connectionClosed(Error: Server timeout elapsed without receiving a message from the server.) called while in state Connected.
[2020-03-25T20:00:09.541Z] Information: Connection reconnecting because of error 'Error: Server timeout elapsed without receiving a message from the server.'.
mSB: Connection: Retrying to connect (undefined)
[2020-03-25T20:00:09.544Z] Information: Reconnect attempt number 1 will start in 0 ms.
[2020-03-25T20:00:09.545Z] Debug: Starting connection with transfer format 'Text'.
[2020-03-25T20:00:09.546Z] Debug: Sending negotiation request: https://localhost:44390/nodeHub/negotiate?negotiateVersion=1.
[2020-03-25T20:00:09.584Z] Debug: Selecting transport 'WebSockets'.
[2020-03-25T20:00:09.596Z] Information: WebSocket connected to wss://localhost:44390/nodeHub?id=qE0s7Wf3hGZtTQ6BbGrGEg.
[2020-03-25T20:00:09.597Z] Debug: The HttpConnection connected successfully.
[2020-03-25T20:00:09.598Z] Debug: Sending handshake request.
[2020-03-25T20:00:09.599Z] Information: Using HubProtocol 'json'.
[2020-03-25T20:00:09.600Z] Debug: Server handshake complete.
[2020-03-25T20:00:09.601Z] Information: HubConnection reconnected successfully.
mSB: Connection: Reconnected

Further technical details

ASP.NET Core version: 3.1

Include the output of dotnet --info


dotnet --info
.NET Core SDK (reflecting any global.json):
Version:   3.1.101
Commit:    b377529961

Runtime Environment: OS Name: Windows OS Version: 10.0.18362 OS Platform: Windows RID: win10-x64 Base Path: C:\Program Files\dotnet\sdk\3.1.101\

Host (useful for support): Version: 3.1.1 Commit: a1388f194c

.NET Core SDKs installed: 2.1.202 [C:\Program Files\dotnet\sdk] 2.1.509 [C:\Program Files\dotnet\sdk] 2.2.109 [C:\Program Files\dotnet\sdk] 3.1.100 [C:\Program Files\dotnet\sdk] 3.1.101 [C:\Program Files\dotnet\sdk]

.NET Core runtimes installed: Microsoft.AspNetCore.All 2.1.13 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All] Microsoft.AspNetCore.All 2.1.15 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All] Microsoft.AspNetCore.All 2.2.7 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All] Microsoft.AspNetCore.App 2.1.13 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 2.1.15 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 2.2.7 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 3.1.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 3.1.1 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.NETCore.App 2.0.9 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 2.1.13 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 2.1.15 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 2.2.7 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 3.1.0 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 3.1.1 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.WindowsDesktop.App 3.1.0 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 3.1.1 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]


- The IDE (VS / VS Code/ VS4Mac) you're running on, and it's version: **VS 2019**

BrennanConroy commented 4 years ago

Tried reproing with a simple app and couldn't, the keepalive worked at the 3 minute interval.

Could you verify that the browser didn't cache a previous version of the code when you didn't have the 3 minute interval?

And if it still repros we might need a repro app.

wmmihaa commented 4 years ago

I get the same behavior from both a browser client and a node.js client. Are you sure you used my exact same settings? I'm just concerned I've used the wrong ones.

As soon as I publish the app to Azure, I'll ping you again so that you can try it out. Cheers

BrennanConroy commented 4 years ago

Yep, copy pasted the settings you set.

wmmihaa commented 4 years ago

I apologize for wasting your time @BrennanConroy . I went on to create a new project and as I couldn't reproduce it, I went back to my original project now it seems to work...I don't know what I must have done wrong, but I've spent hours on this today :(

wmmihaa commented 4 years ago

btw...can I ask you if it's possible to catpture configureLogging to a custom logger with js as I can do with c#?

dotnet / aspnetcore