Files
Paradise/code/controllers/subsystem/garbage.dm
LemonInTheDark 963516769c Changes how the garbage subsystem queue stores and processes info (#19608)
The way """we""" currently do it, each time you want to walk the queue
you're forced to make a copy in memory of the whole thing

There's no real reason to want this, so it seems best to just avoid it
entirely. It creates a TON of usage for no reason, and also risks a lot
of overtime since you can't really batch a list copy like that.

So instead let's just iterate over the length of the queue, constant
rather then O(N) time.

Similarly, rather then using an associated list in the form queue[ref] = gc time,
we could store queue entries in what amounts to a tuple.

This means no associated list stuff, so the operation of queuing becomes
cheaper, and pulling gc time similarly goes from O(log n) to constant time

I stole this work from myself and mso, tg pr 55595
I'm pring it here because I keep seeing affected complain about the
garbage subsystem and he refuses to do it himself. No I don't have an
ego problem I swear
2022-11-05 11:19:27 +00:00

511 lines
16 KiB
Plaintext

SUBSYSTEM_DEF(garbage)
name = "Garbage"
priority = FIRE_PRIORITY_GARBAGE
wait = 2 SECONDS
flags = SS_POST_FIRE_TIMING|SS_BACKGROUND|SS_NO_INIT
runlevels = RUNLEVELS_DEFAULT | RUNLEVEL_LOBBY
init_order = INIT_ORDER_GARBAGE // Why does this have an init order if it has SS_NO_INIT?
offline_implications = "Garbage collection is no longer functional, and objects will not be qdel'd. Immediate server restart recommended."
var/list/collection_timeout = list(2 MINUTES, 10 SECONDS) // deciseconds to wait before moving something up in the queue to the next level
//Stat tracking
var/delslasttick = 0 // number of del()'s we've done this tick
var/gcedlasttick = 0 // number of things that gc'ed last tick
var/totaldels = 0
var/totalgcs = 0
var/highest_del_time = 0
var/highest_del_tickusage = 0
var/list/pass_counts
var/list/fail_counts
var/list/items = list() // Holds our qdel_item statistics datums
//Queue
var/list/queues
#ifdef REFERENCE_TRACKING
var/list/reference_find_on_fail = list()
var/ref_search_stop = FALSE
#endif
/datum/controller/subsystem/garbage/PreInit()
queues = new(GC_QUEUE_COUNT)
pass_counts = new(GC_QUEUE_COUNT)
fail_counts = new(GC_QUEUE_COUNT)
for(var/i in 1 to GC_QUEUE_COUNT)
queues[i] = list()
pass_counts[i] = 0
fail_counts[i] = 0
/datum/controller/subsystem/garbage/get_stat_details()
var/list/msg = list()
var/list/counts = list()
for(var/list/L in queues)
counts += length(L)
msg += "Q:[counts.Join(", ")] | D:[delslasttick] | S:[gcedlasttick] |"
msg += "GCR:"
if(!(delslasttick + gcedlasttick))
msg += "n/a|"
else
msg += "[round((gcedlasttick / (delslasttick + gcedlasttick)) * 100, 0.01)]% |"
msg += "TD:[totaldels] | TS:[totalgcs] |"
if(!(totaldels + totalgcs))
msg += "n/a|"
else
msg += "TGCR:[round((totalgcs / (totaldels + totalgcs)) * 100, 0.01)]% |"
msg += " P:[pass_counts.Join(",")]"
msg += " | F:[fail_counts.Join(",")]"
return msg.Join("")
/datum/controller/subsystem/garbage/get_metrics()
. = ..()
var/list/cust = list()
if((delslasttick + gcedlasttick) == 0) // Account for DIV0
cust["gcr"] = 0
else
cust["gcr"] = (gcedlasttick / (delslasttick + gcedlasttick))
cust["total_harddels"] = totaldels
cust["total_softdels"] = totalgcs
var/i = 0
for(var/list/L in queues)
i++
cust["queue_[i]"] = length(L)
.["custom"] = cust
/datum/controller/subsystem/garbage/Shutdown()
//Adds the del() log to the qdel log file
var/list/dellog = list()
//sort by how long it's wasted hard deleting
sortTim(items, cmp=/proc/cmp_qdel_item_time, associative = TRUE)
for(var/path in items)
var/datum/qdel_item/I = items[path]
dellog += "Path: [path]"
if(I.failures)
dellog += "\tFailures: [I.failures]"
dellog += "\tqdel() Count: [I.qdels]"
dellog += "\tDestroy() Cost: [I.destroy_time]ms"
if(I.hard_deletes)
dellog += "\tTotal Hard Deletes [I.hard_deletes]"
dellog += "\tTime Spent Hard Deleting: [I.hard_delete_time]ms"
if(I.slept_destroy)
dellog += "\tSleeps: [I.slept_destroy]"
if(I.no_respect_force)
dellog += "\tIgnored force: [I.no_respect_force] times"
if(I.no_hint)
dellog += "\tNo hint: [I.no_hint] times"
log_qdel(dellog.Join("\n"))
/datum/controller/subsystem/garbage/fire()
//the fact that this resets its processing each fire (rather then resume where it left off) is intentional.
var/queue = GC_QUEUE_CHECK
while(state == SS_RUNNING)
switch(queue)
if(GC_QUEUE_CHECK)
HandleQueue(GC_QUEUE_CHECK)
queue = GC_QUEUE_CHECK + 1
if(GC_QUEUE_HARDDELETE)
HandleQueue(GC_QUEUE_HARDDELETE)
if(state == SS_PAUSED) //make us wait again before the next run.
state = SS_RUNNING
break
/datum/controller/subsystem/garbage/proc/HandleQueue(level = GC_QUEUE_CHECK)
if(level == GC_QUEUE_CHECK)
delslasttick = 0
gcedlasttick = 0
var/cut_off_time = world.time - collection_timeout[level] //ignore entries newer then this
var/list/queue = queues[level]
var/static/lastlevel
var/static/count = 0
if(count) //runtime last run before we could do this.
var/c = count
count = 0 //so if we runtime on the Cut, we don't try again.
var/list/lastqueue = queues[lastlevel]
lastqueue.Cut(1, c + 1)
lastlevel = level
// The instinct is to use a for in loop here, to walk the entries in the queue
// The trouble is this performs a copy of the queue list, and since this can in theory balloon a LOT
// It's better to just go index by index. It's not a huge deal but it's worth doin IMO
for(var/i in 1 to length(queue))
var/list/packet = queue[i]
if(length(packet) != 2)
count++
if(MC_TICK_CHECK)
return
continue
var/GCd_at_time = packet[2]
if(GCd_at_time > cut_off_time)
break // Everything else is newer, skip them
count++
var/refID = packet[1]
var/datum/D
D = locate(refID)
if(!D || D.gc_destroyed != GCd_at_time) // So if something else coincidently gets the same ref, it's not deleted by mistake
++gcedlasttick
++totalgcs
pass_counts[level]++
#ifdef REFERENCE_TRACKING
reference_find_on_fail -= refID //It's deleted we don't care anymore.
#endif
if(MC_TICK_CHECK)
return
continue
// 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 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 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]
#ifdef REFERENCE_TRACKING
log_gc("GC: -- \ref[src] | [type] was unable to be GC'd --")
#endif
I.failures++
if(GC_QUEUE_HARDDELETE)
HardDelete(D)
if(MC_TICK_CHECK)
return
continue
Queue(D, level + 1)
#ifdef REFERENCE_TRACKING
if(ref_searching)
return
#endif
if(MC_TICK_CHECK)
return
if(count)
queue.Cut(1, count + 1)
count = 0
/datum/controller/subsystem/garbage/proc/Queue(datum/D, level = GC_QUEUE_CHECK)
if(isnull(D))
return
if(level > GC_QUEUE_COUNT)
HardDelete(D)
return
var/gctime = world.time
D.gc_destroyed = gctime
var/list/queue = queues[level]
// I hate byond lists so much man
queue[++queue.len] = list("\ref[D]", gctime)
//this is mainly to separate things profile wise.
/datum/controller/subsystem/garbage/proc/HardDelete(datum/D)
var/time = world.timeofday
var/tick = TICK_USAGE
var/ticktime = world.time
++delslasttick
++totaldels
var/type = D.type
var/refID = "\ref[D]"
del(D)
tick = (TICK_USAGE - tick + ((world.time - ticktime) / world.tick_lag * 100))
var/datum/qdel_item/I = items[type]
I.hard_deletes++
I.hard_delete_time += TICK_DELTA_TO_MS(tick)
if(tick > highest_del_tickusage)
highest_del_tickusage = tick
time = world.timeofday - time
if(!time && TICK_DELTA_TO_MS(tick) > 1)
time = TICK_DELTA_TO_MS(tick) / 100
if(time > highest_del_time)
highest_del_time = time
if(time > 10)
log_game("Error: [type]([refID]) took longer than 1 second to delete (took [time / 10] seconds to delete)")
message_admins("Error: [type]([refID]) took longer than 1 second to delete (took [time / 10] seconds to delete).")
postpone(time)
/datum/controller/subsystem/garbage/Recover()
if(istype(SSgarbage.queues))
for(var/i in 1 to SSgarbage.queues.len)
queues[i] |= SSgarbage.queues[i]
/datum/qdel_item
var/name = ""
var/qdels = 0 //Total number of times it's passed thru qdel.
var/destroy_time = 0 //Total amount of milliseconds spent processing this type's Destroy()
var/failures = 0 //Times it was queued for soft deletion but failed to soft delete.
var/hard_deletes = 0 //Different from failures because it also includes QDEL_HINT_HARDDEL deletions
var/hard_delete_time = 0//Total amount of milliseconds spent hard deleting this type.
var/no_respect_force = 0//Number of times it's not respected force=TRUE
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
/datum/qdel_item/New(mytype)
name = "[mytype]"
#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.
// Datums passed to this will be given a chance to clean up references to allow the GC to collect them.
/proc/qdel(datum/D, force = FALSE, ...)
if(!istype(D))
del(D)
return
var/datum/qdel_item/I = SSgarbage.items[D.type]
if(!I)
I = SSgarbage.items[D.type] = new /datum/qdel_item(D.type)
I.qdels++
if(isnull(D.gc_destroyed))
if(SEND_SIGNAL(D, COMSIG_PARENT_PREQDELETED, force)) // Give the components a chance to prevent their parent from being deleted
return
D.gc_destroyed = GC_CURRENTLY_BEING_QDELETED
var/start_time = world.time
var/start_tick = world.tick_usage
SEND_SIGNAL(D, COMSIG_PARENT_QDELETING, force) // Let the (remaining) components know about the result of Destroy
var/hint = D.Destroy(arglist(args.Copy(2))) // Let our friend know they're about to get fucked up.
if(world.time != start_time)
I.slept_destroy++
else
I.destroy_time += TICK_USAGE_TO_MS(start_tick)
if(!D)
return
switch(hint)
if(QDEL_HINT_QUEUE) //qdel should queue the object for deletion.
SSgarbage.Queue(D)
if(QDEL_HINT_IWILLGC)
D.gc_destroyed = world.time
return
if(QDEL_HINT_LETMELIVE) //qdel should let the object live after calling destory.
if(!force)
D.gc_destroyed = null //clear the gc variable (important!)
return
// Returning LETMELIVE after being told to force destroy
// indicates the objects Destroy() does not respect force
#ifdef TESTING
if(!I.no_respect_force)
testing("WARNING: [D.type] has been force deleted, but is \
returning an immortal QDEL_HINT, indicating it does \
not respect the force flag for qdel(). It has been \
placed in the queue, further instances of this type \
will also be queued.")
#endif
I.no_respect_force++
SSgarbage.Queue(D)
if(QDEL_HINT_HARDDEL) //qdel should assume this object won't gc, and queue a hard delete
SSgarbage.Queue(D, GC_QUEUE_HARDDELETE)
if(QDEL_HINT_HARDDEL_NOW) //qdel should assume this object won't gc, and hard del it post haste.
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 REFERENCE_TRACKING
D.find_references()
#endif
if(QDEL_HINT_IFFAIL_FINDREFERENCE)
SSgarbage.Queue(D)
#ifdef REFERENCE_TRACKING
SSgarbage.reference_find_on_fail["\ref[D]"] = TRUE
#endif
else
#ifdef REFERENCE_TRACKING
if(!I.no_hint)
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 REFERENCE_TRACKING
/datum/proc/find_refs()
set category = "Debug"
set name = "Find References"
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)
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
SSgarbage.can_fire = 1
SSgarbage.next_fire = world.time + world.tick_lag
return
if(!skip_alert)
if(alert("Running this will lock everything up for about 5 minutes. Would you like to begin the search?", "Find References", "Yes", "No") == "No")
running_find_references = null
return
//this keeps the garbage collector from failing to collect objects being searched for in here
SSgarbage.can_fire = 0
if(usr && usr.client)
usr.client.running_find_references = type
log_gc("Beginning search for references to a [type].")
var/starting_time = world.time
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.type]", search_time = starting_time)
log_gc("Finished searching atoms")
for(var/datum/thing) //datums
DoSearchVar(thing, "World -> [thing.type]", search_time = starting_time)
log_gc("Finished searching datums")
for(var/client/thing) //clients
DoSearchVar(thing, "World -> [thing.type]", search_time = starting_time)
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
//restart the garbage collector
SSgarbage.can_fire = 1
SSgarbage.next_fire = world.time + world.tick_lag
/datum/proc/qdel_then_find_references()
set category = "Debug"
set name = "qdel() then Find References"
if(!check_rights(R_DEBUG))
return
qdel(src, TRUE) //force a qdel
if(!running_find_references)
find_references(TRUE)
/datum/proc/qdel_then_if_fail_find_references()
set category = "Debug"
set name = "qdel() then Find References if GC failure"
if(!check_rights(R_DEBUG))
return
qdel_and_find_ref_if_fail(src, TRUE)
/datum/proc/DoSearchVar(potential_container, container_name, recursive_limit = 64, search_time = world.time)
if((usr?.client && !usr.client.running_find_references) || SSgarbage.ref_search_stop)
return
if(!recursive_limit)
log_gc("Recursion limit reached. [container_name]")
return
//Check each time you go down a layer. This makes it a bit slow, but it won't effect the rest of the game at all
#ifndef FIND_REF_NO_CHECK_TICK
CHECK_TICK
#endif
if(istype(potential_container, /datum))
var/datum/datum_container = potential_container
if(datum_container.last_find_references == search_time)
return
datum_container.last_find_references = search_time
var/list/vars_list = datum_container.vars
for(var/varname in vars_list)
#ifndef FIND_REF_NO_CHECK_TICK
CHECK_TICK
#endif
if(varname == "vars" || varname == "vis_locs") //Fun fact, vis_locs don't count for references
continue
var/variable = vars_list[varname]
if(variable == src)
log_gc("Found [type] \ref[src] in [datum_container.type]'s \ref[datum_container] [varname] var. [container_name]")
continue
if(islist(variable))
DoSearchVar(variable, "[container_name] \ref[datum_container] -> [varname] (list)", recursive_limit - 1, search_time)
else if(islist(potential_container))
var/normal = IS_NORMAL_LIST(potential_container)
var/list/potential_cache = potential_container
for(var/element_in_list in potential_cache)
#ifndef FIND_REF_NO_CHECK_TICK
CHECK_TICK
#endif
//Check normal entrys
if(element_in_list == src)
log_gc("Found [type] \ref[src] in list [container_name].")
continue
var/assoc_val = null
if(!isnum(element_in_list) && normal)
assoc_val = potential_cache[element_in_list]
//Check assoc entrys
if(assoc_val == src)
log_gc("Found [type] \ref[src] in list [container_name]\[[element_in_list]\]")
continue
//We need to run both of these checks, since our object could be hiding in either of them
//Check normal sublists
if(islist(element_in_list))
DoSearchVar(element_in_list, "[container_name] -> [element_in_list] (list)", recursive_limit - 1, search_time)
//Check assoc sublists
if(islist(assoc_val))
DoSearchVar(potential_container[element_in_list], "[container_name]\[[element_in_list]\] -> [assoc_val] (list)", recursive_limit - 1, search_time)
#ifndef FIND_REF_NO_CHECK_TICK
CHECK_TICK
#endif
#endif