From a4cf2e451c3445d211c4150f730079c5912bc7cb Mon Sep 17 00:00:00 2001
From: SkyratBot <59378654+SkyratBot@users.noreply.github.com>
Date: Sat, 5 Aug 2023 00:25:55 +0200
Subject: [PATCH] [MIRROR] Adds a system for logging metadata about hard
deletes [MDB IGNORE] (#22878)
* Adds a system for logging metadata about hard deletes (#76956)
## About The Pull Request
I'm sick of the progress bar harddel, and I've ran into this problem in
the past, so I'm just gonna do something about it
If you want to provide an individual logged bit of info about a harddel,
you can override `/datum/proc/dump_harddel_info()` and return a string
containing "whatever"
Use of this should be limited, this could potentially clutter del logs,
especially if it's used on something that fails often, like pipes
I do think it's still useful tho. It's output ingame, in the logs, and
in unit test failures. Hopefully all nicely tho I'm only really 100%
sure about in game.
* Adds a system for logging metadata about hard deletes
---------
Co-authored-by: LemonInTheDark <58055496+LemonInTheDark@users.noreply.github.com>
Co-authored-by: lessthanthree <83487515+lessthnthree@users.noreply.github.com>
---
code/controllers/subsystem/garbage.dm | 26 ++++++++++++-------
code/datums/datum.dm | 5 ++++
code/datums/progressbar.dm | 7 +++++
code/modules/admin/verbs/debug.dm | 3 +++
code/modules/unit_tests/create_and_destroy.dm | 3 +++
5 files changed, 34 insertions(+), 10 deletions(-)
diff --git a/code/controllers/subsystem/garbage.dm b/code/controllers/subsystem/garbage.dm
index e79a836b8b3..f985868679c 100644
--- a/code/controllers/subsystem/garbage.dm
+++ b/code/controllers/subsystem/garbage.dm
@@ -110,6 +110,8 @@ SUBSYSTEM_DEF(garbage)
entry["Total Ignored Force"] = I.no_respect_force
if (I.no_hint)
entry["Total No Hint"] = I.no_hint
+ if(LAZYLEN(I.extra_details))
+ entry["Deleted Metadata"] = I.extra_details
log_qdel("", del_log)
@@ -297,16 +299,19 @@ SUBSYSTEM_DEF(garbage)
++totaldels
var/type = D.type
var/refID = text_ref(D)
+ var/datum/qdel_item/type_info = items[type]
+ var/detail = D.dump_harddel_info()
+ if(detail)
+ LAZYADD(type_info.extra_details, detail)
var/tick_usage = TICK_USAGE
del(D)
tick_usage = TICK_USAGE_TO_MS(tick_usage)
- var/datum/qdel_item/I = items[type]
- I.hard_deletes++
- I.hard_delete_time += tick_usage
- if (tick_usage > I.hard_delete_max)
- I.hard_delete_max = tick_usage
+ type_info.hard_deletes++
+ type_info.hard_delete_time += tick_usage
+ if (tick_usage > type_info.hard_delete_max)
+ type_info.hard_delete_max = tick_usage
if (tick_usage > highest_del_ms)
highest_del_ms = tick_usage
highest_del_type_string = "[type]"
@@ -317,14 +322,14 @@ SUBSYSTEM_DEF(garbage)
postpone(time)
var/threshold = CONFIG_GET(number/hard_deletes_overrun_threshold)
if (threshold && (time > threshold SECONDS))
- if (!(I.qdel_flags & QDEL_ITEM_ADMINS_WARNED))
+ if (!(type_info.qdel_flags & QDEL_ITEM_ADMINS_WARNED))
log_game("Error: [type]([refID]) took longer than [threshold] seconds to delete (took [round(time/10, 0.1)] seconds to delete)")
message_admins("Error: [type]([refID]) took longer than [threshold] seconds to delete (took [round(time/10, 0.1)] seconds to delete).")
- I.qdel_flags |= QDEL_ITEM_ADMINS_WARNED
- I.hard_deletes_over_threshold++
+ type_info.qdel_flags |= QDEL_ITEM_ADMINS_WARNED
+ type_info.hard_deletes_over_threshold++
var/overrun_limit = CONFIG_GET(number/hard_deletes_overrun_limit)
- if (overrun_limit && I.hard_deletes_over_threshold >= overrun_limit)
- I.qdel_flags |= QDEL_ITEM_SUSPENDED_FOR_LAG
+ if (overrun_limit && type_info.hard_deletes_over_threshold >= overrun_limit)
+ type_info.qdel_flags |= QDEL_ITEM_SUSPENDED_FOR_LAG
/datum/controller/subsystem/garbage/Recover()
InitQueues() //We first need to create the queues before recovering data
@@ -346,6 +351,7 @@ SUBSYSTEM_DEF(garbage)
var/no_hint = 0 //!Number of times it's not even bother to give a qdel hint
var/slept_destroy = 0 //!Number of times it's slept in its destroy
var/qdel_flags = 0 //!Flags related to this type's trip thru qdel.
+ var/list/extra_details //!Lazylist of string metadata about the deleted objects
/datum/qdel_item/New(mytype)
name = "[mytype]"
diff --git a/code/datums/datum.dm b/code/datums/datum.dm
index 1ad751a13c3..67db3f62e28 100644
--- a/code/datums/datum.dm
+++ b/code/datums/datum.dm
@@ -402,3 +402,8 @@
var/atom/atom_cast = src // filters only work with images or atoms.
filter_data = null
atom_cast.filters = null
+
+/// Return text from this proc to provide extra context to hard deletes that happen to it
+/// Optional, you should use this for cases where replication is difficult and extra context is required
+/datum/proc/dump_harddel_info()
+ return
diff --git a/code/datums/progressbar.dm b/code/datums/progressbar.dm
index a9f875bd088..003b68bea53 100644
--- a/code/datums/progressbar.dm
+++ b/code/datums/progressbar.dm
@@ -16,6 +16,8 @@
var/last_progress = 0
///Variable to ensure smooth visual stacking on multiple progress bars.
var/listindex = 0
+ ///The type of our last value for bar_loc, for debugging
+ var/location_type
/datum/progressbar/New(mob/User, goal_number, atom/target)
@@ -34,6 +36,7 @@
return
goal = goal_number
bar_loc = target
+ location_type = bar_loc.type
bar = image('icons/effects/progressbar.dmi', bar_loc, "prog_bar_0")
SET_PLANE_EXPLICIT(bar, ABOVE_HUD_PLANE, User)
bar.appearance_flags = APPEARANCE_UI_IGNORE_ALPHA
@@ -137,6 +140,10 @@
QDEL_IN(src, PROGRESSBAR_ANIMATION_TIME)
+///Progress bars are very generic, and what hangs a ref to them depends heavily on the context in which they're used
+///So let's make hunting harddels easier yeah?
+/datum/progressbar/dump_harddel_info()
+ return "Owner's type: [location_type]"
#undef PROGRESSBAR_ANIMATION_TIME
#undef PROGRESSBAR_HEIGHT
diff --git a/code/modules/admin/verbs/debug.dm b/code/modules/admin/verbs/debug.dm
index b131fc935d1..99491dd7cb3 100644
--- a/code/modules/admin/verbs/debug.dm
+++ b/code/modules/admin/verbs/debug.dm
@@ -600,6 +600,9 @@
dellog += "Ignored force: [I.no_respect_force]"
if (I.no_hint)
dellog += "No hint: [I.no_hint]"
+ if(LAZYLEN(I.extra_details))
+ var/details = I.extra_details.Join("")
+ dellog += "Extra Info: "
dellog += ""
dellog += ""
diff --git a/code/modules/unit_tests/create_and_destroy.dm b/code/modules/unit_tests/create_and_destroy.dm
index 97495ffe177..83aa15b51fb 100644
--- a/code/modules/unit_tests/create_and_destroy.dm
+++ b/code/modules/unit_tests/create_and_destroy.dm
@@ -216,6 +216,9 @@ GLOBAL_VAR_INIT(running_create_and_destroy, FALSE)
TEST_FAIL("[item.name] failed to respect force deletion [item.no_respect_force] times out of a total del count of [item.qdels]")
if(item.no_hint)
TEST_FAIL("[item.name] failed to return a qdel hint [item.no_hint] times out of a total del count of [item.qdels]")
+ if(LAZYLEN(item.extra_details))
+ var/details = item.extra_details.Join("\n")
+ TEST_FAIL("[item.name] failed with extra info: \n[details]")
cache_for_sonic_speed = SSatoms.BadInitializeCalls
for(var/path in cache_for_sonic_speed)