diff --git a/code/__defines/process_scheduler.dm b/code/__defines/process_scheduler.dm index d9c8f106ef..f1e30c23ed 100644 --- a/code/__defines/process_scheduler.dm +++ b/code/__defines/process_scheduler.dm @@ -7,13 +7,12 @@ #define PROCESS_STATUS_HUNG 6 // Process time thresholds -#define PROCESS_DEFAULT_HANG_WARNING_TIME 300 // 30 seconds -#define PROCESS_DEFAULT_HANG_ALERT_TIME 600 // 60 seconds -#define PROCESS_DEFAULT_HANG_RESTART_TIME 900 // 90 seconds -#define PROCESS_DEFAULT_SCHEDULE_INTERVAL 50 // 50 ticks -#define PROCESS_DEFAULT_SLEEP_INTERVAL 8 // 1/8th of a tick +#define PROCESS_DEFAULT_HANG_WARNING_TIME 300 // 30 seconds +#define PROCESS_DEFAULT_HANG_ALERT_TIME 600 // 60 seconds +#define PROCESS_DEFAULT_HANG_RESTART_TIME 900 // 90 seconds +#define PROCESS_DEFAULT_SCHEDULE_INTERVAL 50 // 50 ticks +#define PROCESS_DEFAULT_SLEEP_INTERVAL 20 // 20% of a tick +#define PROCESS_DEFAULT_DEFER_USAGE 90 // 90% of a tick -// SCHECK macros -// This references src directly to work around a weird bug with try/catch -#define SCHECK_EVERY(this_many_calls) if(++src.calls_since_last_scheck >= this_many_calls) sleepCheck() -#define SCHECK sleepCheck() +// Sleep check macro +#define SCHECK if(world.tick_usage >= next_sleep_usage) defer() diff --git a/code/controllers/ProcessScheduler/core/process.dm b/code/controllers/ProcessScheduler/core/process.dm index 2d5b8b1b7d..323c5f7663 100644 --- a/code/controllers/ProcessScheduler/core/process.dm +++ b/code/controllers/ProcessScheduler/core/process.dm @@ -48,7 +48,10 @@ // This controls how often the process will yield (call sleep(0)) while it is running. // Every concurrent process should sleep periodically while running in order to allow other // processes to execute concurrently. - var/tmp/sleep_interval + var/tmp/sleep_interval = PROCESS_DEFAULT_SLEEP_INTERVAL + + // Defer usage; the tick usage at which this process will defer until the next tick + var/tmp/defer_usage = PROCESS_DEFAULT_DEFER_USAGE // hang_warning_time - this is the time (in 1/10 seconds) after which the server will begin to show "maybe hung" in the context window var/tmp/hang_warning_time = PROCESS_DEFAULT_HANG_WARNING_TIME @@ -59,19 +62,13 @@ // hang_restart_time - After this much time(in 1/10 seconds), the server will automatically kill and restart the process. var/tmp/hang_restart_time = PROCESS_DEFAULT_HANG_RESTART_TIME - // How many times in the current run has the process deferred work till the next tick? - var/tmp/cpu_defer_count = 0 - - // How many SCHECKs have been skipped (to limit btime calls) - var/tmp/calls_since_last_scheck = 0 + // Number of deciseconds to delay before starting the process + var/start_delay = 0 /** * recordkeeping vars */ - // Records the time (1/10s timeoftick) at which the process last finished sleeping - var/tmp/last_slept = 0 - // Records the time (1/10s timeofgame) at which the process last began running var/tmp/run_start = 0 @@ -85,11 +82,29 @@ var/tmp/last_object + // How many times in the current run has the process deferred work till the next tick? + var/tmp/cpu_defer_count = 0 + // Counts the number of times an exception has occurred; gets reset after 10 var/tmp/list/exceptions = list() - // Number of deciseconds to delay before starting the process - var/start_delay = 0 + // The next tick_usage the process will sleep at + var/tmp/next_sleep_usage + + // Last run duration, in seconds + var/tmp/last_run_time = 0 + + // Last 20 run durations + var/tmp/list/last_twenty_run_times = list() + + // Highest run duration, in seconds + var/tmp/highest_run_time = 0 + + // Tick usage at start of current run (updates upon deferring) + var/tmp/tick_usage_start + + // Accumulated tick usage from before each deferral + var/tmp/tick_usage_accumulated = 0 /datum/controller/process/New(var/datum/controller/processScheduler/scheduler) ..() @@ -97,9 +112,6 @@ previousStatus = "idle" idle() name = "process" - schedule_interval = 50 - sleep_interval = world.tick_lag / PROCESS_DEFAULT_SLEEP_INTERVAL - last_slept = 0 run_start = 0 ticks = 0 last_task = 0 @@ -112,6 +124,10 @@ // Initialize defer count cpu_defer_count = 0 + // Prepare usage tracking (defer() updates these) + tick_usage_start = world.tick_usage + tick_usage_accumulated = 0 + running() main.processStarted(src) @@ -119,11 +135,23 @@ /datum/controller/process/proc/finished() ticks++ + recordRunTime() idle() main.processFinished(src) onFinish() +/datum/controller/process/proc/recordRunTime() + // Convert from tick usage (100/tick) to seconds of CPU time used + var/total_usage = (tick_usage_accumulated + (world.tick_usage - tick_usage_start)) / 1000 * world.tick_lag + + last_run_time = total_usage + if(total_usage > highest_run_time) + highest_run_time = total_usage + if(last_twenty_run_times.len == 20) + last_twenty_run_times.Cut(1, 2) + last_twenty_run_times += total_usage + /datum/controller/process/proc/doWork() /datum/controller/process/proc/setup() @@ -183,10 +211,9 @@ // This should del del(src) -// Do not call this directly - use SHECK or SCHECK_EVERY -/datum/controller/process/proc/sleepCheck(var/tickId = 0) - calls_since_last_scheck = 0 - if (killed) +// Do not call this directly - use SHECK +/datum/controller/process/proc/defer() + if(killed) // The kill proc is the only place where killed is set. // The kill proc should have deleted this datum, and all sleeping procs that are // owned by it. @@ -196,15 +223,14 @@ handleHung() CRASH("Process [name] hung and was restarted.") - if (main.getCurrentTickElapsedTime() > main.timeAllowance) + tick_usage_accumulated += (world.tick_usage - tick_usage_start) + if(world.tick_usage < defer_usage) + sleep(0) + else sleep(world.tick_lag) cpu_defer_count++ - last_slept = 0 - else - if (TimeOfTick > last_slept + sleep_interval) - // If we haven't slept in sleep_interval deciseconds, sleep to allow other work to proceed. - sleep(0) - last_slept = TimeOfTick + tick_usage_start = world.tick_usage + next_sleep_usage = min(world.tick_usage + sleep_interval, defer_usage) /datum/controller/process/proc/update() // Clear delta @@ -231,14 +257,14 @@ return /datum/controller/process/proc/getContext() - return "[name][main.averageRunTime(src)][main.last_run_time[src]][main.highest_run_time[src]][ticks]\n" + return "[name][getAverageRunTime()][last_run_time][highest_run_time][ticks]\n" /datum/controller/process/proc/getContextData() return list( "name" = name, - "averageRunTime" = main.averageRunTime(src), - "lastRunTime" = main.last_run_time[src], - "highestRunTime" = main.highest_run_time[src], + "averageRunTime" = getAverageRunTime(), + "lastRunTime" = last_run_time, + "highestRunTime" = highest_run_time, "ticks" = ticks, "schedule" = schedule_interval, "status" = getStatusText(), @@ -286,7 +312,6 @@ name = target.name schedule_interval = target.schedule_interval sleep_interval = target.sleep_interval - last_slept = 0 run_start = 0 times_killed = target.times_killed ticks = target.ticks @@ -309,21 +334,31 @@ disabled = 0 /datum/controller/process/proc/getAverageRunTime() - return main.averageRunTime(src) + var/t = 0 + var/c = 0 + for(var/time in last_twenty_run_times) + t += time + c++ + + if(c > 0) + return t / c + return c + /datum/controller/process/proc/getLastRunTime() - return main.getProcessLastRunTime(src) + return last_run_time /datum/controller/process/proc/getHighestRunTime() - return main.getProcessHighestRunTime(src) + return highest_run_time /datum/controller/process/proc/getTicks() return ticks /datum/controller/process/proc/statProcess() - var/averageRunTime = round(getAverageRunTime(), 0.1)/10 - var/lastRunTime = round(getLastRunTime(), 0.1)/10 - var/highestRunTime = round(getHighestRunTime(), 0.1)/10 - stat("[name]", "T#[getTicks()] | AR [averageRunTime] | LR [lastRunTime] | HR [highestRunTime] | D [cpu_defer_count]") + var/averageRunTime = round(getAverageRunTime(), 0.001) + var/lastRunTime = round(last_run_time, 0.001) + var/highestRunTime = round(highest_run_time, 0.001) + var/deferTime = round(cpu_defer_count / 10 * world.tick_lag, 0.01) + stat("[name]", "T#[getTicks()] | AR [averageRunTime] | LR [lastRunTime] | HR [highestRunTime] | D [deferTime]") /datum/controller/process/proc/catchException(var/exception/e, var/thrower) if(istype(e)) // Real runtimes go to the real error handler diff --git a/code/controllers/ProcessScheduler/core/processScheduler.dm b/code/controllers/ProcessScheduler/core/processScheduler.dm index dc412ee92a..86dcdac287 100644 --- a/code/controllers/ProcessScheduler/core/processScheduler.dm +++ b/code/controllers/ProcessScheduler/core/processScheduler.dm @@ -20,18 +20,6 @@ var/global/datum/controller/processScheduler/processScheduler // Process last queued times (world time) var/tmp/datum/controller/process/list/last_queued = new - // Process last start times (real time) - var/tmp/datum/controller/process/list/last_start = new - - // Process last run durations - var/tmp/datum/controller/process/list/last_run_time = new - - // Per process list of the last 20 durations - var/tmp/datum/controller/process/list/last_twenty_run_times = new - - // Process highest run time - var/tmp/datum/controller/process/list/highest_run_time = new - // How long to sleep between runs (set to tick_lag in New) var/tmp/scheduler_sleep_interval @@ -41,22 +29,12 @@ var/global/datum/controller/processScheduler/processScheduler // Setup for these processes will be deferred until all the other processes are set up. var/tmp/list/deferredSetupList = new - var/tmp/currentTick = 0 - - var/tmp/timeAllowance = 0 - - var/tmp/cpuAverage = 0 - - var/tmp/timeAllowanceMax = 0 - /datum/controller/processScheduler/New() ..() // When the process scheduler is first new'd, tick_lag may be wrong, so these // get re-initialized when the process scheduler is started. // (These are kept here for any processes that decide to process before round start) scheduler_sleep_interval = world.tick_lag - timeAllowance = world.tick_lag * 0.5 - timeAllowanceMax = world.tick_lag /** * deferSetupFor @@ -88,20 +66,12 @@ var/global/datum/controller/processScheduler/processScheduler isRunning = 1 // tick_lag will have been set by now, so re-initialize these scheduler_sleep_interval = world.tick_lag - timeAllowance = world.tick_lag * 0.5 - timeAllowanceMax = world.tick_lag updateStartDelays() spawn(0) process() /datum/controller/processScheduler/proc/process() - updateCurrentTickData() - - for(var/i=world.tick_lag,i highest_run_time[process]) - highest_run_time[process] = time - - var/list/lastTwenty = last_twenty_run_times[process] - if (lastTwenty.len == 20) - lastTwenty.Cut(1, 2) - lastTwenty.len++ - lastTwenty[lastTwenty.len] = time - -/** - * averageRunTime - * returns the average run time (over the last 20) of the process - */ -/datum/controller/processScheduler/proc/averageRunTime(var/datum/controller/process/process) - var/lastTwenty = last_twenty_run_times[process] - - var/t = 0 - var/c = 0 - for(var/time in lastTwenty) - t += time - c++ - - if(c > 0) - return t / c - return c - -/datum/controller/processScheduler/proc/getProcessLastRunTime(var/datum/controller/process/process) - return last_run_time[process] - -/datum/controller/processScheduler/proc/getProcessHighestRunTime(var/datum/controller/process/process) - return highest_run_time[process] /datum/controller/processScheduler/proc/getStatusData() var/list/data = new @@ -338,34 +221,12 @@ var/global/datum/controller/processScheduler/processScheduler var/datum/controller/process/process = nameToProcessMap[processName] process.disable() -/datum/controller/processScheduler/proc/getCurrentTickElapsedTime() - if (world.time > currentTick) - updateCurrentTickData() - return 0 - else - return TimeOfTick - -/datum/controller/processScheduler/proc/updateCurrentTickData() - if (world.time > currentTick) - // New tick! - currentTick = world.time - updateTimeAllowance() - cpuAverage = (world.cpu + cpuAverage + cpuAverage) / 3 - -/datum/controller/processScheduler/proc/updateTimeAllowance() - // Time allowance goes down linearly with world.cpu. - var/tmp/error = cpuAverage - 100 - var/tmp/timeAllowanceDelta = SIMPLE_SIGN(error) * -0.5 * world.tick_lag * max(0, 0.001 * abs(error)) - - //timeAllowance = world.tick_lag * min(1, 0.5 * ((200/max(1,cpuAverage)) - 1)) - timeAllowance = min(timeAllowanceMax, max(0, timeAllowance + timeAllowanceDelta)) /datum/controller/processScheduler/proc/statProcesses() if(!isRunning) stat("Processes", "Scheduler not running") return stat("Processes", "[processes.len] (R [running.len] / Q [queued.len] / I [idle.len])") - stat(null, "[round(cpuAverage, 0.1)] CPU, [round(timeAllowance, 0.1)/10] TA") for(var/datum/controller/process/p in processes) p.statProcess()