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

[Bug Report] Player detection loop #287

Closed
2 tasks done
Jadiction opened this issue Jan 6, 2025 · 13 comments
Closed
2 tasks done

[Bug Report] Player detection loop #287

Jadiction opened this issue Jan 6, 2025 · 13 comments
Assignees
Labels
bug Something isn't working enhancement New feature or request

Comments

@Jadiction
Copy link

You understand that if you dont provide clear information on your "Problem", "Software and Hardware-Setup" and the "Steps to reproduce" your issue will be closed without any help, because your not willing to do your part?

  • Yes i do!

You understand that im not a Game-Dev or Game-Server-Dev and my support is primary for the Docker-Image and somewhat limited to the Game-Server?

  • Yes i do!

Current behavior

Since the new update, it seems the player detection will sometimes loop join/leave announcements.
After looking into the logs, it seems this happens when it fails to connect via RCON.

Log example:

[2025-01-06 07:55:09] [LOG] RCON executed the command. showplayers
[07:55:24]: Player Jad has left the server.
cli: execute: auth: rcon: rcon: read packet size: EOF
> RCON: 
[2025-01-06 07:55:39] [LOG] RCON executed the command. showplayers
[07:55:39]: Player Jad has joined the server.
[2025-01-06 07:55:39] [LOG] RCON executed the command. broadcast [07:55:39] Jad joined the server
cli: execute: rcon: read tcp 127.0.0.1:38976->127.0.0.1:25575: i/o timeout
> RCON: Broadcasted: [07:55:39] Jad joined the ser

Upon error cli: execute: auth: rcon: rcon: read packet size: EOF it announces the leave, then will "re-announce" the join.
When it times out with the error cli: execute: rcon: read tcp 127.0.0.1:38976->127.0.0.1:25575: i/o timeout it will repeat the join announcement.

A screenshot example of 1 user being in game:
image

Desired behavior

Account for RCON connection failures and avoid false or spam join/leave announcements.

Links to screenshots

No response

Steps to reproduce

Steps to reproduce the behavior:
Unsure if this is a specific issue on my end (although I don't see any changes, errors, or resource issues), or a new issue with the latest Palworld update.

Software setup

  • OS: Linux
  • Docker: Branch - develop

Hardware setup

N/A

Additional context

No response

@Jadiction Jadiction added the bug Something isn't working label Jan 6, 2025
@jammsen
Copy link
Owner

jammsen commented Jan 6, 2025

Hey @Jadiction - A restart of the image or the server fixes the issue right?

Not sure on how to accurately test this though, normally it should not even timeout, its a local connection for rconcli to the system, because its inside the container too.

Very weird, can you provide player-numbers, activity and Hardware-Infos please?

@Jadiction
Copy link
Author

Jadiction commented Jan 6, 2025

Hey @Jadiction - A restart of the image or the server fixes the issue right?

I think it helps for a little, but I don't restart the server often.

Not sure on how to accurately test this though, normally it should not even timeout, its a local connection for rconcli to the system, because its inside the container too.

I wouldn't think it would time out either, but it's somehow managing to do so, that's why I thought it may be a (new) Palworld issue. Perhaps the server has FPS stall times where it fails to reach the RCON connection in time.

Very weird, can you provide player-numbers, activity and Hardware-Infos please?

I've seen it during player numbers being around 1-3. In my example above there was only 1. Currently 2 are online and the issue persists.

Relevant hardware:
CPU - Intel® Core™ i7-5930K CPU @ 3.50GHz | Temperature: 36 °C
Memory - 64 GiB DDR4 (50% usage)

@jammsen
Copy link
Owner

jammsen commented Jan 8, 2025

@Jadiction - I have tried to implement a specific fix for this edge-case, can you please tryout the latest develop tag and tell me if that fixes it for you?

@Jadiction
Copy link
Author

@Jadiction - I have tried to implement a specific fix for this edge-case, can you please tryout the latest develop tag and tell me if that fixes it for you?

Thanks for the update. With my testing, it looks like it runs into an error when loading:
/includes/playerdetection.sh: line 64: player_data: bad array subscript

@jammsen
Copy link
Owner

jammsen commented Jan 9, 2025

Hey @Jadiction - Yeah that was down to a mechanic i didnt catch, sorry.

Looks like its only on broadcast, not on showplayers, but something gets weird and confused, after that error.

Seems like that base problem is on rcon-cli side, see the list of issues related to the same problem:

Not sure if its getting fixed by outdead because the issue is rather old.

I have now implemented an even more complex workaround, not happy with that, but i think i saved it kinda, by putting it behind the ENV-Var RCON_PLAYER_DEBUG=false/true see Env-Var-Docs.

New develop tag is done cooking, feel free to test it with RCON_PLAYER_DEBUG set to true and false please and deliver detailed feedback on this please.

@jammsen jammsen self-assigned this Jan 9, 2025
@jammsen jammsen added the enhancement New feature or request label Jan 9, 2025
@Jadiction
Copy link
Author

Hi @jammsen

With the latest develop version, I got a double join announcement. When this happens, the command output is empty.

With the logs below, you can see it successfully sees me in the server and continues normally, then on the next iteration, it gets a blank command output and believes no players are on the server. It then announces the join (at a later time from initial join)
image
image

@jammsen
Copy link
Owner

jammsen commented Jan 11, 2025

Hi @jammsen

With the latest develop version, I got a double join announcement. When this happens, the command output is empty.

With the logs below, you can see it successfully sees me in the server and continues normally, then on the next iteration, it gets a blank command output and believes no players are on the server. It then announces the join (at a later time from initial join) image image

Could you please mark what you in the full screenshot or so? Im confused on what you mean by this explaination and i did read it 3 times and still am not really sure what you mean, sorry.

@Jadiction
Copy link
Author

Jadiction commented Jan 12, 2025

@jammsen

I'm guessing when it fails to connect to RCON, it gives an empty player list (as shown in the 2nd iteration of the debug messages) so it thinks no players are in the server. Then it iterates again and announces everyone in the server.

This is something persistent as of right now as well:
image
image
(In this screenshot, it actually shows the I/O timeout error, which may be more helpful)
We can see
Box 1: Both players were successfully shown in game (nobody left)
Box 2: The second iteration fails to connect and gets an empty command_output
Box 3: Third iteration (re-)announces the players that were already in game since it believed no players were in the server due to the failed connection in box 2

@jammsen
Copy link
Owner

jammsen commented Jan 12, 2025

(In this screenshot, it actually shows the I/O timeout error, which may be more helpful)

No it actually makes it more confusing, also i did already cover the I/O Timeout error here - #287 (comment) - Its a problem itself with rconcli on "broadcast", not really sure what i should be able to do, if the software simply doesnt do it cleanly.

I'm guessing when it fails to connect to RCON, it gives an empty player list (as shown in the 2nd iteration of the debug messages) so it thinks no players are in the server. Then it iterates again and announces everyone in the server.

No it shouldnt be able to do that, because of https://github.com/jammsen/docker-palworld-dedicated-server/blob/develop/includes/playerdetection.sh#L27-L43 - It checks if the exit-code is good and then checks if the CSV header line is in there and then reads new player data, if the command is weird it unsets current_players in Line 37, which might cause this behavior not sure how this could be reproduced though. WHICH would explain the behavior you are describing, i can just comment out Line 37 and you try again to "bug" it.

But please understand that THAT behavior has nothing to do with

[2025-01-06 07:55:39] [LOG] RCON executed the command. broadcast [07:55:39] Jad joined the server
cli: execute: rcon: read tcp 127.0.0.1:38976->127.0.0.1:25575: i/o timeout

One is on gathering players and one is on sending infos about the announces. Announcing however doesnt fiddle around with the data in current_players. 1 Problem does cause announcing to much and 1 Problem is that the announce isnt exited cleanly and that is up to outdead to fix, not me. (Also the announce goes through but reports an non clean shutdown error or so, im not into go, no idea why that is!)

Please keep thoose 2 things seperated.

jammsen added a commit that referenced this issue Jan 12, 2025
…to empty on no data and no error exit code, for testing
@jammsen
Copy link
Owner

jammsen commented Jan 12, 2025

@Jadiction - Baking is done, its on the develop image, when are you available to join Discord so we can test this out together?

@jammsen
Copy link
Owner

jammsen commented Jan 12, 2025

The Timeout with rconcli seems to be a Palworld rconcli thing, also known already, See theese:
thijsvanloef/palworld-server-docker#492
gorcon/rcon-cli#35

Also here in the documentation of Palworld:
https://tech.palworldgame.com/api/rcon/#notes

@Jadiction
Copy link
Author

@Jadiction - Baking is done, its on the develop image, when are you available to join Discord so we can test this out together?

I updated the container and so far haven't seen the issue. I have joined the Discord and I will keep you updated.

Currently it seems removing current_players=() when the exit status for command_output isn't 0 is the fix.

jammsen added a commit that referenced this issue Jan 14, 2025
@jammsen
Copy link
Owner

jammsen commented Jan 14, 2025

This fix is now on :latest, if you find anything regarding things, feel free to write here or on Discord again, then we can reopen this issue.

@jammsen jammsen closed this as completed Jan 14, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working enhancement New feature or request
Projects
None yet
Development

No branches or pull requests

2 participants