diff --git a/code/_helpers/logging.dm b/code/_helpers/logging.dm index 35618c9b66..57813b0113 100644 --- a/code/_helpers/logging.dm +++ b/code/_helpers/logging.dm @@ -162,3 +162,24 @@ /proc/key_name_admin(var/whom, var/include_name = 1) return key_name(whom, 1, include_name) + +// Helper procs for building detailed log lines +/datum/proc/log_info_line() + return "[src] ([type])" + +/atom/log_info_line() + var/turf/t = get_turf(src) + if(istype(t)) + return "([t]) ([t.x],[t.y],[t.z]) ([t.type])" + else if(loc) + return "([loc]) (0,0,0) ([loc.type])" + else + return "(NULL) (0,0,0) (NULL)" + +/mob/log_info_line() + return "[..()] ([ckey])" + +/proc/log_info_line(var/datum/d) + if(!istype(d)) + return + return d.log_info_line() diff --git a/code/controllers/ProcessScheduler/core/process.dm b/code/controllers/ProcessScheduler/core/process.dm index 836d2124bd..2d5b8b1b7d 100644 --- a/code/controllers/ProcessScheduler/core/process.dm +++ b/code/controllers/ProcessScheduler/core/process.dm @@ -327,9 +327,7 @@ /datum/controller/process/proc/catchException(var/exception/e, var/thrower) if(istype(e)) // Real runtimes go to the real error handler - // There are two newlines here, because handling desc sucks - e.desc = " Caught by process: [name]\n\n" + e.desc - world.Error(e, e_src = thrower) + log_runtime(e, thrower, "Caught by process: [name]") return var/etext = "[e]" var/eid = "[e]" // Exception ID, for tracking repeated exceptions diff --git a/code/modules/admin/admin_verbs.dm b/code/modules/admin/admin_verbs.dm index b1b03a4ac4..8e1e81c603 100644 --- a/code/modules/admin/admin_verbs.dm +++ b/code/modules/admin/admin_verbs.dm @@ -162,7 +162,7 @@ var/list/admin_verbs_server = list( /client/proc/nanomapgen_DumpImage ) var/list/admin_verbs_debug = list( - /client/proc/getruntimelog, //allows us to access runtime logs to somebody, + /client/proc/getruntimelog, //allows us to access runtime logs to somebody, /client/proc/cmd_admin_list_open_jobs, /client/proc/Debug2, /client/proc/kill_air, @@ -196,7 +196,8 @@ var/list/admin_verbs_debug = list( /client/proc/jumptocoord, /client/proc/dsay, /client/proc/toggle_debug_logs, - /client/proc/admin_ghost //allows us to ghost/reenter body at will, + /client/proc/admin_ghost, //allows us to ghost/reenter body at will, + /datum/admins/proc/view_runtimes ) var/list/admin_verbs_paranoid_debug = list( diff --git a/code/modules/admin/topic.dm b/code/modules/admin/topic.dm index 335241d15e..eaadf431bc 100644 --- a/code/modules/admin/topic.dm +++ b/code/modules/admin/topic.dm @@ -1176,6 +1176,18 @@ sleep(2) C.jumptomob(M) + else if(href_list["adminplayerobservefollow"]) + if(!check_rights(R_MENTOR|R_MOD|R_ADMIN|R_SERVER)) + return + + var/mob/M = locate(href_list["adminplayerobservefollow"]) + + var/client/C = usr.client + if(!isobserver(usr)) C.admin_ghost() + var/mob/observer/dead/G = C.mob + sleep(2) + G.ManualFollow(M) + else if(href_list["check_antagonist"]) check_antagonists() diff --git a/code/modules/admin/verbs/debug.dm b/code/modules/admin/verbs/debug.dm index b21abd7e30..b98d3e6627 100644 --- a/code/modules/admin/verbs/debug.dm +++ b/code/modules/admin/verbs/debug.dm @@ -959,3 +959,13 @@ log_admin("[key_name(src)] has toggled [M.key]'s [blockname] block [state]!") else alert("Invalid mob") + +/datum/admins/proc/view_runtimes() + set category = "Debug" + set name = "View Runtimes" + set desc = "Open the Runtime Viewer" + + if(!check_rights(R_DEBUG)) + return + + error_cache.showTo(usr) diff --git a/code/modules/error_handler/_defines.dm b/code/modules/error_handler/_defines.dm new file mode 100644 index 0000000000..0c98f4a9b9 --- /dev/null +++ b/code/modules/error_handler/_defines.dm @@ -0,0 +1,9 @@ +// Settings for the error handler and error viewer + +#define ERROR_COOLDOWN 600 // The "cooldown" time for each occurrence of a unique error +#define ERROR_LIMIT 9 // How many occurrences before the next will silence them +#define ERROR_MAX_COOLDOWN (ERROR_COOLDOWN * ERROR_LIMIT) +#define ERROR_SILENCE_TIME 6000 // How long a unique error will be silenced for + +// How long to wait between messaging admins about occurrences of a unique error +#define ERROR_MSG_DELAY 50 diff --git a/code/modules/error_handler/error_handler.dm b/code/modules/error_handler/error_handler.dm new file mode 100644 index 0000000000..de71bfc1ca --- /dev/null +++ b/code/modules/error_handler/error_handler.dm @@ -0,0 +1,118 @@ +var/list/error_last_seen = list() +// error_cooldown items will either be positive (cooldown time) or negative (silenced error) +// If negative, starts at -1, and goes down by 1 each time that error gets skipped +var/list/error_cooldown = list() +var/total_runtimes = 0 +var/total_runtimes_skipped = 0 +// The ifdef needs to be down here, since the error viewer references total_runtimes +#ifdef DEBUG +/world/Error(var/exception/e, var/datum/e_src) + if(!istype(e)) // Something threw an unusual exception + log_to_dd("\[[time_stamp()]] Uncaught exception: [e]") + return ..() + if(!error_last_seen) // A runtime is occurring too early in start-up initialization + return ..() + total_runtimes++ + + var/erroruid = "[e.file][e.line]" + var/last_seen = error_last_seen[erroruid] + var/cooldown = error_cooldown[erroruid] || 0 + if(last_seen == null) // A new error! + error_last_seen[erroruid] = world.time + last_seen = world.time + if(cooldown < 0) + error_cooldown[erroruid]-- // Used to keep track of skip count for this error + total_runtimes_skipped++ + return // Error is currently silenced, skip handling it + + // Handle cooldowns and silencing spammy errors + var/silencing = 0 + // Each occurrence of a unique error adds to its "cooldown" time... + cooldown = max(0, cooldown - (world.time - last_seen)) + ERROR_COOLDOWN + // ... which is used to silence an error if it occurs too often, too fast + if(cooldown > ERROR_MAX_COOLDOWN) + cooldown = -1 + silencing = 1 + spawn(0) + usr = null + sleep(ERROR_SILENCE_TIME) + var/skipcount = abs(error_cooldown[erroruid]) - 1 + error_cooldown[erroruid] = 0 + if(skipcount > 0) + log_to_dd("\[[time_stamp()]] Skipped [skipcount] runtimes in [e.file],[e.line].") + error_cache.logError(e, skipCount = skipcount) + error_last_seen[erroruid] = world.time + error_cooldown[erroruid] = cooldown + + // The detailed error info needs some tweaking to make it look nice + var/list/srcinfo = null + var/list/usrinfo = null + var/locinfo + // First, try to make better src/usr info lines + if(istype(e_src)) + srcinfo = list(" src: [log_info_line(e_src)]") + locinfo = log_info_line(e_src) + if(locinfo) + srcinfo += " src.loc: [locinfo]" + if(istype(usr)) + usrinfo = list(" usr: [log_info_line(usr)]") + locinfo = log_info_line(usr) + if(locinfo) + usrinfo += " usr.loc: [locinfo]" + // The proceeding mess will almost definitely break if error messages are ever changed + // I apologize in advance + var/list/splitlines = splittext(e.desc, "\n") + var/list/desclines = list() + if(splitlines.len > 2) // If there aren't at least three lines, there's no info + for(var/line in splitlines) + if(length(line) < 3) + continue // Blank line, skip it + if(findtext(line, "source file:")) + continue // Redundant, skip it + if(findtext(line, "usr.loc:")) + continue // Our usr.loc is better, skip it + if(findtext(line, "usr:")) + if(usrinfo) + desclines.Add(usrinfo) + usrinfo = null + continue // Our usr info is better, replace it + if(srcinfo) + if(findtext(line, "src.loc:")) + continue + if(findtext(line, "src:")) + desclines.Add(srcinfo) + srcinfo = null + continue + if(copytext(line, 1, 3) != " ") + desclines += (" " + line) // Pad any unpadded lines, so they look pretty + else + desclines += line + if(srcinfo) // If these aren't null, they haven't been added yet + desclines.Add(srcinfo) + if(usrinfo) + desclines.Add(usrinfo) + if(silencing) + desclines += " (This error will now be silenced for [ERROR_SILENCE_TIME / 600] minutes)" + + // Now to actually output the error info... + log_to_dd("\[[time_stamp()]] Runtime in [e.file],[e.line]: [e]") + for(var/line in desclines) + log_to_dd(line) + if(error_cache) + error_cache.logError(e, desclines, e_src = e_src) + +#endif + +/proc/log_runtime(exception/e, datum/e_src, extra_info) + if(!istype(e)) + world.Error(e, e_src) + return + + if(extra_info) + // Adding extra info adds two newlines, because parsing runtimes is funky + if(islist(extra_info)) + e.desc = " [jointext(extra_info, "\n ")]\n\n" + e.desc + else + e.desc = " [extra_info]\n\n" + e.desc + + world.Error(e, e_src) diff --git a/code/modules/error_handler/error_viewer.dm b/code/modules/error_handler/error_viewer.dm new file mode 100644 index 0000000000..0f1fd0ba96 --- /dev/null +++ b/code/modules/error_handler/error_viewer.dm @@ -0,0 +1,206 @@ +// Error viewing datums, responsible for storing error info, notifying admins +// when errors occur, and showing them to admins on demand. + +// There are 3 different types used here: +// +// - ErrorCache keeps track of all error sources, as well as all individually +// logged errors. Only one instance of this datum should ever exist, and it's +// right here: + +#ifdef DEBUG +var/global/datum/ErrorViewer/ErrorCache/error_cache = new() +#else +// If debugging is disabled, there's nothing useful to log, so don't bother. +var/global/datum/ErrorViewer/ErrorCache/error_cache = null +#endif + +// - ErrorSource datums exist for each line (of code) that generates an error, +// and keep track of all errors generated by that line. +// +// - ErrorEntry datums exist for each logged error, and keep track of all +// relevant info about that error. + +// Common vars and procs are kept at the ErrorViewer level +/datum/ErrorViewer/ + var/name = "" + +/datum/ErrorViewer/proc/browseTo(var/user, var/html) + if(user) + var/datum/browser/popup = new(user, "error_viewer", "Runtime Viewer", 700, 500) + popup.add_head_content({""}) + popup.set_content(html) + popup.open(0) + +/datum/ErrorViewer/proc/buildHeader(var/datum/ErrorViewer/back_to, var/linear, var/refreshable) + // Common starter HTML for showTo + var/html = "" + + if(istype(back_to)) + html += "[back_to.makeLink("<<<", null, linear)] " + if(refreshable) + html += "[makeLink("Refresh", null, linear)]" + if(html) + html += "

" + return html + +/datum/ErrorViewer/proc/showTo(var/user, var/datum/ErrorViewer/back_to, var/linear) + // Specific to each child type + return + +/datum/ErrorViewer/proc/makeLink(var/linktext, var/datum/ErrorViewer/back_to, var/linear) + var/back_to_param = "" + if(!linktext) + linktext = name + if(istype(back_to)) + back_to_param = ";viewruntime_backto=\ref[back_to]" + if(linear) + back_to_param += ";viewruntime_linear=1" + return "[html_encode(linktext)]" + +/datum/ErrorViewer/Topic(href, href_list) + if(..()) + return 1 + if(href_list["viewruntime_backto"]) + showTo(usr, locate(href_list["viewruntime_backto"]), href_list["viewruntime_linear"]) + else + showTo(usr, null, href_list["viewruntime_linear"]) + +/datum/ErrorViewer/ErrorCache + var/list/errors = list() + var/list/error_sources = list() + var/list/errors_silenced = list() + +/datum/ErrorViewer/ErrorCache/showTo(var/user, var/datum/ErrorViewer/back_to, var/linear) + var/html = buildHeader(null, linear, refreshable=1) + html += "[total_runtimes] runtimes, [total_runtimes_skipped] skipped

" + if(!linear) + html += "organized | [makeLink("linear", null, 1)]
" + var/datum/ErrorViewer/ErrorSource/error_source + for(var/erroruid in error_sources) + error_source = error_sources[erroruid] + html += "

[error_source.makeLink(null, src)]

" + else + html += "[makeLink("organized", null)] | linear
" + for(var/datum/ErrorViewer/ErrorEntry/error_entry in errors) + html += "

[error_entry.makeLink(null, src, 1)]

" + browseTo(user, html) + +/datum/ErrorViewer/ErrorCache/proc/logError(var/exception/e, var/list/desclines, var/skipCount, var/datum/e_src) + if(!istype(e)) + return // Abnormal exception, don't even bother + + var/erroruid = "[e.file][e.line]" + var/datum/ErrorViewer/ErrorSource/error_source = error_sources[erroruid] + if(!error_source) + error_source = new(e) + error_sources[erroruid] = error_source + + var/datum/ErrorViewer/ErrorEntry/error_entry = new(e, desclines, skipCount, e_src) + error_entry.error_source = error_source + errors += error_entry + error_source.errors += error_entry + if(skipCount) + return // Skip notifying admins about skipped errors + + // Show the error to admins with debug messages turned on, but only if one + // from the same source hasn't been shown too recently + // (Also, make sure config is initialized, or log_debug will runtime) + if(config && error_source.next_message_at <= world.time) + var/const/viewtext = "\[view]" // Nesting these in other brackets went poorly + log_debug("Runtime in [e.file],[e.line]: [html_encode(e.name)] [error_entry.makeLink(viewtext)]") + error_source.next_message_at = world.time + ERROR_MSG_DELAY + +/datum/ErrorViewer/ErrorSource + var/list/errors = list() + var/next_message_at = 0 + +/datum/ErrorViewer/ErrorSource/New(var/exception/e) + if(!istype(e)) + name = "\[[time_stamp()]] Uncaught exceptions" + return + name = "\[[time_stamp()]] Runtime in [e.file],[e.line]: [e]" + +/datum/ErrorViewer/ErrorSource/showTo(var/user, var/datum/ErrorViewer/back_to, var/linear) + if(!istype(back_to)) + back_to = error_cache + var/html = buildHeader(back_to, refreshable=1) + for(var/datum/ErrorViewer/ErrorEntry/error_entry in errors) + html += "

[error_entry.makeLink(null, src)]

" + browseTo(user, html) + +/datum/ErrorViewer/ErrorEntry + var/datum/ErrorViewer/ErrorSource/error_source + var/exception/exc + var/desc = "" + var/srcRef + var/srcType + var/turf/srcLoc + var/usrRef + var/turf/usrLoc + var/isSkipCount + +/datum/ErrorViewer/ErrorEntry/New(var/exception/e, var/list/desclines, var/skipCount, var/datum/e_src) + if(!istype(e)) + name = "\[[time_stamp()]] Uncaught exception: [e]" + return + if(skipCount) + name = "\[[time_stamp()]] Skipped [skipCount] runtimes in [e.file],[e.line]." + isSkipCount = TRUE + return + name = "\[[time_stamp()]] Runtime in [e.file],[e.line]: [e]" + exc = e + if(istype(desclines)) + for(var/line in desclines) + // There's probably a better way to do this than non-breaking spaces... + desc += "  " + html_encode(line) + "
" + if(istype(e_src)) + srcRef = "\ref[e_src]" + srcType = e_src.type + srcLoc = get_turf(e_src) + if(usr) + usrRef = "\ref[usr]" + usrLoc = get_turf(usr) + +/datum/ErrorViewer/ErrorEntry/showTo(var/user, var/datum/ErrorViewer/back_to, var/linear) + if(!istype(back_to)) + back_to = error_source + var/html = buildHeader(back_to, linear) + html += "
[html_encode(name)]
[desc]
" + if(srcRef) + html += "
src: VV" + if(ispath(srcType, /mob)) + html += " PP" + html += " Follow" + if(istype(srcLoc)) + html += "
src.loc: VV" + html += " JMP" + if(usrRef) + html += "
usr: VV" + html += " PP" + html += " Follow" + if(istype(usrLoc)) + html += "
usr.loc: VV" + html += " JMP" + browseTo(user, html) + +/datum/ErrorViewer/ErrorEntry/makeLink(var/linktext, var/datum/ErrorViewer/back_to, var/linear) + if(isSkipCount) + return html_encode(name) + else + return ..() diff --git a/code/modules/error_handler/~defines.dm b/code/modules/error_handler/~defines.dm new file mode 100644 index 0000000000..98712eaa09 --- /dev/null +++ b/code/modules/error_handler/~defines.dm @@ -0,0 +1,6 @@ +// Settings for the error handler and error viewer +#undef ERROR_COOLDOWN +#undef ERROR_LIMIT +#undef ERROR_MAX_COOLDOWN +#undef ERROR_SILENCE_TIME +#undef ERROR_MSG_DELAY diff --git a/polaris.dme b/polaris.dme index 045a3f731f..2c1b93404f 100644 --- a/polaris.dme +++ b/polaris.dme @@ -1274,6 +1274,10 @@ #include "code\modules\economy\price_list.dm" #include "code\modules\economy\retail_scanner.dm" #include "code\modules\economy\TradeDestinations.dm" +#include "code\modules\error_handler\_defines.dm" +#include "code\modules\error_handler\error_handler.dm" +#include "code\modules\error_handler\error_viewer.dm" +#include "code\modules\error_handler\~defines.dm" #include "code\modules\events\apc_damage.dm" #include "code\modules\events\blob.dm" #include "code\modules\events\brand_intelligence.dm"