Skip to content

TcMenu server connection issues #551

Open
Open
TcMenu server connection issues#551
@vzahradnik

Description

@vzahradnik
vzahradnik
opened on Apr 27, 2025

Describe the bug
This bug report is about issues while using TagVal protocol where TcMenu Arduino code actively innitiates connection to the remote server.

I will update this ticket once I find more issues.

  1. TcMenu server is terminated, client tries to connect. Once the server is rebooted, after a while client reconnects ==> OK
  2. TcMenu server runs but the client is rebooted. Server still holds the old connection entry. Once the client is up, it tries to establish a connection with the new socket (IP is usually the same, the port is different). Connection is never established. Server keeps sending heartbeat to disconnected client. Here is the log:
2025-04-27 20:21:46,285 INFO  [SocketClientRemoteConnector] (remote-socket) TCP /192.168.1.94:64853 - Transition BootstrapInProgressState->ConnectionReadyState for TCP /192.168.1.94:64853
2025-04-27 20:21:46,287 INFO  [RemoteMenuController] (remote-socket) Connection state changed to connected = CONNECTION_READY
2025-04-27 20:21:46,288 INFO  [ConnectionReadyState] (remote-socket) Heartbeat interval is 60000
2025-04-27 20:21:46,460 INFO  [SocketClientRemoteConnector] (remote-socket) TCP /192.168.1.93:60596 - Transition BootstrapInProgressState->ConnectionReadyState for TCP /192.168.1.93:60596
2025-04-27 20:21:46,461 INFO  [RemoteMenuController] (remote-socket) Connection state changed to connected = CONNECTION_READY
2025-04-27 20:21:46,461 INFO  [ConnectionReadyState] (remote-socket) Heartbeat interval is 60000
2025-04-27 20:23:51,323 INFO  [SocketClientRemoteServer] (Thread-77) Accepted client /192.168.1.94:53698
2025-04-27 20:23:51,324 INFO  [SocketClientRemoteConnector] (Thread-77) NULL - Transition NoState->NoOperationInitialState for NULL
2025-04-27 20:23:51,324 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.94:53698 - Client acquired from /192.168.1.94:53698
2025-04-27 20:23:51,324 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.94:53698 - Transition NoOperationInitialState->SocketAwaitJoinState for TCP /192.168.1.94:53698
2025-04-27 20:23:51,324 INFO  [RemoteMenuController] (Thread-77) Connection state changed to connected = ESTABLISHED_CONNECTION
2025-04-27 20:23:51,324 INFO  [SocketClientRemoteServer] (Thread-77) Attempting to accept client connection on port: 3333
2025-04-27 20:24:38,123 INFO  [SocketClientRemoteServer] (Thread-77) Accepted client /192.168.1.94:51898
2025-04-27 20:24:38,123 INFO  [SocketClientRemoteConnector] (Thread-77) NULL - Transition NoState->NoOperationInitialState for NULL
2025-04-27 20:24:38,124 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.94:51898 - Client acquired from /192.168.1.94:51898
2025-04-27 20:24:38,124 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.94:51898 - Transition NoOperationInitialState->SocketAwaitJoinState for TCP /192.168.1.94:51898
2025-04-27 20:24:38,124 INFO  [RemoteMenuController] (Thread-77) Connection state changed to connected = ESTABLISHED_CONNECTION
2025-04-27 20:24:38,125 INFO  [SocketClientRemoteServer] (Thread-77) Attempting to accept client connection on port: 3333

2025-04-27 22:33:38,885 INFO  [SocketClientRemoteServer] (Thread-77) Accepted client /192.168.1.93:60599
2025-04-27 22:33:38,889 INFO  [SocketClientRemoteConnector] (Thread-77) NULL - Transition NoState->NoOperationInitialState for NULL
2025-04-27 22:33:38,900 INFO  [RemoteMenuController] (remote-socket) Connection state changed to connected = NOT_STARTED
2025-04-27 22:33:38,902 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Client acquired from /192.168.1.93:60599
2025-04-27 22:33:38,903 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition NoOperationInitialState->SocketAwaitJoinState for TCP /192.168.1.93:60599
2025-04-27 22:33:38,906 INFO  [RemoteMenuController] (Thread-77) Connection state changed to connected = ESTABLISHED_CONNECTION
2025-04-27 22:33:38,907 INFO  [SocketClientRemoteConnector] (remote-socket) TCP /192.168.1.93:60599 - Started ticker thread for TCP /192.168.1.93:60599
2025-04-27 22:33:38,907 INFO  [SocketClientRemoteServer] (Thread-77) Attempting to accept client connection on port: 3333
2025-04-27 22:33:38,953 INFO  [SocketClientRemoteConnector] (remote-socket) TCP /192.168.1.93:60599 - Transition SocketAwaitJoinState->JoinMessageArrivedState for TCP /192.168.1.93:60599
2025-04-27 22:33:38,955 INFO  [RemoteMenuController] (remote-socket) Connection state changed to connected = SEND_AUTH
2025-04-27 22:33:39,022 INFO  [JoinMessageArrivedState] (remote-socket) Authenticated successfully with TCP /192.168.1.93:60599
2025-04-27 22:33:39,022 INFO  [SocketClientRemoteConnector] (remote-socket) TCP /192.168.1.93:60599 - Transition JoinMessageArrivedState->AwaitingBootstrapState for TCP /192.168.1.93:60599
2025-04-27 22:33:39,023 INFO  [RemoteMenuController] (remote-socket) Connection state changed to connected = AUTHENTICATED
2025-04-27 22:33:39,023 INFO  [SocketClientRemoteConnector] (remote-socket) TCP /192.168.1.93:60599 - Transition AwaitingBootstrapState->BootstrapInProgressState for TCP /192.168.1.93:60599
2025-04-27 22:33:39,023 INFO  [RemoteMenuController] (remote-socket) Connection state changed to connected = BOOTSTRAPPING
2025-04-27 22:33:39,324 INFO  [SocketClientRemoteConnector] (remote-socket) TCP /192.168.1.93:60599 - Transition BootstrapInProgressState->ConnectionReadyState for TCP /192.168.1.93:60599
2025-04-27 22:33:39,325 INFO  [RemoteMenuController] (remote-socket) Connection state changed to connected = CONNECTION_READY
2025-04-27 22:33:39,326 INFO  [ConnectionReadyState] (remote-socket) Heartbeat interval is 60000
2025-04-27 22:33:40,326 INFO  [ConnectionReadyState] (remote-socket) Heartbeat being sent due to inactivity TCP /192.168.1.93:60599
2025-04-27 22:33:41,225 INFO  [SocketClientRemoteServer] (Thread-77) Accepted client /192.168.1.94:51901
2025-04-27 22:33:41,226 INFO  [SocketClientRemoteConnector] (Thread-77) NULL - Transition NoState->NoOperationInitialState for NULL
2025-04-27 22:33:41,226 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,227 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ConnectionReadyState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,227 INFO  [ConnectionReadyState] (Thread-77) Force closing connection TCP /192.168.1.93:60599
2025-04-27 22:33:41,228 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,228 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,228 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,228 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,229 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,229 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,229 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,229 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,230 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,230 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,230 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,231 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,231 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,231 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,231 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,231 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,233 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,233 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,233 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,233 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,234 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,234 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,234 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,235 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,235 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,235 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,235 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,236 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,236 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,237 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,237 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,237 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,237 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599
2025-04-27 22:33:41,238 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Transition ClientConnectionFailedState->ClientConnectionFailedState for TCP /192.168.1.93:60599
2025-04-27 22:33:41,238 INFO  [SocketClientRemoteConnector] (Thread-77) TCP /192.168.1.93:60599 - Closing client socket TCP /192.168.1.93:60599

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions