Raised This Month: $32 Target: $400
 8% 

Solved [TF2] Basic problems hooking disconnect events with plugin


Post New Thread Reply   
 
Thread Tools Display Modes
Author Message
Haytil
Junior Member
Join Date: Oct 2018
Old 10-15-2018 , 15:52   [TF2] Basic problems hooking disconnect events with plugin
Reply With Quote #1

Hi,

I'm trying to log how long players play for, by checking their client time on disconnect. Problem is, it seems like my plugin disconnecting handler is only firing sporadically. I've written two test plugins and ran them simultaneously. Here are the plugins, as well as results:

Plugin 1 (doesn't log actual time played):

Code:
#include <sourcemod>

public Plugin myinfo =
{
	name = "Test_Plugin_1",
	author = "Haytil",
	description = "Testing player connecting/disconnecting and file writing with timing.",
	version = "1.0",
	url = "http://www.haytil.net/"
};

public void OnPluginStart()
{
	PrintToServer("Starting Test_Plugin_1...");
	
	HookEvent("player_connect", OnPlayerConnect_Test_1, EventHookMode_Pre);
	HookEvent("player_disconnect", OnPlayerDisconnect_Test_1, EventHookMode_Pre); 
}

public Action OnPlayerConnect_Test_1(Event event, char[] name, bool dontBroadcast)
{	
	char name_buffer[512];
	char id_buffer[512];
	
	event.GetString("name", name_buffer, 511, "Unknown_Name");
	event.GetString("networkid", id_buffer, 511, "Unknown_ID");

	File f = OpenFile("Test_1_Output.txt", "a");
	f.WriteString(name_buffer, false);
	f.WriteString(" (", false);
	f.WriteString(id_buffer, false);
	f.WriteString(") connected.\n", false);
	
	f.Close();

	return Plugin_Continue;
}

public Action OnPlayerDisconnect_Test_1(Event event, char[] name, bool dontBroadcast)
{
	char name_buffer[512];
	char id_buffer[512];
	
	event.GetString("name", name_buffer, 511, "Unknown_Name");
	event.GetString("networkid", id_buffer, 511, "Unknown_ID");

	File f = OpenFile("Test_1_Output.txt", "a");
	f.WriteString(name_buffer, false);
	f.WriteString(" (", false);
	f.WriteString(id_buffer, false);
	f.WriteString(") disconnected after playing ", false);
	f.WriteString("\n", false);
	
	f.Close();
	
	return Plugin_Continue;
}
Results: 847 connect messages, 806 disconnected messages


Plugin 2 (logs actual time played):

Code:
#include <sourcemod>

public Plugin myinfo =
{
	name = "Test_Plugin_2",
	author = "Haytil",
	description = "Testing player connecting/disconnecting and file writing with timing.",
	version = "1.0",
	url = "http://www.haytil.net/"
};

public void OnPluginStart()
{
	PrintToServer("Starting Test_Plugin_2...");
	
	HookEvent("player_connect", OnPlayerConnect_Test_2, EventHookMode_Pre);
	HookEvent("player_disconnect", OnPlayerDisconnect_Test_2, EventHookMode_Pre); 
}

public Action OnPlayerConnect_Test_2(Event event, char[] name, bool dontBroadcast)
{	
	char name_buffer[512];
	char id_buffer[512];
	
	event.GetString("name", name_buffer, 511, "Unknown_Name");
	event.GetString("networkid", id_buffer, 511, "Unknown_ID");

	File f = OpenFile("Test_2_Output.txt", "a");
	f.WriteString(name_buffer, false);
	f.WriteString(" (", false);
	f.WriteString(id_buffer, false);
	f.WriteString(") connected.\n", false);
	
	f.Close();

	return Plugin_Continue;
}

public Action OnPlayerDisconnect_Test_2(Event event, char[] name, bool dontBroadcast)
{
	char name_buffer[512];
	char id_buffer[512];
	
	event.GetString("name", name_buffer, 511, "Unknown_Name");
	event.GetString("networkid", id_buffer, 511, "Unknown_ID");
	
	File f = OpenFile("Test_2_Output.txt", "a");
	f.WriteString(name_buffer, false);
	f.WriteString(" (", false);
		
	int client_index = event.GetInt("userid", -1);
	
	float time = 0;
	
	if (client_index > -1)
	{
		time = GetClientTime(client_index);
	}
	char time_string[64];
	FloatToString(time, time_string, 63);
	
	char index_string[64];
	IntToString(client_index, index_string, 63);
	
	f.WriteString(id_buffer, false);
	f.WriteString(") (index: ", false);
	f.WriteString(index_string, false);
	f.WriteString(") disconnected after playing ", false);
	f.WriteString(time_string, false);
	f.WriteString(" seconds.", false);
	f.WriteString("\n", false);
	
	f.Close();
	
	return Plugin_Continue;
}
Results: 847 connect messages, 59 disconnected messages



ANALYSIS: There are two discrepancies I'm worried about here.

First, both log files were collected after the server was empty. This would mean we should expect the number of "connect" messsages to equal the number of "disconnect" messages, as there's no one still left that has yet to disconnect when the logs were collected. If the plugin began running while people were on the server, then the number of disconnect messages should be within a value of 32 of the number of connect messages (since the server is 32-people max). However, the first plugin has 41 more "connect" messages than "disconnect" messages, implying that some "disconnect"s were not logged by the first plugin.

Second, both plugins were run simultaneously. As expected, both have the same number of "connected" messages in their respective log files. But the second plugin only has 59 "disconnect" messages, which is both far fewer than the number of "connect" messages as well as far fewer than the number of "disconnect" messages from the first plugin. This means that, for some reason, the second plugin's "On Disconnect" function is rarely being called.

I thought this might be a contention/multi-threading issue, as multiple disconnects might fight for "write" access to the same file at the same time, but as far as I am aware, SourceMod and plugins all run on a single thread, so that can't be it.

Does anyone have any advice about what could be wrong with my code or what I'm doing wrong? I can't log total play time if most players' disconnects are ignored by the code...

Thanks!

Last edited by Haytil; 10-22-2018 at 00:56.
Haytil is offline
Bacardi
Veteran Member
Join Date: Jan 2010
Location: mom's basement
Old 10-15-2018 , 17:28   Re: [TF2] Basic problems hooking disconnect events with plugin
Reply With Quote #2

I'm not 100% sure, but open file rapidly many times (when people connect and disconnect) without check did you actually manage open the file and write in it...

Anyway, I don't have time to test your method and what problems it have.
---------

What if you continue using "HookEvent player_disconnect", only. You could use it as EventHookMode_Post , not big deal.

And get player connection time, what you also see from "status" console command.
https://sm.alliedmods.net/new-api/clients/GetClientTime
But I haven't check, can you get full connection time on player disconnect event. I remember, connection time will reset when player leave from server and come back.

And use log system https://sm.alliedmods.net/new-api/logging/LogToFileEx

Like this way. I have not tested, but it compiled code tough
PHP Code:
public void OnPluginStart()
{
    
HookEvent("player_disconnect"player_disconnect); 
}

public 
void player_disconnect(Event eventchar[] namebool dontBroadcast)
{
    
int userid event.GetInt("userid");
    
int client GetClientOfUserId(userid); // If we get client index by userid, player should be still in game, right ? :)

    
if( client <= MaxClients && !IsFakeClient(client)) // Valid player index and filter bots out
    
{
        
int time RoundToNearest(GetClientTime(client));
        
LogToFileEx("players_connection_time.txt""Player %L - connection time = %i hours %i minutes %i seconds "clienttime 3600, (time 60) % 60time 60);
    }



Last edited by Bacardi; 10-15-2018 at 17:31.
Bacardi is offline
Haytil
Junior Member
Join Date: Oct 2018
Old 10-15-2018 , 19:20   Re: [TF2] Basic problems hooking disconnect events with plugin
Reply With Quote #3

Quote:
Originally Posted by Bacardi View Post
What if you continue using "HookEvent player_disconnect", only. You could use it as EventHookMode_Post , not big deal.
Well, I will need to log connection events so I have a value to compare my disconnect events with (my problem above is because I know I have 847 connections and only 59 disconnections - without a value for "connections," I would not know that 59 was very wrong!)

But I will log my connections to a separate file, to reduce how frequently each file is opened/closed.

Quote:
And get player connection time, what you also see from "status" console command.
https://sm.alliedmods.net/new-api/clients/GetClientTime
But I haven't check, can you get full connection time on player disconnect event. I remember, connection time will reset when player leave from server and come back.
Ok, this doesn't seem substantially different from what I do - again, the problem isn't currently that the connection times are wrong, it's that the disconnection messages simply aren't logged at all.

But I will try this.

Again, is this really different from manually opening, writing, and closing the file myself? The file is opened just as often if I use the log system.

But I will try it your way.

Here is the code I will run tonight:

PHP Code:
#include <sourcemod>

public Plugin myinfo =
{
    
name "HaytilTest_5",
    
author "Haytil",
    
description "Testing player connecting/disconnecting and file writing with timing and database file.",
    
version "1.0",
    
url "http://www.haytil.net"
};

public 
void OnPluginStart()
{
    
PrintToServer("Starting HaytilTest_5...");
    
    
HookEvent("player_connect"OnPlayerConnectTest5EventHookMode_Post);
    
HookEvent("player_disconnect"OnPlayerDisconnectTest5EventHookMode_Post); 
}

public 
void OnPlayerConnectTest5(Event eventchar[] namebool dontBroadcast)
{
    
char name_buffer[512];
    
char id_buffer[512];
    
    
event.GetString("name"name_buffer511"Unknown_Name");
    
event.GetString("networkid"id_buffer511"Unknown_ID");
    
    
LogToFileEx("Test_5_Connect_Output.txt""Player %s (%s) connected."name_bufferid_buffer);
}

public 
void OnPlayerDisconnectTest5(Event eventchar[] namebool dontBroadcast)
{
    
int userid event.GetInt("userid");
    
int client GetClientOfUserId(userid); // If we get client index by userid, player should be still in game, right ? :)
    
    
char name_buffer[512];
    
char id_buffer[512];
    
    
event.GetString("name"name_buffer511"Unknown_Name");
    
event.GetString("networkid"id_buffer511"Unknown_ID");
    
    if (
client && client <= MaxClients)
    {
        if (!
IsFakeClient(client))
        {
            
int time RoundToNearest(GetClientTime(client));
            
LogToFileEx("Test_5_Disconnect_Output.txt""Player %s (%s) disconnected - Client #%L connection time = %i hours %i minutes %i seconds "name_bufferid_bufferclienttime 3600, (time 60) % 60time 60);
        }
        else
        {
            
LogToFileEx("Test_5_Disconnect_Output.txt""Bot %s (%s) disconnected."name_bufferid_buffer);
        }
    }
    else
    {
        
LogToFileEx("Test_5_Disconnect_Output.txt""Disconnection from %s (%s) - invalid client value %L."name_bufferid_bufferclient);
    }

I will run it on the server tonight and post results in the morning (unless anyone else has other suggestions).
Haytil is offline
asherkin
SourceMod Developer
Join Date: Aug 2009
Location: OnGameFrame()
Old 10-16-2018 , 15:49   Re: [TF2] Basic problems hooking disconnect events with plugin
Reply With Quote #4

Do you have any messages in your SourceMod error logs?
__________________
asherkin is offline
Haytil
Junior Member
Join Date: Oct 2018
Old 10-22-2018 , 00:56   Re: [TF2] Basic problems hooking disconnect events with plugin
Reply With Quote #5

Thanks for your help, the new code works.

I believe the issue is I was using the "userid" from the event as the "client" value, when the two are actually different things (though this was not very clear from the documentation). Getting the client from the userid, and then just using the client from there on out, is the way to go.

Thanks!

Quote:
Originally Posted by asherkin View Post
Do you have any messages in your SourceMod error logs?
I did, but not know that they even existed, so did not think to check. I'm quite new to this
Haytil is offline
Bacardi
Veteran Member
Join Date: Jan 2010
Location: mom's basement
Old 10-22-2018 , 08:47   Re: [TF2] Basic problems hooking disconnect events with plugin
Reply With Quote #6

Yes, exactly.
"userid" is kind of... ticket number. This number increase by one everytime when players CONNECT to server.
Player hold this same ticket number as long as he stay in server till he disconnect from server.
(Ticket numbers are temporary, disposable.)

And to be clear, when hook Events (connect/disconnect), these have different behaviour than
SourceMod:
https://sm.alliedmods.net/new-api/cl...nClientConnect
https://sm.alliedmods.net/new-api/cl...ientDisconnect

These SourceMod forwards are called even over map change. (If I remember right)

Hooked Events (connect/disconnect) work only when player reconnect, map change not interfere.

You can see players "#userid's" from behind console command status, you see they connection time and you notice, player who have lower userid number, have longer connection time on server.

Quote:
Originally Posted by Haytil View Post
Thanks for your help, the new code works.

I believe the issue is I was using the "userid" from the event as the "client" value, when the two are actually different things (though this was not very clear from the documentation). Getting the client from the userid, and then just using the client from there on out, is the way to go.

Thanks!



I did, but not know that they even existed, so did not think to check. I'm quite new to this
__________________
Do not Private Message @me

Last edited by Bacardi; 10-22-2018 at 08:50.
Bacardi is offline
Reply



Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off

Forum Jump


All times are GMT -4. The time now is 20:12.


Powered by vBulletin®
Copyright ©2000 - 2024, vBulletin Solutions, Inc.
Theme made by Freecode