can pass char to this now

no need to reconvert this stuff from const char to std::string and back to const char really lol

src/CMakeLists.txt

@@ -275,6 +275,7 @@ if(${SRB2_CONFIG_HAVE_BLUA})
 		lua_hooklib.c
 		lua_hudlib.c
 		lua_hudlib_drawlist.c
+		lua_profile.cpp
 		lua_infolib.c
 		lua_maplib.c
 		lua_mathlib.c
@@ -290,6 +291,7 @@ if(${SRB2_CONFIG_HAVE_BLUA})
 		lua_hook.h
 		lua_hud.h
 		lua_hudlib_drawlist.h
+		lua_profile.h
 		lua_libs.h
 		lua_script.h
 		lua_udatalib.h

src/Sourcefile

@@ -99,3 +99,4 @@ lua_skinlib.c
 lua_thinkerlib.c
 lua_udatalib.c
 lua_glib.c
+lua_profile.cpp

src/d_clisrv.c

@@ -6848,7 +6848,10 @@ boolean TryRunTics(tic_t realtics)
 			DEBFILE(va("============ Running tic %d (local %d)\n", gametic, leveltime));
 
 			if (update_stats)
+			{
+				ps_prevtictime = ps_tictime;
 				PS_START_TIMING(ps_tictime);
+			}
 
 			G_Ticker((gametic % NEWTICRATERATIO) == 0);
 			ExtraDataTicker();

src/d_main.c

@@ -79,6 +79,7 @@
 #include "core/memory.h"
 
 #include "lua_script.h"
+#include "lua_profile.h"
 
 /* Manually defined asset hashes for non-CMake builds
  * Last updated 2015 / 05 / 03 - SRB2 v2.1.15 - srb2.srb
@@ -658,6 +659,11 @@ static boolean D_Display(void)
 
 	    CON_Drawer(); // Ha, i LIED!
 
+		if (cv_lua_profile.value > 0)
+		{
+			LUA_RenderTimers();
+		}
+
 		PS_START_TIMING(ps_swaptime);
 		I_FinishUpdate(); // page flip or blit buffer
 		PS_STOP_TIMING(ps_swaptime);

src/d_netcmd.c

@@ -47,6 +47,7 @@
 #include "z_zone.h"
 #include "lua_script.h"
 #include "lua_hook.h"
+#include "lua_profile.h"
 #include "m_cond.h"
 #include "m_anigif.h"
 #include "k_kart.h" // SRB2kart
@@ -506,6 +507,9 @@ static CV_PossibleValue_t ps_descriptor_cons_t[] = {
 	{1, "Average"}, {2, "SD"}, {3, "Minimum"}, {4, "Maximum"}, {0, NULL}};
 consvar_t cv_ps_descriptor = {"ps_descriptor", "Average", 0, ps_descriptor_cons_t, NULL, 0, NULL, NULL, 0, 0, NULL};
 
+//consvar_t cv_lua_profile = {"lua_profile", "0").values(CV_Unsigned).onchange(lua_profile_OnChange).description("Show hook timings over an average of N tics");
+consvar_t cv_lua_profile = {"lua_profile", "0", CV_CALL, CV_Unsigned, lua_profile_OnChange, 0, NULL, NULL, 0, 0, NULL};
+
 // only there to better keep track of it globally
 consvar_t cv_director = {"director", "Off", CV_HIDEN, CV_OnOff, NULL, 0, NULL, NULL, 0, 0, NULL};
 
@@ -933,6 +937,8 @@ void D_RegisterClientCommands(void)
 	CV_RegisterVar(&cv_palette);
 	CV_RegisterVar(&cv_palettenum);
 
+	CV_RegisterVar(&cv_lua_profile);
+
 	// m_menu.c
 	CV_RegisterVar(&cv_chatheight);
 	CV_RegisterVar(&cv_chatwidth);

src/d_netcmd.h

@@ -189,6 +189,8 @@ extern consvar_t cv_ps_thinkframe_page;
 extern consvar_t cv_ps_samplesize;
 extern consvar_t cv_ps_descriptor;
 
+extern consvar_t cv_lua_profile;
+
 extern consvar_t cv_director, cv_kartdebugdirector, cv_showdirectorhud;
 
 extern consvar_t cv_showtrackaddon;

src/lua_hooklib.c

@@ -25,6 +25,7 @@
 #include "lua_libs.h"
 #include "lua_hook.h"
 #include "lua_hud.h" // hud_running errors
+#include "lua_profile.h"
 
 /* =========================================================================
                                   ABSTRACTION
@@ -445,11 +446,54 @@ FUNCINLINE static ATTRINLINE void get_hook_from_table(Hook_State *hook, int n)
 	lua_getref(gL, hookRefs[hook->id]);
 }
 
+static int pcall(Hook_State *hook)
+{
+	return lua_pcall(gL, hook->values, hook->results, EINDEX);
+}
+
+static const char *hook_name(Hook_State *hook)
+{
+	if (hud_running)
+	{
+		return hudHookNames[hook->hook_type];
+	}
+	else if (hook->string)
+	{
+		return stringHookNames[hook->hook_type];
+	}
+	//else if (hook->mobj_type > 0)
+	else if (hook->mobj_type != NONMOHOOK)
+	{
+		return mobjHookNames[hook->hook_type];
+	}
+	else
+	{
+		return hookNames[hook->hook_type];
+	}
+}
+
+static int pcall_timed_or_untimed(Hook_State *hook)
+{
+	if (!hud_running && cv_lua_profile.value > 0)
+	{
+		lua_timer_t *timer = LUA_BeginFunctionTimer(gL, -1 - hook->values, hook_name(hook));
+		int k = pcall(hook);
+		LUA_EndFunctionTimer(timer);
+
+		return k;
+	}
+	else
+	{
+		return pcall(hook);
+	}
+}
+
 static int call_single_hook_no_copy(Hook_State *hook)
 {
 	hook_important = hook->important;
 
-	if (lua_pcall(gL, hook->values, hook->results, EINDEX) == 0)
+	//if (lua_pcall(gL, hook->values, hook->results, EINDEX) == 0)
+	if (pcall_timed_or_untimed(hook) == 0)
 	{
 		if (hook->results > 0)
 		{

src/lua_infolib.c

@@ -22,7 +22,8 @@
 #include "lua_script.h"
 #include "lua_libs.h"
 #include "lua_hud.h" // hud_running errors
-#include "lua_hook.h"	// cmd errors
+#include "lua_hook.h" // hook_cmd_running errors
+#include "lua_profile.h"
 
 boolean LUA_CallAction(enum actionnum actionnum, mobj_t *actor);
 state_t *astate = NULL;
@@ -110,7 +111,10 @@ static void A_Lua(mobj_t *actor)
 	LUA_PushUserdata(gL, actor, META_MOBJ);
 	lua_pushinteger(gL, var1);
 	lua_pushinteger(gL, var2);
+
+	lua_timer_t *timer = LUA_BeginFunctionTimer(gL, -4, "A_Lua");
 	LUA_Call(gL, 3, 0, 1);
+	LUA_EndFunctionTimer(timer);
 
 	lua_pop(gL, 1); // pop error handler
 

src/lua_profile.cpp

@@ -0,0 +1,264 @@
+// DR. ROBOTNIK'S RING RACERS
+//-----------------------------------------------------------------------------
+// Copyright (C) 2025 by James Robert Roman
+// Copyright (C) 2025 by Kart Krew
+//
+// This program is free software distributed under the
+// terms of the GNU General Public License, version 2.
+// See the 'LICENSE' file for more details.
+//-----------------------------------------------------------------------------
+
+#include "screen.h"
+#include <algorithm>
+#include <cstddef>
+#include <unordered_map>
+#include <string>
+#include <string_view>
+#include <vector>
+
+extern "C" {
+#include "blua/lua.h"
+};
+
+#include "v_video.h"
+
+#include "command.h"
+#include "doomtype.h"
+#include "i_system.h"
+#include "lua_profile.h"
+#include "m_perfstats.h"
+
+extern "C" consvar_t cv_lua_profile;
+
+namespace
+{
+
+precise_t g_time_reference;
+int g_tics_counted;
+
+double g_running_tic_time;
+double g_avg_tic_time;
+
+bool g_invalid;
+
+}; // namespace
+
+struct lua_timer_t
+{
+	struct Stat
+	{
+		double calls = 0;
+		double time = 0.0;
+	};
+
+	Stat running, avg;
+};
+
+namespace
+{
+
+std::unordered_map<std::string, lua_timer_t> g_tic_timers;
+
+}; // namespace
+
+lua_timer_t* LUA_BeginFunctionTimer(lua_State* L, int fn_idx, const char* name)
+{
+	lua_Debug ar;
+
+	lua_pushvalue(L, fn_idx);
+	lua_getinfo(L, ">S", &ar);
+
+	auto label = [&]
+	{
+		using sv = std::string_view;
+		sv view{ar.source};
+
+		switch (view.front())
+		{
+		case '@': // file
+			if (std::size_t p = view.rfind('/'); p != sv::npos) // lump or base
+			{
+				return view.substr(p + 1);
+			}
+			break;
+
+		case '=': // ??
+			view.remove_prefix(1);
+			break;
+		}
+
+		return view;
+	};
+
+	// i sure hope this std::string mess is fine...
+	auto [it, ins] = g_tic_timers.try_emplace(std::string(va("%s:%d (%s)", std::string(label()).c_str(), ar.linedefined, name)));
+	auto& [key, timer] = *it;
+
+	g_time_reference = I_GetPreciseTime();
+
+	return &timer;
+}
+
+void LUA_EndFunctionTimer(lua_timer_t* timer)
+{
+	precise_t t = I_GetPreciseTime() - g_time_reference;
+	double precision = I_GetPrecisePrecision();
+
+	timer->running.time += t / precision;
+	timer->running.calls += 1.0;
+}
+
+void LUA_ResetTicTimers(void)
+{
+	if (cv_lua_profile.value <= 0)
+	{
+		return;
+	}
+
+	if (g_tics_counted < cv_lua_profile.value)
+	{
+		g_tics_counted++;
+
+		double precision = I_GetPrecisePrecision();
+		g_running_tic_time += ps_prevtictime.value.p / precision;
+	}
+	else
+	{
+		double counted = g_tics_counted;
+
+		for (auto& [key, timer] : g_tic_timers)
+		{
+			timer.avg = {timer.running.calls / counted, timer.running.time / counted};
+			timer.running = {};
+		}
+
+		g_avg_tic_time = g_running_tic_time / counted;
+		g_running_tic_time = 0.0;
+
+		g_tics_counted = 1;
+
+		g_invalid = false;
+	}
+}
+
+void LUA_RenderTimers(void)
+{
+	constexpr int kRowHeight = 4;
+	float row_y = kRowHeight;
+
+	// pretty much what the whole srb2::Draw does lol
+	auto draw_row = [](float x, float y, INT32 flags, const char *str)
+	{
+		V_DrawSmallStringAtFixed(
+			FloatToFixed(x),
+			FloatToFixed(y),
+			V_MONOSPACE|V_ALLOWLOWERCASE|flags,
+			str
+		);
+	};
+
+	draw_row(0.f, 0.f, 0, va("-- AVERAGES PER TIC (over %d tics) --", cv_lua_profile.value));
+
+	if (g_invalid)
+	{
+		draw_row(0.f, row_y, V_GRAYMAP, "  <Data pending>");
+		return;
+	}
+
+	std::vector<decltype(g_tic_timers)::iterator> view;
+	view.reserve(g_tic_timers.size());
+
+	auto color_flag = [](double t)
+	{
+		if (t < 10.0)
+		{
+			return V_GRAYMAP;
+		}
+		else if (t >= 100.0)
+		{
+			return V_YELLOWMAP;
+		}
+		else
+		{
+			return 0;
+		}
+	};
+
+	{
+		double cum = 0.0;
+
+		for (auto it = g_tic_timers.begin(); it != g_tic_timers.end(); ++it)
+		{
+			auto& [key, timer] = *it;
+
+			cum += timer.avg.time;
+
+			if (timer.avg.time > 0.0)
+			{
+				view.push_back(it);
+			}
+		}
+
+		{
+			const INT32 tally_flags = color_flag(cum * 1'000'000.0);
+
+			draw_row(0.f, row_y, tally_flags, va("%8.2f us - TOTAL", cum * 1'000'000.0));
+			draw_row(0.f, row_y + kRowHeight, tally_flags, va("%8.2f ms", cum * 1000.0));
+
+			// dont need to show this if we didnt capture over time
+			// this would just show nan or inf anyways
+			if (std::fpclassify(g_avg_tic_time) != FP_ZERO)
+			{
+				draw_row(0.f, row_y + kRowHeight * 2, tally_flags, va(
+				"%8.2f%% overhead (%.2f / %.2f) <-- not counting rendering time",
+																		(cum / g_avg_tic_time) * 100.0,
+																		(cum * (double)TICRATE),
+																		(g_avg_tic_time * (double)TICRATE)
+				));
+			}
+		}
+
+		row_y += kRowHeight * 4;
+	}
+
+	std::sort(
+		view.rbegin(),
+		view.rend(),
+		[](auto a, auto b)
+		{
+			auto& [k1, t1] = *a;
+			auto& [k2, t2] = *b;
+			return t1.avg.time < t2.avg.time;
+		}
+	);
+
+	for (auto it : view)
+	{
+		auto& [key, timer] = *it;
+
+		double t = timer.avg.time * 1'000'000.0;
+
+		draw_row(0.f, row_y, color_flag(t), va(
+			"%8.2f us %8.2f calls - %s",
+			t,
+			timer.avg.calls,
+			key.c_str()
+		));
+
+		row_y += kRowHeight;
+
+		// FIXME this is all ugly and sucks
+		if (row_y >= BASEVIDHEIGHT)
+			break;
+	}
+}
+
+extern "C" void lua_profile_OnChange(void)
+{
+	g_invalid = true;
+
+	if (cv_lua_profile.value == 0)
+	{
+		g_tic_timers = {};
+	}
+}

src/lua_profile.h

@@ -0,0 +1,38 @@
+// DR. ROBOTNIK'S RING RACERS
+//-----------------------------------------------------------------------------
+// Copyright (C) 2025 by James Robert Roman
+// Copyright (C) 2025 by Kart Krew
+//
+// This program is free software distributed under the
+// terms of the GNU General Public License, version 2.
+// See the 'LICENSE' file for more details.
+//-----------------------------------------------------------------------------
+
+#ifndef lua_profile_h
+#define lua_profile_h
+
+#include "blua/lua.h"
+#include "doomtype.h"
+//#include "typedef.h"
+
+#ifdef __cplusplus
+extern "C" {
+#endif
+
+struct lua_timer_t;
+typedef struct lua_timer_t lua_timer_t;
+
+void LUA_ResetTicTimers(void);
+
+lua_timer_t *LUA_BeginFunctionTimer(lua_State *L, int fn_idx, const char *name);
+void LUA_EndFunctionTimer(lua_timer_t *timer);
+
+void LUA_RenderTimers(void);
+
+void lua_profile_OnChange(void);
+
+#ifdef __cplusplus
+} // extern "C"
+#endif
+
+#endif/*lua_profile_h*/

src/m_perfstats.c

@@ -47,6 +47,7 @@ struct perfstatrow {
 static ps_metric_t ps_frametime = {0};
 
 ps_metric_t ps_tictime = {0};
+ps_metric_t ps_prevtictime = {0};
 
 ps_metric_t ps_playerthink_time = {0};
 ps_metric_t ps_thinkertime = {0};

src/m_perfstats.h

@@ -36,6 +36,7 @@ typedef struct
 #define PS_STOP_TIMING(metric) metric.value.p = I_GetPreciseTime() - metric.value.p
 
 extern ps_metric_t ps_tictime;
+extern ps_metric_t ps_prevtictime;
 
 extern ps_metric_t ps_playerthink_time;
 extern ps_metric_t ps_thinkertime;

src/p_tick.c

@@ -38,6 +38,8 @@
 #include "i_video.h" // rendermode
 #include "m_perfstats.h"
 
+#include "lua_profile.h"
+
 // Object place
 #include "m_cheat.h"
 
@@ -622,6 +624,8 @@ void P_Ticker(boolean run)
 			}
 		}
 
+		LUA_ResetTicTimers();
+
 		ps_lua_mobjhooks.value.i = 0;
 		ps_checkposition_calls.value.i = 0;
 
@@ -629,6 +633,7 @@ void P_Ticker(boolean run)
 		LUA_HookPreThinkFrame();
 		PS_STOP_TIMING(ps_lua_prethinkframe_time);
 
+		// OK! Now that we got all of that sorted, players can think!
 		PS_START_TIMING(ps_playerthink_time);
 		for (i = 0; i < MAXPLAYERS; i++)
 		{
@@ -675,6 +680,7 @@ void P_Ticker(boolean run)
 		PS_STOP_TIMING(ps_lua_thinkframe_time);
 	}
 
+	// Run shield positioning
 	P_RunOverlays();
 	P_RunShadows();
 
@@ -796,7 +802,7 @@ void P_Ticker(boolean run)
 				if (!player->mo)
 					continue;
 
-				const boolean skybox = (skyboxmo[0] && cv_skybox.value);
+				const boolean skybox = (skyboxmo[0] && cv_skybox.value); // True if there's a skybox object and skyboxes are on
 
 				if (skyVisiblePerPlayer[i] && skybox)
 				{