Server Closes Connection After Reconnection

Post here your questions about SFS2X. Here we discuss all server-side matters. For client API questions see the dedicated forums.

Moderators: Lapo, Bax

User avatar
Aet
Posts: 34
Joined: 15 Aug 2019, 23:10

Server Closes Connection After Reconnection

Postby Aet » 16 Mar 2021, 02:09

We have a fairly unusual issue I'm trying to figure out with our Smartfox 2.17 server and Unity client.
When we kill the clientside connection with smartfox.KillConnection(), if we send any sort of server request before reconnection occurs then after reconnecting the server immediately kicks the client. Locally reconnection has no issue, this may just be because local reconnection is so quick.

Serverside the following messages are given:

Code: Select all

Session created: { Id: 17739
User login: A
Room joined: R
Session created: { Id: 17741
Session removed: { Id: 17741 (not clear on why this extra session exists)
Session was resurrected: { Id: 17739,
Reconnected USER: A
Session removed: { Id: 17739
User disconnected: A
Exception: com.smartfoxserver.v2.exceptions.SFSRuntimeException
Message: System Request rejected: client is not using an encrypted connection. Request: SetUserVariables, User: A
Description: Runtime error while processing request
+--- --- ---+
Stack Trace:
+--- --- ---+
com.smartfoxserver.v2.controllers.BaseControllerCommand.checkRequestPermissions(BaseControllerCommand.java:150)
com.smartfoxserver.v2.controllers.BaseControllerCommand.checkRequestPermissions(BaseControllerCommand.java:197)
com.smartfoxserver.v2.controllers.system.SetUserVariables.execute(SetUserVariables.java:41)
com.smartfoxserver.v2.controllers.v290.SystemReqController.processRequest(SystemReqController.java:172)
com.smartfoxserver.v2.controllers.v290.SystemReqController.enqueueRequest(SystemReqController.java:127)
com.smartfoxserver.bitswarm.io.protocols.AbstractProtocolCodec.dispatchRequestToController(AbstractProtocolCodec.java:39)
com.smartfoxserver.v2.protocol.SFSProtocolCodec.dispatchRequest(SFSProtocolCodec.java:133)
com.smartfoxserver.v2.protocol.SFSProtocolCodec.onPacketRead(SFSProtocolCodec.java:90)
com.smartfoxserver.v2.protocol.binary.BinaryIoHandler$1.run(BinaryIoHandler.java:477)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

Session created: { Id: 17742, (unsure about the existence of this session as well)

com.smartfoxserver.bitswarm.exceptions.SessionReconnectionException: Session Reconnection failure. The passed Session is not managed by the ReconnectionManager: java.nio.channels.SocketChannel[connected local= remote=]
   com.smartfoxserver.bitswarm.sessions.DefaultReconnectionManager.reconnectSession(DefaultReconnectionManager.java:155)
   com.smartfoxserver.bitswarm.sessions.DefaultSessionManager.reconnectSession(DefaultSessionManager.java:373)
   com.smartfoxserver.v2.controllers.system.Handshake.execute(Handshake.java:68)
   com.smartfoxserver.v2.controllers.v290.SystemReqController.processRequest(SystemReqController.java:172)
   com.smartfoxserver.v2.controllers.v290.SystemReqController.enqueueRequest(SystemReqController.java:127)
   com.smartfoxserver.bitswarm.io.protocols.AbstractProtocolCodec.dispatchRequestToController(AbstractProtocolCodec.java:39)
   com.smartfoxserver.v2.protocol.SFSProtocolCodec.dispatchRequest(SFSProtocolCodec.java:133)
   com.smartfoxserver.v2.protocol.SFSProtocolCodec.onPacketRead(SFSProtocolCodec.java:90)
   com.smartfoxserver.v2.protocol.binary.BinaryIoHandler$1.run(BinaryIoHandler.java:477)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   java.lang.Thread.run(Thread.java:748)

com.smartfoxserver.v2.exceptions.SFSRuntimeException:
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
Exception: com.smartfoxserver.v2.exceptions.SFSRuntimeException
Message: System Request rejected: { Id: 17742, Type: DEFAULT, Logged: No, IP:  }, Client is not logged in.
Description: Runtime error while processing request
+--- --- ---+
Stack Trace:
+--- --- ---+
com.smartfoxserver.v2.controllers.BaseControllerCommand.checkRequestPermissions(BaseControllerCommand.java:112)
com.smartfoxserver.v2.controllers.BaseControllerCommand.checkRequestPermissions(BaseControllerCommand.java:197)
com.smartfoxserver.v2.controllers.system.SetUserVariables.execute(SetUserVariables.java:41)
com.smartfoxserver.v2.controllers.v290.SystemReqController.processRequest(SystemReqController.java:172)
com.smartfoxserver.v2.controllers.v290.SystemReqController.enqueueRequest(SystemReqController.java:127)
com.smartfoxserver.bitswarm.io.protocols.AbstractProtocolCodec.dispatchRequestToController(AbstractProtocolCodec.java:39)
com.smartfoxserver.v2.protocol.SFSProtocolCodec.dispatchRequest(SFSProtocolCodec.java:133)
com.smartfoxserver.v2.protocol.SFSProtocolCodec.onPacketRead(SFSProtocolCodec.java:90)
com.smartfoxserver.v2.protocol.binary.BinaryIoHandler$1.run(BinaryIoHandler.java:477)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::


After this I get the same Client not logged in message a few times before the client disconnects and session 17743 is removed.

On the client side I get this order of events:

Code: Select all

Command KillConnection done
[SFS - ERROR] [TCPSocketLayer] General error reading data from socket: Unable to read data from the transport connection: A blocking operation was interrupted by a call to WSACancelBlockingCall.
OnConnectionRetry
OnConnectionResume
[SFS - ERROR] [TCPSocketLayer] Connection closed by the remote side
OnConnectionRetry
OnConnectionLost



This is all an encrypted connection, however the local testing was setup with encryption as well and local reconnects fine. We also reconnect fine if the client is standing still and sends no messages. I've tried blocking all messages to Smartfox while disconnected but it seems due to timing issues some will still be sent while disconnecting, or perhaps right after reconnecting (judging by the messages server side complaining about unencrypted an SetUserVariable request) if the client is moving around while the disconnection happens.

This is completely reproducible and seems to have the same order of error messages and content as I showed above. We only call smartfox.connect() once so I do not know where these extra sessions come from.

Any thoughts on where to look for what this problem might be? Thanks so much for any advice! If you want to discuss this with the full logs or request any code we can take this off the forums as well of course.
User avatar
Lapo
Site Admin
Posts: 23008
Joined: 21 Mar 2005, 09:50
Location: Italy

Re: Server Closes Connection After Reconnection

Postby Lapo » 16 Mar 2021, 09:15

Hi,
can you give us a step-by-step description of how to reproduce the problem?
We'll try it on our end.

Thanks
Lapo
--
gotoAndPlay()
...addicted to flash games
User avatar
Aet
Posts: 34
Joined: 15 Aug 2019, 23:10

Re: Server Closes Connection After Reconnection

Postby Aet » 16 Mar 2021, 16:27

Apologies, to be clear I mean reproducible as in with our code base it is consistent to get this exact order of errors and issue.

I doubt it is something internal to Smartfox, I would just like some advice on where to look, because of how unusual this error is, and the fact it seems to be coming from serverside makes it seem like the cause is some hole in my Smartfox knowledge.

If you wanted to test if it reproducible in the smallest Smartfox environment you could, it would be an encrypted remote server being connected to by a client (far enough away to have some level of lag communicating to the server) that sends a SetVariableRequestUpdate 10 or so times a second (to ensure it sends one before reconnecting) and runs smartfox.KillConnection() without blocking the SetVariableRequestUpdate sends (in our case we block them when smartfox.IsConnected is false but some clearly still get through).

Reconnection time is set to 20 seconds.
User avatar
Lapo
Site Admin
Posts: 23008
Joined: 21 Mar 2005, 09:50
Location: Italy

Re: Server Closes Connection After Reconnection

Postby Lapo » 16 Mar 2021, 17:21

Hi,
thanks for the clarification.
I think we can attempt to reproduce that kind of scenario.

We'll set the test up tomorrow and see what we can find.

I doubt it is something internal to Smartfox, I would just like some advice on where to look, because of how unusual this error is, and the fact it seems to be coming from serverside makes it seem like the cause is some hole in my Smartfox knowledge.

I don't have any specific suggestions as of now.
I'd rather check this test case and see if we can reproduce it.

We'll post once we've run the test.
Cheers
Lapo

--

gotoAndPlay()

...addicted to flash games
User avatar
Aet
Posts: 34
Joined: 15 Aug 2019, 23:10

Re: Server Closes Connection After Reconnection

Postby Aet » 16 Mar 2021, 21:17

Thanks so much! You are the best Lapo!
User avatar
Aet
Posts: 34
Joined: 15 Aug 2019, 23:10

Re: Server Closes Connection After Reconnection

Postby Aet » 17 Mar 2021, 05:45

So we figured out how to stop the timing issues from affecting our case. We were relying on Smartfox.IsConnected. However it appears that there is some lag before that becomes false after a disconnection, if instead we set an isReconnecting boolean on CONNECTION_RETRY that blocks outgoing message it appears to solve the timing problem. CONNECTION_RESUME can turn it off. I'm surprised that CONNECTION_RETRY happens earlier than IsConnected becomes set to false, but it appears that is the case.

Simple solution, and it solved the issue for us, but definitely something weird going on with the fact a SetUserVariablesRequest sent while disconnected causes the disconnect from Smartfox after reconnected, so I expect there is some underlying issue there.
User avatar
Lapo
Site Admin
Posts: 23008
Joined: 21 Mar 2005, 09:50
Location: Italy

Re: Server Closes Connection After Reconnection

Postby Lapo » 17 Mar 2021, 08:04

The idea of checking the isReconnecting flag makes a lot of sense and it escaped me :? Indeed that's the best approach.
In any case thanks for reporting, we'll investigate your test case and see what else we can find.

Can you confirm you're using the latest C# API, version 1.7.13?

Thanks
Lapo

--

gotoAndPlay()

...addicted to flash games
User avatar
Aet
Posts: 34
Joined: 15 Aug 2019, 23:10

Re: Server Closes Connection After Reconnection

Postby Aet » 17 Mar 2021, 08:46

I can confirm the version number is 1.7.13.

Return to “SFS2X Questions”

Who is online

Users browsing this forum: No registered users and 42 guests