[BUG] empty Steam IDs in DB / 'STEAM_ID_STOP_IGNORING_RETVALS' in playerrank

[Jay2k1]

Observed behaviour

We've had playerrank entries with empy steamid and a steamid64 of STEAM_ID_STOP_IGNORING_RETVALS. If you google that, you find that this is a value that GetClientAuthId() returns as a steam ID when it fails to look up a player's steam ID.
You also find that you should never use GetClientAuthId() without checking it's return value -- it can be false if it fails to look up the player's steam ID. In other words:
This is bad:

char szSteamId64[64];
GetClientAuthId(client, AuthId_SteamID64, szSteamId64, sizeof(szSteamId64), true);
do_stuff(szSteamId64);

This is good:

char szSteamId64[64];
if ( GetClientAuthId(client, AuthId_SteamID64, szSteamId64, sizeof(szSteamId64), true) )
    do_stuff(szSteamId64);

Because the timer does it the bad way, it'll happily write an empty steam ID and the 'stop ignoring' string as steamid64 into the DB.

Obviously, this can be fixed by checking the retval, but the real question is, why would it fail to retrieve the steam ID in the first place and what can be done about it?

I've been debugging a lot and think I have figured it out:

Cause for the bug

When a player connects, this OnClientPutInServer forward function in surftimer will be called. At the end in L498, it calls LoadClientSetting() after setting g_iSettingToLoad[client] to 0. From there, the respective setting is being loaded and g_iSettingToLoad[client] is ++'d, this repeats until it has looped through all "settings" that need loading.

One of these "load a setting" functions that LoadClientSetting() calls is db_viewPlayerPoints(). It retrieves stats like time alive, time in spec etc. from ck_playerrank. If no results are returned because it's a new player, its callback will run
GetClientAuthId() to retrieve the player's steamid64 and then create a ck_playerrank profile for this player:

SurfTimer/addons/sourcemod/scripting/surftimer/sql.sp

Lines 1533 to 1537 in dfdd356

	char szSteamId64[64];
	GetClientAuthId(client, AuthId_SteamID64, szSteamId64, MAX_NAME_LENGTH, true);
	Format(szQuery, sizeof(szQuery), sql_insertPlayerRank, g_szSteamID[client], szSteamId64, szName, g_szCountry[client], g_szCountryCode[client], g_szContinentCode[client], GetTime());
	SQL_TQuery(g_hDb, SQL_CheckCallback, szQuery, _, DBPrio_Low);

So this is where the wrong DB entries come from, and by tracing back from here, I found it is initially caused by the OnClientPutInServer forward.

Sourcemod says this about OnClientPutInServer:

Called when a client is entering the game.
Whether a client has a steamid is undefined until OnClientAuthorized is called, which may occur either before or after OnClientPutInServer.

I have added some debug logging for OnClientAuthorized, and indeed, in one particular case the OnClientAuthorized happened 85 seconds after the actual player connect (where the timer created a playerrank profile with STEAM_ID_STOP_IGNORING_RETVALS as steamid64). It seems to work 99% of the time, but there's still that one percent where maybe steam ID servers are slow to respond or something, and then this happens.

L 01/21/2023 - 18:08:15: "Nick redacted<13><STEAM_1:0:123456><>" connected, address ""
L 01/21/2023 - 18:08:35: "Nick redacted<13><STEAM_1:0:123456><>" entered the game
L 01/21/2023 - 18:08:35: [Surftimer] db_viewPlayerPointsCallback(): client 10: no profile found, creating new profile for steam ID ''
L 01/21/2023 - 18:09:50: "Nick redacted<13><STEAM_1:0:123456><>" STEAM USERID validated
L 01/21/2023 - 18:09:50: Nick redacted (STEAM_1:0:123456) connected. IP address: 1.2.3.4:27005
L 01/21/2023 - 18:09:50: [Surftimer-debug] OnClientAuthorized(client 10 auth STEAM_1:0:123456): GetClientAuthId: found steam id STEAM_1:0:123456

Possible solution

Because functions called in this forward rely on knowing a player's steam ID, I think it should not be used. It is suggested to use OnClientPostAdminCheck instead, which is...

Called once a client is authorized and fully in-game, and after all post-connection authorizations have been performed.
This callback is guaranteed to occur on all clients, and always after each OnClientPutInServer() call.

So I think fixing this is as easy as replacing
public void OnClientPutInServer(int client)
by
public void OnClientPostAdminCheck(int client)
here:

SurfTimer/addons/sourcemod/scripting/SurfTimer.sp

Line 431 in 4afec45

public void OnClientPutInServer(int client)

Does that sound like a good idea?

[tslashd]

I have done some testing with OnClientPostAdminCheck and the RETVALS issue occurs significantly less than with OnClientPutInServer but it still happens randomly.
Maybe we can check if RETVALS exists, stop loading client settings and ask them to reconnect or add a command to reload all your settings only if your ID was picked up as STEAM_ID_STOP_IGNORING_RETVALS upon joining?

EDIT:
Something along the lines of:

public void OnClientPostAdminCheck(int client)
{
  char szSteamId64[32];
  if ( !GetClientAuthId(client, AuthId_SteamID64, szSteamId64, sizeof(szSteamId64), true) )
    ReconnectClient(client);
  .......
}

[Jay2k1]

I have done some testing with OnClientPostAdminCheck and the RETVALS issue occurs significantly less than with OnClientPutInServer but it still happens randomly.

That sounds strange to me. As far as I understood, you get STEAM_ID_STOP_IGNORING_RETVALS when you use GetClientAuthId() on a client that is not authorized yet. It then returns false and sets the steam ID variable to STEAM_ID_STOP_IGNORING_RETVALS in case you ignore the false it returns.

If, however, you wait for either OnClientPostAdminCheck or OnClientAuthorized, this should not be possible, unless maybe the client authentication process hits a timeout or something. And OnClientPostAdminCheck only triggers once both OnClientAuthorized and OnClientPutInServer have fired, so it should™ be safe to use in that regard.

I have done some testing too, I moved the GeoIP lookup and storing the steam ID to OnClientAuthorized and the whole rest of the player initialization to OnClientPostAdminCheck. We haven't had a single issue with STEAM_ID_STOP_IGNORING_RETVALS appearing in the database since, which makes sense to me. However, before my change, it would only happen once in, say, 2-3 months, so I feel it's still too early to draw conclusions.

[csgentr]

now bots are not working after this update. it's show dark place from bots view