RCON closes with error, no error stack

ect0s commented 1 year ago

Description of Issue

Every now and then RCON will close with an error, but without an error stack log line,

[RCON][1] Disconnecting from: 15.235.160.4:21114
[RCON][1] Socket closed with an error.
[RCON][1] Disconnected from: 15.235.160.4:21114
[SquadServer][1] Setting up new RCON instance...
[RCON][1] Connecting to: 15.235.160.4:21114
[RCON][1] Connected to: 15.235.160.4:21114
[RCON][1] Authentication succeeded.

From here: https://github.com/Team-Silver-Sphere/SquadJS/blob/dc2bc1d663fb5b4aecab39d9072ef51dad089fae/core/rcon.js#L180

I would expect to see Logger.verbose('RCON', 1, Socket had error:, err);

Errors or Screenshots of Issue

Squad Information

SquadJS Version: 3.6.1
Squad Version: 4.1

If potentially relevant, please provide regarding the state of the Squad server at the time of error, e.g. the current layer.

System Information

Operating System: Linux
NodeJS Version: Node14
Yarn Version: N/A

I believe this may be due to us missing an 'end' event from the TCP socket, where the squad server has closed its side for whatever reason; though I'm still confused as to why we never see the error surface.

I had noticed this in previous versions of squadjs, but generally when our server had died off in the night.

https://nodejs.org/api/net.html#event-end

https://github.com/Team-Silver-Sphere/SquadJS/blob/dc2bc1d663fb5b4aecab39d9072ef51dad089fae/core/rcon.js#L35

ect0s commented 1 year ago

https://github.com/Team-Silver-Sphere/SquadJS/blob/dc2bc1d663fb5b4aecab39d9072ef51dad089fae/core/rcon.js#L172

Is this ternary backwards?

Close() with out data will result in the false case; leading to "with an Error"

reck1610 commented 1 year ago

Yeah, that's backwards.

I checked the node documentation to rule out, that the parameter was poorly named. https://nodejs.org/api/net.html#event-close_1

Event: 'close' Added in: v0.1.90

hadError \<boolean> true if the socket had a transmission error.

Emitted once the socket is fully closed. The argument hadError is a boolean which says if the socket was closed due to a transmission error.

ect0s commented 1 year ago

Yeah, that's backwards.

I checked the node documentation to rule out, that the parameter was poorly named. https://nodejs.org/api/net.html#event-close_1

Event: 'close' Added in: v0.1.90

hadError true if the socket had a transmission error.

Emitted once the socket is fully closed. The argument hadError is a boolean which says if the socket was closed due to a transmission error.

Yeah, thought so.

One thing I noticed, is with squadjs RCON timeout values, if we get blocked or broken in RCON (see #200 ) eventually squad will force close the socket; this is why I was wondering about us missing an "end" listener.

With the fixes in #267 (which is still missing the above listener!) we shouldn't ever timeout due to the 30 second polling loops we have.

I can remember helping someone else with an RCON tool and they had a similar issue with RCON closing if they didn't send a command for multiple minutes.

lbzepoqo commented 1 year ago

Hi, I just want to start that I don't have technical knowledge about this stuff.

I am currently experiencing this issue since February 20, 2022 UTC+8, I'm just sharing the date since that day and the day before I haven't changed anything in the settings nor installed any new plugins. It just began showing up on logs on that day.

What I see in the logs are these lines, and keeps happening non-stop:

[RCON][1] Connecting to: 15.235.160.4:21114
[RCON][1] Connected to: 15.235.160.4:21114
[RCON][1] Authentication succeeded.
[RCON][1] Socket closed with an error.
[RCON][1] Sleeping 5000ms before reconnecting.
[RCON][1] Connecting to: 15.235.160.4:21114
[RCON][1] Connected to: 15.235.160.4:21114
[RCON][1] Authentication succeeded.

In our Squad's logs, these shows too:

[2023.02.24-19.22.09:810][140]LogRCONServer: Warning: 1073142:HandleListenerConnectionAccepted(): Client is attempting multiple logins from 15.235.160.4, stopping older sessions
[2023.02.24-19.22.09:832][141]LogRCONServer: 1073896:CloseConnection(): Closing socket for 15.235.160.4:36788
[2023.02.24-19.22.14:822][365]LogRCONServer: Warning: 1073142:HandleListenerConnectionAccepted(): Client is attempting multiple logins from 15.235.160.4, stopping older sessions
[2023.02.24-19.22.14:822][365]LogRCONServer: 1073897:CloseConnection(): Closing socket for 15.235.160.4:36812
[2023.02.24-19.22.19:835][590]LogRCONServer: Warning: 1073142:HandleListenerConnectionAccepted(): Client is attempting multiple logins from 15.235.160.4, stopping older sessions
[2023.02.24-19.22.19:835][590]LogRCONServer: 1073902:CloseConnection(): Closing socket for 15.235.160.4:36836
[2023.02.24-19.22.24:847][815]LogRCONServer: Warning: 1073142:HandleListenerConnectionAccepted(): Client is attempting multiple logins from 15.235.160.4, stopping older sessions
[2023.02.24-19.22.24:847][815]LogRCONServer: 1073903:CloseConnection(): Closing socket for 15.235.160.4:36860
[2023.02.24-19.22.29:837][ 39]LogRCONServer: Warning: 1073142:HandleListenerConnectionAccepted(): Client is attempting multiple logins from 15.235.160.4, stopping older sessions
[2023.02.24-19.22.29:859][ 40]LogRCONServer: 1073904:CloseConnection(): Closing socket for 15.235.160.4:36882

What I tried so far:

I was initially running the changes in #267 and decided to change it back with the original version of the file and it still kept showing.
I reinstalled SquadJS, no custom plugins and all plugins set to false. Yet, it still showing those error.
I even tried changing my rcon password assuming that it got leaked but still the same.
Turned up verbosity level for RCON and SquadServer and attached the file here in Discord RCON.
Setting MaxConnections in RCON.cfg in Squad's config files to MaxConnections=4096. I am still requesting to add this in the arguments instead.

I hope someone can help enlighten me with the issue.

EDIT: As I was typing this, the issue went away. Feb 25, 2023 UTC+8

Team-Silver-Sphere / SquadJS