diff --git a/code/__DEFINES/logging.dm b/code/__DEFINES/logging.dm index 9cfe197c0ca..0883e7e5cbc 100644 --- a/code/__DEFINES/logging.dm +++ b/code/__DEFINES/logging.dm @@ -89,6 +89,7 @@ #define LOG_CATEGORY_TELECOMMS "telecomms" #define LOG_CATEGORY_TOOL "tool" #define LOG_CATEGORY_VIRUS "virus" +#define LOG_CATEGORY_QDEL "qdel" // Admin categories #define LOG_CATEGORY_ADMIN "admin" @@ -107,7 +108,6 @@ #define LOG_CATEGORY_DEBUG_LUA "debug-lua" #define LOG_CATEGORY_DEBUG_MAPPING "debug-mapping" #define LOG_CATEGORY_DEBUG_MOBTAG "debug-mobtag" -#define LOG_CATEGORY_DEBUG_QDEL "debug-qdel" #define LOG_CATEGORY_DEBUG_SQL "debug-sql" #define LOG_CATEGORY_DEBUG_TGUI "debug-tgui" @@ -140,6 +140,12 @@ #define LOG_CATEGORY_PDA_CHAT "pda-chat" #define LOG_CATEGORY_PDA_COMMENT "pda-comment" +// Flags that apply to the entry_flags var on logging categories +// These effect how entry datums process the inputs passed into them +/// Enables data list usage for readable log entries +/// You'll likely want to disable internal formatting to make this work properly +#define ENTRY_USE_DATA_W_READABLE (1<<0) + #define SCHEMA_VERSION "schema-version" // Default log schema version diff --git a/code/__HELPERS/logging/debug.dm b/code/__HELPERS/logging/debug.dm index 1a2685e0092..c4ed2f1086f 100644 --- a/code/__HELPERS/logging/debug.dm +++ b/code/__HELPERS/logging/debug.dm @@ -35,9 +35,8 @@ WRITE_LOG_NO_FORMAT(GLOB.perf_log, .) /// Logging for hard deletes -/// Done once, at roundend. Really just a text file -/proc/log_qdel(text) - WRITE_LOG(GLOB.world_qdel_log, "QDEL: [text]") +/proc/log_qdel(text, list/data) + logger.Log(LOG_CATEGORY_QDEL, text, data) /* Log to the logfile only. */ /proc/log_runtime(text, list/data) diff --git a/code/_globalvars/logging.dm b/code/_globalvars/logging.dm index 52ea9067421..4d0b0698679 100644 --- a/code/_globalvars/logging.dm +++ b/code/_globalvars/logging.dm @@ -32,7 +32,6 @@ GLOBAL_PROTECT(##log_var_name);\ // These should be used where the log category cannot easily be a json log file. DECLARE_LOG(config_error_log, DONT_START_LOG) DECLARE_LOG(perf_log, DONT_START_LOG) // Declared here but name is set in time_track subsystem -DECLARE_LOG_NAMED(world_qdel_log, "qdel", START_LOG) #ifdef REFERENCE_DOING_IT_LIVE DECLARE_LOG_NAMED(harddel_log, "harddels", START_LOG) diff --git a/code/controllers/subsystem/garbage.dm b/code/controllers/subsystem/garbage.dm index 6d297998fef..086fcd760c5 100644 --- a/code/controllers/subsystem/garbage.dm +++ b/code/controllers/subsystem/garbage.dm @@ -82,32 +82,36 @@ SUBSYSTEM_DEF(garbage) /datum/controller/subsystem/garbage/Shutdown() //Adds the del() log to the qdel log file - var/list/dellog = list() + var/list/del_log = list() //sort by how long it's wasted hard deleting sortTim(items, cmp=/proc/cmp_qdel_item_time, associative = TRUE) for(var/path in items) var/datum/qdel_item/I = items[path] - dellog += "Path: [path]" + var/list/entry = list() + del_log[path] = entry + if (I.qdel_flags & QDEL_ITEM_SUSPENDED_FOR_LAG) - dellog += "\tSUSPENDED FOR LAG" + entry["SUSPENDED FOR LAG"] = TRUE if (I.failures) - dellog += "\tFailures: [I.failures]" - dellog += "\tqdel() Count: [I.qdels]" - dellog += "\tDestroy() Cost: [I.destroy_time]ms" + entry["Failures"] = I.failures + entry["qdel() Count"] = I.qdels + entry["Destroy() Cost (ms)"] = I.destroy_time + if (I.hard_deletes) - dellog += "\tTotal Hard Deletes: [I.hard_deletes]" - dellog += "\tTime Spent Hard Deleting: [I.hard_delete_time]ms" - dellog += "\tHighest Time Spent Hard Deleting: [I.hard_delete_max]ms" + entry["Total Hard Deletes"] = I.hard_deletes + entry["Time Spend Hard Deleting (ms)"] = I.hard_delete_time + entry["Highest Time Spend Hard Deleting (ms)"] = I.hard_delete_max if (I.hard_deletes_over_threshold) - dellog += "\tHard Deletes Over Threshold: [I.hard_deletes_over_threshold]" + entry["Hard Deletes Over Threshold"] = I.hard_deletes_over_threshold if (I.slept_destroy) - dellog += "\tSleeps: [I.slept_destroy]" + entry["Total Sleeps"] = I.slept_destroy if (I.no_respect_force) - dellog += "\tIgnored force: [I.no_respect_force] times" + entry["Total Ignored Force"] = I.no_respect_force if (I.no_hint) - dellog += "\tNo hint: [I.no_hint] times" - log_qdel(dellog.Join("\n")) + entry["Total No Hint"] = I.no_hint + + log_qdel("", del_log) /datum/controller/subsystem/garbage/fire() //the fact that this resets its processing each fire (rather then resume where it left off) is intentional. @@ -278,7 +282,7 @@ SUBSYSTEM_DEF(garbage) #endif if (D.gc_destroyed <= 0) D.gc_destroyed = queue_time - + var/list/queue = queues[level] queue[++queue.len] = list(queue_time, refid, D.gc_destroyed) // not += for byond reasons diff --git a/code/modules/logging/categories/log_category_debug.dm b/code/modules/logging/categories/log_category_debug.dm index 417a56773d6..03b7d519547 100644 --- a/code/modules/logging/categories/log_category_debug.dm +++ b/code/modules/logging/categories/log_category_debug.dm @@ -39,7 +39,3 @@ category = LOG_CATEGORY_DEBUG_ASSET config_flag = /datum/config_entry/flag/log_asset master_category = /datum/log_category/debug - -/datum/log_category/debug_qdel - category = LOG_CATEGORY_DEBUG_QDEL - master_category = /datum/log_category/debug diff --git a/code/modules/logging/categories/log_category_misc.dm b/code/modules/logging/categories/log_category_misc.dm index 5cc77fed203..b24d13e94ec 100644 --- a/code/modules/logging/categories/log_category_misc.dm +++ b/code/modules/logging/categories/log_category_misc.dm @@ -56,3 +56,10 @@ /datum/log_category/speech_indicator category = LOG_CATEGORY_SPEECH_INDICATOR config_flag = /datum/config_entry/flag/log_speech_indicators + +// Logs seperately, printed into on server shutdown to store hard deletes and such +/datum/log_category/debug_qdel + category = LOG_CATEGORY_QDEL + // We want this human readable so it's easy to see at a glance + entry_flags = ENTRY_USE_DATA_W_READABLE + internal_formatting = FALSE diff --git a/code/modules/logging/log_category.dm b/code/modules/logging/log_category.dm index 82dcc57d0fe..fe86491b902 100644 --- a/code/modules/logging/log_category.dm +++ b/code/modules/logging/log_category.dm @@ -10,6 +10,10 @@ /// The master category that contains this category var/datum/log_category/master_category + /// Flags to apply to our /datum/log_entry's + /// See code/__DEFINES/logging/dm + var/entry_flags = NONE + /// If set this config flag is checked to enable this log category var/config_flag @@ -32,6 +36,7 @@ GENERAL_PROTECT_DATUM(/datum/log_category) timestamp = logger.human_readable_timestamp(), category = category, message = message, + flags = entry_flags, data = data, semver_store = semver_store, ) diff --git a/code/modules/logging/log_entry.dm b/code/modules/logging/log_entry.dm index 0f47cef6796..4b5bf19775b 100644 --- a/code/modules/logging/log_entry.dm +++ b/code/modules/logging/log_entry.dm @@ -24,6 +24,10 @@ /// Message of the log entry. var/message + /// Bitfield that describes how exactly to log stuff exactly + /// See code/__DEFINES/logging/dm + var/flags = NONE + /// Data of the log entry; optional. var/list/data @@ -32,12 +36,13 @@ GENERAL_PROTECT_DATUM(/datum/log_entry) -/datum/log_entry/New(timestamp, category, message, list/data, list/semver_store) +/datum/log_entry/New(timestamp, category, message, flags, list/data, list/semver_store) ..() src.id = next_id++ src.timestamp = timestamp src.category = category + src.flags = flags src.message = message with_data(data) with_semver_store(semver_store) @@ -62,10 +67,19 @@ GENERAL_PROTECT_DATUM(/datum/log_entry) /// Converts the log entry to a human-readable string. /datum/log_entry/proc/to_readable_text(format = TRUE) + var/output = "" if(format) - return "\[[timestamp]\] [uppertext(category)]: [message]" + output += "\[[timestamp]\] [uppertext(category)]: [message]" else - return "[message]" + output += "[message]" + + if(flags & ENTRY_USE_DATA_W_READABLE) +#if DM_VERSION >= 515 + output += json_encode(data, JSON_PRETTY_PRINT) +#else + output += json_encode(data) +#endif + return output /// Converts the log entry to a JSON string. /datum/log_entry/proc/to_json_text()