High CPU Load with bots in an empty lobby

[major-mayer]

Description

When I create a (headless) server an no one is on the server, the CPU load is quite decent, just taking a few percent or so.
But as soon as you spawn bots (or ai karts) on the server the CPU load goes directly up to 100% even though no other (real) player is on the server and no game is running.
Interestingly the high cpu load does not come from the Supertuxkart process which spawns the bots, but instead from the server process itself.
I could understand that bots need more ressources when they are ingame, but I don't think this should be the case in an empty lobby.

Steps to reproduce

1. Create a public WAN server with 15 slots
2. Spawn a bunch of bots on it from the same host

Configuration

STK release version:

STK Source (PPA, distribution package, official binary, etc.): Self compiled from source to make use of the -DSERVER_ONLY=ON and -DUSE_SYSTEM_ENET=ON variable

System: Debian Buster in a Docker container

Graphics card: None

CPU: AMD Ryzen 3400G

Additional information

Screenshot from the CPU load diagram (from Portainer):

stdout.log:

Initialize SuperTuxKart user account

[verbose  ] main: Error messages and other text output will be logged to /home/stk/.config/supertuxkart/config-0.10/stdout.log.

[info   ] [FileManager]: Data files will be fetched from: '/usr/local/share/supertuxkart/data/'

[info   ] [FileManager]: User directory is '/home/stk/.config/supertuxkart/config-0.10/'.

[info   ] [FileManager]: Addons files will be stored in '/home/stk/.local/share/supertuxkart/addons/'.

[info   ] [FileManager]: Screenshots will be stored in '/home/stk/.local/share/supertuxkart/screenshots/'.

[info   ] [FileManager]: User-defined grand prix will be stored in '/home/stk/.local/share/supertuxkart/grandprix/'.

[info   ] [FileManager]: Asset 0 will be loaded from '/usr/local/share/supertuxkart/data/challenges/'.

[info   ] [FileManager]: Asset 1 will be loaded from '/usr/local/share/supertuxkart/data/gfx/'.

[info   ] [FileManager]: Asset 2 will be loaded from '/usr/local/share/supertuxkart/data/grandprix/'.

[info   ] [FileManager]: Asset 3 will be loaded from '/usr/local/share/supertuxkart/data/gui/icons/'.

[info   ] [FileManager]: Asset 4 will be loaded from '/usr/local/share/supertuxkart/data/gui/screens/'.

[info   ] [FileManager]: Asset 5 will be loaded from '/usr/local/share/supertuxkart/data/gui/dialogs/'.

[info   ] [FileManager]: Asset 6 will be loaded from '/usr/local/share/supertuxkart/data/replay/'.

[info   ] [FileManager]: Asset 7 will be loaded from '/usr/local/share/supertuxkart/data/shaders/'.

[info   ] [FileManager]: Asset 8 will be loaded from '/usr/local/share/supertuxkart/data/skins/'.

[info   ] [FileManager]: Asset 9 will be loaded from '/usr/local/share/supertuxkart/data/ttf/'.

[info   ] [FileManager]: Asset 10 will be loaded from '/usr/local/share/supertuxkart/data/po/'.

[info   ] [FileManager]: Asset 11 will be loaded from '/usr/local/share/supertuxkart/data/library/'.

[info   ] [FileManager]: Asset 12 will be loaded from '/usr/local/share/supertuxkart/data/models/'.

[info   ] [FileManager]: Asset 13 will be loaded from '/usr/local/share/supertuxkart/data/music/'.

[info   ] [FileManager]: Asset 14 will be loaded from '/usr/local/share/supertuxkart/data/sfx/'.

[info   ] [FileManager]: Asset 15 will be loaded from '/usr/local/share/supertuxkart/data/textures/'.

[info   ] [FileManager]: Asset 16 will be loaded from '/usr/local/share/supertuxkart/data/tracks/'.

..:: Antarctica Rendering Engine 2.0 ::..

[info   ] HTTPRequest: Sending userid=287075&token=************************ to https://online.supertuxkart.net/api/v2/user/saved-session/

[info   ] GrandPrixManager: Loading Grand Prix files from /usr/local/share/supertuxkart/data/grandprix/

[info   ] GrandPrixManager: Loading Grand Prix files from /home/stk/.local/share/supertuxkart/grandprix/

[info   ] HTTPRequest: Sending username=******&password=********************&save-session=true to https://online.supertuxkart.net/api/v2/user/connect/

[info   ] Main: Logged in from command-line.

[info   ] Main: Done saving user, leaving

[verbose  ] Thread: Start waiting 3454397.711000

[info   ] HTTPRequest: Sending userid=287075&token=************************ to https://online.supertuxkart.net/api/v2/user/client-quit/

[verbose  ] Thread: Waited 0.567000 seconds for thread to become deleteable.

[verbose  ] Thread: Stop waiting 3454398.279000

[info   ] Singleton: Destroyed singleton.

$stk_aikarts is set

Starting SuperTuxKart server in background

$stk_serverpw is empty - connect 10 bots to server without a password

[verbose  ] main: Error messages and other text output will be logged to /home/stk/.config/supertuxkart/config-0.10/server_config.log.

[info   ] [FileManager]: Data files will be fetched from: '/usr/local/share/supertuxkart/data/'

[info   ] [FileManager]: User directory is '/home/stk/.config/supertuxkart/config-0.10/'.

[info   ] [FileManager]: Addons files will be stored in '/home/stk/.local/share/supertuxkart/addons/'.

[info   ] [FileManager]: Screenshots will be stored in '/home/stk/.local/share/supertuxkart/screenshots/'.

[info   ] [FileManager]: User-defined grand prix will be stored in '/home/stk/.local/share/supertuxkart/grandprix/'.

[info   ] [FileManager]: Asset 0 will be loaded from '/usr/local/share/supertuxkart/data/challenges/'.

[info   ] [FileManager]: Asset 1 will be loaded from '/usr/local/share/supertuxkart/data/gfx/'.

[info   ] [FileManager]: Asset 2 will be loaded from '/usr/local/share/supertuxkart/data/grandprix/'.

[info   ] [FileManager]: Asset 3 will be loaded from '/usr/local/share/supertuxkart/data/gui/icons/'.

[info   ] [FileManager]: Asset 4 will be loaded from '/usr/local/share/supertuxkart/data/gui/screens/'.

[info   ] [FileManager]: Asset 5 will be loaded from '/usr/local/share/supertuxkart/data/gui/dialogs/'.

[info   ] [FileManager]: Asset 6 will be loaded from '/usr/local/share/supertuxkart/data/replay/'.

[info   ] [FileManager]: Asset 7 will be loaded from '/usr/local/share/supertuxkart/data/shaders/'.

[info   ] [FileManager]: Asset 8 will be loaded from '/usr/local/share/supertuxkart/data/skins/'.

[info   ] [FileManager]: Asset 9 will be loaded from '/usr/local/share/supertuxkart/data/ttf/'.

[info   ] [FileManager]: Asset 10 will be loaded from '/usr/local/share/supertuxkart/data/po/'.

[info   ] [FileManager]: Asset 11 will be loaded from '/usr/local/share/supertuxkart/data/library/'.

[info   ] [FileManager]: Asset 12 will be loaded from '/usr/local/share/supertuxkart/data/models/'.

[info   ] [FileManager]: Asset 13 will be loaded from '/usr/local/share/supertuxkart/data/music/'.

[info   ] [FileManager]: Asset 14 will be loaded from '/usr/local/share/supertuxkart/data/sfx/'.

[info   ] [FileManager]: Asset 15 will be loaded from '/usr/local/share/supertuxkart/data/textures/'.

[info   ] [FileManager]: Asset 16 will be loaded from '/usr/local/share/supertuxkart/data/tracks/'.

..:: Antarctica Rendering Engine 2.0 ::..

[info   ] HTTPRequest: Sending userid=287075&token=************************ to https://online.supertuxkart.net/api/v2/user/saved-session/

[info   ] GrandPrixManager: Loading Grand Prix files from /usr/local/share/supertuxkart/data/grandprix/

[info   ] GrandPrixManager: Loading Grand Prix files from /home/stk/.local/share/supertuxkart/grandprix/

[info   ] HTTPRequest: Sending userid=287075&token=************************&visitingid=287075 to https://online.supertuxkart.net/api/v2/user/get-friends-list/

[info   ] NetworkConfig: System is IPv4 only.

Tue Feb 23 07:58:56 2021 [info   ] STKHost: Host initialized.

Tue Feb 23 07:58:56 2021 [warn   ] STKHost: Disable IPv6 socket due to missing IPv6.

Tue Feb 23 07:58:56 2021 [info   ] STKHost: Server port is 2759

Available command:

help, Print this.

quit, Shut down the server.

kickall, Kick all players out of STKHost.

kick #, kick # peer of STKHost.

kickban #, kick and ban # peer of STKHost.

listpeers, List all peers with host ID and IP.

listban, List IP ban list of server.

speedstats, Show upload and download speed.

Tue Feb 23 07:58:56 2021 [info   ] ServerLobby: Resetting the server to its initial state.

Tue Feb 23 07:58:56 2021 [info   ] ProtocolManager: A 11ServerLobby protocol has been started.

Tue Feb 23 07:58:56 2021 [info   ] main: Creating a WAN server '*****;'.

Tue Feb 23 07:58:56 2021 [info   ] STKHost: Listening has been started.

Tue Feb 23 07:58:56 2021 [info   ] ServerLobby: Public IPv4 server address 5.146.220.33:2759

Tue Feb 23 07:58:56 2021 [info   ] HTTPRequest: Sending userid=287075&token=************************&address=93510689&port=2759&private_port=2759&name=******%20%F0%9F%A4%96&max_players=15&difficulty=2&game_mode=3&password=*&version=6 to https://online.supertuxkart.net/api/v2/server/create/

Tue Feb 23 07:58:57 2021 [info   ] ServerLobby: Server 253226 is now online.

[verbose  ] main: Error messages and other text output will be logged to /home/stk/.config/supertuxkart/config-0.10/stdout.log.

[info   ] [FileManager]: Data files will be fetched from: '/usr/local/share/supertuxkart/data/'

[info   ] [FileManager]: User directory is '/home/stk/.config/supertuxkart/config-0.10/'.

[info   ] [FileManager]: Addons files will be stored in '/home/stk/.local/share/supertuxkart/addons/'.

[info   ] [FileManager]: Screenshots will be stored in '/home/stk/.local/share/supertuxkart/screenshots/'.

[info   ] [FileManager]: User-defined grand prix will be stored in '/home/stk/.local/share/supertuxkart/grandprix/'.

[info   ] [FileManager]: Asset 0 will be loaded from '/usr/local/share/supertuxkart/data/challenges/'.

[info   ] [FileManager]: Asset 1 will be loaded from '/usr/local/share/supertuxkart/data/gfx/'.

[info   ] [FileManager]: Asset 2 will be loaded from '/usr/local/share/supertuxkart/data/grandprix/'.

[info   ] [FileManager]: Asset 3 will be loaded from '/usr/local/share/supertuxkart/data/gui/icons/'.

[info   ] [FileManager]: Asset 4 will be loaded from '/usr/local/share/supertuxkart/data/gui/screens/'.

[info   ] [FileManager]: Asset 5 will be loaded from '/usr/local/share/supertuxkart/data/gui/dialogs/'.

[info   ] [FileManager]: Asset 6 will be loaded from '/usr/local/share/supertuxkart/data/replay/'.

[info   ] [FileManager]: Asset 7 will be loaded from '/usr/local/share/supertuxkart/data/shaders/'.

[info   ] [FileManager]: Asset 8 will be loaded from '/usr/local/share/supertuxkart/data/skins/'.

[info   ] [FileManager]: Asset 9 will be loaded from '/usr/local/share/supertuxkart/data/ttf/'.

[info   ] [FileManager]: Asset 10 will be loaded from '/usr/local/share/supertuxkart/data/po/'.

[info   ] [FileManager]: Asset 11 will be loaded from '/usr/local/share/supertuxkart/data/library/'.

[info   ] [FileManager]: Asset 12 will be loaded from '/usr/local/share/supertuxkart/data/models/'.

[info   ] [FileManager]: Asset 13 will be loaded from '/usr/local/share/supertuxkart/data/music/'.

[info   ] [FileManager]: Asset 14 will be loaded from '/usr/local/share/supertuxkart/data/sfx/'.

[info   ] [FileManager]: Asset 15 will be loaded from '/usr/local/share/supertuxkart/data/textures/'.

[info   ] [FileManager]: Asset 16 will be loaded from '/usr/local/share/supertuxkart/data/tracks/'.

..:: Antarctica Rendering Engine 2.0 ::..

[info   ] HTTPRequest: Sending userid=287075&token=************************ to https://online.supertuxkart.net/api/v2/user/saved-session/

[info   ] GrandPrixManager: Loading Grand Prix files from /usr/local/share/supertuxkart/data/grandprix/

[info   ] GrandPrixManager: Loading Grand Prix files from /home/stk/.local/share/supertuxkart/grandprix/

[info   ] STKHost: Host initialized.

[info   ] ConnectToServer: SETUP

[info   ] ProtocolManager: A 15ConnectToServer protocol has been started.

[info   ] ConnectToServer: Trying connecting to 127.0.0.1:2759 from port 34920, retry remain: 3

[info   ] ConnectToServer: Connected to 127.0.0.1:2759

[info   ] ProtocolManager: A 11ClientLobby protocol has been started.

[info   ] ProtocolManager: A 15ConnectToServer protocol has been terminated.

[info   ] STKHost: Listening has been started.

Tue Feb 23 07:59:09 2021 [info   ] STKHost: 127.0.0.1:34920 has just connected. There are now 1 peers.

Tue Feb 23 07:59:09 2021 [info   ] ServerLobby: Message of type 1 received.

Tue Feb 23 07:59:09 2021 [info   ] ServerLobby: New player Bot with online id 0 from 127.0.0.1:34920 with AI.

Tue Feb 23 07:59:09 2021 [info   ] ServerLobby: New player Bot 1 with online id 0 from 127.0.0.1:34920 with AI.

Tue Feb 23 07:59:09 2021 [info   ] ServerLobby: New player Bot 2 with online id 0 from 127.0.0.1:34920 with AI.

Tue Feb 23 07:59:09 2021 [info   ] ServerLobby: New player Bot 3 with online id 0 from 127.0.0.1:34920 with AI.

Tue Feb 23 07:59:09 2021 [info   ] ServerLobby: New player Bot 4 with online id 0 from 127.0.0.1:34920 with AI.

Tue Feb 23 07:59:09 2021 [info   ] ServerLobby: New player Bot 5 with online id 0 from 127.0.0.1:34920 with AI.

Tue Feb 23 07:59:09 2021 [info   ] ServerLobby: New player Bot 6 with online id 0 from 127.0.0.1:34920 with AI.

Tue Feb 23 07:59:09 2021 [info   ] ServerLobby: New player Bot 7 with online id 0 from 127.0.0.1:34920 with AI.

Tue Feb 23 07:59:09 2021 [info   ] ServerLobby: New player Bot 8 with online id 0 from 127.0.0.1:34920 with AI.

Tue Feb 23 07:59:09 2021 [info   ] ServerLobby: New player Bot 9 with online id 0 from 127.0.0.1:34920 with AI.

[info   ] ClientLobby: Synchronous message of type 4

[info   ] ClientLobby: Synchronous message of type 6

[info   ] ClientLobby: Synchronous message of type 3

[info   ] ClientLobby: The server accepted the connection.

[info   ] HTTPRequest: Sending userid=287075&token=************************&visitingid=287075 to https://online.supertuxkart.net/api/v2/user/get-friends-list/

[info   ] NetworkTimerSynchronizer: Network timer synchronized, difference: 0ms

[Benau]

#4299?

[major-mayer]

Oh nice that was easy :) Thanks for the quick hint!
Disabling the network console reduced the CPU load by 90% 😲
Maybe this should be documented a bit better, probably here where you could directly explain this in the default server config.