Skip to content

Commit

Permalink
Various debug messaging improvements
Browse files Browse the repository at this point in the history
  • Loading branch information
francinum committed Mar 31, 2024
1 parent 90671ef commit f5d173f
Show file tree
Hide file tree
Showing 20 changed files with 194 additions and 45 deletions.
16 changes: 0 additions & 16 deletions code/__DEFINES/chat.dm
Original file line number Diff line number Diff line change
Expand Up @@ -18,19 +18,3 @@
#define MESSAGE_TYPE_ADMINLOG "adminlog"
#define MESSAGE_TYPE_ATTACKLOG "attacklog"
#define MESSAGE_TYPE_DEBUG "debug"

//debug printing macros (for development and testing)
/// Used for debug messages to the world
#define debug_world(msg) if (GLOB.Debug2) to_chat(world, \
type = MESSAGE_TYPE_DEBUG, \
text = "DEBUG: [msg]")
/// Used for debug messages to the player
#define debug_usr(msg) if (GLOB.Debug2&&usr) to_chat(usr, \
type = MESSAGE_TYPE_DEBUG, \
text = "DEBUG: [msg]")
/// Used for debug messages to the admins
#define debug_admins(msg) if (GLOB.Debug2) to_chat(GLOB.admins, \
type = MESSAGE_TYPE_DEBUG, \
text = "DEBUG: [msg]")
/// Used for debug messages to the server
#define debug_world_log(msg) if (GLOB.Debug2) log_world("DEBUG: [msg]")
8 changes: 8 additions & 0 deletions code/__DEFINES/debug_messaging.dm
Original file line number Diff line number Diff line change
@@ -0,0 +1,8 @@
#define DBG_TRACE "trace"
#define DBG_INFO "info"
#define DBG_WARN "warn"
#define DBG_ERROR "error"

#define DBG_LOG_WORLD (1 << 0)
#define DBG_STACK_TRACE (1 << 1)
#define DBG_ALWAYS (1 << 2)
4 changes: 4 additions & 0 deletions code/__DEFINES/span.dm
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,10 @@
#define span_danger(str) ("<span class='danger'>" + str + "</span>")
#define span_deadsay(str) ("<span class='deadsay'>" + str + "</span>")
#define span_debug(str) ("<span class='debug'>" + str + "</span>")
#define span_debug_trace(str) ("<span class='debug debug_trace'>" + str + "</span>")
#define span_debug_info(str) ("<span class='debug debug_info'>" + str + "</span>")
#define span_debug_warn(str) ("<span class='debug debug_warn'>" + str + "</span>")
#define span_debug_error(str) ("<span class='debug debug_error'>" + str + "</span>")
#define span_deconversion_message(str) ("<span class='deconversion_message'>" + str + "</span>")
#define span_drone(str) ("<span class='drone'>" + str + "</span>")
#define span_engradio(str) ("<span class='engradio'>" + str + "</span>")
Expand Down
75 changes: 75 additions & 0 deletions code/__HELPERS/debug_messaging.dm
Original file line number Diff line number Diff line change
@@ -0,0 +1,75 @@
/* Helpers for Debug Messaging
*
* Log Levels conform to standard Unix expectations.
* All have the same argument set
*
* Messages are built as follows
* $PREFIX: $MESSAGE
*
* Messages are passed to chat only when the running server is in debug (is_debug_server), or live debugging has been enabled (GLOB.Debug2)
* Messages are passed globally on debug servers, otherwise Messages are passed to admins if live debugging is enabled.
* The single exception is TRACE level messages, which REQUIRE live debugging, this is to decrease general noise.
*
* - level | Log level, controls the message border's color. Traces are only sent to chat when Live Debugging is enabled.
* - DBG_TRACE: white | Spammy stuff, raw values of a calculation, etc.
* - DBG_INFO: blue (default) | State changes, progress indications, Etc.
* - DBG_WARN: orange | An issue has been handled cleanly, or something isn't right, but not enough to cause a problem for players.
* - DBG_ERROR: red | Errors. Something has gone wrong and you're probably just about to bail out of the proc. Consider throwing a stack as well.
*
* - prefix | Describes the sending system, Examples: Packets/IRPS, Jobs/AssignCaptain
* - default: "DEBUG"
*
* - message | The actual content of the message.
* - Required.
*
* - additional | Additional actions to take. Bitfield.
* - DBG_LOG_WORLD (default) | call log_world with message.
* - DBG_STACK_TRACE | Throw a stack trace.
* - DBG_ALWAYS | Send regardless of debug status.
*
*/

/proc/message_debug(level = DBG_INFO, prefix = "DEBUG", message, additional = DBG_LOG_WORLD)
// If we're a trace message and debugging is not enabled, return immediately.
// or we aren't being forced to send regardless.
if(level == DBG_TRACE && !GLOB.Debug2 && !(additional & DBG_ALWAYS))
return
// No message, No Service.
if(!message)
CRASH("Debug message without message? Wack.")

/// Built message with prefix.
var/built_message = "[prefix]: [message]"

/// Severity span class to use.
var/severity_class
switch(level)
if(DBG_TRACE)
severity_class = "debug_trace"
if(DBG_INFO)
severity_class = "debug_info"
if(DBG_WARN)
severity_class = "debug_warn"
if(DBG_ERROR)
severity_class = "debug_error"
else
message_debug(DBG_ERROR, "DebugMessage/Severity", "Invalid severity level [level]. Setting to error.", DBG_STACK_TRACE)
level = DBG_ERROR
severity_class = "debug_error"

// Check if we throw a stack trace.
if(additional & DBG_STACK_TRACE)
stack_trace("[level]| [built_message]")
// Log to world.
if(additional & DBG_LOG_WORLD)
log_world("[level]| [built_message]")

//Do we sent this, and to who?
//Trace requires Debug2 explicitly.
if((additional & DBG_ALWAYS) || GLOB.Debug2 || (GLOB.is_debug_server && (level != DBG_TRACE)))
to_chat(
target = (GLOB.is_debug_server ? world : GLOB.admins),
type = MESSAGE_TYPE_DEBUG,
html = "<div class='debug [severity_class]'>[built_message]</div>"
)
6 changes: 3 additions & 3 deletions code/controllers/master.dm
Original file line number Diff line number Diff line change
Expand Up @@ -199,7 +199,7 @@ GLOBAL_REAL(Master, /datum/controller/master) = new
current_runlevel = Master.current_runlevel
StartProcessing(10)
else
to_chat(world, span_boldannounce("The Master Controller is having some issues, we will need to re-initialize EVERYTHING"))
to_chat(world, span_debug_error("The Master Controller is having some issues, we will need to re-initialize EVERYTHING"))
Initialize(20, TRUE)


Expand Down Expand Up @@ -248,7 +248,7 @@ GLOBAL_REAL(Master, /datum/controller/master) = new
current_initializing_subsystem = subsystem

if(GLOB.is_debug_server)
to_chat(world, span_boldnotice("Initializing [subsystem.name]..."))
message_debug(DBG_INFO, "MC/Initialize","Initializing [subsystem.name]")

subsystem.Initialize(REALTIMEOFDAY)
CHECK_TICK
Expand Down Expand Up @@ -293,7 +293,7 @@ GLOBAL_REAL(Master, /datum/controller/master) = new
if(isnull(old_runlevel))
old_runlevel = "NULL"

testing("MC: Runlevel changed from [old_runlevel] to [new_runlevel]")
message_debug(DBG_INFO, "MC/Runlevel", "Runlevel changed from [old_runlevel] to [new_runlevel]")
current_runlevel = log(2, new_runlevel) + 1
if(current_runlevel < 1)
CRASH("Attempted to set invalid runlevel: [new_runlevel]")
Expand Down
5 changes: 3 additions & 2 deletions code/controllers/subsystem.dm
Original file line number Diff line number Diff line change
Expand Up @@ -277,8 +277,9 @@
var/time = (REALTIMEOFDAY - start_timeofday) / 10
var/msg = "Initialized [name] subsystem within [time] second[time == 1 ? "" : "s"]!"
if(GLOB.is_debug_server)
to_chat(world, span_debug("[msg]"))
log_world(msg)
message_debug(DBG_INFO, "MC/Initialize", msg)
else
log_world(msg)
return time

/datum/controller/subsystem/stat_entry(msg)
Expand Down
8 changes: 4 additions & 4 deletions code/controllers/subsystem/airmachines.dm
Original file line number Diff line number Diff line change
Expand Up @@ -25,13 +25,13 @@ SUBSYSTEM_DEF(airmachines)

/datum/controller/subsystem/airmachines/Initialize(timeofday)
var/starttime = REALTIMEOFDAY
to_chat(world, span_debug("Airmachines: Setting up atmospheric machinery..."))
to_chat(world, span_debug_info("Airmachines: Setting up atmospheric machinery..."))
setup_atmos_machinery()
to_chat(world, span_debug("Airmachines: Airmachine setup completed in [(REALTIMEOFDAY- starttime) / 10] seconds!"))
to_chat(world, span_debug_info("Airmachines: Airmachine setup completed in [(REALTIMEOFDAY- starttime) / 10] seconds!"))
starttime = REALTIMEOFDAY
to_chat(world, span_debug("Airmachines: Creating pipenets..."))
to_chat(world, span_debug_info("Airmachines: Creating pipenets..."))
setup_pipenets()
to_chat(world, span_debug("Airmachines: Pipenet creation completed in [(REALTIMEOFDAY- starttime) / 10] seconds!"))
to_chat(world, span_debug_info("Airmachines: Pipenet creation completed in [(REALTIMEOFDAY- starttime) / 10] seconds!"))
return ..()

/datum/controller/subsystem/airmachines/stat_entry(msg)
Expand Down
2 changes: 1 addition & 1 deletion code/controllers/subsystem/job.dm
Original file line number Diff line number Diff line change
Expand Up @@ -119,7 +119,7 @@ SUBSYSTEM_DEF(job)
if(!job.config_check())
continue
if(!job.map_check()) //Even though we initialize before mapping, this is fine because the config is loaded at new
testing("Removed [job.type] due to map config")
message_debug(DBG_INFO, "SSJob/SetupOccupations", "Removed [job.type] due to map config.")
continue
new_all_occupations += job
name_occupations[job.title] = job
Expand Down
10 changes: 5 additions & 5 deletions code/controllers/subsystem/mapping.dm
Original file line number Diff line number Diff line change
Expand Up @@ -294,7 +294,7 @@ Used by the AI doomsday and the self-destruct nuke.
z_list = SSmapping.z_list
multiz_levels = SSmapping.multiz_levels

#define INIT_ANNOUNCE(X) to_chat(world, span_debug("[X]")); log_world(X)
#define INIT_ANNOUNCE(X) to_chat(world, X); log_world(X)
/datum/controller/subsystem/mapping/proc/LoadGroup(list/errorList, name, path, files, list/traits, list/default_traits, silent = FALSE)
. = list()
var/start_time = REALTIMEOFDAY
Expand All @@ -319,7 +319,7 @@ Used by the AI doomsday and the self-destruct nuke.
for (var/i in 1 to total_z)
traits += list(default_traits)
else if (total_z != traits.len) // mismatch
INIT_ANNOUNCE("WARNING: [traits.len] trait sets specified for [total_z] z-levels in [path]!")
message_debug(DBG_WARN, "SSMapping/LoadGroup", "[traits.len] trait sets specified for [total_z] z-levels in [path]!", DBG_ALWAYS | DBG_LOG_WORLD)
if (total_z < traits.len) // ignore extra traits
traits.Cut(total_z + 1)
while (total_z > traits.len) // fall back to defaults on extra levels
Expand All @@ -342,7 +342,7 @@ Used by the AI doomsday and the self-destruct nuke.
errorList |= pm.original_path

if(!silent)
INIT_ANNOUNCE("Loaded [name] in [(REALTIMEOFDAY - start_time)/10]s!")
INIT_ANNOUNCE(span_debug_info("Loaded [name] in [(REALTIMEOFDAY - start_time)/10]s!"))
return parsed_maps

/datum/controller/subsystem/mapping/proc/loadWorld()
Expand All @@ -354,7 +354,7 @@ Used by the AI doomsday and the self-destruct nuke.

// load the station
station_start = world.maxz + 1
INIT_ANNOUNCE("Loading [config.map_name]...")
INIT_ANNOUNCE(span_debug_info("Loading [config.map_name]..."))
LoadGroup(FailedZs, "Station", config.map_path, config.map_file, config.traits, ZTRAITS_STATION)

if(SSdbcore.Connect())
Expand All @@ -377,7 +377,7 @@ Used by the AI doomsday and the self-destruct nuke.
for(var/I in 2 to FailedZs.len)
msg += ", [FailedZs[I]]"
msg += ". Yell at your server host!"
INIT_ANNOUNCE(msg)
INIT_ANNOUNCE(span_debug_error(msg))
#undef INIT_ANNOUNCE

// Custom maps are removed after station loading so the map files does not persist for no reason.
Expand Down
5 changes: 4 additions & 1 deletion code/controllers/subsystem/ticker.dm
Original file line number Diff line number Diff line change
Expand Up @@ -229,7 +229,10 @@ SUBSYSTEM_DEF(ticker)
SSjob.ResetOccupations()
return FALSE
else
message_admins(span_notice("DEBUG: Bypassing prestart checks..."))
if(can_continue)
message_debug(DBG_INFO, "SSTicker/setup", "Roundstart checks were skipped, but would have passed anyways.")
else
message_debug(DBG_WARN, "SSTicket/setup", "Roundstart checks failed. Bypassing due to live debugging.")

CHECK_TICK

Expand Down
2 changes: 1 addition & 1 deletion code/modules/admin/IsBanned.dm
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,7 @@
#define STICKYBAN_MAX_ADMIN_MATCHES 1

/world/IsBanned(key, address, computer_id, type, real_bans_only=FALSE)
debug_world_log("isbanned(): '[args.Join("', '")]'")
message_debug(DBG_TRACE, "World/IsBanned", "[args.Join("', '")]", NONE)
if (!key || (!real_bans_only && (!address || !computer_id)))
if(real_bans_only)
return FALSE
Expand Down
2 changes: 1 addition & 1 deletion code/modules/admin/admin_verbs.dm
Original file line number Diff line number Diff line change
Expand Up @@ -845,7 +845,7 @@ GLOBAL_PROTECT(admin_verbs_hideable)
if (tile)
var/mob/living/carbon/human/hooman = new(tile)
hooman.equipOutfit(pick(subtypesof(/datum/outfit)))
testing("Spawned test mob at [COORD(tile)]")
message_debug(DBG_TRACE, "PopulateWorld", "Spawned test mob at [COORD(tile)]")
while (!area && --j > 0)

/client/proc/toggle_AI_interact()
Expand Down
6 changes: 1 addition & 5 deletions code/modules/admin/ipintel.dm
Original file line number Diff line number Diff line change
Expand Up @@ -129,8 +129,4 @@
SSipintel.throttle = world.timeofday + (10 * 120 * SSipintel.errors)
else
error += " Attempting retry on [ip]."
log_ipintel(error)

/proc/log_ipintel(text)
log_game("IPINTEL: [text]")
debug_admins("IPINTEL: [text]")
message_debug(DBG_ERROR, "IPIntel", error)
4 changes: 2 additions & 2 deletions code/modules/admin/verbs/adminhelp.dm
Original file line number Diff line number Diff line change
Expand Up @@ -888,7 +888,7 @@ GLOBAL_DATUM_INIT(admin_help_ui_handler, /datum/admin_help_ui_handler, new)
*/
/proc/send2otherserver(source, msg, type = "Ahelp", target_servers, list/additional_data = list())
if(!CONFIG_GET(string/comms_key))
debug_world_log("Server cross-comms message not sent for lack of configured key")
message_debug(DBG_TRACE, "WorldComms/send2otherserver", "Server cross-comms message not sent for lack of configured key")
return

var/our_id = CONFIG_GET(string/cross_comms_name)
Expand All @@ -911,7 +911,7 @@ GLOBAL_DATUM_INIT(admin_help_ui_handler, /datum/admin_help_ui_handler, new)
if (auth)
var/comms_key = CONFIG_GET(string/comms_key)
if(!comms_key)
debug_world_log("Server cross-comms message not sent for lack of configured key")
message_debug(DBG_TRACE, "WorldComms/send_cross_comms", "Server cross-comms message not sent for lack of configured key")
return
message["key"] = comms_key
var/list/servers = CONFIG_GET(keyed_list/cross_server)
Expand Down
4 changes: 2 additions & 2 deletions code/modules/food_and_drinks/kitchen_machinery/processor.dm
Original file line number Diff line number Diff line change
Expand Up @@ -132,7 +132,7 @@
for(var/atom/movable/movable_input as anything in processor_contents)
var/datum/food_processor_process/recipe = PROCESSOR_SELECT_RECIPE(movable_input)
if (!recipe)
log_admin("DEBUG: [movable_input] in processor doesn't have a suitable recipe. How did it get in there? Please report it immediately!!!")
message_debug(DBG_ERROR, "FoodProcessor/interact", "[movable_input] in processor doesn't have a suitable recipe. Make a bug report.", DBG_ALWAYS | DBG_LOG_WORLD)
continue
total_time += recipe.time
var/offset = prob(50) ? -2 : 2
Expand All @@ -141,7 +141,7 @@
for(var/atom/movable/O in processor_contents)
var/datum/food_processor_process/P = PROCESSOR_SELECT_RECIPE(O)
if (!P)
log_admin("DEBUG: [O] in processor doesn't have a suitable recipe. How do you put it in?")
message_debug(DBG_ERROR, "FoodProcessor/interact", "[O] in processor doesn't have a suitable recipe. Make a bug report.", DBG_ALWAYS | DBG_LOG_WORLD)
continue
process_food(P, O)
pixel_x = base_pixel_x //return to its spot after shaking
Expand Down
2 changes: 1 addition & 1 deletion code/modules/reagents/chemistry/recipes.dm
Original file line number Diff line number Diff line change
Expand Up @@ -358,7 +358,7 @@
var/turf/target = locate(holder_turf.x + equilibrium.data["[id]_x"], holder_turf.y + equilibrium.data["[id]_y"], holder_turf.z)
//new /obj/effect/hotspot(target)
target.create_fire(1, 10)
debug_world("X: [equilibrium.data["[id]_x"]], Y: [equilibrium.data["[id]_x"]]")
message_debug(DBG_TRACE, "ChemReact/FireVortex", "X: [equilibrium.data["[id]_x"]], Y: [equilibrium.data["[id]_x"]]", NONE)

/*
* Creates a square of fire in a fire_range radius,
Expand Down
2 changes: 1 addition & 1 deletion code/modules/shuttle/shuttle.dm
Original file line number Diff line number Diff line change
Expand Up @@ -543,7 +543,7 @@
//call the shuttle to destination S
/obj/docking_port/mobile/proc/request(obj/docking_port/stationary/S)
if(!check_dock(S))
testing("check_dock failed on request for [src]")
message_debug(DBG_TRACE, "DockingPort/request", "check_dock failed on request for [src]")
return

if(mode == SHUTTLE_IGNITING && destination == S)
Expand Down
2 changes: 2 additions & 0 deletions daedalus.dme
Original file line number Diff line number Diff line change
Expand Up @@ -69,6 +69,7 @@
#include "code\__DEFINES\credits.dm"
#include "code\__DEFINES\cult.dm"
#include "code\__DEFINES\database.dm"
#include "code\__DEFINES\debug_messaging.dm"
#include "code\__DEFINES\decal_defines.dm"
#include "code\__DEFINES\devices.dm"
#include "code\__DEFINES\direction_junctions.dm"
Expand Down Expand Up @@ -345,6 +346,7 @@
#include "code\__HELPERS\construction.dm"
#include "code\__HELPERS\dates.dm"
#include "code\__HELPERS\datums.dm"
#include "code\__HELPERS\debug_messaging.dm"
#include "code\__HELPERS\dna.dm"
#include "code\__HELPERS\files.dm"
#include "code\__HELPERS\filters.dm"
Expand Down
38 changes: 38 additions & 0 deletions tgui/packages/tgui-panel/styles/goon/chat-dark.scss
Original file line number Diff line number Diff line change
Expand Up @@ -980,7 +980,45 @@ em {

.debug {
color: #5ce43d;
background-color: black;
font-weight: bold;
font-family: monospace;
border: 1px groove grey;
width: 80ch;
margin-top: 1px;
margin-bottom: 1px;
}

.debug_trace{
border-color: grey;
}
.debug_trace::before {
content: "TRACE|";
color:grey;
}

.debug_info {
border-color: cyan;
}
.debug_info::before {
content: "INFO|";
color:cyan;
}

.debug_warn {
border-color: orange;
}
.debug_warn::before {
content: "WARN|";
color:orange;
}

.debug_error {
border-color: red;
}
.debug_error::before {
content: "ERROR|";
color:red;
}

.adminpmbox {
Expand Down
Loading

0 comments on commit f5d173f

Please sign in to comment.