diff --git a/code/__DEFINES/math.dm b/code/__DEFINES/math.dm index 534e0d3608b..5b3f51b4e39 100644 --- a/code/__DEFINES/math.dm +++ b/code/__DEFINES/math.dm @@ -10,6 +10,8 @@ #define T20C 293.15 // 20degC #define TCMB 2.7 // -270.3degC +#define SHORT_REAL_LIMIT 16777216 + //"fancy" math for calculating time in ms from tick_usage percentage and the length of ticks //percent_of_tick_used * (ticklag * 100(to convert to ms)) / 100(percent ratio) //collapsed to percent_of_tick_used * tick_lag diff --git a/code/__DEFINES/profile.dm b/code/__DEFINES/profile.dm index bbc229712d9..28fc7782ce3 100644 --- a/code/__DEFINES/profile.dm +++ b/code/__DEFINES/profile.dm @@ -1,19 +1,28 @@ -#define PROFILE_START PROFILE_STORE = list();PROFILE_SET +#define PROFILE_START ;PROFILE_STORE = list();PROFILE_SET; +#define PROFILE_STOP ;PROFILE_STORE = null; -#define PROFILE_SET PROFILE_TIME = TICK_USAGE_REAL; PROFILE_LINE = __LINE__; PROFILE_FILE = __FILE__; PROFILE_SLEEPCHECK = world.time +#define PROFILE_SET ;PROFILE_TIME = TICK_USAGE_REAL; PROFILE_LINE = __LINE__; PROFILE_FILE = __FILE__; PROFILE_SLEEPCHECK = world.time; -#define PROFILE_TICK \ - if (PROFILE_SLEEPCHECK == world.time) {\ - var/PROFILE_STRING = "[PROFILE_FILE]:[PROFILE_LINE] - [__FILE__]:[__LINE__]" \ - var/list/PROFILE_ITEM = PROFILE_STORE[PROFILE_STRING];\ - if (!PROFILE_ITEM) {\ - PROFILE_ITEM = new(PROFILE_ITEM_LEN);\ - PROFILE_STORE[PROFILE_STRING] = PROFILE_ITEM\ - }\ - PROFILE_ITEM[PROFILE_ITEM_TIME] += TICK_USAGE_TO_MS(PROFILE_TIME);\ - PROFILE_ITEM[PROFILE_ITEM_COUNT]++;\ - }\ - PROFILE_SET +#define PROFILE_TICK ;\ + if (PROFILE_STORE) {\ + var/PROFILE_TICK_USAGE_REAL = TICK_USAGE_REAL;\ + if (PROFILE_SLEEPCHECK == world.time) {\ + var/PROFILE_STRING = "[PROFILE_FILE]:[PROFILE_LINE] - [__FILE__]:[__LINE__]";\ + var/list/PROFILE_ITEM = PROFILE_STORE[PROFILE_STRING];\ + if (!PROFILE_ITEM) {\ + PROFILE_ITEM = new(PROFILE_ITEM_LEN);\ + PROFILE_STORE[PROFILE_STRING] = PROFILE_ITEM;\ + PROFILE_ITEM[PROFILE_ITEM_TIME] = 0;\ + PROFILE_ITEM[PROFILE_ITEM_COUNT] = 0;\ + };\ + PROFILE_ITEM[PROFILE_ITEM_TIME] += TICK_DELTA_TO_MS(PROFILE_TICK_USAGE_REAL-PROFILE_TIME);\ + var/PROFILE_INCR_AMOUNT = min(1, 2**round(PROFILE_ITEM[PROFILE_ITEM_COUNT]/SHORT_REAL_LIMIT));\ + if (prob(100/PROFILE_INCR_AMOUNT)) {\ + PROFILE_ITEM[PROFILE_ITEM_COUNT] += PROFILE_INCR_AMOUNT;\ + };\ + };\ + PROFILE_SET;\ + }; #define PROFILE_ITEM_LEN 2 #define PROFILE_ITEM_TIME 1 diff --git a/code/__HELPERS/cmp.dm b/code/__HELPERS/cmp.dm index 9edad7de67b..17cec51c1e4 100644 --- a/code/__HELPERS/cmp.dm +++ b/code/__HELPERS/cmp.dm @@ -60,4 +60,10 @@ GLOBAL_VAR_INIT(cmp_field, "name") . = B.qdels - A.qdels /proc/cmp_profile_avg_time_dsc(list/A, list/B) - return (B["TIME"]/(B["COUNT"] || 1)) - (A["TIME"]/(A["COUNT"] || 1)) + return (B[PROFILE_ITEM_TIME]/(B[PROFILE_ITEM_COUNT] || 1)) - (A[PROFILE_ITEM_TIME]/(A[PROFILE_ITEM_COUNT] || 1)) + +/proc/cmp_profile_time_dsc(list/A, list/B) + return B[PROFILE_ITEM_TIME] - A[PROFILE_ITEM_TIME] + +/proc/cmp_profile_count_dsc(list/A, list/B) + return B[PROFILE_ITEM_COUNT] - A[PROFILE_ITEM_COUNT] diff --git a/code/datums/profiling.dm b/code/datums/profiling.dm index d336ef32c04..49a80d0eded 100644 --- a/code/datums/profiling.dm +++ b/code/datums/profiling.dm @@ -6,13 +6,13 @@ GLOBAL_REAL_VAR(PROFILE_SLEEPCHECK) GLOBAL_REAL_VAR(PROFILE_TIME) -/proc/profile_show(var/user) - sortTim(PROFILE_STORE, /proc/cmp_profile_avg_time_dsc, TRUE) +/proc/profile_show(user, sort = /proc/cmp_profile_avg_time_dsc) + sortTim(PROFILE_STORE, sort, TRUE) var/list/lines = list() for (var/entry in PROFILE_STORE) var/list/data = PROFILE_STORE[entry] - lines += "[entry] => [num2text(data["TIME"], 10)]ms ([data["COUNT"]]) (avg:[num2text(data["TIME"]/(data["COUNT"] || 1), 99)])" + lines += "[entry] => [num2text(data[PROFILE_ITEM_TIME], 10)]ms ([data[PROFILE_ITEM_COUNT]]) (avg:[num2text(data[PROFILE_ITEM_TIME]/(data[PROFILE_ITEM_COUNT] || 1), 99)])" user << browse("
  1. [lines.Join("
  2. ")]
", "window=[url_encode(GUID())]") diff --git a/code/modules/admin/verbs/debug.dm b/code/modules/admin/verbs/debug.dm index 980dfd0a596..853344cc25a 100644 --- a/code/modules/admin/verbs/debug.dm +++ b/code/modules/admin/verbs/debug.dm @@ -871,3 +871,42 @@ GLOBAL_PROTECT(LastAdminCalledProc) message_admins("[key_name_admin(src)] pumped a random event.") SSblackbox.add_details("admin_verb","Pump Random Event") log_admin("[key_name(src)] pumped a random event.") + +/client/proc/start_line_profiling() + set category = "Profile" + set name = "Start Line Profiling" + set desc = "Starts tracking line by line profiling for code lines that support it" + + PROFILE_START + + message_admins("[key_name_admin(src)] started line by line profiling.") + SSblackbox.add_details("admin_verb","Start Line Profiling") + log_admin("[key_name(src)] started line by line profiling.") + +/client/proc/stop_line_profiling() + set category = "Profile" + set name = "Stops Line Profiling" + set desc = "Stops tracking line by line profiling for code lines that support it" + + PROFILE_STOP + + message_admins("[key_name_admin(src)] stopped line by line profiling.") + SSblackbox.add_details("admin_verb","stop Line Profiling") + log_admin("[key_name(src)] stopped line by line profiling.") + +/client/proc/show_line_profiling() + set category = "Profile" + set name = "Show Line Profiling" + set desc = "Shows tracked profiling info from code lines that support it" + + var/sortlist = list( + "Avg time" = /proc/cmp_profile_avg_time_dsc, + "Total Time" = /proc/cmp_profile_time_dsc, + "Call Count" = /proc/cmp_profile_count_dsc + ) + var/sort = input(src, "Sort type?", "Sort Type", "Avg time") as null|anything in sortlist + if (!sort) + return + sort = sortlist[sort] + profile_show(src, sort) + diff --git a/code/modules/admin/verbs/mapping.dm b/code/modules/admin/verbs/mapping.dm index 3ceb1aeb756..d5600995636 100644 --- a/code/modules/admin/verbs/mapping.dm +++ b/code/modules/admin/verbs/mapping.dm @@ -42,7 +42,10 @@ GLOBAL_LIST_INIT(admin_verbs_debug_mapping, list( /client/proc/print_pointers, /client/proc/cmd_show_at_list, /client/proc/cmd_show_at_markers, - /client/proc/manipulate_organs + /client/proc/manipulate_organs, + /client/proc/start_line_profiling, + /client/proc/stop_line_profiling, + /client/proc/show_line_profiling )) /obj/effect/debugging/mapfix_marker