diff --git a/code/controllers/configuration/entries/general.dm b/code/controllers/configuration/entries/general.dm index d5673a92485ba..5b788a621ef6a 100644 --- a/code/controllers/configuration/entries/general.dm +++ b/code/controllers/configuration/entries/general.dm @@ -626,6 +626,12 @@ /datum/config_entry/flag/auto_profile +/datum/config_entry/number/drift_dump_threshold + default = 4 SECONDS + +/datum/config_entry/number/drift_profile_delay + default = 15 SECONDS + /datum/config_entry/string/centcom_ban_db // URL for the CentCom Galactic Ban DB API /datum/config_entry/string/centcom_source_whitelist diff --git a/code/controllers/master.dm b/code/controllers/master.dm index 694f2906bf57d..1697d3e41b76c 100644 --- a/code/controllers/master.dm +++ b/code/controllers/master.dm @@ -32,6 +32,8 @@ GLOBAL_REAL(Master, /datum/controller/master) var/init_timeofday var/init_time var/tickdrift = 0 + /// Tickdrift as of last tick, w no averaging going on + var/olddrift = 0 /// How long is the MC sleeping between runs, read only (set by Loop() based off of anti-tick-contention heuristics) var/sleep_delta = 1 @@ -60,6 +62,10 @@ GLOBAL_REAL(Master, /datum/controller/master) /// Outside of initialization, returns null. var/current_initializing_subsystem = null + /// The last decisecond we force dumped profiling information + /// Used to avoid spamming profile reads since they can be expensive (string memes) + var/last_profiled = 0 + var/static/restart_clear = 0 var/static/restart_timeout = 0 var/static/restart_count = 0 @@ -442,9 +448,14 @@ GLOBAL_REAL(Master, /datum/controller/master) canary.use_variable() //the actual loop. while (1) - tickdrift = max(0, MC_AVERAGE_FAST(tickdrift, (((REALTIMEOFDAY - init_timeofday) - (world.time - init_time)) / world.tick_lag))) + var/newdrift = ((REALTIMEOFDAY - init_timeofday) - (world.time - init_time)) / world.tick_lag + tickdrift = max(0, MC_AVERAGE_FAST(tickdrift, newdrift)) var/starting_tick_usage = TICK_USAGE + if(newdrift - olddrift >= CONFIG_GET(number/drift_dump_threshold)) + AttemptProfileDump(CONFIG_GET(number/drift_profile_delay)) + olddrift = newdrift + if (init_stage != init_stage_completed) return MC_LOOP_RTN_NEWSTAGES if (processing <= 0) @@ -803,3 +814,11 @@ GLOBAL_REAL(Master, /datum/controller/master) for (var/thing in subsystems) var/datum/controller/subsystem/SS = thing SS.OnConfigLoad() + +/// Attempts to dump our current profile info into a file, triggered if the MC thinks shit is going down +/// Accepts a delay in deciseconds of how long ago our last dump can be, this saves causing performance problems ourselves +/datum/controller/master/proc/AttemptProfileDump(delay) + if(REALTIMEOFDAY - last_profiled <= delay) + return FALSE + last_profiled = REALTIMEOFDAY + SSprofiler.DumpFile(allow_yield = FALSE) diff --git a/code/controllers/subsystem/profiler.dm b/code/controllers/subsystem/profiler.dm index 4b3a1a9971178..dc06c2bc6ae7f 100644 --- a/code/controllers/subsystem/profiler.dm +++ b/code/controllers/subsystem/profiler.dm @@ -21,13 +21,20 @@ SUBSYSTEM_DEF(profiler) StopProfiling() //Stop the early start profiler return SS_INIT_SUCCESS -/datum/controller/subsystem/profiler/fire() +/datum/controller/subsystem/profiler/OnConfigLoad() if(CONFIG_GET(flag/auto_profile)) - DumpFile() + 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() + DumpFile(allow_yield = FALSE) world.Profile(PROFILE_CLEAR, type = "sendmaps") return ..() @@ -39,13 +46,13 @@ SUBSYSTEM_DEF(profiler) world.Profile(PROFILE_STOP) world.Profile(PROFILE_STOP, type = "sendmaps") - -/datum/controller/subsystem/profiler/proc/DumpFile() +/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)) - CHECK_TICK + 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.") diff --git a/config/config.txt b/config/config.txt index 681ce98fe6429..e026e4fb9c629 100644 --- a/config/config.txt +++ b/config/config.txt @@ -469,6 +469,12 @@ DEFAULT_VIEW_SQUARE 15x15 ## Enable automatic profiling - Byond 513.1506 and newer only. #AUTO_PROFILE +## Threshold (in deciseconds) for real time between ticks before we start dumping profiles +DRIFT_DUMP_THRESHOLD 40 + +## How long to wait (in deciseconds) after a profile dump before logging another tickdrift sourced one +DRIFT_PROFILE_DELAY 150 + ## Uncomment to enable global ban DB using the provided URL. The API should expect to receive a ckey at the end of the URL. ## More API details can be found here: https://centcom.melonmesa.com #CENTCOM_BAN_DB https://centcom.melonmesa.com/ban/search