From 0572d30cb0deef75fb981934e55f40cba027ba34 Mon Sep 17 00:00:00 2001 From: SkyratBot <59378654+SkyratBot@users.noreply.github.com> Date: Sun, 8 Nov 2020 06:03:16 +0100 Subject: [PATCH] [MIRROR] performance logging (#1629) * performance logging (#54809) Dumps a bunch of perf info to a csv every 10 seconds. Currently this info is only stored in blackbox where it's effectively useless. csv is a very easy to parse format and is natively supported by a lot of data analysis tools * performance logging Co-authored-by: Rob Bailey --- code/__HELPERS/_logging.dm | 3 +++ code/_globalvars/logging.dm | 3 +++ code/controllers/subsystem/time_track.dm | 25 +++++++++++++++++++++++ code/game/world.dm | 26 ++++++++++++++++++++++++ 4 files changed, 57 insertions(+) diff --git a/code/__HELPERS/_logging.dm b/code/__HELPERS/_logging.dm index 41573ed7af7..823bc05858f 100644 --- a/code/__HELPERS/_logging.dm +++ b/code/__HELPERS/_logging.dm @@ -202,6 +202,9 @@ /proc/log_mapping(text) WRITE_LOG(GLOB.world_map_error_log, text) +/proc/log_perf(list/perf_info) + WRITE_LOG_NO_FORMAT(GLOB.perf_log, perf_info.Join(",")) + /** * Appends a tgui-related log entry. All arguments are optional. */ diff --git a/code/_globalvars/logging.dm b/code/_globalvars/logging.dm index 927b169ae03..af50698a003 100644 --- a/code/_globalvars/logging.dm +++ b/code/_globalvars/logging.dm @@ -45,6 +45,9 @@ GLOBAL_PROTECT(tgui_log) GLOBAL_VAR(world_shuttle_log) GLOBAL_PROTECT(world_shuttle_log) +GLOBAL_VAR(perf_log) +GLOBAL_PROTECT(perf_log) + GLOBAL_VAR(demo_log) GLOBAL_PROTECT(demo_log) diff --git a/code/controllers/subsystem/time_track.dm b/code/controllers/subsystem/time_track.dm index acc817ad1f3..30666339a70 100644 --- a/code/controllers/subsystem/time_track.dm +++ b/code/controllers/subsystem/time_track.dm @@ -37,3 +37,28 @@ SUBSYSTEM_DEF(time_track) last_tick_byond_time = current_byondtime last_tick_tickcount = current_tickcount SSblackbox.record_feedback("associative", "time_dilation_current", 1, list("[SQLtime()]" = list("current" = "[time_dilation_current]", "avg_fast" = "[time_dilation_avg_fast]", "avg" = "[time_dilation_avg]", "avg_slow" = "[time_dilation_avg_slow]"))) + log_perf( + list( + world.time, + length(GLOB.clients), + time_dilation_current, + time_dilation_avg_fast, + time_dilation_avg, + time_dilation_avg_slow, + MAPTICK_LAST_INTERNAL_TICK_USAGE, + length(SStimer.timer_id_dict), + SSair.cost_turfs, + SSair.cost_groups, + SSair.cost_highpressure, + SSair.cost_hotspots, + SSair.cost_superconductivity, + SSair.cost_pipenets, + SSair.cost_rebuilds, + length(SSair.active_turfs), + length(SSair.excited_groups), + length(SSair.hotspots), + length(SSair.networks), + length(SSair.high_pressure_delta), + length(SSair.active_super_conductivity) + ) + ) diff --git a/code/game/world.dm b/code/game/world.dm index 25d0cac8dd1..1126374a7d6 100644 --- a/code/game/world.dm +++ b/code/game/world.dm @@ -144,6 +144,7 @@ GLOBAL_VAR(restart_counter) GLOB.world_paper_log = "[GLOB.log_directory]/paper.log" GLOB.tgui_log = "[GLOB.log_directory]/tgui.log" GLOB.world_shuttle_log = "[GLOB.log_directory]/shuttle.log" + GLOB.perf_log = "[GLOB.log_directory]/perf.csv" GLOB.demo_log = "[GLOB.log_directory]/demo.log" @@ -163,6 +164,31 @@ GLOBAL_VAR(restart_counter) start_log(GLOB.world_job_debug_log) start_log(GLOB.tgui_log) start_log(GLOB.world_shuttle_log) + log_perf( + list( + "time", + "players", + "tidi", + "tidi_fastavg", + "tidi_avg", + "tidi_slowavg", + "maptick", + "num_timers", + "air_turf_cost", + "air_eg_cost", + "air_highpressure_cost", + "air_hotspots_cost", + "air_superconductivity_cost", + "air_pipenets_cost", + "air_rebuilds_cost", + "air_turf_count", + "air_eg_count", + "air_hotspot_count", + "air_network_count", + "air_delta_count", + "air_superconductive_count" + ) + ) GLOB.changelog_hash = md5('html/changelog.html') //for telling if the changelog has changed recently if(fexists(GLOB.config_error_log))