From ced8c44d513417ab4b09cfd05ca096339733bbaa Mon Sep 17 00:00:00 2001
From: Erki <skull132@users.noreply.github.com>
Date: Wed, 10 Jun 2020 09:03:24 +0300
Subject: [PATCH] Automated Profiler (#9053)

Adds a lock-up detecting profiler to the game, using BYOND's new programmatic access to the profiler.

The idea is that we have an SS that's roughly called every tick. This will detect a lock-up by using world.timeofday. There might be a small issue with midnight rollover but eh. Don't. Really care. A notice is printed for each printout. These can later be processed in Python.
---
 aurorastation.dme                       |  1 +
 code/__defines/subsystem-priority.dm    |  1 +
 code/controllers/configuration.dm       | 11 +++++
 code/controllers/subsystems/profiler.dm | 54 +++++++++++++++++++++++++
 html/changelogs/skull132_profiler.yml   |  5 +++
 5 files changed, 72 insertions(+)
 create mode 100644 code/controllers/subsystems/profiler.dm
 create mode 100644 html/changelogs/skull132_profiler.yml

diff --git a/aurorastation.dme b/aurorastation.dme
index d2e4c19a49e..86ce60a4b4b 100644
--- a/aurorastation.dme
+++ b/aurorastation.dme
@@ -210,6 +210,7 @@
 #include "code\controllers\subsystems\parallax.dm"
 #include "code\controllers\subsystems\plants.dm"
 #include "code\controllers\subsystems\power.dm"
+#include "code\controllers\subsystems\profiler.dm"
 #include "code\controllers\subsystems\radio.dm"
 #include "code\controllers\subsystems\records.dm"
 #include "code\controllers\subsystems\responseteam.dm"
diff --git a/code/__defines/subsystem-priority.dm b/code/__defines/subsystem-priority.dm
index f64c42f1b81..9290a7e6d8b 100644
--- a/code/__defines/subsystem-priority.dm
+++ b/code/__defines/subsystem-priority.dm
@@ -35,6 +35,7 @@
 #define SS_PRIORITY_OVERLAY   100	// Applies overlays. May cause overlay pop-in if it gets behind.
 //#define SS_PRIORITY_DEFAULT  50	// This is defined somewhere else.
 #define SS_PRIORITY_TIMER      20	// Timed event scheduling. This is important.
+#define SS_PRIORITY_PROFILE    15
 #define SS_PRIORITY_SMOOTHING  10	// Smooth turf generation.
 #define SS_PRIORITY_ORBIT       5	// Orbit datum updates.
 #define SS_PRIORITY_ICON_UPDATE 5	// Queued icon updates. Mostly used by APCs and tables.
diff --git a/code/controllers/configuration.dm b/code/controllers/configuration.dm
index 2623d95965a..76c3a68d5a2 100644
--- a/code/controllers/configuration.dm
+++ b/code/controllers/configuration.dm
@@ -309,6 +309,10 @@ var/list/gamemode_cache = list()
 
 	var/news_use_forum_api = FALSE
 
+	var/profiler_is_enabled = FALSE
+	var/profiler_restart_period = 120 SECONDS
+	var/profiler_timeout_threshold = 5 SECONDS
+
 /datum/configuration/New()
 	var/list/L = typesof(/datum/game_mode) - /datum/game_mode
 	for (var/T in L)
@@ -933,6 +937,13 @@ var/list/gamemode_cache = list()
 				if ("news_use_forum_api")
 					news_use_forum_api = TRUE
 
+				if ("profiler_enabled")
+					profiler_is_enabled = TRUE
+				if ("profiler_restart_period")
+					profiler_restart_period = text2num(value) SECONDS
+				if ("profiler_timeout_threshold")
+					profiler_timeout_threshold = text2num(value)
+
 				else
 					log_misc("Unknown setting in configuration: '[name]'")
 
diff --git a/code/controllers/subsystems/profiler.dm b/code/controllers/subsystems/profiler.dm
new file mode 100644
index 00000000000..6a05f23ff71
--- /dev/null
+++ b/code/controllers/subsystems/profiler.dm
@@ -0,0 +1,54 @@
+
+var/datum/controller/subsystem/profiler/SSprofiler
+
+/datum/controller/subsystem/profiler
+	name = "Profiler"
+	wait = 1
+	priority = SS_PRIORITY_PROFILE
+
+	flags = SS_TICKER|SS_FIRE_IN_LOBBY
+
+	var/last_fire_rt = 0
+	var/threshold = 0
+
+	var/next_restart = 0
+	var/restart_period = 0
+
+/datum/controller/subsystem/profiler/New()
+	NEW_SS_GLOBAL(SSprofiler)
+
+/datum/controller/subsystem/profiler/Initialize()
+	if (!config.profiler_is_enabled)
+		..()
+		flags |= SS_NO_FIRE
+		return
+
+	restart_period = config.profiler_restart_period
+	threshold = config.profiler_timeout_threshold
+
+	..()
+
+/datum/controller/subsystem/profiler/fire()
+	. = world.timeofday
+
+	if (!last_fire_rt)
+		last_fire_rt = .
+		next_restart = world.time + restart_period
+		world.Profile(PROFILE_START)
+
+	if (. - last_fire_rt > threshold)
+		DumpData()
+	else if (world.time > next_restart)
+		RestartProfiler()
+
+	last_fire_rt = .
+
+/datum/controller/subsystem/profiler/proc/DumpData()
+	admin_notice(SPAN_DANGER("Profiler: dump profile after CPU spike."), R_SERVER|R_DEV)
+
+	var/name = "[game_id]_[time2text(world.timeofday, "hh-mm-ss")]"
+	text2file(world.Profile(0, "json"), "data/logs/profiler/[game_id]/[name].json")
+
+/datum/controller/subsystem/profiler/proc/RestartProfiler()
+	world.Profile(PROFILE_CLEAR)
+	next_restart = world.time + restart_period
diff --git a/html/changelogs/skull132_profiler.yml b/html/changelogs/skull132_profiler.yml
new file mode 100644
index 00000000000..80a3e7ac121
--- /dev/null
+++ b/html/changelogs/skull132_profiler.yml
@@ -0,0 +1,5 @@
+author: Skull132
+delete-after: True
+
+changes:
+  - backend: "An automated server timeout profiler has been implemented."