handlesys: Output allocation timestamp during panic (#1110)

* Track Handle creation time

* Move ConVar operations outside of loop

* We support bee's here

* Catch windows awfulness

* Prevent Character Truncation

* Add timestamp info to memory leak dump

* Remove last line and adjust new leak dump output

* KyleS fixes

* Fixed width output

* Create invalid parameter failure redirection helper

* Fix rebase regression

* Update sm_invalidparamhandler.h

* Update HandleSys.cpp

* Update HandleSys.cpp

* Update HandleSys.cpp

Co-authored-by: Kyle Sanderson <kyle.leet@gmail.com>

core/logic/HandleSys.cpp

@@ -30,6 +30,7 @@
  */
 
 #include "HandleSys.h"
+#include <time.h>
 #include <assert.h>
 #include <string.h>
 #include "common_logic.h"
@@ -38,10 +39,18 @@
 #include "PluginSys.h"
 #include <am-string.h>
 #include <bridge/include/ILogger.h>
+#include <bridge/include/CoreProvider.h>
+#include <ISourceMod.h>
+
+#include "sm_platform.h"
+#ifdef PLATFORM_WINDOWS
+#include "sm_invalidparamhandler.h"
+#endif
 
 HandleSystem g_HandleSys;
 
 QHandle *ignore_handle;
+extern ConVar *g_datetime_format;
 
 inline HandleType_t TypeParent(HandleType_t type)
 {
@@ -430,7 +439,7 @@ Handle_t HandleSystem::CreateHandleInt(HandleType_t type,
 
 	pHandle->object = object;
 	pHandle->clone = 0;
-
+	pHandle->timestamp = g_pSM->GetAdjustedTime();
 	return handle;
 }
 
@@ -1014,6 +1023,8 @@ bool HandleSystem::TryAndFreeSomeHandles()
 	unsigned int * pCount = new unsigned int[HANDLESYS_TYPEARRAY_SIZE+1];
 	memset(pCount, 0, ((HANDLESYS_TYPEARRAY_SIZE + 1) * sizeof(unsigned int)));
 
+	const QHandle *oldest = nullptr;
+	const QHandle *newest = nullptr;
 	for (unsigned int i = 1; i <= m_HandleTail; ++i)
 	{
 		const QHandle &Handle = m_Handles[i];
@@ -1030,6 +1041,15 @@ bool HandleSystem::TryAndFreeSomeHandles()
 			highest_index = ((Handle.type) + 1);
 		}
 
+		if (!oldest || oldest->timestamp > Handle.timestamp)
+		{
+			oldest = &Handle;
+		}
+		if (!newest || newest->timestamp < Handle.timestamp)
+		{
+			newest = &Handle;
+		}
+		
 		if (Handle.clone != 0)
 		{
 			continue;
@@ -1057,7 +1077,33 @@ bool HandleSystem::TryAndFreeSomeHandles()
 
 		HANDLE_LOG_VERY_BAD("Type\t%-20.20s|\tCount\t%u", pTypeName, pCount[i]);
 	}
+	
+	const char *fmt = bridge->GetCvarString(g_datetime_format);
 
+	char oldstamp[256], newstamp[256]; // 256 should be more than enough
+
+	// scope for InvalidParameterHandler
+	{
+#ifdef PLATFORM_WINDOWS
+		InvalidParameterHandler p;
+#endif
+		size_t written = strftime(oldstamp, sizeof(oldstamp), fmt, localtime(&oldest->timestamp));
+		if (!written)
+		{
+			ke::SafeStrcpy(oldstamp, sizeof(oldstamp), "INVALID");
+		}
+
+		written = strftime(newstamp, sizeof(newstamp), fmt, localtime(&newest->timestamp));
+		if (!written)
+		{
+			ke::SafeStrcpy(newstamp, sizeof(newstamp), "INVALID");
+		}
+	}
+
+
+	HANDLE_LOG_VERY_BAD("--------------------------------------------------------------------------");
+	HANDLE_LOG_VERY_BAD("Oldest Living Handle: %s created at %s", m_Types[oldest->type].name->c_str(), oldstamp);
+	HANDLE_LOG_VERY_BAD("Newest Living Handle: %s created at %s", m_Types[newest->type].name->c_str(), newstamp);
 	HANDLE_LOG_VERY_BAD("-- Approximately %d bytes of memory are in use by (%u) Handles.\n", total_size, total);
 	delete [] pCount;
 
@@ -1081,8 +1127,10 @@ static void rep(const HandleReporter &fn, const char *fmt, ...)
 void HandleSystem::Dump(const HandleReporter &fn)
 {
 	unsigned int total_size = 0;
-	rep(fn, "%-10.10s\t%-20.20s\t%-20.20s\t%-10.10s", "Handle", "Owner", "Type", "Memory");
+	rep(fn, "%-10.10s\t%-20.20s\t%-20.20s\t%-10.10s\t%-30.30s", "Handle", "Owner", "Type", "Memory", "Time Created");
-	rep(fn, "--------------------------------------------------------------------------");
+	rep(fn, "---------------------------------------------------------------------------------------------");
+	
+	const char *fmt = bridge->GetCvarString(g_datetime_format);
 	for (unsigned int i = 1; i <= m_HandleTail; i++)
 	{
 		if (m_Handles[i].set != HandleSet_Used)
@@ -1150,19 +1198,33 @@ void HandleSystem::Dump(const HandleReporter &fn)
 			bresult = pType->dispatch->GetHandleApproxSize(m_Handles[i].type, m_Handles[i].object, &size);
 		}
 
+		char date[256]; // 256 should be more than enough
+		size_t written = 0;
+		// scope for InvalidParameterHandler
+		{
+#ifdef PLATFORM_WINDOWS
+			InvalidParameterHandler p;
+#endif
+			written = strftime(date, sizeof(date), fmt, localtime(&m_Handles[i].timestamp));
+		}
+
+		if (!written)
+		{
+			ke::SafeStrcpy(date, sizeof(date), "INVALID");
+		}
+
 		if (pType->dispatch->GetDispatchVersion() < HANDLESYS_MEMUSAGE_MIN_VERSION
 			|| !bresult)
 		{
-			rep(fn, "0x%08x\t%-20.20s\t%-20.20s\t%-10.10s", index, owner, type, "-1");
+			rep(fn, "0x%08x\t%-20.20s\t%-20.20s\t%-10.10s\t%-30.30s", index, owner, type, "-1", date);
 		}
 		else
 		{
 			char buffer[32];
 			ke::SafeSprintf(buffer, sizeof(buffer), "%d", size);
-			rep(fn, "0x%08x\t%-20.20s\t%-20.20s\t%-10.10s", index, owner, type, buffer);
+			rep(fn, "0x%08x\t%-20.20s\t%-20.20s\t%-10.10s\t%-30.30s", index, owner, type, buffer, date);
 			total_size += size;
 		}
 	}
 	rep(fn, "-- Approximately %d bytes of memory are in use by Handles.\n", total_size);
 }
-

core/logic/HandleSys.h

@@ -90,6 +90,7 @@ struct QHandle
 	bool access_special;		/* Whether or not access rules are special or type-derived */
 	bool is_destroying;			/* Whether or not the handle is being destroyed */
 	HandleAccess sec;			/* Security rules */
+	time_t timestamp;			/* Creation timestamp */
 	/* The following variables are unrelated to the Handle array, and used 
 	 * as an inlined chain of information */
 	unsigned int freeID;		/* ID of a free handle in the free handle chain */

core/logic/smn_core.cpp

@@ -45,6 +45,7 @@
 
 #if defined PLATFORM_WINDOWS
 #include <windows.h>
+#include "sm_invalidparamhandler.h"
 #elif defined PLATFORM_POSIX
 #include <limits.h>
 #include <unistd.h>
@@ -65,7 +66,7 @@ HandleType_t g_FrameIter;
 
 IForward *g_OnLogAction = NULL;
 
-static ConVar *sm_datetime_format = NULL;
+ConVar *g_datetime_format = NULL;
 
 class CoreNativeHelpers : 
 	public SMGlobalClass,
@@ -91,7 +92,7 @@ public:
 			Param_Cell,
 			Param_String);
 		
-		sm_datetime_format = bridge->FindConVar("sm_datetime_format");
+		g_datetime_format = bridge->FindConVar("sm_datetime_format");
 	}
 	void OnHandleDestroy(HandleType_t type, void *object)
 	{
@@ -173,19 +174,6 @@ static cell_t GetTime(IPluginContext *pContext, const cell_t *params)
 	return static_cast<cell_t>(t);
 }
 
-#if defined SUBPLATFORM_SECURECRT
-void _ignore_invalid_parameter(
-						const wchar_t * expression,
-						const wchar_t * function, 
-						const wchar_t * file, 
-						unsigned int line,
-						uintptr_t pReserved
-						)
-{
-	/* Wow we don't care, thanks Microsoft. */
-}
-#endif
-
 static cell_t FormatTime(IPluginContext *pContext, const cell_t *params)
 {
 	char *format, *buffer;
@@ -194,19 +182,20 @@ static cell_t FormatTime(IPluginContext *pContext, const cell_t *params)
 
 	if (format == NULL)
 	{
-		format = const_cast<char *>(bridge->GetCvarString(sm_datetime_format));
+		format = const_cast<char *>(bridge->GetCvarString(g_datetime_format));
 	}
 
-#if defined SUBPLATFORM_SECURECRT
+	time_t t;
-	_invalid_parameter_handler handler = _set_invalid_parameter_handler(_ignore_invalid_parameter);
+	size_t written = 0;
-#endif
+	
-
+	// scope for InvalidParameterHandler
-	time_t t = (params[4] == -1) ? g_pSM->GetAdjustedTime() : (time_t)params[4];
+	{
-	size_t written = strftime(buffer, params[2], format, localtime(&t));
+#ifdef PLATFORM_WINDOWS
-
+		InvalidParameterHandler p;
-#if defined SUBPLATFORM_SECURECRT
-	_set_invalid_parameter_handler(handler);
 #endif
+		t = (params[4] == -1) ? g_pSM->GetAdjustedTime() : (time_t)params[4];
+		written = strftime(buffer, params[2], format, localtime(&t));
+	}
 
 	if (params[2] && format[0] != '\0' && !written)
 	{

extensions/sdktools/vhelpers.cpp

@@ -34,6 +34,11 @@
 #include "vhelpers.h"
 #include "vglobals.h"
 
+#include "sm_platform.h"
+#ifdef PLATFORM_WINDOWS
+#include "sm_invalidparamhandler.h"
+#endif
+
 CallHelper s_Teleport;
 CallHelper s_GetVelocity;
 CallHelper s_EyeAngles;
@@ -492,19 +497,6 @@ void UTIL_DrawSendTable(FILE *fp, SendTable *pTable, int level = 1)
 	}
 }
 
-#if defined SUBPLATFORM_SECURECRT
-void _ignore_invalid_parameter(
-	const wchar_t * expression,
-	const wchar_t * function, 
-	const wchar_t * file,
-	unsigned int line,
-	uintptr_t pReserved
-	)
-{
-	/* Wow we don't care, thanks Microsoft. */
-}
-#endif
-
 CON_COMMAND(sm_dump_netprops_xml, "Dumps the networkable property table as an XML file")
 {
 #if SOURCE_ENGINE <= SE_DARKMESSIAH
@@ -537,16 +529,14 @@ CON_COMMAND(sm_dump_netprops_xml, "Dumps the networkable property table as an XM
 	char buffer[80];
 	buffer[0] = 0;
 
-#if defined SUBPLATFORM_SECURECRT
-	_invalid_parameter_handler handler = _set_invalid_parameter_handler(_ignore_invalid_parameter);
-#endif
-
 	time_t t = g_pSM->GetAdjustedTime();
-	size_t written = strftime(buffer, sizeof(buffer), "%Y/%m/%d", localtime(&t));
+	size_t written = 0;
-
+	{
-#if defined SUBPLATFORM_SECURECRT
+#ifdef PLATFORM_WINDOWS
-	_set_invalid_parameter_handler(handler);
+		InvalidParameterHandler p;
 #endif
+		written = strftime(buffer, sizeof(buffer), "%Y/%m/%d", localtime(&t));
+	}
 
 	fprintf(fp, "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n\n");
 	fprintf(fp, "<!-- Dump of all network properties for \"%s\" as at %s -->\n\n", g_pSM->GetGameFolderName(), buffer);
@@ -593,16 +583,14 @@ CON_COMMAND(sm_dump_netprops, "Dumps the networkable property table as a text fi
 	char buffer[80];
 	buffer[0] = 0;
 
-#if defined SUBPLATFORM_SECURECRT
-	_invalid_parameter_handler handler = _set_invalid_parameter_handler(_ignore_invalid_parameter);
-#endif
-
 	time_t t = g_pSM->GetAdjustedTime();
-	size_t written = strftime(buffer, sizeof(buffer), "%Y/%m/%d", localtime(&t));
+	size_t written = 0;
-
+	{
-#if defined SUBPLATFORM_SECURECRT
+#ifdef PLATFORM_WINDOWS
-	_set_invalid_parameter_handler(handler);
+		InvalidParameterHandler p;
 #endif
+		written = strftime(buffer, sizeof(buffer), "%Y/%m/%d", localtime(&t));
+	}
 
 	fprintf(fp, "// Dump of all network properties for \"%s\" as at %s\n//\n\n", g_pSM->GetGameFolderName(), buffer);
 
@@ -734,16 +722,14 @@ CON_COMMAND(sm_dump_classes, "Dumps the class list as a text file")
 	char buffer[80];
 	buffer[0] = 0;
 
-#if defined SUBPLATFORM_SECURECRT
-	_invalid_parameter_handler handler = _set_invalid_parameter_handler(_ignore_invalid_parameter);
-#endif
-
 	time_t t = g_pSM->GetAdjustedTime();
-	size_t written = strftime(buffer, sizeof(buffer), "%Y/%m/%d", localtime(&t));
+	size_t written = 0;
-
+	{
-#if defined SUBPLATFORM_SECURECRT
+#ifdef PLATFORM_WINDOWS
-	_set_invalid_parameter_handler(handler);
+		InvalidParameterHandler p;
 #endif
+		written = strftime(buffer, sizeof(buffer), "%Y/%m/%d", localtime(&t));
+	}
 
 	fprintf(fp, "// Dump of all classes for \"%s\" as at %s\n//\n\n", g_pSM->GetGameFolderName(), buffer);
 
@@ -898,16 +884,14 @@ CON_COMMAND(sm_dump_datamaps, "Dumps the data map list as a text file")
 	char buffer[80];
 	buffer[0] = 0;
 
-#if defined SUBPLATFORM_SECURECRT
-	_invalid_parameter_handler handler = _set_invalid_parameter_handler(_ignore_invalid_parameter);
-#endif
-
 	time_t t = g_pSM->GetAdjustedTime();
-	size_t written = strftime(buffer, sizeof(buffer), "%Y/%m/%d", localtime(&t));
+	size_t written = 0;
-
+	{
-#if defined SUBPLATFORM_SECURECRT
+#ifdef PLATFORM_WINDOWS
-	_set_invalid_parameter_handler(handler);
+		InvalidParameterHandler p;
 #endif
+		written = strftime(buffer, sizeof(buffer), "%Y/%m/%d", localtime(&t));
+	}
 
 	fprintf(fp, "// Dump of all datamaps for \"%s\" as at %s\n//\n//\n", g_pSM->GetGameFolderName(), buffer);
 

public/sm_invalidparamhandler.h

@@ -0,0 +1,62 @@
+/**
+ * vim: set ts=4 :
+ * =============================================================================
+ * SourceMod
+ * Copyright (C) 2004-2019 AlliedModders LLC.  All rights reserved.
+ * =============================================================================
+ *
+ * This program is free software; you can redistribute it and/or modify it under
+ * the terms of the GNU General Public License, version 3.0, as published by the
+ * Free Software Foundation.
+ * 
+ * This program is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
+ * FOR A PARTICULAR PURPOSE.  See the GNU General Public License for more
+ * details.
+ *
+ * You should have received a copy of the GNU General Public License along with
+ * this program.  If not, see <http://www.gnu.org/licenses/>.
+ *
+ * As a special exception, AlliedModders LLC gives you permission to link the
+ * code of this program (as well as its derivative works) to "Half-Life 2," the
+ * "Source Engine," the "SourcePawn JIT," and any Game MODs that run on software
+ * by the Valve Corporation.  You must obey the GNU General Public License in
+ * all respects for all other code used.  Additionally, AlliedModders LLC grants
+ * this exception to all derivative works.  AlliedModders LLC defines further
+ * exceptions, found in LICENSE.txt (as of this writing, version JULY-31-2007),
+ * or <http://www.sourcemod.net/license.php>.
+ *
+ * Version: $Id$
+ */
+
+#include <cstdlib>
+
+#include "sm_platform.h"
+#ifndef PLATFORM_WINDOWS
+	#error InvalidParameterHandler included in non-Windows build
+#endif
+
+/**
+ * Allows easy CRT invalid parameter redirection, previous handler is reset upon object destruction.
+ */
+class InvalidParameterHandler {
+public:
+	InvalidParameterHandler() {
+		this->old = _set_invalid_parameter_handler([](const wchar_t * expression, const wchar_t * function,  const wchar_t * file,  unsigned int line, uintptr_t pReserved) {
+			return;
+		});
+	}
+	InvalidParameterHandler(_invalid_parameter_handler newhandler) {
+		this->old = _set_invalid_parameter_handler(newhandler);
+	}
+	~InvalidParameterHandler() {
+		_set_invalid_parameter_handler(this->old);
+	}
+
+	// explicitly disable copy cstr and assignment
+	InvalidParameterHandler(const InvalidParameterHandler &) = delete;
+	InvalidParameterHandler& operator=(const InvalidParameterHandler &) = delete;
+
+private:
+	_invalid_parameter_handler old;
+};

public/sm_platform.h

@@ -71,9 +71,6 @@
 #define PLATFORM_SEP_ALTCHAR	'/'
 #define PLATFORM_SEP			"\\"
 #define PLATFORM_EXTERN_C		extern "C" __declspec(dllexport)
-#if defined _MSC_VER && _MSC_VER >= 1400
-#define SUBPLATFORM_SECURECRT
-#endif
 #elif defined __linux__ || defined __APPLE__
 #if defined __linux__
 # define PLATFORM_LINUX			1