From 811517ecb2484b1694adfebd726d9322e3aa646f Mon Sep 17 00:00:00 2001 From: Kyle Spier-Swenson Date: Fri, 8 Dec 2017 13:02:34 -0800 Subject: [PATCH] [ready]Timer queuing tweaks: binary sorted inserts and rolling buckets. (#33098) * Timer queuing tweaks: binary sorted inserts and rolling buckets. Client time timers now uses a binary search algorithm for its sorted inserts. Processing now uses a binary sorted insert, rather then sorting it with sortTim during bucket_shifts. Buckets now automatically wrap around rather then get regenerated every minute. (Rolling queue) * Fixes some queue management bugs. * Fixes a Order of Operations goof up in the ticks<->ds macros. @ninjanomnom your pain is my success * Remove debug line * Fixes some binary insert bugs, fixes client time timers, moved id over to GUID * Fixes initialization-time timers fucking everything up --- code/__DEFINES/time.dm | 4 +- code/controllers/subsystem/timer.dm | 301 ++++++++++++++++++---------- 2 files changed, 202 insertions(+), 103 deletions(-) diff --git a/code/__DEFINES/time.dm b/code/__DEFINES/time.dm index 987d52e0cd..8bc4d039f6 100644 --- a/code/__DEFINES/time.dm +++ b/code/__DEFINES/time.dm @@ -22,6 +22,6 @@ When using time2text(), please use "DDD" to find the weekday. Refrain from using #define TICKS *world.tick_lag -#define DS2TICKS(DS) (DS/world.tick_lag) +#define DS2TICKS(DS) ((DS)/world.tick_lag) -#define TICKS2DS(T) (T TICKS) \ No newline at end of file +#define TICKS2DS(T) ((T) TICKS) \ No newline at end of file diff --git a/code/controllers/subsystem/timer.dm b/code/controllers/subsystem/timer.dm index 3a2ca82bcd..f24068dbff 100644 --- a/code/controllers/subsystem/timer.dm +++ b/code/controllers/subsystem/timer.dm @@ -1,5 +1,6 @@ #define BUCKET_LEN (world.fps*1*60) //how many ticks should we keep in the bucket. (1 minutes worth) -#define BUCKET_POS(timer) (round((timer.timeToRun - SStimer.head_offset) / world.tick_lag) + 1) +#define BUCKET_POS(timer) ((round((timer.timeToRun - SStimer.head_offset) / world.tick_lag) % BUCKET_LEN) + 1) +#define TIMER_MAX (world.time + TICKS2DS(min(BUCKET_LEN-(SStimer.practical_offset-DS2TICKS(world.time - SStimer.head_offset))-1, BUCKET_LEN-1))) #define TIMER_ID_MAX (2**24) //max float with integer precision SUBSYSTEM_DEF(timer) @@ -9,11 +10,11 @@ SUBSYSTEM_DEF(timer) flags = SS_TICKER|SS_NO_INIT - var/list/datum/timedevent/processing = list() + var/list/datum/timedevent/second_queue = list() //awe, yes, you've had first queue, but what about second queue? var/list/hashes = list() var/head_offset = 0 //world.time of the first entry in the the bucket. - var/practical_offset = 0 //index of the first non-empty item in the bucket. + var/practical_offset = 1 //index of the first non-empty item in the bucket. var/bucket_resolution = 0 //world.tick_lag the bucket was designed for var/bucket_count = 0 //how many timers are in the buckets @@ -27,13 +28,19 @@ SUBSYSTEM_DEF(timer) var/static/last_invoke_warning = 0 var/static/bucket_auto_reset = TRUE +/datum/controller/subsystem/timer/PreInit() + bucket_list.len = BUCKET_LEN + head_offset = world.time + bucket_resolution = world.tick_lag + /datum/controller/subsystem/timer/stat_entry(msg) - ..("B:[bucket_count] P:[length(processing)] H:[length(hashes)] C:[length(clienttime_timers)]") + ..("B:[bucket_count] P:[length(second_queue)] H:[length(hashes)] C:[length(clienttime_timers)] S:[length(timer_id_dict)]") /datum/controller/subsystem/timer/fire(resumed = FALSE) var/lit = last_invoke_tick var/last_check = world.time - TIMER_NO_INVOKE_WARNING var/list/bucket_list = src.bucket_list + if(!bucket_count) last_invoke_tick = world.time @@ -60,50 +67,62 @@ SUBSYSTEM_DEF(timer) bucket_node = bucket_node.next anti_loop_check-- while(bucket_node && bucket_node != bucket_head && anti_loop_check) - log_world("Active timers in the processing queue:") - for(var/I in processing) + log_world("Active timers in the second_queue queue:") + for(var/I in second_queue) log_world(get_timer_debug_string(I)) - while(length(clienttime_timers)) - var/datum/timedevent/ctime_timer = clienttime_timers[clienttime_timers.len] - if (ctime_timer.timeToRun <= REALTIMEOFDAY) - --clienttime_timers.len - var/datum/callback/callBack = ctime_timer.callBack - ctime_timer.spent = REALTIMEOFDAY - callBack.InvokeAsync() - qdel(ctime_timer) - else - break //None of the rest are ready to run + var/next_clienttime_timer_index = 0 + var/len = length(clienttime_timers) + + for (next_clienttime_timer_index in 1 to len) if (MC_TICK_CHECK) - return + next_clienttime_timer_index-- + break + var/datum/timedevent/ctime_timer = clienttime_timers[next_clienttime_timer_index] + if (ctime_timer.timeToRun > REALTIMEOFDAY) + next_clienttime_timer_index-- + break + + var/datum/callback/callBack = ctime_timer.callBack + if (!callBack) + clienttime_timers.Cut(next_clienttime_timer_index,next_clienttime_timer_index+1) + CRASH("Invalid timer: [get_timer_debug_string(ctime_timer)] world.time: [world.time], head_offset: [head_offset], practical_offset: [practical_offset], REALTIMEOFDAY: [REALTIMEOFDAY]") + + ctime_timer.spent = REALTIMEOFDAY + callBack.InvokeAsync() + qdel(ctime_timer) + + + if (next_clienttime_timer_index) + clienttime_timers.Cut(1,next_clienttime_timer_index+1) + + if (MC_TICK_CHECK) + return var/static/list/spent = list() var/static/datum/timedevent/timer - var/static/datum/timedevent/head + if (practical_offset > BUCKET_LEN) + head_offset += TICKS2DS(BUCKET_LEN) + practical_offset = 1 + resumed = FALSE - if (practical_offset > BUCKET_LEN || (!resumed && length(bucket_list) != BUCKET_LEN || world.tick_lag != bucket_resolution)) - shift_buckets() + if ((length(bucket_list) != BUCKET_LEN) || (world.tick_lag != bucket_resolution)) + reset_buckets() bucket_list = src.bucket_list resumed = FALSE if (!resumed) timer = null - head = null - while (practical_offset <= BUCKET_LEN && head_offset + (practical_offset*world.tick_lag) <= world.time && !MC_TICK_CHECK) + while (practical_offset <= BUCKET_LEN && head_offset + (practical_offset*world.tick_lag) <= world.time) + var/datum/timedevent/head = bucket_list[practical_offset] if (!timer || !head || timer == head) head = bucket_list[practical_offset] - if (!head) - practical_offset++ - if (MC_TICK_CHECK) - break - continue timer = head - do + while (timer) var/datum/callback/callBack = timer.callBack if (!callBack) - qdel(timer) bucket_resolution = null //force bucket recreation CRASH("Invalid timer: [get_timer_debug_string(timer)] world.time: [world.time], head_offset: [head_offset], practical_offset: [practical_offset]") @@ -113,15 +132,68 @@ SUBSYSTEM_DEF(timer) callBack.InvokeAsync() last_invoke_tick = world.time - timer = timer.next - if (MC_TICK_CHECK) return - while (timer && timer != head) - timer = null + + timer = timer.next + if (timer == head) + break + + bucket_list[practical_offset++] = null - if (MC_TICK_CHECK) - return + + //we freed up a bucket, lets see if anything in second_queue needs to be shifted to that bucket. + var/i = 0 + var/L = length(second_queue) + for (i in 1 to L) + timer = second_queue[i] + if (timer.timeToRun >= TIMER_MAX) + i-- + break + + if (timer.timeToRun < head_offset) + bucket_resolution = null //force bucket recreation + CRASH("[i] Invalid timer state: Timer in long run queue with a time to run less then head_offset. [get_timer_debug_string(timer)] world.time: [world.time], head_offset: [head_offset], practical_offset: [practical_offset]") + + if (timer.callBack && !timer.spent) + timer.callBack.InvokeAsync() + spent += timer + bucket_count++ + else if(!QDELETED(timer)) + qdel(timer) + continue + + if (timer.timeToRun < head_offset + TICKS2DS(practical_offset)) + bucket_resolution = null //force bucket recreation + CRASH("[i] Invalid timer state: Timer in long run queue that would require a backtrack to transfer to short run queue. [get_timer_debug_string(timer)] world.time: [world.time], head_offset: [head_offset], practical_offset: [practical_offset]") + if (timer.callBack && !timer.spent) + timer.callBack.InvokeAsync() + spent += timer + bucket_count++ + else if(!QDELETED(timer)) + qdel(timer) + continue + + bucket_count++ + var/bucket_pos = max(1, BUCKET_POS(timer)) + + var/datum/timedevent/bucket_head = bucket_list[bucket_pos] + if (!bucket_head) + bucket_list[bucket_pos] = timer + timer.next = null + timer.prev = null + continue + + if (!bucket_head.prev) + bucket_head.prev = bucket_head + timer.next = bucket_head + timer.prev = bucket_head.prev + timer.next.prev = timer + timer.prev.next = timer + if (i) + second_queue.Cut(1, i+1) + + timer = null bucket_count -= length(spent) @@ -141,7 +213,7 @@ SUBSYSTEM_DEF(timer) if(!TE.callBack) . += ", NO CALLBACK" -/datum/controller/subsystem/timer/proc/shift_buckets() +/datum/controller/subsystem/timer/proc/reset_buckets() var/list/bucket_list = src.bucket_list var/list/alltimers = list() //collect the timers currently in the bucket @@ -162,7 +234,7 @@ SUBSYSTEM_DEF(timer) head_offset = world.time bucket_resolution = world.tick_lag - alltimers += processing + alltimers += second_queue if (!length(alltimers)) return @@ -173,22 +245,26 @@ SUBSYSTEM_DEF(timer) if (head.timeToRun < head_offset) head_offset = head.timeToRun - var/list/timers_to_remove = list() - - for (var/thing in alltimers) - var/datum/timedevent/timer = thing + var/new_bucket_count + var/i = 1 + for (i in 1 to length(alltimers)) + var/datum/timedevent/timer = alltimers[1] if (!timer) - timers_to_remove += timer continue var/bucket_pos = BUCKET_POS(timer) - if (bucket_pos > BUCKET_LEN) + if (timer.timeToRun >= TIMER_MAX) + i-- break - timers_to_remove += timer //remove it from the big list once we are done + if (!timer.callBack || timer.spent) + WARNING("Invalid timer: [get_timer_debug_string(timer)] world.time: [world.time], head_offset: [head_offset], practical_offset: [practical_offset]") + if (timer.callBack) + qdel(timer) continue - bucket_count++ + + new_bucket_count++ var/datum/timedevent/bucket_head = bucket_list[bucket_pos] if (!bucket_head) bucket_list[bucket_pos] = timer @@ -202,12 +278,14 @@ SUBSYSTEM_DEF(timer) timer.prev = bucket_head.prev timer.next.prev = timer timer.prev.next = timer - - processing = (alltimers - timers_to_remove) + if (i) + alltimers.Cut(1, i+1) + second_queue = alltimers + bucket_count = new_bucket_count /datum/controller/subsystem/timer/Recover() - processing |= SStimer.processing + second_queue |= SStimer.second_queue hashes |= SStimer.hashes timer_id_dict |= SStimer.timer_id_dict bucket_list |= SStimer.bucket_list @@ -224,8 +302,6 @@ SUBSYSTEM_DEF(timer) var/datum/timedevent/next var/datum/timedevent/prev - var/static/nextid = 1 - /datum/timedevent/New(datum/callback/callBack, timeToRun, flags, hash) id = TIMER_ID_NULL src.callBack = callBack @@ -235,56 +311,65 @@ SUBSYSTEM_DEF(timer) if (flags & TIMER_UNIQUE) SStimer.hashes[hash] = src + if (flags & TIMER_STOPPABLE) - do - if (nextid >= TIMER_ID_MAX) - nextid = 1 - id = nextid++ - while(SStimer.timer_id_dict["timerid" + num2text(id, 8)]) - SStimer.timer_id_dict["timerid" + num2text(id, 8)] = src + id = GUID() + SStimer.timer_id_dict[id] = src - name = "Timer: " + num2text(id, 8) + ", TTR: [timeToRun], Flags: [jointext(bitfield2list(flags, list("TIMER_UNIQUE", "TIMER_OVERRIDE", "TIMER_CLIENT_TIME", "TIMER_STOPPABLE", "TIMER_NO_HASH_WAIT")), ", ")], callBack: [REF(callBack)], callBack.object: [callBack.object][REF(callBack.object)]([getcallingtype()]), callBack.delegate:[callBack.delegate]([callBack.arguments ? callBack.arguments.Join(", ") : ""])" + name = "Timer: [id] (\ref[src]), TTR: [timeToRun], Flags: [jointext(bitfield2list(flags, list("TIMER_UNIQUE", "TIMER_OVERRIDE", "TIMER_CLIENT_TIME", "TIMER_STOPPABLE", "TIMER_NO_HASH_WAIT")), ", ")], callBack: \ref[callBack], callBack.object: [callBack.object]\ref[callBack.object]([getcallingtype()]), callBack.delegate:[callBack.delegate]([callBack.arguments ? callBack.arguments.Join(", ") : ""])" - if (spent) - CRASH("HOLY JESUS. WHAT IS THAT? WHAT THE FUCK IS THAT?") + if ((timeToRun < world.time || timeToRun < SStimer.head_offset) && !(flags & TIMER_CLIENT_TIME)) + CRASH("Invalid timer state: Timer created that would require a backtrack to run (addtimer would never let this happen): [SStimer.get_timer_debug_string(src)]") if (callBack.object != GLOBAL_PROC) LAZYADD(callBack.object.active_timers, src) + + var/list/L + if (flags & TIMER_CLIENT_TIME) - //sorted insert - var/list/ctts = SStimer.clienttime_timers - var/cttl = length(ctts) + L = SStimer.clienttime_timers + else if (timeToRun >= TIMER_MAX) + L = SStimer.second_queue + + + if (L) + //binary search sorted insert + var/cttl = length(L) if(cttl) - var/datum/timedevent/Last = ctts[cttl] - if(Last.timeToRun >= timeToRun) - ctts += src - else - for(var/i in cttl to 1 step -1) - var/datum/timedevent/E = ctts[i] - if(E.timeToRun <= timeToRun) - ctts.Insert(i, src) - break + var/left = 1 + var/right = cttl + var/mid = (left+right) >> 1 //rounded divide by two for hedgehogs + + var/datum/timedevent/item + while (left < right) + item = L[mid] + if (item.timeToRun <= timeToRun) + left = mid+1 + else + right = mid + mid = (left+right) >> 1 + + item = L[mid] + mid = item.timeToRun > timeToRun ? mid : mid+1 + L.Insert(mid, src) + else - ctts += src + L += src return //get the list of buckets var/list/bucket_list = SStimer.bucket_list + //calculate our place in the bucket list var/bucket_pos = BUCKET_POS(src) - //we are too far aways from needing to run to be in the bucket list, shift_buckets() will handle us. - if (bucket_pos > length(bucket_list)) - SStimer.processing += src - return + //get the bucket for our tick var/datum/timedevent/bucket_head = bucket_list[bucket_pos] SStimer.bucket_count++ //empty bucket, we will just add ourselves if (!bucket_head) bucket_list[bucket_pos] = src - if (bucket_pos < SStimer.practical_offset) - SStimer.practical_offset = bucket_pos return //other wise, lets do a simplified linked list add. if (!bucket_head.prev) @@ -296,10 +381,9 @@ SUBSYSTEM_DEF(timer) /datum/timedevent/Destroy() ..() - if (flags & TIMER_UNIQUE) + if (flags & TIMER_UNIQUE && hash) SStimer.hashes -= hash - if (callBack && callBack.object && callBack.object != GLOBAL_PROC && callBack.object.active_timers) callBack.object.active_timers -= src UNSETEMPTY(callBack.object.active_timers) @@ -307,13 +391,33 @@ SUBSYSTEM_DEF(timer) callBack = null if (flags & TIMER_STOPPABLE) - SStimer.timer_id_dict -= "timerid" + num2text(id, 8) + SStimer.timer_id_dict -= id if (flags & TIMER_CLIENT_TIME) - SStimer.clienttime_timers -= src + if (!spent) + spent = world.time + SStimer.clienttime_timers -= src return QDEL_HINT_IWILLGC if (!spent) + spent = world.time + var/bucketpos = BUCKET_POS(src) + var/datum/timedevent/buckethead + var/list/bucket_list = SStimer.bucket_list + if (bucketpos > 0) + buckethead = bucket_list[bucketpos] + + if (buckethead == src) + bucket_list[bucketpos] = next + SStimer.bucket_count-- + else if (timeToRun < TIMER_MAX || next || prev) + SStimer.bucket_count-- + else + var/l = length(SStimer.second_queue) + SStimer.second_queue -= src + if (l == length(SStimer.second_queue)) + SStimer.bucket_count-- + if (prev == next && next) next.prev = null prev.next = null @@ -322,19 +426,6 @@ SUBSYSTEM_DEF(timer) prev.next = next if (next) next.prev = prev - - var/bucketpos = BUCKET_POS(src) - var/datum/timedevent/buckethead - var/list/bucket_list = SStimer.bucket_list - - if (bucketpos > 0 && bucketpos <= length(bucket_list)) - buckethead = bucket_list[bucketpos] - SStimer.bucket_count-- - else - SStimer.processing -= src - - if (buckethead == src) - bucket_list[bucketpos] = next else if (prev && prev.next == src) prev.next = next @@ -351,9 +442,16 @@ SUBSYSTEM_DEF(timer) else . = "[callBack.object.type]" -/proc/addtimer(datum/callback/callback, wait, flags) +/proc/addtimer(datum/callback/callback, wait = 0, flags = 0) if (!callback) - return + CRASH("addtimer called without a callback") + + if (wait < 0) + stack_trace("Addtimer called with a negitive wait. Converting to 0") + + //alot of things add short timers on themselves in their destroy, we ignore those cases + if (wait >= 1 && callback && callback.object && callback.object != GLOBAL_PROC && QDELETED(callback.object)) + stack_trace("Add timer called with a callback assigned to a qdeleted object") wait = max(wait, 0) @@ -374,11 +472,10 @@ SUBSYSTEM_DEF(timer) var/datum/timedevent/hash_timer = SStimer.hashes[hash] if(hash_timer) if (hash_timer.spent) //it's pending deletion, pretend it doesn't exist. - hash_timer.hash = null - SStimer.hashes -= hash + hash_timer.hash = null //but keep it from accidentally deleting us else - if (flags & TIMER_OVERRIDE) + hash_timer.hash = null //no need having it delete it's hash if we are going to replace it qdel(hash_timer) else if (hash_timer.flags & TIMER_STOPPABLE) @@ -403,7 +500,7 @@ SUBSYSTEM_DEF(timer) qdel(id) return TRUE //id is string - var/datum/timedevent/timer = SStimer.timer_id_dict["timerid[id]"] + var/datum/timedevent/timer = SStimer.timer_id_dict[id] if (timer && !timer.spent) qdel(timer) return TRUE @@ -412,3 +509,5 @@ SUBSYSTEM_DEF(timer) #undef BUCKET_LEN #undef BUCKET_POS +#undef TIMER_MAX +#undef TIMER_ID_MAX \ No newline at end of file