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!