[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>
This commit is contained in:
SkyratBot
2023-08-04 15:25:55 -07:00
committed by GitHub
co-authored by LemonInTheDark lessthanthree
parent 61ddecfeb8
commit a4cf2e451c
5 changed files with 34 additions and 10 deletions
+16 -10
View File
@@ -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]"
+5
View File
@@ -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
+7
View File
@@ -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
+3
View File
@@ -600,6 +600,9 @@
dellog += "<li>Ignored force: [I.no_respect_force]</li>"
if (I.no_hint)
dellog += "<li>No hint: [I.no_hint]</li>"
if(LAZYLEN(I.extra_details))
var/details = I.extra_details.Join("</li><li>")
dellog += "<li>Extra Info: <ul><li>[details]</li></ul>"
dellog += "</ul></li>"
dellog += "</ol>"
@@ -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)