Files
Bubberstation/code/controllers/subsystem/profiler.dm
SkyratBot 78e2efff88 [MIRROR] Emergency Profile Dumps [MDB IGNORE] (#22006)
* Emergency Profile Dumps (#75924)

## About The Pull Request

Adds some hooks to the MC that detect if something ate a ton of real
time last tick, and reacts by dumping our current profile into a file

It's really frustrating to see a spike in td in our performance logs,
but see no reason in the profile because it's only taken every 5
minutes. This resolves that

I'm throwing this up so mso can give it a look over, not sure if I want
to use defines or configs here, taking suggestions

🆑
server: Adds a system to emergency dump profiles if too much time passes
between ticks
config: Added configs that control how often emergency profiles are
allowed to dump, alongside the threshold for what counts as too much
time between ticks
/🆑

* Emergency Profile Dumps

---------

Co-authored-by: LemonInTheDark <58055496+LemonInTheDark@users.noreply.github.com>
Co-authored-by: GoldenAlpharex <58045821+GoldenAlpharex@users.noreply.github.com>
Co-authored-by: lessthanthree <83487515+lessthnthree@users.noreply.github.com>
Co-authored-by: Pinta <68373373+softcerv@users.noreply.github.com>
Co-authored-by: Bloop <vinylspiders@gmail.com>
Co-authored-by: Bloop <13398309+vinylspiders@users.noreply.github.com>
2023-09-02 12:55:00 -04:00

75 lines
2.4 KiB
Plaintext

#define PROFILER_FILENAME "profiler.json"
#define SENDMAPS_FILENAME "sendmaps.json"
SUBSYSTEM_DEF(profiler)
name = "Profiler"
init_order = INIT_ORDER_PROFILER
runlevels = RUNLEVELS_DEFAULT | RUNLEVEL_LOBBY
wait = 3000
var/fetch_cost = 0
var/write_cost = 0
/datum/controller/subsystem/profiler/stat_entry(msg)
msg += "F:[round(fetch_cost,1)]ms"
msg += "|W:[round(write_cost,1)]ms"
return msg
/datum/controller/subsystem/profiler/Initialize()
if(CONFIG_GET(flag/auto_profile))
StartProfiling()
else
StopProfiling() //Stop the early start profiler
return SS_INIT_SUCCESS
/datum/controller/subsystem/profiler/OnConfigLoad()
if(CONFIG_GET(flag/auto_profile))
StartProfiling()
can_fire = TRUE
else
StopProfiling()
can_fire = FALSE
/datum/controller/subsystem/profiler/fire()
DumpFile()
/datum/controller/subsystem/profiler/Shutdown()
if(CONFIG_GET(flag/auto_profile))
DumpFile(allow_yield = FALSE)
world.Profile(PROFILE_CLEAR, type = "sendmaps")
return ..()
/datum/controller/subsystem/profiler/proc/StartProfiling()
world.Profile(PROFILE_START)
world.Profile(PROFILE_START, type = "sendmaps")
/datum/controller/subsystem/profiler/proc/StopProfiling()
world.Profile(PROFILE_STOP)
world.Profile(PROFILE_STOP, type = "sendmaps")
/datum/controller/subsystem/profiler/proc/DumpFile(allow_yield = TRUE)
var/timer = TICK_USAGE_REAL
var/current_profile_data = world.Profile(PROFILE_REFRESH, format = "json")
var/current_sendmaps_data = world.Profile(PROFILE_REFRESH, type = "sendmaps", format="json")
fetch_cost = MC_AVERAGE(fetch_cost, TICK_DELTA_TO_MS(TICK_USAGE_REAL - timer))
if(allow_yield)
CHECK_TICK
if(!length(current_profile_data)) //Would be nice to have explicit proc to check this
stack_trace("Warning, profiling stopped manually before dump.")
var/prof_file = file("[GLOB.log_directory]/[PROFILER_FILENAME]")
if(fexists(prof_file))
fdel(prof_file)
if(!length(current_sendmaps_data)) //Would be nice to have explicit proc to check this
stack_trace("Warning, sendmaps profiling stopped manually before dump.")
var/sendmaps_file = file("[GLOB.log_directory]/[SENDMAPS_FILENAME]")
if(fexists(sendmaps_file))
fdel(sendmaps_file)
timer = TICK_USAGE_REAL
WRITE_FILE(prof_file, current_profile_data)
WRITE_FILE(sendmaps_file, current_sendmaps_data)
write_cost = MC_AVERAGE(write_cost, TICK_DELTA_TO_MS(TICK_USAGE_REAL - timer))
#undef PROFILER_FILENAME
#undef SENDMAPS_FILENAME