From 8ee3da24cb811ca5c425bc4aec954eee22ca371d Mon Sep 17 00:00:00 2001 From: Unreal Karaulov Date: Mon, 6 Dec 2021 05:38:49 +0300 Subject: [PATCH] Added new debug feature: Performance Monitor. (#1019) * Performance Monitor. Search big performance issues for any plugin that in debug mode. No server slow down. Output is plugin and function name, and server execution lag in ms. Output target: current amxlog file. * Adding cvar to enable perflog. Force for all plugin if amx_debug is 2. * Update cvar name * Use another clock from chrono * Fix debug check * Skip internal amxx exec * Move includes * Fix debug check in amx_ExecPerf * Tried to compile without min/max undefined --- amxmodx/CForward.cpp | 7 +++---- amxmodx/amx.cpp | 37 +++++++++++++++++++++++++++++++++++++ amxmodx/amx.h | 1 + amxmodx/amxmodx.cpp | 2 +- amxmodx/amxmodx.h | 2 ++ amxmodx/debugger.cpp | 6 +++--- amxmodx/meta_api.cpp | 8 ++++++++ amxmodx/modules.cpp | 4 ++-- amxmodx/natives.cpp | 3 +-- configs/amxx.cfg | 10 ++++++++++ configs/cstrike/amxx.cfg | 9 +++++++++ configs/ns/amxx.cfg | 11 +++++++++++ 12 files changed, 88 insertions(+), 12 deletions(-) diff --git a/amxmodx/CForward.cpp b/amxmodx/CForward.cpp index 4b6ea2d8..36ea332e 100755 --- a/amxmodx/CForward.cpp +++ b/amxmodx/CForward.cpp @@ -122,8 +122,8 @@ cell CForward::execute(cell *params, ForwardPreparedArray *preparedArrays) #if defined BINLOG_ENABLED g_BinLog.WriteOp(BinLog_CallPubFunc, iter->pPlugin->getId(), iter->func); #endif - int err = amx_Exec(amx, &retVal, iter->func); - + + int err = amx_ExecPerf(amx, &retVal, iter->func); // log runtime error, if any if (err != AMX_ERR_NONE) { @@ -327,8 +327,7 @@ cell CSPForward::execute(cell *params, ForwardPreparedArray *preparedArrays) #if defined BINLOG_ENABLED g_BinLog.WriteOp(BinLog_CallPubFunc, pPlugin->getId(), m_Func); #endif - int err = amx_Exec(m_Amx, &retVal, m_Func); - + int err = amx_ExecPerf(m_Amx, &retVal, m_Func); if (err != AMX_ERR_NONE) { //Did something else set an error? diff --git a/amxmodx/amx.cpp b/amxmodx/amx.cpp index 1a4c8724..93f38b69 100755 --- a/amxmodx/amx.cpp +++ b/amxmodx/amx.cpp @@ -66,6 +66,9 @@ #include #endif +#include +#include +#include /* When one or more of the AMX_funcname macris are defined, we want * to compile only those functions. However, when none of these macros @@ -4173,3 +4176,37 @@ int AMXAPI amx_GetStringOld(char *dest,const cell *source,int use_wchar) dest[len]='\0'; /* store terminator */ return AMX_ERR_NONE; } + +int AMXAPI amx_ExecPerf(AMX* amx, cell* retval, int index) +{ + CPluginMngr::CPlugin* perf_Plug = g_plugins.findPluginFast(amx); + if (amxmodx_perflog->value > 0.0f && perf_Plug && (perf_Plug->isDebug() || (int)amxmodx_debug->value == 2)) + { + char perf_funcname[sNAMEMAX + 1]; + perf_funcname[0] = '\0'; + amx_GetPublic(perf_Plug->getAMX(), index, perf_funcname); + if (perf_funcname[0] == '\0') + sprintf(perf_funcname, "Unknown_ID%d", index); + + const char* perf_plugname = perf_Plug->getName(); + if (!perf_plugname || perf_plugname[0] == '\0') + perf_plugname = "Unknown_plugin"; + + using std::chrono::steady_clock; + using std::chrono::duration_cast; + using std::chrono::duration; + using std::chrono::microseconds; + + auto t1 = steady_clock::now(); + int err = amx_Exec(amx, retval, index); + + auto ms_int = duration_cast(steady_clock::now() - t1); + auto ms_float = (float)(ms_int.count() / 1000.0f); + if (ms_float >= amxmodx_perflog->value) + { + AMXXLOG_Log("[%s] performance issue. Function %s executed more than %.*fms.", perf_plugname, perf_funcname, 1, ms_float); + } + return err; + } + return amx_Exec(amx, retval, index); +} diff --git a/amxmodx/amx.h b/amxmodx/amx.h index 54fbbfa6..e6ccb4a4 100755 --- a/amxmodx/amx.h +++ b/amxmodx/amx.h @@ -382,6 +382,7 @@ int AMXAPI amx_Callback(AMX *amx, cell index, cell *result, cell *params); int AMXAPI amx_CheckNatives(AMX *amx, AMX_NATIVE_FILTER nf); int AMXAPI amx_Cleanup(AMX *amx); int AMXAPI amx_Clone(AMX *amxClone, AMX *amxSource, void *data); +int AMXAPI amx_ExecPerf(AMX* amx, cell* retval, int index); int AMXAPI amx_Exec(AMX *amx, cell *retval, int index); int AMXAPI amx_FindNative(AMX *amx, const char *name, int *index); int AMXAPI amx_FindPublic(AMX *amx, const char *funcname, int *index); diff --git a/amxmodx/amxmodx.cpp b/amxmodx/amxmodx.cpp index 0fab2b38..13a5b9f6 100755 --- a/amxmodx/amxmodx.cpp +++ b/amxmodx/amxmodx.cpp @@ -3709,7 +3709,7 @@ static cell AMX_NATIVE_CALL callfunc_end(AMX *amx, cell *params) amx_Push(pAmx, gparams[i]); } - err = amx_Exec(pAmx, &retVal, func); + err = amx_ExecPerf(pAmx, &retVal, func); if (err != AMX_ERR_NONE) { diff --git a/amxmodx/amxmodx.h b/amxmodx/amxmodx.h index 037662e9..6c3e8ae4 100755 --- a/amxmodx/amxmodx.h +++ b/amxmodx/amxmodx.h @@ -196,7 +196,9 @@ extern bool g_official_mod; extern bool g_dontprecache; extern int g_srvindex; extern cvar_t* amxmodx_version; +extern cvar_t* amxmodx_debug; extern cvar_t* amxmodx_language; +extern cvar_t* amxmodx_perflog; extern cvar_t* hostname; extern cvar_t* mp_timelimit; extern fakecmd_t g_fakecmd; diff --git a/amxmodx/debugger.cpp b/amxmodx/debugger.cpp index 41281822..eb232f6d 100755 --- a/amxmodx/debugger.cpp +++ b/amxmodx/debugger.cpp @@ -728,7 +728,7 @@ int Handler::HandleModule(const char *module, bool isClass) m_pAmx->flags |= AMX_FLAG_PRENIT; amx_Push(m_pAmx, isClass ? 1 : 0); amx_PushString(m_pAmx, &hea_addr, &phys_addr, module, 0, 0); - int err = amx_Exec(m_pAmx, &retval, m_iModFunc); + int err = amx_ExecPerf(m_pAmx, &retval, m_iModFunc); amx_Release(m_pAmx, hea_addr); m_pAmx->flags &= ~AMX_FLAG_PRENIT; @@ -768,7 +768,7 @@ int Handler::HandleNative(const char *native, int index, int trap) amx_Push(m_pAmx, trap); amx_Push(m_pAmx, index); amx_PushString(m_pAmx, &hea_addr, &phys_addr, native, 0, 0); - int err = amx_Exec(m_pAmx, &retval, m_iNatFunc); + int err = amx_ExecPerf(m_pAmx, &retval, m_iNatFunc); if (err != AMX_ERR_NONE) { //LogError() took care of something for us. @@ -841,7 +841,7 @@ int Handler::HandleError(const char *msg) amx_PushString(m_pAmx, &hea_addr, &phys_addr, msg, 0, 0); amx_Push(m_pAmx, pDebugger ? 1 : 0); amx_Push(m_pAmx, error); - int err = amx_Exec(m_pAmx, &result, m_iErrFunc); + int err = amx_ExecPerf(m_pAmx, &result, m_iErrFunc); if (err != AMX_ERR_NONE) { //handle this manually. diff --git a/amxmodx/meta_api.cpp b/amxmodx/meta_api.cpp index 3287697c..81560a91 100755 --- a/amxmodx/meta_api.cpp +++ b/amxmodx/meta_api.cpp @@ -135,9 +135,14 @@ cvar_t init_amxmodx_debug = {"amx_debug", "1", FCVAR_SPONLY}; cvar_t init_amxmodx_mldebug = {"amx_mldebug", "", FCVAR_SPONLY}; cvar_t init_amxmodx_language = {"amx_language", "en", FCVAR_SERVER}; cvar_t init_amxmodx_cl_langs = {"amx_client_languages", "1", FCVAR_SERVER}; +cvar_t init_amxmodx_perflog = { "amx_perflog_ms", "1.0", FCVAR_SPONLY }; + cvar_t* amxmodx_version = NULL; cvar_t* amxmodx_modules = NULL; +cvar_t* amxmodx_debug = NULL; cvar_t* amxmodx_language = NULL; +cvar_t* amxmodx_perflog = NULL; + cvar_t* hostname = NULL; cvar_t* mp_timelimit = NULL; @@ -1627,9 +1632,12 @@ C_DLLEXPORT int Meta_Attach(PLUG_LOADTIME now, META_FUNCTIONS *pFunctionTable, m CVAR_REGISTER(&init_amxmodx_mldebug); CVAR_REGISTER(&init_amxmodx_language); CVAR_REGISTER(&init_amxmodx_cl_langs); + CVAR_REGISTER(&init_amxmodx_perflog); amxmodx_version = CVAR_GET_POINTER(init_amxmodx_version.name); + amxmodx_debug = CVAR_GET_POINTER(init_amxmodx_debug.name); amxmodx_language = CVAR_GET_POINTER(init_amxmodx_language.name); + amxmodx_perflog = CVAR_GET_POINTER(init_amxmodx_perflog.name); REG_SVR_COMMAND("amxx", amx_command); diff --git a/amxmodx/modules.cpp b/amxmodx/modules.cpp index 4f1e5fe3..068b8d08 100755 --- a/amxmodx/modules.cpp +++ b/amxmodx/modules.cpp @@ -187,7 +187,7 @@ int load_amxscript_internal(AMX *amx, void **program, const char *filename, char bool will_be_debugged = false; tagAMX_DBG *pDbg = NULL; - if ((int)CVAR_GET_FLOAT("amx_debug") >= 2 || debug) + if ((int)amxmodx_debug->value == 2 || debug) { if ((hdr->file_version < CUR_FILE_VERSION)) { @@ -544,7 +544,7 @@ int set_amxnatives(AMX* amx, char error[128]) if (amx_FindPublic(amx, "plugin_natives", &idx) == AMX_ERR_NONE) { - if ((err = amx_Exec(amx, &retval, idx)) != AMX_ERR_NONE) + if ((err = amx_ExecPerf(amx, &retval, idx)) != AMX_ERR_NONE) { Debugger::GenericMessage(amx, err); AMXXLOG_Log("An error occurred in plugin_natives. This is dangerous!"); diff --git a/amxmodx/natives.cpp b/amxmodx/natives.cpp index 411e3d22..d5ae1c70 100755 --- a/amxmodx/natives.cpp +++ b/amxmodx/natives.cpp @@ -112,8 +112,7 @@ int amxx_DynaCallback(int idx, AMX *amx, cell *params) pDebugger->BeginExec(); } - err=amx_Exec(pNative->amx, &ret, pNative->func); - + err = amx_ExecPerf(pNative->amx, &ret, pNative->func); if (err != AMX_ERR_NONE) { if (pDebugger && pDebugger->ErrorExists()) diff --git a/configs/amxx.cfg b/configs/amxx.cfg index 00d34474..7e4f5a00 100755 --- a/configs/amxx.cfg +++ b/configs/amxx.cfg @@ -181,3 +181,13 @@ amx_debug 1 // // Default value: "" amx_mldebug "" + +// Performance monitor +// +// If function executed more than amx_perflog_ms milliseconds +// print plugin and function name to current amxmodx log file. +// +// Time in milliseconds +// Default value: 1.0 +// +amx_perflog_ms 1.0 \ No newline at end of file diff --git a/configs/cstrike/amxx.cfg b/configs/cstrike/amxx.cfg index a6fb7ba3..d93e8b1e 100755 --- a/configs/cstrike/amxx.cfg +++ b/configs/cstrike/amxx.cfg @@ -221,3 +221,12 @@ amx_statsx_freeze -2.0 // Default value: 0 amx_restrmapsettings 0 +// Performance monitor +// +// If function executed more than amx_perflog_ms milliseconds +// print plugin and function name to current amxmodx log file. +// +// Time in milliseconds +// Default value: 1.0 +// +amx_perflog_ms 1.0 \ No newline at end of file diff --git a/configs/ns/amxx.cfg b/configs/ns/amxx.cfg index 047fadf9..15f6d3a1 100755 --- a/configs/ns/amxx.cfg +++ b/configs/ns/amxx.cfg @@ -218,3 +218,14 @@ amx_idle_ignore_immunity 1 // // Default value: 4 amx_unstuck_frequency 4 + + +// Performance monitor +// +// If function executed more than amx_perflog_ms milliseconds +// print plugin and function name to current amxmodx log file. +// +// Time in milliseconds +// Default value: 1.0 +// +amx_perflog_ms 1.0 \ No newline at end of file