diff --git a/code/_helpers/logging.dm b/code/_helpers/logging.dm index 7f3393ccc9..18cede2ea4 100644 --- a/code/_helpers/logging.dm +++ b/code/_helpers/logging.dm @@ -259,20 +259,28 @@ return key_name(whom, 1, include_name) // Helper procs for building detailed log lines +// +// These procs must not fail under ANY CIRCUMSTANCES! +// + /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])" + return "[.] @ [t.log_info_line()]" else if(loc) - return "([loc]) (0,0,0) ([loc.type])" + return "[.] @ ([loc]) (0,0,0) ([loc.type])" else - return "(NULL) (0,0,0) (NULL)" + return "[.] @ (NULL) (0,0,0) (NULL)" + +/turf/log_info_line() + return "([src]) ([x],[y],[z]) ([type])" /mob/log_info_line() - return "[..()] ([ckey])" + return "[..()] (ckey=[ckey])" /proc/log_info_line(var/datum/d) if(!d) diff --git a/code/controllers/failsafe.dm b/code/controllers/failsafe.dm index 0589d5fa7f..254472a2c8 100644 --- a/code/controllers/failsafe.dm +++ b/code/controllers/failsafe.dm @@ -52,6 +52,7 @@ var/datum/controller/failsafe/Failsafe if(Master.processing && Master.iteration) // Check if processing is done yet. if(Master.iteration == master_iteration) + log_debug("DEFCON [defcon]: Master.iteration=[Master.iteration] Master.last_run=[Master.last_run] world.time=[world.time]") switch(defcon) if(4,5) --defcon @@ -71,7 +72,7 @@ var/datum/controller/failsafe/Failsafe master_iteration = 0 to_chat(admins, "MC restarted successfully") else if(rtn < 0) - log_game("FailSafe: Could not restart MC, runtime encountered. Entering defcon 0") + log_world("FailSafe: Could not restart MC, runtime encountered. Entering defcon 0") to_chat(admins, "ERROR: DEFCON [defcon_pretty()]. Could not restart MC, runtime encountered. I will silently keep retrying.") //if the return number was 0, it just means the mc was restarted too recently, and it just needs some time before we try again //no need to handle that specially when defcon 0 can handle it diff --git a/code/controllers/master.dm b/code/controllers/master.dm index 644ab8d2f0..cc6b224b5b 100644 --- a/code/controllers/master.dm +++ b/code/controllers/master.dm @@ -50,6 +50,8 @@ GLOBAL_REAL(Master, /datum/controller/master) = new var/current_runlevel //for scheduling different subsystems for different stages of the round + var/dbg_is_running_subsystem = FALSE // TEMPORARY DEBUGGING - true only while we are actually waiting on a subsystem + var/static/restart_clear = 0 var/static/restart_timeout = 0 var/static/restart_count = 0 @@ -221,10 +223,12 @@ GLOBAL_REAL(Master, /datum/controller/master) = new //loop ended, restart the mc log_game("MC crashed or runtimed, restarting") message_admins("MC crashed or runtimed, restarting") + log_world("MC crashed or runtimed, restarting") var/rtn2 = Recreate_MC() if (rtn2 <= 0) log_game("Failed to recreate MC (Error code: [rtn2]), it's up to the failsafe now") message_admins("Failed to recreate MC (Error code: [rtn2]), it's up to the failsafe now") + log_world("Failed to recreate MC (Error code: [rtn2]), it's up to the failsafe now") Failsafe.defcon = 2 // Main loop. @@ -336,6 +340,7 @@ GLOBAL_REAL(Master, /datum/controller/master) = new subsystems_to_check = tickersubsystems if (CheckQueue(subsystems_to_check) <= 0) + log_world("MC: CheckQueue(subsystems_to_check) exited uncleanly, SoftReset (error_level=[error_level]") if (!SoftReset(tickersubsystems, runlevel_sorted_subsystems)) log_world("MC: SoftReset() failed, crashing") return @@ -348,6 +353,7 @@ GLOBAL_REAL(Master, /datum/controller/master) = new if (queue_head) if (RunQueue() <= 0) + log_world("MC: RunQueue() exited uncleanly, running SoftReset (error_level=[error_level]") if (!SoftReset(tickersubsystems, runlevel_sorted_subsystems)) log_world("MC: SoftReset() failed, crashing") return @@ -470,9 +476,11 @@ GLOBAL_REAL(Master, /datum/controller/master) = new queue_node.state = SS_RUNNING + dbg_is_running_subsystem = TRUE // TEMPORARY DEBUGGING tick_usage = TICK_USAGE var/state = queue_node.ignite(queue_node_paused) tick_usage = TICK_USAGE - tick_usage + dbg_is_running_subsystem = FALSE // TEMPORARY DEBUGGING if (state == SS_RUNNING) state = SS_IDLE diff --git a/code/modules/error_handler/error_handler.dm b/code/modules/error_handler/error_handler.dm index 098ea614b5..edae4c42ea 100644 --- a/code/modules/error_handler/error_handler.dm +++ b/code/modules/error_handler/error_handler.dm @@ -51,12 +51,12 @@ GLOBAL_VAR_INIT(total_runtimes_skipped, 0) // 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]" + var/atom/atom_e_src = e_src + if(istype(atom_e_src)) + srcinfo += " src.loc: [log_info_line(atom_e_src.loc)]" if(istype(usr)) usrinfo = list(" usr: [log_info_line(usr)]") - locinfo = log_info_line(usr) + locinfo = log_info_line(usr.loc) if(locinfo) usrinfo += " usr.loc: [locinfo]" // The proceeding mess will almost definitely break if error messages are ever changed diff --git a/code/modules/vore/trycatch_vr.dm b/code/modules/vore/trycatch_vr.dm index 78e91e91eb..396352aadc 100644 --- a/code/modules/vore/trycatch_vr.dm +++ b/code/modules/vore/trycatch_vr.dm @@ -25,6 +25,7 @@ The proc you're attemping should return nonzero values on success. catch(var/exception/e) error("attempt_vr runtimed when calling [procname] on [callon].") error("attempt_vr catch: [e] on [e.file]:[e.line]") + log_runtime(e) return 0 /*