alliedmodders / amxmodx

AMX Mod X - Half-Life 1 Scripting and Administration
http://www.amxmodx.org/
496 stars 198 forks source link

client_disconnected not working properly on latest 1.9 #646

Closed OciXCrom closed 5 years ago

OciXCrom commented 5 years ago

My server was running on 1.8.3 for a few years. Ever since I updated it to 1.9 players started reporting various issues related to events that happen when players disconnect.

The only change I made during the update was replacing client_disconnect with client_disconnected in most plugins.

Player-related data started failing to save in client_disconnected. For example, I had made it so the player's played time would save - no time was saved with the new forward. I switched back to client_disconnect and things started working again.

I added logs to both client_disconnect and client_disconnected in order to figure out what's going on. I have this in one plugin:

public client_disconnect(id)
{
    log_to_file(g_szLogFile, "[client_disconnect] %n is disconnecting", id)

    user_time[id] = jb_gettime(id, 0)
    user_currenttime[id] = jb_gettime(id, 1)
    SaveData(id)
    log_to_file(g_szLogFile, "[client_disconnect] %n data saving", id)
}

public client_disconnected(id)
{
    log_to_file(g_szLogFile, "[client_disconnected] %n is disconnecting", id)

    user_time[id] = jb_gettime(id, 0)
    user_currenttime[id] = jb_gettime(id, 1)
    //SaveData(id)
    log_to_file(g_szLogFile, "[client_disconnected] %n data saving", id)
}

And this in another one:

public client_disconnected(id)
    log_amx("jb_extreme.amxx %n client_disconnected", id)

Here's the result from the first plugin:

L 12/16/2018 - 22:30:06: [client_disconnect] -Abstergo- is disconnecting
L 12/16/2018 - 22:30:06: 
L 12/16/2018 - 22:30:22: [client_disconnect] D3aDpOoL is disconnecting
L 12/16/2018 - 22:30:22: 
L 12/16/2018 - 22:30:46: [client_disconnect] Xekase is disconnecting
L 12/16/2018 - 22:30:46: 
L 12/16/2018 - 22:30:51: [client_disconnect] _-^FU[93]KRU^_- is disconnecting
L 12/16/2018 - 22:30:51: 

As you can see, only the client_disconnect event outputs the correct message, while client_disconnected outputs a blank message. 40000 log lines were generated in the file and not one of them managed to output the message from client_disconnected.

Occasionally, an error log is printed as well with a abnormal player index (above 32).

L 12/17/2018 - 00:04:21: [AMXX] Displaying debug trace (plugin "jb_playedtime.amxx", version "1.3.4")
L 12/17/2018 - 00:04:21: [AMXX] Run time error 10: native error (native "log_to_file")
L 12/17/2018 - 00:04:21: [AMXX]    [0] jb_playedtime.sma::SaveData (line 133)
L 12/17/2018 - 00:04:21: [AMXX]    [1] jb_playedtime.sma::client_disconnect (line 110)
L 12/17/2018 - 00:04:25: Client index 49 is invalid

How does the forward manage to have a wrong player index?

Please note that only 502 errors were generated, while 8331 messages were printed to the log file, which means that the error doesn't pop-up all the time, although the event is not working.

The second plugin failed to output the log message as well, but didn't generate an error log yet (I added the message 2 hours ago).

The server is running on Linux + ReHLDS using the latest 5234 build of 1.9. I tried updating multiple times in case I missed something.

dystopm commented 5 years ago

It makes sense. After I upgraded to 1.9-dev, some players reported that some data (that is managed to be written on client_disconnected) was not properly updated.

Arkshine commented 5 years ago

1.8.3 is 1.9. Nothing has changed.

If client_disconnected is not called, this means that the function could not be retrieved from ReHLDS. Typically the version compiled with AMXX (3.4 I believe) doesn't match the version you have: the major version is not the same or the minor version is inferior.

At server start, do you have a message in the console client_disconnected and client_remove forwards have been disabled with the reason?

What is your ReHLDS version?

Arkshine commented 5 years ago

Looks like they bumped the minor version. It's now 3.5. AMXX needs to be updated then. Will do ASAP.

EDIT: fixed.

I wish people would report this earlier. Next time, if you update ReHLDS, check always the AMXX log before and if the version mismatches, report it.

WPMGPRoSToTeMa commented 5 years ago

@Arkshine this is weird, major versions are the same and the minor version of rehlds >= the minor version of resdk, so it should work.

Arkshine commented 5 years ago

You're right, maybe he's using <= 3.3 or there is an issue elsewhere.

dystopm commented 5 years ago

And, where's the 3.5 version? I just see 3.4 on official rep

OciXCrom commented 5 years ago

Yup, I didn't notice the error:

L 12/19/2018 - 14:51:33: client_disconnected and client_remove forwards have been disabled - update ReHLDS.

I updated to the new dev-build just now and I'll check the new logs later to see if they're generating properly.

OciXCrom commented 5 years ago

The logs from client_disconnected started generating after the update, but I still get this error:

L 12/19/2018 - 21:15:02: [AMXX] Displaying debug trace (plugin "jb_playedtime.amxx", version "1.3.4")
L 12/19/2018 - 21:15:02: [AMXX] Run time error 10: native error (native "log_to_file")
L 12/19/2018 - 21:15:02: [AMXX]    [0] jb_playedtime.sma::SaveData (line 133)
L 12/19/2018 - 21:15:02: [AMXX]    [1] jb_playedtime.sma::client_disconnect (line 110)
L 12/19/2018 - 21:17:47: Client index 49 is invalid

I just noticed that the error is in client_disconnect, not client_disconnected. How?

WPMGPRoSToTeMa commented 5 years ago

@OciXCrom can you show SaveData function?

OciXCrom commented 5 years ago

I don't think it's related because the log_amx function is the first line in client_disconnect so even if id was modified in any way by SaveData, it will still be the id passed from client_disconnect in the first line of the forward. Here:

public SaveData(id)
{   
    new vaultdata[128]
    formatex(vaultdata, charsmax(vaultdata), "%i %i %i %i", user_time[id], user_option[id], get_systime(), user_currenttime[id])
    nvault_set(g_vault, g_szAuthId[id], vaultdata)
}
Dr-Strange91 commented 5 years ago

Today I compiled a plugin with client_disconnect the compiler sent me lose identity error and asked to change it into client_disconnected.

OciXCrom commented 5 years ago

@Dr-Strange91 That's perfectly normal. client_disconnected is a replacement for client_disconnect, so the old one is deprecated an you'll get a warning not to use it anymore.

WPMGPRoSToTeMa commented 5 years ago

@OciXCrom hm, where is log_to_file inside SaveData?

OciXCrom commented 5 years ago

Why do I need it? The code never got to SaveData. It stopped in the beginning of client_disconnected.

WPMGPRoSToTeMa commented 5 years ago

@OciXCrom stack trace looks like log_to_file is called from SaveData. It is also weird that Client index X is invalid log line has different time than other lines.

dystopm commented 5 years ago

A bunch of posts because you don't want to attach some code, should they really help you? I'm having the same doubts they have, including @WPMGPRoSToTeMa - error log throws that log_to_file is called inside SaveData, but it is not written there, it is somewhere else? - answer: provide code, or wait for someone else's patience

OciXCrom commented 5 years ago

@PM32 I'm not a noob in coding for you to think that I'm not providing the needed information. I provided the full function that gives the error - you don't need any other piece of the code in order to see what's going on. The plugins in my server are private so I'm not going to share the entire code.

I woulnd't be posting this issue if everything was working normal. Obviously there is something weird going on as the error is said to be in another place.

I don't recall having a log_to_file function put in SaveData. Maybe I did and removed it later, but this still doesn't explain why the client index is invalid, as SaveData is called directly from client_disconnected and isn't used anywhere else in the code. If client_disconnected is disabled because of an old ReHLDS version, why is it getting called in the first place?

Anyways, things are working as they should with the new dev-build.