From 8fdf5960e43b97cd039ea363c5e1d1c7dc315cfe Mon Sep 17 00:00:00 2001
From: AffectedArc07 <25063394+AffectedArc07@users.noreply.github.com>
Date: Tue, 25 May 2021 11:00:13 +0100
Subject: [PATCH] DNM - Ref finder improvements

---
 code/__HELPERS/_logging.dm            |   8 ++
 code/_compile_options.dm              |  10 +-
 code/_globalvars/logging.dm           |   5 +
 code/controllers/subsystem/garbage.dm | 136 +++++++++++++++++---------
 code/datums/datum.dm                  |   2 +-
 code/game/world.dm                    |   5 +
 code/modules/admin/admin_verbs.dm     |   7 +-
 7 files changed, 123 insertions(+), 50 deletions(-)

diff --git a/code/__HELPERS/_logging.dm b/code/__HELPERS/_logging.dm
index 34e7f3fda28..f1b76b72004 100644
--- a/code/__HELPERS/_logging.dm
+++ b/code/__HELPERS/_logging.dm
@@ -143,6 +143,14 @@ GLOBAL_PROTECT(log_end)
 /proc/log_tgui(text)
 	rustg_log_write(GLOB.tgui_log, "[text][GLOB.log_end]")
 
+#ifdef REFERENCE_TRACKING
+/proc/log_gc(text)
+	rustg_log_write(GLOB.gc_log, "[text][GLOB.log_end]")
+	for(var/client/C in GLOB.admins)
+		if(check_rights(R_DEBUG, 0, C.mob) && (C.prefs.toggles & PREFTOGGLE_CHAT_DEBUGLOGS))
+			to_chat(C, "GC DEBUG: [text]")
+#endif
+
 /proc/log_sql(text)
 	rustg_log_write(GLOB.sql_log, "[text][GLOB.log_end]")
 	SEND_TEXT(world.log, text) // Redirect it to DD too
diff --git a/code/_compile_options.dm b/code/_compile_options.dm
index 21e3765ddde..372e39d7602 100644
--- a/code/_compile_options.dm
+++ b/code/_compile_options.dm
@@ -9,13 +9,15 @@
 #define UNIT_TESTS
 #endif
 
-#ifdef TESTING
-//#define GC_FAILURE_HARD_LOOKUP	//makes paths that fail to GC call find_references before del'ing.
-									//implies FIND_REF_NO_CHECK_TICK
+/***** All toggles for the GC ref finder *****/
+
+#define REFERENCE_TRACKING		// Uncomment to enable ref finding
+
+//#define GC_FAILURE_HARD_LOOKUP	//makes paths that fail to GC call find_references before del'ing. implies FIND_REF_NO_CHECK_TICK
 
 //#define FIND_REF_NO_CHECK_TICK	//Sets world.loop_checks to false and prevents find references from sleeping
 
-#endif
+/***** End toggles for the GC ref finder *****/
 
 #define IS_MODE_COMPILED(MODE) (ispath(text2path("/datum/game_mode/"+(MODE))))
 
diff --git a/code/_globalvars/logging.dm b/code/_globalvars/logging.dm
index 1e0a82c1c28..6fbfde6168d 100644
--- a/code/_globalvars/logging.dm
+++ b/code/_globalvars/logging.dm
@@ -24,6 +24,11 @@ GLOBAL_PROTECT(sql_log)
 GLOBAL_VAR(round_id)
 GLOBAL_PROTECT(round_id)
 
+#ifdef REFERENCE_TRACKING
+GLOBAL_VAR(gc_log)
+GLOBAL_PROTECT(gc_log)
+#endif
+
 GLOBAL_LIST_EMPTY(jobMax)
 GLOBAL_PROTECT(jobMax)
 GLOBAL_LIST_EMPTY(admin_log)
diff --git a/code/controllers/subsystem/garbage.dm b/code/controllers/subsystem/garbage.dm
index e50c372584a..6206d645ff0 100644
--- a/code/controllers/subsystem/garbage.dm
+++ b/code/controllers/subsystem/garbage.dm
@@ -26,8 +26,10 @@ SUBSYSTEM_DEF(garbage)
 	//Queue
 	var/list/queues
 
-	#ifdef TESTING
+	#ifdef REFERENCE_TRACKING
 	var/list/reference_find_on_fail = list()
+	//We default to true so the game can just "continue working" if there's no one to read the data
+	var/ref_search_stop = TRUE
 	#endif
 
 
@@ -137,7 +139,7 @@ SUBSYSTEM_DEF(garbage)
 			++gcedlasttick
 			++totalgcs
 			pass_counts[level]++
-			#ifdef TESTING
+			#ifdef REFERENCE_TRACKING
 			reference_find_on_fail -= refID		//It's deleted we don't care anymore.
 			#endif
 			if(MC_TICK_CHECK)
@@ -146,20 +148,27 @@ SUBSYSTEM_DEF(garbage)
 
 		// Something's still referring to the qdel'd object.
 		fail_counts[level]++
+		#ifdef REFERENCE_TRACKING
+		var/ref_searching = FALSE
+		#endif
 		switch(level)
 			if(GC_QUEUE_CHECK)
-				#ifdef TESTING
-				if(reference_find_on_fail[refID])
-					D.find_references()
+				#ifdef REFERENCE_TRACKING
+				if(reference_find_on_fail[refID] && !ref_search_stop)
+					INVOKE_ASYNC(D, /datum/proc/find_references)
+					ref_searching = TRUE
 				#ifdef GC_FAILURE_HARD_LOOKUP
-				else
-					D.find_references()
+				else if (!ref_search_stop)
+					INVOKE_ASYNC(D, /datum/proc/find_references)
+					ref_searching = TRUE
 				#endif
 				reference_find_on_fail -= refID
 				#endif
 				var/type = D.type
 				var/datum/qdel_item/I = items[type]
-				testing("GC: -- \ref[src] | [type] was unable to be GC'd --")
+				#ifdef REFERENCE_TRACKING
+				log_gc("GC: -- \ref[src] | [type] was unable to be GC'd --")
+				#endif
 				I.failures++
 			if(GC_QUEUE_HARDDELETE)
 				HardDelete(D)
@@ -169,6 +178,11 @@ SUBSYSTEM_DEF(garbage)
 
 		Queue(D, level + 1)
 
+		#ifdef REFERENCE_TRACKING
+		if(ref_searching)
+			return
+		#endif
+
 		if(MC_TICK_CHECK)
 			return
 	if(count)
@@ -243,10 +257,14 @@ SUBSYSTEM_DEF(garbage)
 /datum/qdel_item/New(mytype)
 	name = "[mytype]"
 
-#ifdef TESTING
-/proc/qdel_and_find_ref_if_fail(datum/D, force = FALSE)
-	SSgarbage.reference_find_on_fail["\ref[D]"] = TRUE
-	qdel(D, force)
+#ifdef REFERENCE_TRACKING
+/proc/qdel_and_find_ref_if_fail(datum/thing_to_del, force = FALSE)
+	thing_to_del.qdel_and_find_ref_if_fail(force)
+
+/datum/proc/qdel_and_find_ref_if_fail(force = FALSE)
+	SSgarbage.reference_find_on_fail["\ref[src]"] = TRUE
+	qdel(src, force)
+
 #endif
 
 // Should be treated as a replacement for the 'del' keyword.
@@ -304,38 +322,40 @@ SUBSYSTEM_DEF(garbage)
 				SSgarbage.HardDelete(D)
 			if(QDEL_HINT_FINDREFERENCE)//qdel will, if TESTING is enabled, display all references to this object, then queue the object for deletion.
 				SSgarbage.Queue(D)
-				#ifdef TESTING
+				#ifdef REFERENCE_TRACKING
 				D.find_references()
 				#endif
 			if(QDEL_HINT_IFFAIL_FINDREFERENCE)
 				SSgarbage.Queue(D)
-				#ifdef TESTING
+				#ifdef REFERENCE_TRACKING
 				SSgarbage.reference_find_on_fail["\ref[D]"] = TRUE
 				#endif
 			else
-				#ifdef TESTING
+				#ifdef REFERENCE_TRACKING
 				if(!I.no_hint)
-					testing("WARNING: [D.type] is not returning a qdel hint. It is being placed in the queue. Further instances of this type will also be queued.")
+					log_gc("WARNING: [D.type] is not returning a qdel hint. It is being placed in the queue. Further instances of this type will also be queued.")
 				#endif
 				I.no_hint++
 				SSgarbage.Queue(D)
 	else if(D.gc_destroyed == GC_CURRENTLY_BEING_QDELETED)
 		CRASH("[D.type] destroy proc was called multiple times, likely due to a qdel loop in the Destroy logic")
 
-#ifdef TESTING
+#ifdef REFERENCE_TRACKING
 
-/datum/verb/find_refs()
+/client/proc/find_refs()
+	set src in world
 	set category = "Debug"
 	set name = "Find References"
-	set src in world
 
+	if(!check_rights(R_DEBUG))
+		return
 	find_references(FALSE)
 
 /datum/proc/find_references(skip_alert)
 	running_find_references = type
 	if(usr && usr.client)
 		if(usr.client.running_find_references)
-			testing("CANCELLED search for references to a [usr.client.running_find_references].")
+			log_gc("CANCELLED search for references to a [usr.client.running_find_references].")
 			usr.client.running_find_references = null
 			running_find_references = null
 			//restart the garbage collector
@@ -354,20 +374,27 @@ SUBSYSTEM_DEF(garbage)
 	if(usr && usr.client)
 		usr.client.running_find_references = type
 
-	testing("Beginning search for references to a [type].")
-	last_find_references = world.time
+	log_gc("Beginning search for references to a [type].")
+	var/starting_time = world.time
 
-	DoSearchVar(GLOB) //globals
+	DoSearchVar(GLOB, "GLOB") //globals
+	log_gc("Finished searching globals")
 	for(var/datum/thing in world) //atoms (don't beleive it's lies)
-		DoSearchVar(thing, "World -> [thing]")
+		DoSearchVar(thing, "World -> [thing.type]", search_time = starting_time)
+
+	log_gc("Finished searching atoms")
 
 	for(var/datum/thing) //datums
-		DoSearchVar(thing, "World -> [thing]")
+		DoSearchVar(thing, "World -> [thing.type]", search_time = starting_time)
+
+	log_gc("Finished searching datums")
 
 	for(var/client/thing) //clients
-		DoSearchVar(thing, "World -> [thing]")
+		DoSearchVar(thing, "World -> [thing.type]", search_time = starting_time)
 
-	testing("Completed search for references to a [type].")
+	log_gc("Finished searching clients")
+
+	log_gc("Completed search for references to a [type].")
 	if(usr && usr.client)
 		usr.client.running_find_references = null
 	running_find_references = null
@@ -376,58 +403,79 @@ SUBSYSTEM_DEF(garbage)
 	SSgarbage.can_fire = 1
 	SSgarbage.next_fire = world.time + world.tick_lag
 
-/datum/verb/qdel_then_find_references()
+/client/proc/qdel_then_find_references()
+	set src in world
 	set category = "Debug"
 	set name = "qdel() then Find References"
-	set src in world
+	if(!check_rights(R_DEBUG))
+		return
 
-	qdel(src, TRUE)		//Force.
+	qdel(src, TRUE) //force a qdel
 	if(!running_find_references)
 		find_references(TRUE)
 
-/datum/verb/qdel_then_if_fail_find_references()
+/client/proc/qdel_then_if_fail_find_references()
+	set src in world
 	set category = "Debug"
 	set name = "qdel() then Find References if GC failure"
-	set src in world
+	if(!check_rights(R_DEBUG))
+		return
 
 	qdel_and_find_ref_if_fail(src, TRUE)
 
-/datum/proc/DoSearchVar(X, Xname, recursive_limit = 64)
-	if(usr && usr.client && !usr.client.running_find_references)
+/datum/proc/DoSearchVar(X, Xname, recursive_limit = 64, search_time = world.time)
+	if(usr && usr.client && !usr.client.running_find_references || SSgarbage.ref_search_stop)
 		return
+
 	if(!recursive_limit)
+		log_gc("Recursion limit hit for [Xname].")
 		return
 
 	if(istype(X, /datum))
 		var/datum/D = X
-		if(D.last_find_references == last_find_references)
+		if(D.last_find_references == search_time)
 			return
 
-		D.last_find_references = last_find_references
+		D.last_find_references = search_time
 		var/list/L = D.vars
 
 		for(var/varname in L)
-			if(varname == "vars")
+			if(varname == "vars"|| varname == "vis_locs") //Fun fact, vis_locs don't count for references
 				continue
 			var/variable = L[varname]
 
 			if(variable == src)
-				testing("Found [src.type] \ref[src] in [D.type]'s [varname] var. [Xname]")
+				log_gc("Found [src.type] \ref[src] in [D.type]'s [varname] var. [Xname]")
+				continue
 
 			else if(islist(variable))
-				DoSearchVar(variable, "[Xname] -> list", recursive_limit - 1)
+				DoSearchVar(variable, "[Xname] \ref[D] -> [varname] (list)", recursive_limit - 1, search_time)
 
 	else if(islist(X))
 		var/normal = IS_NORMAL_LIST(X)
+		var/list/potential_cache = X
 		for(var/I in X)
 			if(I == src)
-				testing("Found [src.type] \ref[src] in list [Xname].")
+				log_gc("Found [src.type] \ref[src] in list [Xname].")
+				continue
 
-			else if(I && !isnum(I) && normal && X[I] == src)
-				testing("Found [src.type] \ref[src] in list [Xname]\[[I]\]")
+			var/assoc_val = null
+			if(!isnum(I) && normal)
+				assoc_val = potential_cache[I]
 
-			else if(islist(I))
-				DoSearchVar(I, "[Xname] -> list", recursive_limit - 1)
+			//Check assoc entrys
+			if(assoc_val == src)
+				log_gc("Found [src.type] \ref[src] in list [Xname]\[[I]\]")
+				continue
+
+			//We need to run both of these checks, since our object could be hiding in either of them
+			//Check normal sublists
+			if(islist(I))
+				DoSearchVar(I, "[Xname] -> [I] (list)", recursive_limit - 1, search_time)
+
+			//Check assoc sublists
+			if(islist(assoc_val))
+				DoSearchVar(X[I], "[Xname]\[[I]\] -> [X[I]] (list)", recursive_limit - 1, search_time)
 
 #ifndef FIND_REF_NO_CHECK_TICK
 	CHECK_TICK
diff --git a/code/datums/datum.dm b/code/datums/datum.dm
index 8d3ec92cf40..68acd8c8d61 100644
--- a/code/datums/datum.dm
+++ b/code/datums/datum.dm
@@ -10,7 +10,7 @@
 	var/var_edited = FALSE //Warranty void if seal is broken
 	var/tmp/unique_datum_id = null
 
-#ifdef TESTING
+#ifdef REFERENCE_TRACKING
 	var/running_find_references
 	var/last_find_references = 0
 #endif
diff --git a/code/game/world.dm b/code/game/world.dm
index c72ed4859ab..3ec63280fd2 100644
--- a/code/game/world.dm
+++ b/code/game/world.dm
@@ -260,6 +260,11 @@ GLOBAL_LIST_EMPTY(world_topic_handlers)
 	start_log(GLOB.http_log)
 	start_log(GLOB.sql_log)
 
+	#ifdef REFERENCE_TRACKING
+	GLOB.gc_log = "[GLOB.log_directory]/gc_debug.log"
+	start_log(GLOB.gc_log)
+	#endif
+
 	// This log follows a special format and this path should NOT be used for anything else
 	GLOB.runtime_summary_log = "data/logs/runtime_summary.log"
 	if(fexists(GLOB.runtime_summary_log))
diff --git a/code/modules/admin/admin_verbs.dm b/code/modules/admin/admin_verbs.dm
index ef2b92e28d7..df42540c0b8 100644
--- a/code/modules/admin/admin_verbs.dm
+++ b/code/modules/admin/admin_verbs.dm
@@ -167,7 +167,12 @@ GLOBAL_LIST_INIT(admin_verbs_debug, list(
 	/client/proc/toggle_medal_disable,
 	/client/proc/uid_log,
 	/client/proc/visualise_active_turfs,
-	/client/proc/reestablish_db_connection
+	/client/proc/reestablish_db_connection,
+	#ifdef REFERENCE_TRACKING
+	/client/proc/find_refs,
+	/client/proc/qdel_then_find_references,
+	/client/proc/qdel_then_if_fail_find_references,
+	#endif
 	))
 GLOBAL_LIST_INIT(admin_verbs_possess, list(
 	/proc/possess,