profiler, the stuff of nightmares

Author: 1fbff5f83b23d39d38b1dfcb4cac8d9b

byond-extools/src/core/byond_structures.h

@@ -99,8 +99,12 @@ struct ProcConstants
 	Value usr;
 	ExecutionContext* context;
 	int unknown3;
-	int unknown4;
-	int unknown5;
+	int unknown4; //some callback thing
+	union
+	{
+		int unknown5;
+		int extended_profile_id;
+	};
 	int arg_count;
 	Value* args;
 };
@@ -121,12 +125,13 @@ struct ExecutionContext
 	Value* stack;
 	short local_var_count;
 	short stack_size;
-	int unknown;
+	int unknown; //callback something
 	Value* current_iterator;
 	int iterator_allocated;
 	int iterator_length;
 	int iterator_index;
-	char unknown4[7];
+	int another_unknown2;
+	char unknown4[3];
 	char iterator_filtered_type;
 	char unknown5;
 	char iterator_unknown;
@@ -135,6 +140,11 @@ struct ExecutionContext
 	char unknown7[2];
 	bool paused;
 	char unknown8[51];
+
+	int hash()
+	{
+		return constants->proc_id + (int)constants->args;
+	}
 };
 
 struct ProcSetupEntry

byond-extools/src/core/core.cpp

@@ -3,6 +3,7 @@
 #include "../tffi/tffi.h"
 #include "../proxy/proxy_object.h"
 #include "../optimizer/optimizer.h"
+#include "../extended_profiling/extended_profiling.h"
 
 CrashProcPtr CrashProc;
 SuspendPtr Suspend;
@@ -14,6 +15,8 @@ GetProcArrayEntryPtr GetProcArrayEntry;
 GetStringTableEntryPtr GetStringTableEntry;
 CallGlobalProcPtr CallGlobalProc;
 GetProfileInfoPtr GetProfileInfo;
+ProcCleanupPtr ProcCleanup;
+CreateContextPtr CreateContext;
 
 ExecutionContext** Core::current_execution_context_ptr;
 ExecutionContext** Core::parent_context_ptr_hack;
@@ -36,9 +39,9 @@ bool Core::initialize()
 	return initialized;
 }
 
-void Core::Alert(const char* what) {
+void Core::Alert(std::string what) {
 #ifdef _WIN32
-	MessageBoxA(NULL, what, "Ouch!", NULL);
+	MessageBoxA(NULL, what.c_str(), "Ouch!", NULL);
 #else
 	printf("%s\n", what);
 #endif
@@ -112,6 +115,7 @@ extern "C" EXPORT const char* core_initialize(int n_args, const char* args)
 		return bad;
 	}
 	optimizer_initialize();
+	extended_profiling_initialize();
 	return good;
 }
 

byond-extools/src/core/core.h

@@ -27,7 +27,7 @@ namespace Core
 	ExecutionContext* get_context();
 	ExecutionContext* _get_parent_context();
 	unsigned int register_opcode(std::string name, opcode_handler handler);
-	void Alert(const char* what);
+	void Alert(std::string what);
 	bool initialize();
 	extern bool initialized;
 	Value get_stack_value(unsigned int which);

byond-extools/src/core/find_functions.cpp

@@ -21,6 +21,8 @@ bool Core::find_functions()
 	FIND_OR_DIE(GetStringTableEntry, "55 8B EC 8B 4D 08 3B 0D ?? ?? ?? ?? 73 10 A1");
 	FIND_OR_DIE(CallGlobalProc, "55 8B EC 81 EC 98 00 00 00 A1 ?? ?? ?? ?? 33 C5 89 45 FC 8B 55 14 8B 45 30 89 85 6C FF FF FF 53 8B 5D 24 56 8B 75 2C 57 8B 7D 28 81 FA FF FF 00 00 75 ?? 0F 57 C0 66 0F 13 85 68 FF FF FF 8B BD 6C FF FF FF 8B 9D 68 FF FF FF 85 F6");
 	FIND_OR_DIE(GetProfileInfo, "55 8B EC A1 ?? ?? ?? ?? 56 8B 75 08 3B F0 73 30 8B ?? ?? ?? ?? ?? 85 C9 75 36 8D 04 80 C1 E0 03 50 FF 15 ?? ?? ?? ?? 83 C4 04 A3 ?? ?? ?? ?? 85 C0 75 12 68 ?? ?? ?? ?? E8 ?? ?? ?? ?? 83 C4 04 33 C0 5E 5D C3 E8 ?? ?? ?? ?? 8B ?? ?? ?? ?? ?? 8D 04 B6 8D 04 C1 5E 5D C3");
+	FIND_OR_DIE(ProcCleanup, "55 8B EC 53 8B ?? ?? ?? ?? ?? 56 8B 75 08 57 8B 7E 44 85 FF 74 2A 8B 47 1C 89 46 44 FF 77 08 FF 37 E8 ?? ?? ?? ?? 8D 47 10 50 E8 ?? ?? ?? ?? FF 37 FF D3 57 FF D3 8B 7E 44 83 C4 14 85 FF 75 D6 FF 76 50 FF 76 48 E8");
+	FIND_OR_DIE(CreateContext, "55 8B EC 83 EC 64 56 57 8B 7D 08 8B 4F 18 85 C9 0F 84 ?? ?? ?? ?? A1 ?? ?? ?? ?? 89 41 04 8B 4F 18 89 ?? ?? ?? ?? ?? 80 79 69 00");
 	current_execution_context_ptr = *(ExecutionContext * **)Pocket::Sigscan::FindPattern(BYONDCORE, "A1 ?? ?? ?? ?? 8D ?? ?? ?? ?? ?? 83 C4 08 89 48 28 8D ?? ?? ?? ?? ?? 89 48 2C 83 3D ?? ?? ?? ?? ?? 74 25 8B 00 FF 30 E8 ?? ?? ?? ?? 83 C4 04 FF 30 E8 ?? ?? ?? ?? 83 C4 04 FF 30 68 ?? ?? ?? ?? E8 ?? ?? ?? ?? 83 C4 08 66 ?? ?? ?? ?? ?? ?? A1 ?? ?? ?? ?? 75 28 A8 02 75 24 E8 ?? ?? ?? ?? 85 C0 75 09 50", 1);
 	proc_setup_table = **(ProcSetupEntry * ***)Pocket::Sigscan::FindPattern(BYONDCORE, "A1 ?? ?? ?? ?? FF 34 B8 FF D6 47 83 C4 04 3B ?? ?? ?? ?? ?? 72 EA FF 35 ?? ?? ?? ?? FF D6 33 FF 83 C4 04 39 ?? ?? ?? ?? ?? 76 1E", 1);
 	some_flags_including_profile = *(unsigned int**)Pocket::Sigscan::FindPattern(BYONDCORE, "F7 05 ?? ?? ?? ?? ?? ?? ?? ?? 74 34 8B 01 FF 30 E8 ?? ?? ?? ?? 83 C4 04 8B D8 E8 ?? ?? ?? ?? 8B F0 8B FA E8 ?? ?? ?? ?? 85 DB 74 02 FF 03 8B ?? ?? ?? ?? ?? 89 71 70 89 79 74 89 41 78 89 51 7C 83 3D ?? ?? ?? ?? ?? 5B 74 37", 2);

byond-extools/src/core/hooking.cpp

@@ -4,6 +4,7 @@
 #include <fstream>
 #include "json.hpp"
 #include <stack>
+#include "../extended_profiling/extended_profiling.h"
 
 #ifdef _WIN32
 static PLH::CapstoneDisassembler* disassembler;
@@ -13,131 +14,16 @@ urmem::hook CrashProcDetour;
 CrashProcPtr oCrashProc;
 CallGlobalProcPtr oCallGlobalProc;
 
-#define TOMICROS(x) std::chrono::duration_cast<std::chrono::microseconds>(x).count()
-
-struct ExtendedProfile
-{
-	unsigned int proc_id;
-	int* bytecode; //facilitate faster searches up the call stack
-	std::vector<ExtendedProfile*> subcalls;
-	std::chrono::time_point<std::chrono::steady_clock> start_time;
-	std::chrono::time_point<std::chrono::steady_clock> end_time;
-	unsigned long long total_time = 0;
-	int call_id = 0;
-};
-
-ExtendedProfile* proc_being_profiled;
-ExtendedProfile* profile_result;
-std::stack<ExtendedProfile*> call_stack;
-
-void output_subcalls(std::string base, std::ofstream& output, ExtendedProfile* profile, int depth)
-{
-	base += Core::get_proc(profile->proc_id).name+";";
-	//Core::Alert(base.c_str());
-	if (!(profile->subcalls.empty()))
-	{
-		output << base << "self " << TOMICROS(profile->subcalls.back()->start_time - profile->start_time) << "\n";
-		for (ExtendedProfile* sub : profile->subcalls)
-		{
-			output_subcalls(base, output, sub, ++depth);
-		}
-		ExtendedProfile* last_sub = profile->subcalls.back();
-		output << base << "self " << TOMICROS(profile_result->end_time - last_sub->end_time) << "\n";
-	}
-	else
-	{
-		base.pop_back();
-		output << base << " "<< TOMICROS(profile->end_time - profile->start_time) << "\n";
-	}
-}
-
-void dump_extended_profile()
-{
-	/*nlohmann::json result;
-	result["version"] = "0.0.1";
-	result["$schema"] = "https://www.speedscope.app/file-format-schema.json";
-	result["name"] = Core::get_proc(profile_result->proc_id).name;
-	result["activeProfileIndex"] = 1;
-
-	nlohmann::json shared;
-	std::vector<std::pair<std::string, std::string>> frames;
-	frames.push_back({ "name", "self" });
-	frames.push_back({"name", Core::get_proc(profile_result->proc_id).name });
-	for (ExtendedProfile* sub : profile_result->subcalls)
-	{
-		frames.push_back({ "name", Core::get_proc(sub->proc_id).name });
-	}
-	shared["frames"] = frames;
-	result["shared"] = shared;
-
-	nlohmann::json profile;
-	profile["type"] = "sampled";
-	profile["name"] = Core::get_proc(profile_result->proc_id).name;
-	profile["unit"] = "microseconds";
-	profile["startValue"] = 0;
-	profile["endValue"] = profile_result->total_time;
-	
-
-	std::ofstream output("extended_profile.txt");
-	output << result.dump();*/
-	std::ofstream output("extended_profile.txt");
-	output_subcalls("", output, profile_result, 0);
-	output.flush();
-}
+//ExecutionContext* last_suspended_ec;
 
 trvh __cdecl hCallGlobalProc(char unk1, int unk2, int proc_type, unsigned int proc_id, int const_0, char unk3, int unk4, Value* argList, unsigned int argListLen, int const_0_2, int const_0_3)
 {
-	int call_id = 0;
-	if (extended_profiling_procs.find(proc_id) != extended_profiling_procs.end())
-	{
-		proc_being_profiled = new ExtendedProfile();
-		proc_being_profiled->proc_id = proc_id;
-		proc_being_profiled->bytecode = Core::get_context()->bytecode;
-		proc_being_profiled->start_time = std::chrono::high_resolution_clock::now();
-		call_stack.push(proc_being_profiled);
-	}
-	if (proc_being_profiled && proc_being_profiled->proc_id != proc_id)
-	{
-		call_id = rand();
-		ExecutionContext* parent_ctx = Core::_get_parent_context();
-		if (call_stack.top()->proc_id == Core::get_proc(parent_ctx->bytecode).id)
-		{
-			ExtendedProfile* subcall = new ExtendedProfile();
-			subcall->proc_id = proc_id;
-			subcall->bytecode = Core::get_proc(proc_id).get_bytecode();
-			subcall->start_time = std::chrono::high_resolution_clock::now();
-			subcall->call_id = call_id;
-			call_stack.top()->subcalls.push_back(subcall);
-			call_stack.push(subcall);
-		}
-	}
 	if (proc_hooks.find(proc_id) != proc_hooks.end())
 	{
 		trvh result = proc_hooks[proc_id](argList, argListLen);
-		Core::Alert("hook");
 		return result;
 	}
 	trvh result = oCallGlobalProc(unk1, unk2, proc_type, proc_id, const_0, unk3, unk4, argList, argListLen, const_0_2, const_0_3);
-	if (proc_being_profiled)
-	{
-		ExtendedProfile* top = call_stack.top();
-		if (top->proc_id == proc_id)
-		{
-			ExtendedProfile* sub = call_stack.top();
-			sub->end_time = std::chrono::high_resolution_clock::now();
-			call_stack.pop();
-			sub->total_time = std::chrono::duration_cast<std::chrono::microseconds>(sub->end_time - sub->start_time).count();
-		}
-		if (proc_being_profiled->proc_id == proc_id)
-		{
-			proc_being_profiled->end_time = std::chrono::high_resolution_clock::now();
-			proc_being_profiled->total_time = std::chrono::duration_cast<std::chrono::microseconds>(proc_being_profiled->end_time - proc_being_profiled->start_time).count();
-			profile_result = proc_being_profiled;
-			proc_being_profiled = nullptr;
-			dump_extended_profile();
-			//Core::Alert("Extended profile results written to file");
-		}
-	}
 	return result;
 }
 
@@ -155,7 +41,6 @@ void hCrashProc(char* error, int argument)
 #endif
 }
 
-
 void* Core::install_hook(void* original, void* hook)
 {
 #ifdef _WIN32

byond-extools/src/core/internal_functions.h

@@ -38,6 +38,8 @@ typedef SuspendedProc* (*SuspendPtr)(ExecutionContext* ctx) __attribute__((regpa
 typedef void(*StartTimingPtr)(SuspendedProc*) __attribute__((regparm(3)));
 #endif
 typedef ProfileInfo* (*GetProfileInfoPtr)(unsigned int proc_id);
+typedef void(*ProcCleanupPtr)(ExecutionContext* thing_that_just_executed); //this one is hooked to help with extended profiling
+typedef void(*CreateContextPtr)(void* unknown, ExecutionContext* new_ctx);
 
 extern CrashProcPtr CrashProc;
 extern StartTimingPtr StartTiming;
@@ -48,4 +50,6 @@ extern GetStringTableIndexPtr GetStringTableIndex;
 extern GetProcArrayEntryPtr GetProcArrayEntry;
 extern GetStringTableEntryPtr GetStringTableEntry;
 extern CallGlobalProcPtr CallGlobalProc;
-extern GetProfileInfoPtr GetProfileInfo;
+extern GetProfileInfoPtr GetProfileInfo;
+extern ProcCleanupPtr ProcCleanup;
+extern CreateContextPtr CreateContext;

byond-extools/src/core/proc_management.cpp

@@ -1,6 +1,7 @@
 #include "proc_management.h"
 #include "../dmdism/disassembly.h"
 #include "../dmdism/disassembler.h"
+#include "../extended_profiling/extended_profiling.h"
 
 std::vector<Core::Proc> procs_by_id;
 std::unordered_map<std::string, Core::Proc> procs_by_name;
@@ -57,6 +58,11 @@ ProfileInfo* Core::Proc::profile()
 	return GetProfileInfo(id);
 }
 
+void Core::Proc::extended_profile()
+{
+	procs_to_profile[id] = true;
+}
+
 void Core::Proc::hook(ProcHook hook_func)
 {
 	proc_hooks[id] = hook_func;
@@ -131,5 +137,11 @@ bool Core::populate_proc_list()
 		procs_by_bytecode[p.get_bytecode()] = p;
 		i++;
 	}
+	//Temporary - fake proc used by profiler
+	Proc sleep = Proc();
+	sleep.id = i;
+	sleep.name = "SLEEP";
+	procs_by_id.push_back(sleep);
+	procs_by_name["SLEEP"] = sleep;
 	return true;
 }

byond-extools/src/core/proc_management.h

@@ -36,6 +36,7 @@ namespace Core
 		void assemble(Disassembly disasm);
 
 		ProfileInfo* profile();
+		void extended_profile();
 		void hook(ProcHook hook_func);
 		Value call(std::vector<Value> arguments, Value usr = Value::Null(), Value src = Value::Null());
 
@@ -48,6 +49,16 @@ namespace Core
 		{
 			return id == rhs.id;
 		}
+
+		operator int()
+		{
+			return id;
+		}
+
+		operator std::string()
+		{
+			return name;
+		}
 	};
 
 	Proc get_proc(std::string name);

byond-extools/src/core/various_testing.cpp

@@ -54,7 +54,10 @@ trvh update_light_objects;
 void init_testing()
 {
 	Core::enable_profiling();
-	//extended_profiling_procs[Core::get_proc("/datum/controller/subsystem/atoms/proc/InitializeAtoms").id] = true;
+	Core::get_proc("/datum/explosion/New").extended_profile();
+	//Core::get_proc("/client/verb/test_reentry").extended_profile();
+	//Core::get_proc("/client/verb/test_extended_profiling").extended_profile();
+	//extended_profiling_procs[.id] = true;
 	//Core::get_proc("/proc/cheap_hypotenuse_hook").hook(cheap_hypotenuse);
 	//Core::get_proc("/proc/measure_get_variable").hook(measure_get_variable);
 	//Core::get_proc("/proc/laugh").hook(show_profiles);