Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

JS Client reconnection, HubConnection.ts. Incorrect number of reconnection attempts is logged. #42806

Open
1 task done
babinik opened this issue Jul 19, 2022 · 0 comments
Open
1 task done

JS Client reconnection, HubConnection.ts. Incorrect number of reconnection attempts is logged. #42806

babinik opened this issue Jul 19, 2022 · 0 comments

Comments

@babinik
Copy link

@babinik babinik commented Jul 19, 2022

Is there an existing issue for this?

  • I have searched the existing issues

Describe the bug

JS SignalR Client version: 6.0.7

/** The version of the SignalR client. */
const VERSION = "6.0.7";

Overview.

Using standard SignalR reconnection mechanism, and in case connection was not finally established, the number of reconnection attempts is incorrectly logged. The number is -> reconnection attempts + 1, but expected to be -> reconnection attempts.

Details.

source: HubConnection.ts
method: private async _reconnect(error?: Error)

Problematic code-snippet _reconnect() loop source:

while (nextRetryDelay !== null) {
    this._logger.log(LogLevel.Information, `Reconnect attempt number ${previousReconnectAttempts} will start in ${nextRetryDelay} ms.`);

    //...

    try {
        await this._startInternal();

        // ...

        return;
    } catch (e) {
        this._logger.log(LogLevel.Information, `Reconnect attempt failed because of error '${e}'.`);
        // ... 

        retryError = e instanceof Error ? e : new Error(e.toString());
        // ! source code line number 822, previousReconnectAttempts++
        // increment, which finally influence on the incorrect log message (in case connection was not established).
        nextRetryDelay = this._getNextRetryDelay(previousReconnectAttempts++, Date.now() - reconnectStartTime, retryError);
    }
}

// ! source code line number 826
// incorrect number of reconnection attempts logged.
this._logger.log(LogLevel.Information, `Reconnect retries have been exhausted after ${Date.now() - reconnectStartTime} ms and ${previousReconnectAttempts} failed attempts. Connection disconnecting.`);

this._completeClose();

source line 822:
nextRetryDelay = this._getNextRetryDelay(previousReconnectAttempts++, Date.now() - reconnectStartTime, retryError);
source line 826:
this._logger.log(LogLevel.Information, `Reconnect retries have been exhausted after ${Date.now() - reconnectStartTime} ms and ${previousReconnectAttempts} failed attempts. Connection disconnecting.`);

Issue example.

When standard .withAutomaticReconnect() (witch attempts to reconnect 4 times [0, 2000, 10000, 30000]) fails to reconnect the following log message is logged:

[2022-07-19T07:55:10.103Z] Information: Reconnect retries have been exhausted after 58811 ms and 5 failed attempts. Connection disconnecting.

Message contains 5 attempts, but actually there were 4 attempts.

Expected Behavior

In case reconnection fails to establish connection, then the number of attempts logged should correspond to the number of actual reconnection attempts.

Steps To Reproduce

  1. Create connection and start it.
const hubConnection = new signalR.HubConnectionBuilder()
    .withUrl("<connectionURL>")
    .withAutomaticReconnect()
    .configureLogging(signalR.LogLevel.Information);


hubConnection.start();

  1. Stop hub, interrupting (closing) connection.

  2. Check log messages.

Example:

[2022-07-19T07:54:11.293Z] Information: Reconnect attempt number 1 will start in 0 ms.


[2022-07-19T07:54:15.388Z] Information: Reconnect attempt failed because of error 'Error: Failed to complete negotiation with the server: TypeError: Failed to fetch'.
[2022-07-19T07:54:15.388Z] Information: Reconnect attempt number 2 will start in 2000 ms.
[2022-07-19T07:54:21.464Z] Warning: Error from HTTP request. TypeError: Failed to fetch.


[2022-07-19T07:54:21.465Z] Information: Reconnect attempt failed because of error 'Error: Failed to complete negotiation with the server: TypeError: Failed to fetch'.
[2022-07-19T07:54:21.465Z] Information: Reconnect attempt number 3 will start in 10000 ms.
[2022-07-19T07:54:35.575Z] Warning: Error from HTTP request. TypeError: Failed to fetch.


[2022-07-19T07:54:35.576Z] Information: Reconnect attempt failed because of error 'Error: Failed to complete negotiation with the server: TypeError: Failed to fetch'.
[2022-07-19T07:54:35.576Z] Information: Reconnect attempt number 4 will start in 30000 ms.
[2022-07-19T07:55:10.102Z] Warning: Error from HTTP request. TypeError: Failed to fetch.


[2022-07-19T07:55:10.103Z] Information: Reconnect attempt failed because of error 'Error: Failed to complete negotiation with the server: TypeError: Failed to fetch'.
[2022-07-19T07:55:10.103Z] Information: Reconnect retries have been exhausted after 58811 ms and 5 failed attempts. Connection disconnecting.

There were 4 actual attempts to reconnect. Logged 5 attempts -> "Reconnect retries have been exhausted after 58811 ms and 5 failed attempts."

Exceptions (if any)

No response

.NET Version

6.0.300

Anything else?

No response
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@babinik