Logging fixes and catches (#79621)

THIS IS A REDO BECAUSE GITHUB SUCKS ASS

## About The Pull Request

Hardens logging against sudden and unexpected cases where we try to log
to a category that is not initialized or the file goes missing.

## Why It's Good For The Game

Logging needs to be robust and bullet proof

code/__DEFINES/_protect.dm

@@ -1,4 +1,5 @@
 ///Protects a datum from being VV'd or spawned through admin manipulation
+#ifndef TESTING
 #define GENERAL_PROTECT_DATUM(Path)\
 ##Path/can_vv_get(var_name){\
 	return FALSE;\
@@ -15,3 +16,6 @@
 ##Path/Write(savefile/savefile){\
 	return;\
 }
+#else
+#define GENERAL_PROTECT_DATUM(Path)
+#endif

code/__DEFINES/logging.dm

@@ -88,8 +88,9 @@
 #define LOG_ENTRY_KEY_ID "id"
 #define LOG_ENTRY_KEY_SCHEMA_VERSION "s-ver"
 
-// Category for invalid/missing categories
+// Internal categories
-#define LOG_CATEGORY_NOT_FOUND "invalid-category"
+#define LOG_CATEGORY_INTERNAL_CATEGORY_NOT_FOUND "internal-category-not-found"
+#define LOG_CATEGORY_INTERNAL_ERROR "internal-error"
 
 // Misc categories
 #define LOG_CATEGORY_ATTACK "attack"

code/modules/logging/categories/log_category_internal.dm

@@ -0,0 +1,6 @@
+/datum/log_category/internal
+	category = LOG_CATEGORY_INTERNAL_ERROR
+
+/datum/log_category/internal_unknown_category
+	category = LOG_CATEGORY_INTERNAL_CATEGORY_NOT_FOUND
+	master_category = /datum/log_category/internal

code/modules/logging/log_category.dm

@@ -20,6 +20,9 @@
 	/// Whether or not this log should not be publically visible
 	var/secret = FALSE
 
+	/// The list of header information for this category. Used for log file re-initialization
+	var/list/category_header
+
 	/// Whether the readable version of the log message is formatted internally instead of by rustg
 	/// IF YOU CHANGE THIS VERIFY LOGS ARE STILL PARSED CORRECTLY
 	var/internal_formatting = FALSE
@@ -32,10 +35,6 @@
 
 GENERAL_PROTECT_DATUM(/datum/log_category)
 
-/// Backup log category to catch attempts to log to a category that doesn't exist
-/datum/log_category/backup_category_not_found
-	category = LOG_CATEGORY_NOT_FOUND
-
 /// Add an entry to this category. It is very important that any data you provide doesn't hold references to anything!
 /datum/log_category/proc/create_entry(message, list/data, list/semver_store)
 	var/datum/log_entry/entry = new(

code/modules/logging/log_entry.dm

@@ -95,19 +95,33 @@ GENERAL_PROTECT_DATUM(/datum/log_entry)
 
 #undef MANUAL_JSON_ENTRY
 
+#define CHECK_AND_TRY_FILE_ERROR_RECOVERY(file) \
+	var/static/in_error_recovery = FALSE; \
+	if(!fexists(##file)) { \
+		if(in_error_recovery) { \
+			in_error_recovery = FALSE; \
+			CRASH("Failed to error recover log file: [file]"); \
+		}; \
+		in_error_recovery = TRUE; \
+		logger.Log(LOG_CATEGORY_INTERNAL_ERROR, "attempting to perform file error recovery: [file]"); \
+		logger.init_category_file(logger.log_categories[category]); \
+		call(src, __PROC__)(arglist(args)); \
+		return; \
+	}; \
+	in_error_recovery = FALSE;
+
 /// Writes the log entry to a file.
 /datum/log_entry/proc/write_entry_to_file(file)
-	if(!fexists(file))
+	CHECK_AND_TRY_FILE_ERROR_RECOVERY(file)
-		CRASH("Attempted to log to an uninitialized file: [file]")
 	WRITE_LOG_NO_FORMAT(file, "[to_json_text()]\n")
 
 /// Writes the log entry to a file as a human-readable string.
 /datum/log_entry/proc/write_readable_entry_to_file(file, format_internally = TRUE)
-	if(!fexists(file))
+	CHECK_AND_TRY_FILE_ERROR_RECOVERY(file)
-		CRASH("Attempted to log to an uninitialized file: [file]")
-
 	// If it's being formatted internally we need to manually add a newline
 	if(format_internally)
 		WRITE_LOG_NO_FORMAT(file, "[to_readable_text(format = TRUE)]\n")
 	else
 		WRITE_LOG(file, "[to_readable_text(format = FALSE)]")
+
+#undef CHECK_AND_TRY_FILE_ERROR_RECOVERY

code/modules/logging/log_holder.dm

@@ -107,7 +107,7 @@ GENERAL_PROTECT_DATUM(/datum/log_holder)
 		return
 
 	switch(action)
-		if("refresh")
+		if("re-render")
 			cache_ui_data()
 			SStgui.update_uis(src)
 			return TRUE
@@ -206,6 +206,42 @@ GENERAL_PROTECT_DATUM(/datum/log_holder)
 
 	return category_tree
 
+/// Log entry header used to mark a file is being reset
+#define LOG_CATEGORY_RESET_FILE_MARKER "{\"LOG FILE RESET -- THIS IS AN ERROR\"}"
+#define LOG_CATEGORY_RESET_FILE_MARKER_READABLE "LOG FILE RESET -- THIS IS AN ERROR"
+/// Gets a recovery file for the given path. Caches the last known recovery path for each path.
+/datum/log_holder/proc/get_recovery_file_for(path)
+	var/static/cache
+	if(isnull(cache))
+		cache = list()
+
+	var/count = cache[path] || 0
+	while(fexists("[path].rec[count]"))
+		count++
+	cache[path] = count
+
+	return "[path].rec[count]"
+
+/// Sets up the given category's file and header.
+/datum/log_holder/proc/init_category_file(datum/log_category/category)
+	var/file_path = category.get_output_file(null)
+	if(fexists(file_path)) // already exists? implant a reset marker
+		rustg_file_append(LOG_CATEGORY_RESET_FILE_MARKER, file_path)
+		fcopy(file_path, get_recovery_file_for(file_path))
+	rustg_file_write("[json_encode(category.category_header)]\n", file_path)
+
+	if(!human_readable_enabled)
+		return
+
+	file_path = category.get_output_file(null, "log")
+	if(fexists(file_path))
+		rustg_file_append(LOG_CATEGORY_RESET_FILE_MARKER_READABLE, file_path)
+		fcopy(file_path, get_recovery_file_for(file_path))
+	rustg_file_write("\[[human_readable_timestamp()]\] Starting up round ID [round_id].\n - -------------------------\n", file_path)
+
+#undef LOG_CATEGORY_RESET_FILE_MARKER
+#undef LOG_CATEGORY_RESET_FILE_MARKER_READABLE
+
 /// Initializes the given log category and populates the list of contained categories based on the sub category list
 /datum/log_holder/proc/init_log_category(datum/log_category/category_type, list/datum/log_category/sub_categories)
 	var/datum/log_category/category_instance = new category_type
@@ -239,9 +275,8 @@ GENERAL_PROTECT_DATUM(/datum/log_holder)
 		LOG_HEADER_CATEGORY = category_instance.category,
 	)
 
-	rustg_file_write("[json_encode(category_header)]\n", category_instance.get_output_file(null))
+	category_instance.category_header = category_header
-	if(human_readable_enabled)
+	init_category_file(category_instance, category_header)
-		rustg_file_write("\[[human_readable_timestamp()]\] Starting up round ID [round_id].\n - -------------------------\n", category_instance.get_output_file(null, "log"))
 
 /datum/log_holder/proc/human_readable_timestamp(precision = 3)
 	var/start = time2text(world.timeofday, "YYYY-MM-DD hh:mm:ss")
@@ -270,7 +305,7 @@ GENERAL_PROTECT_DATUM(/datum/log_holder)
 		stack_trace("Logging with a non-text message")
 
 	if(!category)
-		category = LOG_CATEGORY_NOT_FOUND
+		category = LOG_CATEGORY_INTERNAL_CATEGORY_NOT_FOUND
 		stack_trace("Logging with a null or empty category")
 
 	if(data && !islist(data))
@@ -286,7 +321,7 @@ GENERAL_PROTECT_DATUM(/datum/log_holder)
 
 	var/datum/log_category/log_category = log_categories[category]
 	if(!log_category)
-		Log(LOG_CATEGORY_NOT_FOUND, message, data)
+		Log(LOG_CATEGORY_INTERNAL_CATEGORY_NOT_FOUND, message, data)
 		CRASH("Attempted to log to a category that doesn't exist! [category]")
 
 	var/list/semver_store = null

tgstation.dme

@@ -4263,6 +4263,7 @@
 #include "code\modules\logging\categories\log_category_debug.dm"
 #include "code\modules\logging\categories\log_category_game.dm"
 #include "code\modules\logging\categories\log_category_href.dm"
+#include "code\modules\logging\categories\log_category_internal.dm"
 #include "code\modules\logging\categories\log_category_misc.dm"
 #include "code\modules\logging\categories\log_category_pda.dm"
 #include "code\modules\logging\categories\log_category_silo.dm"