diff --git a/code/dbgprint.cpp b/code/dbgprint.cpp index 34935f46a..6bd6096da 100644 --- a/code/dbgprint.cpp +++ b/code/dbgprint.cpp @@ -16,20 +16,40 @@ #include "dbgprint.h" #include "opents_build.h" + +#ifdef _WIN32 #include "win.h" +#include #include +#else +#include +#endif -#include -#include -#include +#ifdef __APPLE__ +// For parsing .plist files. +#include +#endif + +#include +#include #include +#include #include -#include -#include +#include +#include +#include +#include +#include +#include +#include +#include #include +#include +#include +#include -#define CONSOLE_WINDOW_NAME "Debug Console" +#define CONSOLE_WINDOW_NAME "Debug Console" #ifdef _DEBUG static char const BuildType[] = "debug"; @@ -37,143 +57,318 @@ static char const BuildType[] = "debug"; static char const BuildType[] = "release"; #endif -static char const DebugTruncationNotice[] = "\n*** Log size limit reached. Nothing further will be written to this file. ***\n"; +static char const DebugTruncationNotice[] = "\n\n*** Log size limit reached. Nothing further will be written to this file. ***\n"; static constexpr size_t DEBUG_MESSAGE_MAX = 4096; static constexpr unsigned DEBUG_LOG_MAX_AGE_DAYS = 14; -static constexpr unsigned __int64 DEBUG_LOG_MAX_BYTES = 64ui64 * 1024ui64 * 1024ui64; -static constexpr unsigned __int64 DEBUG_LOG_NOTICE_RESERVE = sizeof(DebugTruncationNotice) - 1; -static constexpr unsigned __int64 DEBUG_LOG_BUDGET = DEBUG_LOG_MAX_BYTES - DEBUG_LOG_NOTICE_RESERVE; +static constexpr uint64_t DEBUG_LOG_MAX_BYTES = (uint64_t)64 * 1024 * 1024; +static constexpr uint64_t DEBUG_LOG_NOTICE_RESERVE = sizeof(DebugTruncationNotice) - 1; +static constexpr uint64_t DEBUG_LOG_BUDGET = DEBUG_LOG_MAX_BYTES - DEBUG_LOG_NOTICE_RESERVE; static constexpr size_t DEBUG_CONSOLE_REPLAY_MAX = 64 * 1024; -static SRWLOCK DebugLock = SRWLOCK_INIT; -static DWORD DebugLockOwner = 0; -static bool DebugInitDone = false; -static bool AtLineStart = true; -static bool ConsoleActive = false; -static HANDLE DebugFile = INVALID_HANDLE_VALUE; -static HANDLE DebugConsole = INVALID_HANDLE_VALUE; -static char DebugDirectory[MAX_PATH]; -static char DebugFileName[MAX_PATH]; -static unsigned __int64 DebugBytesWritten = 0; - -// Text logged before the console opens, written to it when it does. Past the limit, the rest -// of that text is in the log file only. -static std::string ConsoleReplay; +typedef std::chrono::time_point system_time_point; + +class EarlyInitMessage +{ + public: + EarlyInitMessage(const system_time_point & timestamp_utc_in, const std::string_view & text_in, bool with_prefix_in) : + timestamp_utc(timestamp_utc_in), + text(text_in), + with_prefix(with_prefix_in) + { + } + + system_time_point timestamp_utc; + std::string text; + bool with_prefix; +}; + +// Lazy Initialization singleton to make sure the module's state is valid +// when accessed through static initializers. +class DebugPrint +{ + private: + DebugPrint() : + Initialized(false), + Destroyed(false), + AtLineStart(true), + ConsoleActive(false), + File(NULL), + FileBytesWritten(0), + UTCtoLocal_sec(0), + ArgsConsoleRequested(false), + ArgsFullCommandLine(u8"(unknown)") + { + } + + ~DebugPrint() + { + if (!Initialized && EarlyLogReplay.has_value()) { + std::cerr << "Warning: Messages logged with DebugString(), but Debug_Init() was never called!" << std::endl; + } + if (File) { + fclose(File); + File = NULL; + } + Destroyed = true; + } + + public: + static DebugPrint & instance(void) + { + static DebugPrint global_state; + return global_state; + } + + template + void Debug_Command_Line_Parse(int argc, const T * argv[]); + std::filesystem::path Get_Logging_Directory(void); + bool Enable_Console_Locked(void); + void Init_Locked(void); + void Write_Text_Locked(char const * text, size_t length); + void Write_Message_Locked(char const * buffer, size_t length, bool with_prefix, const system_time_point * msg_ts = NULL); + void Write_Banner_Locked(const system_time_point & started_utc); + void Emit(char const * buffer, size_t length, bool with_prefix); + + // Recursive mutex allows calling debug functions from within debug functions. + std::recursive_mutex Lock; + bool Initialized; + bool Destroyed; + bool AtLineStart; + bool ConsoleActive; + std::filesystem::path Directory; + std::filesystem::path FilePath; + // C++20 doesn't support std::ios::noreplace (added in C++23), uset C API with "x" flag. + FILE * File; + uint64_t FileBytesWritten; + // Needed for fast timestamp evaluation. Not accurate when running the game during a DST switch. + std::chrono::seconds::rep UTCtoLocal_sec; + + // Information collected from command-line arguments. + bool ArgsConsoleRequested; + std::u8string ArgsUserDirectory; + std::u8string ArgsFullCommandLine; + + // Text logged before Debug_Init() is called. No limit is in place, it's expected that only + // a handful of messages will be generated by static initializers of other modules. Destroyed + // after Debug_Init() is called. + std::optional> EarlyLogReplay; + + // Text logged before the console opens, written to it when it does. Past the limit, the rest + // of that text is in the log file only. Destroyed after the console is opened. + std::optional ConsoleReplay; +}; + +static void Assign_Arg_String(std::u8string & arg_str, const std::u8string_view & value, const std::u8string_view & defVal) +{ + (void)defVal; + arg_str = value; +} + +#ifdef _WIN32 +static void Assign_Arg_String(std::u8string & arg_str, const std::wstring_view & val_str, const std::u8string_view & defVal) +{ + int buf_siz = WideCharToMultiByte(CP_UTF8, 0, val_str.data(), val_str.size(), NULL, 0, NULL, NULL); + if (buf_siz > 0) { + arg_str.resize(buf_siz); + int conv_count = WideCharToMultiByte(CP_UTF8, 0, val_str.data(), val_str.size(), reinterpret_cast(arg_str.data()), arg_str.size(), NULL, NULL); + if (conv_count > 0) { + // Should realistically never happen, but just to be sure. + if (conv_count < arg_str.size()) { + arg_str.resize(conv_count); + } + + // success + return; + } + } + arg_str = defVal; +} +#endif /// -/// Reports whether the command line asks for the debug console. The game's own parser runs -/// too late to catch the messages written during early startup, so the raw command line is -/// read here instead. +/// Parse the command-line arguments relevant for the debug print module. The game's +/// own parser runs too late to catch the messages written during early startup, +/// so the raw command line is read here instead. /// -static bool Command_Line_Requests_Console(void) +template +void DebugPrint::Debug_Command_Line_Parse(int argc, const T * argv[]) { - int argc = 0; - LPWSTR * argv = CommandLineToArgvW(GetCommandLineW(), &argc); - if (argv == NULL) { - return(false); + return; } - bool requested = false; + bool console_requested = false; + std::basic_string full_cmdline; + std::basic_string user_dir; // Index zero is the executable path, which may itself look like an option. - for (int index = 1; index < argc && !requested; index++) { - wchar_t const * token = argv[index]; - - if (token[0] != L'-' || (token[1] != L'X' && token[1] != L'x')) { - continue; + for (int index = 1; index < argc; index++) { + T const * token = argv[index]; + + if (token[0] == L'-' && (token[1] == L'X' || token[1] == L'x')) { + for (T const * code = token + 2; *code != L'\0'; code++) { + if (*code == L'C' || *code == L'c') { + console_requested = true; + break; + } + } } - for (wchar_t const * code = token + 2; *code != L'\0'; code++) { - if (*code == L'C' || *code == L'c') { - requested = true; - break; + if constexpr (sizeof(T) == 1) { + + const char * prefix = "-USERDIR="; + size_t prefix_len = strlen(prefix); + size_t token_len = strlen(reinterpret_cast(token)); + + if (token_len >= prefix_len && strnicmp(reinterpret_cast(token), prefix, prefix_len) == 0) { + user_dir = std::basic_string(&token[prefix_len], token_len - prefix_len); + } + } else { + const wchar_t * prefix = L"-USERDIR="; + size_t prefix_len = wcslen(prefix); + size_t token_len = wcslen(token); + + if (token_len >= prefix_len && _wcsnicmp(token, prefix, prefix_len) == 0) { + user_dir = std::basic_string(&token[prefix_len], token_len - prefix_len); } } - } - LocalFree(argv); - return(requested); + // The arguments only. The executable path usually carries the account name, and re-joining + // the arguments loses the shell's original quoting, which a diagnostic can live without. + if (index > 1) { + full_cmdline.push_back(L' '); + } + full_cmdline += token; + } + if (full_cmdline.empty()) { + ArgsFullCommandLine = u8"(none)"; + } else { + Assign_Arg_String(ArgsFullCommandLine, full_cmdline, u8"(unknown)"); + } + if (!user_dir.empty()) { + Assign_Arg_String(ArgsUserDirectory, user_dir, u8""); + } + if (console_requested) { + ArgsConsoleRequested = true; + } } /// -/// Deletes files matching a pattern that were last written more than the given number of days -/// ago. Directories are never removed. +/// Get the location of the directory appropriate for storing logs for OpenTS. /// -/// Directory to search, without a trailing separator. -/// File name pattern, such as "DEBUG_*.LOG". -/// Age threshold in days. Values above 90 are rejected. -/// True if the directory was searched. -bool Delete_Files_Older_Than(char const * directory, char const * pattern, unsigned days) +std::filesystem::path DebugPrint::Get_Logging_Directory(void) { - if (directory == NULL || pattern == NULL || days > 90) { - return(false); + if (!ArgsUserDirectory.empty()) { + return std::filesystem::path(ArgsUserDirectory) / u8"Debug"; } - SYSTEMTIME now; - FILETIME now_stamp; - GetSystemTime(&now); - if (!SystemTimeToFileTime(&now, &now_stamp)) { - return(false); +#if defined(_WIN32) + + std::vector path_buf; + path_buf.resize(MAX_PATH); + + DWORD path_len = 0; + bool path_truncated; + do { + path_len = GetModuleFileNameW(GetModuleHandle(NULL), path_buf.data(), path_buf.size()); + path_truncated = false; + + if (path_len == 0) { + break; + } else if (path_len == path_buf.size()) { + path_buf.resize(path_buf.size() * 2); + path_truncated = true; + } + } while (path_truncated); + + if (path_len > 0) { + return std::filesystem::path(std::wstring_view(path_buf.data(), path_len)).remove_filename() / u8"Debug"; } - ULARGE_INTEGER cutoff; - cutoff.LowPart = now_stamp.dwLowDateTime; - cutoff.HighPart = now_stamp.dwHighDateTime; +#elif defined(__APPLE__) - unsigned __int64 const age = (unsigned __int64)days * 24ui64 * 60ui64 * 60ui64 * 10000000ui64; - if (cutoff.QuadPart < age) { - return(false); + const char * home_path = getenv("HOME"); + if (home_path != NULL && home_path[0] != '\0') { + return std::filesystem::path(std::u8string_view((const char8_t *)home_path, strlen(home_path))) / u8"Library" / u8"Logs" / u8"OpenTS"; } - cutoff.QuadPart -= age; - char search[MAX_PATH]; - snprintf(search, sizeof(search), "%s\\%s", directory, pattern); +#else + const char * state_path = getenv("XDG_STATE_HOME"); + if (state_path != NULL && state_path[0] != '\0') { + return std::filesystem::path(std::u8string_view((const char8_t *)state_path, strlen(state_path))) / u8"OpenTS"; + } - WIN32_FIND_DATA found; - HANDLE search_handle = FindFirstFile(search, &found); - if (search_handle == INVALID_HANDLE_VALUE) { - return(false); + const char * home_path = getenv("HOME"); + if (home_path != NULL && home_path[0] != '\0') { + return std::filesystem::path(std::u8string_view((const char8_t *)home_path, strlen(home_path))) / u8".local" / u8"state" / u8"OpenTS"; } +#endif - do { - if ((found.dwFileAttributes & FILE_ATTRIBUTE_DIRECTORY) != 0) { - continue; - } + // If all else fails, store logs in the CWD + return std::filesystem::path(".") / "OpenTS-Logs"; +} - ULARGE_INTEGER written; - written.LowPart = found.ftLastWriteTime.dwLowDateTime; - written.HighPart = found.ftLastWriteTime.dwHighDateTime; +/// +/// Deletes files matching a pattern that were last written more than the given number of days +/// ago. Directories are never removed. +/// +/// Directory to search. +/// File name regex pattern, such as "DEBUG_.*\\.LOG". +/// Age threshold in days. +/// True if the directory was searched. +bool Delete_Files_Older_Than(const std::filesystem::path & directory, const std::string_view & pattern, unsigned int days) +{ + if (directory.empty() || pattern.empty()) { + return (false); + } - if (written.QuadPart == 0 || written.QuadPart >= cutoff.QuadPart) { - continue; + // Use "native encoding" regex - not perfect, but should be good enough. + // FIXME: Use ICU for proper UTF-8 regex support. + std::regex regex(pattern.cbegin(), pattern.cend(), std::regex::basic | std::regex::icase); + + std::chrono::time_point now = std::chrono::file_clock::now(); + std::chrono::time_point cutoff = now - std::chrono::days(days); + std::vector to_remove; + bool dir_searched = false; + + std::error_code ec; + for (auto iter = std::filesystem::directory_iterator {directory, ec}; iter != end(iter); iter.increment(ec)) { + if (ec) { + break; } + const std::filesystem::directory_entry & dir_entry = *iter; + const std::u8string fname = dir_entry.path().filename().u8string(); + const std::string_view fname_cast((const char *)fname.data(), fname.size()); - char victim[MAX_PATH]; - snprintf(victim, sizeof(victim), "%s\\%s", directory, found.cFileName); - DeleteFile(victim); + if (std::regex_match(fname_cast.cbegin(), fname_cast.cend(), regex) && dir_entry.last_write_time() < cutoff && !dir_entry.is_directory()) { - } while (FindNextFile(search_handle, &found)); + to_remove.push_back(dir_entry.path()); + } + dir_searched = true; + } + for (auto const & path : to_remove) { + std::filesystem::remove(path, ec); + } - FindClose(search_handle); - return(true); + return dir_searched; } +#ifdef _WIN32 /// /// Allocates the console and points the standard streams at it. The caller holds the logging /// lock. /// -static void Init_Console_Locked(void) +bool DebugPrint::Enable_Console_Locked(void) { if (ConsoleActive) { - return; + return true; } - if (!AllocConsole()) { - return; + if (!Initialized || !AllocConsole()) { + return false; } SetConsoleTitle(CONSOLE_WINDOW_NAME); @@ -203,7 +398,7 @@ static void Init_Console_Locked(void) SetStdHandle(STD_INPUT_HANDLE, input); } - DebugConsole = GetStdHandle(STD_OUTPUT_HANDLE); + HANDLE DebugConsole = GetStdHandle(STD_OUTPUT_HANDLE); if (DebugConsole == NULL) { DebugConsole = INVALID_HANDLE_VALUE; } @@ -229,15 +424,75 @@ static void Init_Console_Locked(void) ConsoleActive = true; - if (DebugConsole != INVALID_HANDLE_VALUE && !ConsoleReplay.empty()) { + if (DebugConsole != INVALID_HANDLE_VALUE && ConsoleReplay.has_value() && !ConsoleReplay->empty()) { DWORD actual; - WriteConsole(DebugConsole, ConsoleReplay.data(), (DWORD)ConsoleReplay.size(), &actual, NULL); + WriteConsole(DebugConsole, ConsoleReplay->data(), (DWORD)ConsoleReplay->size(), &actual, NULL); } - std::string().swap(ConsoleReplay); + ConsoleReplay.reset(); + return true; } +#else + +/// +/// Enables logging to the console. Expects that the system can handle UTF-8 +/// by default, only very old UNIX systems do not. The caller holds +/// the logging lock. +/// +bool DebugPrint::Enable_Console_Locked(void) +{ + if (ConsoleActive) { + return true; + } + + if (!Initialized) { + return false; + } -static void Write_Banner_Locked(SYSTEMTIME const & started); + ConsoleActive = true; + + if (ConsoleReplay.has_value() && !ConsoleReplay->empty()) { + std::cout << *ConsoleReplay; + std::cout.flush(); + } + ConsoleReplay.reset(); + return true; +} +#endif + + +/// +/// Determines the time difference in seconds between the specified reference time in UTC +/// and the local time. Useful for determining the current local time from system_clock +/// timestamps, but only accurate until the next DST switch. +/// +static std::chrono::seconds Get_UTC_Local_Offset(system_time_point reference_time) +{ + time_t utc_time = std::chrono::system_clock::to_time_t(reference_time); + struct tm buf; + +#ifdef _WIN32 + errno_t rc = localtime_s(&buf, &utc_time); + if (rc != 0) { + return std::chrono::seconds(0); + } +#else + struct tm * ret = localtime_r(&utc_time, &buf); + if (ret == NULL) { + return std::chrono::seconds(0); + } +#endif + system_time_point ref_time_rounded = std::chrono::system_clock::from_time_t(utc_time); + const auto ref_time_sec_tp = std::chrono::time_point_cast(ref_time_rounded); + const auto ref_time_secs = ref_time_sec_tp.time_since_epoch().count(); + + // C++20 specifies that system_clock timestamps are in Unix time, so the following calculations should be accurate: + int delta_secs = buf.tm_sec - (ref_time_secs % 60); + int delta_mins = buf.tm_min - ((ref_time_secs / 60) % 60); + int delta_hours = buf.tm_hour - (((ref_time_secs / 60) / 60) % 24); + + return std::chrono::seconds((((delta_hours * 60) + delta_mins) * 60) + delta_secs); +} /// @@ -245,105 +500,171 @@ static void Write_Banner_Locked(SYSTEMTIME const & started); /// line asks for it. The caller holds the logging lock. A log that cannot be opened leaves the /// debugger and console sinks working. /// -static void Init_Locked(void) +void DebugPrint::Init_Locked(void) { - if (DebugInitDone) { + if (Initialized) { return; } - DebugInitDone = true; - char path_to_exe[MAX_PATH]; - char drive[_MAX_DRIVE]; - char dir[_MAX_DIR]; + system_time_point now_utc; - // The log belongs beside the executable, which is not yet the current directory. - if (GetModuleFileName(GetModuleHandle(NULL), path_to_exe, sizeof(path_to_exe)) != 0) { - _splitpath(path_to_exe, drive, dir, NULL, NULL); - snprintf(DebugDirectory, sizeof(DebugDirectory), "%s%sDebug", drive, dir); + if (EarlyLogReplay.has_value() && !EarlyLogReplay->empty()) { + now_utc = (*EarlyLogReplay)[0].timestamp_utc; + } else { + now_utc = std::chrono::system_clock::now(); } - SYSTEMTIME now; - GetLocalTime(&now); + // Evaluate local timezone offset needed for fast timestamp generation. + const auto utc_offset = Get_UTC_Local_Offset(now_utc); + UTCtoLocal_sec = utc_offset.count(); - char timestamp[32]; - snprintf(timestamp, sizeof(timestamp), "%02u-%02u-%04u_%02u-%02u-%02u", - now.wDay, now.wMonth, now.wYear, now.wHour, now.wMinute, now.wSecond); + // Round down the time to seconds, to avoid showing decimal digits in formatted string. + const auto now_local_sec = std::chrono::time_point_cast(now_utc + utc_offset); + Directory = Get_Logging_Directory(); - if (DebugDirectory[0] != '\0' - && (CreateDirectory(DebugDirectory, NULL) || GetLastError() == ERROR_ALREADY_EXISTS)) { + if (File != NULL) { + fclose(File); + File = NULL; + } - Delete_Files_Older_Than(DebugDirectory, "DEBUG_*.LOG", DEBUG_LOG_MAX_AGE_DAYS); + std::error_code ec; + std::filesystem::create_directories(Directory, ec); + if (ec) { + Directory.clear(); + } else { + Delete_Files_Older_Than(Directory, "DEBUG_.*\\.LOG", DEBUG_LOG_MAX_AGE_DAYS); + FilePath = Directory / std::format("DEBUG_{:%d-%m-%Y_%H-%M-%S}.LOG", now_local_sec); - snprintf(DebugFileName, sizeof(DebugFileName), "%s\\DEBUG_%s.LOG", DebugDirectory, timestamp); - DebugFile = CreateFile(DebugFileName, GENERIC_WRITE, FILE_SHARE_READ, NULL, - CREATE_NEW, FILE_ATTRIBUTE_NORMAL, NULL); +#ifdef _WIN32 + File = _wfopen(FilePath.c_str(), L"wxb"); +#else + File = fopen(FilePath.c_str(), "wxb"); +#endif // A second process started in the same second must not disturb the first one's log. - if (DebugFile == INVALID_HANDLE_VALUE) { - snprintf(DebugFileName, sizeof(DebugFileName), "%s\\DEBUG_%s_%lu.LOG", - DebugDirectory, timestamp, GetCurrentProcessId()); - DebugFile = CreateFile(DebugFileName, GENERIC_WRITE, FILE_SHARE_READ, NULL, - CREATE_NEW, FILE_ATTRIBUTE_NORMAL, NULL); + if (File == NULL) { +#ifdef _WIN32 + DWORD process_id = GetCurrentProcessId(); +#else + pid_t process_id = getpid(); +#endif + FilePath = Directory / std::format("DEBUG_{:%d-%m-%Y_%H-%M-%S}_{}.LOG", now_local_sec, process_id); + +#ifdef _WIN32 + File = _wfopen(FilePath.c_str(), L"wxb"); +#else + File = fopen(FilePath.c_str(), "wxb"); +#endif } - if (DebugFile == INVALID_HANDLE_VALUE) { - DebugFileName[0] = '\0'; + if (File == NULL) { + FilePath.clear(); } } + Initialized = true; - if (Command_Line_Requests_Console()) { - Init_Console_Locked(); + if (ArgsConsoleRequested) { + Enable_Console_Locked(); } // Last, so that the banner heads the log and also reaches a console that has just opened. - Write_Banner_Locked(now); + Write_Banner_Locked(now_utc); + + if (EarlyLogReplay.has_value()) { + for (const EarlyInitMessage & msg : *EarlyLogReplay) { + Write_Message_Locked(msg.text.data(), msg.text.size(), msg.with_prefix, &msg.timestamp_utc); + } + } + EarlyLogReplay.reset(); } /// /// Writes raw text to every enabled sink. The caller holds the logging lock. +/// The string buffer must be zero-terminated for OutputDebugString() to work correctly. +/// When the text ends with a newline, the output buffers are flushed, so that the latest +/// record is available in case of an imminent crash. /// -static void Write_Text_Locked(char const * text, size_t length) +/// String buffer to write. Must be zero-terminated. +/// Number of bytes in text to write. +void DebugPrint::Write_Text_Locked(char const * text, size_t length) { - DWORD actual; + if (text == NULL || length == 0) { + return; + } + + bool should_flush = false; + if (text[length - 1] == '\n') { + should_flush = true; + } + + if (File != NULL && !ferror(File)) { - if (DebugFile != INVALID_HANDLE_VALUE) { + size_t file_bytes_total = std::min(FileBytesWritten + length, DEBUG_LOG_BUDGET); + if (file_bytes_total > FileBytesWritten) { + fwrite(text, 1, file_bytes_total - FileBytesWritten, File); + FileBytesWritten = file_bytes_total; + } // The notice is paid for out of the reserve, so the file never passes its limit. - if (DebugBytesWritten + length > DEBUG_LOG_BUDGET) { - WriteFile(DebugFile, DebugTruncationNotice, (DWORD)DEBUG_LOG_NOTICE_RESERVE, &actual, NULL); - CloseHandle(DebugFile); - DebugFile = INVALID_HANDLE_VALUE; - } else { - WriteFile(DebugFile, text, (DWORD)length, &actual, NULL); - DebugBytesWritten += length; + if (file_bytes_total == DEBUG_LOG_BUDGET) { + fwrite(DebugTruncationNotice, 1, DEBUG_LOG_NOTICE_RESERVE, File); + fclose(File); + File = NULL; + } else if (should_flush) { + fflush(File); } + + } else if (File != NULL) { + fclose(File); + File = NULL; } +#ifdef _WIN32 // Reporting to a debugger that is not there costs an exception round trip per message, // which is far more than the rest of this function put together. if (IsDebuggerPresent()) { OutputDebugString(text); } +#endif if (ConsoleActive) { - if (DebugConsole != INVALID_HANDLE_VALUE) { - WriteConsole(DebugConsole, text, (DWORD)length, &actual, NULL); + std::cout.write(text, length); + if (should_flush) { + std::cout.flush(); + } + } else { + if (!ConsoleReplay.has_value()) { + ConsoleReplay.emplace(); + } + if (ConsoleReplay->size() + length <= DEBUG_CONSOLE_REPLAY_MAX) { + ConsoleReplay->append(text, length); } - } else if (ConsoleReplay.size() + length <= DEBUG_CONSOLE_REPLAY_MAX) { - ConsoleReplay.append(text, length); } } /// /// Writes one finished message, stamping the record prefix when one is due. The caller holds -/// the logging lock. +/// the logging lock. The string buffer must be zero-terminated for OutputDebugString() +/// to work correctly. In the event that Debug_Init() had not yet been called, the message +/// is recorded for processing at a later time. /// -static void Write_Message_Locked(char const * buffer, bool with_prefix) +/// String buffer to write. Must be zero-terminated. +/// Length of the string in the provided buffer. +/// Whether or not to stamp the message. +/// Optional timestamp associated with the message. +void DebugPrint::Write_Message_Locked(char const * buffer, size_t length, bool with_prefix, const system_time_point * msg_ts) { - size_t const length = strlen(buffer); - if (length == 0) { + if (length == 0 || buffer == NULL) { + return; + } + + if (!Initialized) { + if (!EarlyLogReplay.has_value()) { + EarlyLogReplay.emplace(); + } + EarlyLogReplay->emplace_back(std::chrono::system_clock::now(), std::string_view(buffer, length), with_prefix); return; } @@ -351,19 +672,26 @@ static void Write_Message_Locked(char const * buffer, bool with_prefix) // line assembled from several calls is stamped where it starts. Prefix and message go out // together to keep this to one write per call. if (with_prefix && AtLineStart) { - SYSTEMTIME now; - GetLocalTime(&now); - - char stamped[DEBUG_MESSAGE_MAX + 32]; - int const written = snprintf(stamped, sizeof(stamped), "[%02u:%02u:%02u.%03u] %s", - now.wHour, now.wMinute, now.wSecond, now.wMilliseconds, buffer); - if (written > 0) { - // snprintf reports the length it wanted, which is not what was stored. - size_t const kept = std::min(size_t(written), sizeof(stamped) - 1); - Write_Text_Locked(stamped, kept); - AtLineStart = buffer[length - 1] == '\n'; - return; + system_time_point now_utc; + + if (msg_ts != NULL) { + now_utc = *msg_ts; + } else { + now_utc = std::chrono::system_clock::now(); } + const auto now_utc_millis = std::chrono::time_point_cast(now_utc); + + // Evaluation using std::chrono::current_zone()->to_local() and std::format() too slow under Debug build. + // This approach trades accuracy for speed, e.g. showing the wrong time if a DST switch happens while the game is running. + auto millis = now_utc_millis.time_since_epoch().count(); + auto secs = (millis / 1000) + UTCtoLocal_sec; + auto mins = secs / 60; + auto hours = mins / 60; + + char timestamp_buf[16]; + snprintf(timestamp_buf, sizeof(timestamp_buf), "[%.2u:%.2u:%.2u.%.3u] ", (unsigned int)(hours % 24), (unsigned int)(mins % 60), (unsigned int)(secs % 60), (unsigned int)(millis % 1000)); + timestamp_buf[sizeof(timestamp_buf) - 1] = '\0'; + Write_Text_Locked(timestamp_buf, strlen(timestamp_buf)); } Write_Text_Locked(buffer, length); @@ -371,13 +699,264 @@ static void Write_Message_Locked(char const * buffer, bool with_prefix) } +#if defined(__APPLE__) +/// +/// Retrieves a string identifying the operating system version from a PLIST file. +/// +/// Filesystem path to the SystemVersion.plist file. +static std::string Get_PLIST_Version(const char * plist_path) +{ + // Explicit check to avoid warning on stderr from libxml2 + std::error_code ec; + bool file_exists = std::filesystem::exists(std::filesystem::path {(const char8_t *)plist_path}, ec); + if (ec || !file_exists) { + return std::string(); + } + + xmlDocPtr doc = xmlParseFile(plist_path); + if (doc == NULL) { + return std::string(); + } + + xmlNodePtr root = xmlDocGetRootElement(doc); + if (root == NULL) { + // empty plist file + xmlFreeDoc(doc); + return std::string(); + } + + if (xmlStrcmp(root->name, (const xmlChar *)"plist") != 0) { + // bad root element + xmlFreeDoc(doc); + return std::string(); + } + xmlNodePtr dict = NULL; + + for (xmlNodePtr iter = root->xmlChildrenNode; iter != NULL; iter = iter->next) { + if (xmlStrcmp(iter->name, (const xmlChar *)"dict") == 0) { + dict = iter; + break; + } + } + if (dict == NULL) { + // missing dictionary + xmlFreeDoc(doc); + return std::string(); + } + + enum { + OSX_PLIST_BUILD = 0, + OSX_PLIST_COPYRIGHT = 1, + OSX_PLIST_PRODUCT = 2, + OSX_PLIST_VER = 3, + OSX_PLIST_UNKNOWN = 4 + } next_plist_item; + + std::string build; + std::string copyright; + std::string product; + std::string ver; + + next_plist_item = OSX_PLIST_UNKNOWN; + bool have_data = false; + for (xmlNodePtr iter = dict->xmlChildrenNode; iter != NULL; iter = iter->next) { + if (xmlStrcmp(iter->name, (const xmlChar *)"key") == 0) { + next_plist_item = OSX_PLIST_UNKNOWN; + xmlChar * key = NULL; + if (iter->xmlChildrenNode) { + key = xmlNodeListGetString(doc, iter->xmlChildrenNode, 1); + } + if (key != NULL) { + if (xmlStrcmp(key, (const xmlChar *)"ProductBuildVersion") == 0) { + next_plist_item = OSX_PLIST_BUILD; + } else if (xmlStrcmp(key, (const xmlChar *)"ProductCopyright") == 0) { + next_plist_item = OSX_PLIST_COPYRIGHT; + } else if (xmlStrcmp(key, (const xmlChar *)"ProductName") == 0) { + next_plist_item = OSX_PLIST_PRODUCT; + } else if (xmlStrcmp(key, (const xmlChar *)"ProductUserVisibleVersion") == 0) { + next_plist_item = OSX_PLIST_VER; + } + xmlFree(key); + } + } else if (next_plist_item < OSX_PLIST_UNKNOWN && xmlStrcmp(iter->name, (const xmlChar *)"string") == 0) { + xmlChar * val = NULL; + if (iter->xmlChildrenNode) { + val = xmlNodeListGetString(doc, iter->xmlChildrenNode, 1); + } + if (val != NULL) { + switch (next_plist_item) { + case OSX_PLIST_BUILD: + build = (const char *)val; + have_data = true; + break; + case OSX_PLIST_COPYRIGHT: + copyright = (const char *)val; + have_data = true; + break; + case OSX_PLIST_PRODUCT: + product = (const char *)val; + have_data = true; + break; + case OSX_PLIST_VER: + ver = (const char *)val; + have_data = true; + break; + default: + break; + } + xmlFree(val); + } + } + } + + xmlFreeDoc(doc); + + if (have_data) { + return std::format("{} {} (build {}), Copyright {}", product, ver, build, copyright); + } else { + return std::string(); + } +} +#elif !defined(_WIN32) + + +/// +/// Strip quotes from a quoted string. This function doesn't handle all corner-cases +/// and escape sequences, so it shouldn't be used for data that will be further processed, +/// though it should be sufficient for displaying text to the user where potential +/// formatting errors are inconsequential. +/// +/// Quoted string to be copied without outer quotes. +static std::string Strip_Quotes(const std::string_view & input) +{ + std::string ret; + bool escape = false; + + for (const char & c : input) { + switch (c) { + case '\\': + if (!escape) { + escape = true; + } else { + ret.push_back(c); + escape = false; + } + break; + case '"': + if (escape) { + ret.push_back(c); + escape = false; + } + break; + default: + ret.push_back(c); + escape = false; + } + } + return ret; +} + + +/// +/// Retrieves a string identifying the operating system version from an os-release(5) file. +/// This is applicable for Linux and various other systems like FreeBSD. +/// +/// Filesystem path to the os-release file. +static std::string Get_OS_Release_Version(const std::filesystem::path & path) +{ + std::ifstream file(path); + + if (!file.is_open() || !file) { + return std::string(); + } + + std::string name; + std::string version; + std::string pretty_name; + + std::regex name_regex("NAME=\\(.*\\)", std::regex::basic); + std::regex ver_regex("VERSION=\\(.*\\)", std::regex::basic); + std::regex pretty_name_regex("PRETTY_NAME=\\(.*\\)", std::regex::basic); + + for (std::string line; std::getline(file, line);) { + + std::smatch results; + if (name.empty() && std::regex_match(line, results, name_regex) && results.size() > 1) { + name = results[1]; + if (name[0] == '"') { + name = Strip_Quotes(name); + } + continue; + } + if (version.empty() && std::regex_match(line, results, ver_regex) && results.size() > 1) { + version = results[1]; + if (version[0] == '"') { + version = Strip_Quotes(version); + } + continue; + } + if (pretty_name.empty() && std::regex_match(line, results, pretty_name_regex) && results.size() > 1) { + pretty_name = results[1]; + if (pretty_name[0] == '"') { + pretty_name = Strip_Quotes(pretty_name); + } + continue; + } + } + + if (!pretty_name.empty()) { + return pretty_name; + + } else if (!name.empty() && !version.empty()) { + return std::format("{} {}", name, version); + + } else if (!version.empty()) { + return std::format("{} {}", "Linux", version); + + } else { + return name; + } +} +#endif /* !defined(__WIN32) && !defined(__APPLE__) */ + + +#ifndef _WIN32 +/// +/// Retrieves a string identifying the operating system version using the uname command. +/// This is applicable for all UNIX-like operating systems. +/// +static std::string Get_UNAME(void) +{ + std::string buffer; + FILE * stream = popen("uname -a", "r"); + + if (stream) { + for (int c = getc(stream); c != EOF; c = getc(stream)) { + buffer.push_back(c); + } + int status = pclose(stream); + + if (status == 0) { + while (buffer.back() == '\n') { + buffer.pop_back(); + } + } else { + buffer.clear(); + } + } + + return buffer; +} +#endif + + /// /// Opens the log with the wordmark and the facts that identify the build and the run. The /// caller holds the logging lock, so the text goes through the unlocked sink directly; /// DebugStringNoPrefix would meet the re-entrancy guard and reach the debugger only. /// -/// The time this run's log was opened. -static void Write_Banner_Locked(SYSTEMTIME const & started) +/// The time this run's log was opened. +void DebugPrint::Write_Banner_Locked(const system_time_point & started_utc) { // A raw literal keeps the lettering readable, and keeps its backslashes out of the reach of // escape processing. It opens on its own line so the rows line up here, which costs a @@ -393,201 +972,366 @@ R"ART( )ART"; - Write_Message_Locked(Wordmark + 1, false); + Write_Message_Locked(&Wordmark[1], sizeof(Wordmark) - 2, false); + + // Buffer, to avoid needlessly repeated allocs/deallocs with std::format() + std::string line; - char line[512]; + std::format_to(std::back_inserter(line), "Version : OpenTS {} ({} {} build)\n", OPENTS_VERSION, OPENTS_ARCH, BuildType); + Write_Message_Locked(line.data(), line.size(), false); + line.clear(); - snprintf(line, sizeof(line), "Version : OpenTS %s (%s %s build)\n", OPENTS_VERSION, OPENTS_ARCH, BuildType); - Write_Message_Locked(line, false); + std::format_to(std::back_inserter(line), "Commit : {} on {}{}\n", OPENTS_COMMIT, OPENTS_BRANCH, OPENTS_COMMIT_DIRTY ? " (modified)" : ""); + Write_Message_Locked(line.data(), line.size(), false); + line.clear(); - snprintf(line, sizeof(line), "Commit : %s on %s%s\n", OPENTS_COMMIT, OPENTS_BRANCH, - OPENTS_COMMIT_DIRTY ? " (modified)" : ""); - Write_Message_Locked(line, false); + std::format_to(std::back_inserter(line), "Committed: {}\n", OPENTS_COMMIT_DATE); + Write_Message_Locked(line.data(), line.size(), false); + line.clear(); - snprintf(line, sizeof(line), "Committed: %s\n", OPENTS_COMMIT_DATE); - Write_Message_Locked(line, false); - snprintf(line, sizeof(line), "Started : %04u-%02u-%02u %02u:%02u:%02u\n", - started.wYear, started.wMonth, started.wDay, - started.wHour, started.wMinute, started.wSecond); - Write_Message_Locked(line, false); + // Display the started time in the local timezone, rounded down to seconds. + const auto started_utc_sec = std::chrono::time_point_cast(started_utc); + const auto started_local_sec = started_utc_sec + std::chrono::seconds(UTCtoLocal_sec); + std::format_to(std::back_inserter(line), "Started : {}\n", started_local_sec); + Write_Message_Locked(line.data(), line.size(), false); + line.clear(); + +#ifdef _WIN32 // Windows answers GetVersionEx with 6.2 for want of a compatibility manifest, so the real // build number has to come from RtlGetVersion. - char system[64] = "unknown"; + std::string system = "unknown"; HMODULE ntdll = GetModuleHandle("ntdll.dll"); if (ntdll != NULL) { - typedef LONG (WINAPI * RtlGetVersionType)(PRTL_OSVERSIONINFOW); - RtlGetVersionType const rtl_get_version = - (RtlGetVersionType)GetProcAddress(ntdll, "RtlGetVersion"); + typedef LONG(WINAPI * RtlGetVersionType)(PRTL_OSVERSIONINFOW); + RtlGetVersionType const rtl_get_version = (RtlGetVersionType)GetProcAddress(ntdll, "RtlGetVersion"); if (rtl_get_version != NULL) { - RTL_OSVERSIONINFOW version = { 0 }; + RTL_OSVERSIONINFOW version = {0}; version.dwOSVersionInfoSize = sizeof(version); if (rtl_get_version(&version) == 0) { - snprintf(system, sizeof(system), "Windows %lu.%lu.%lu", - version.dwMajorVersion, version.dwMinorVersion, version.dwBuildNumber); + system = std::format("Windows {}.{}.{}", version.dwMajorVersion, version.dwMinorVersion, version.dwBuildNumber); } } } - - snprintf(line, sizeof(line), "System : %s\n", system); - Write_Message_Locked(line, false); + std::format_to(std::back_inserter(line), "System : {}\n", system); + Write_Message_Locked(line.data(), line.size(), false); + line.clear(); // Windows before 10 version 1903 ignores the manifest's request for UTF-8. - snprintf(line, sizeof(line), "Codepage : ANSI %u, OEM %u\n", GetACP(), GetOEMCP()); - Write_Message_Locked(line, false); - - // The arguments only. The executable path usually carries the account name, and re-joining - // the arguments loses the shell's original quoting, which a diagnostic can live without. - char options[256] = "(none)"; - int argc = 0; - LPWSTR * argv = CommandLineToArgvW(GetCommandLineW(), &argc); - - if (argv != NULL) { - size_t used = 0; - for (int index = 1; index < argc; index++) { - int const written = snprintf(options + used, sizeof(options) - used, "%s%ls", - used == 0 ? "" : " ", argv[index]); - if (written <= 0 || size_t(written) >= sizeof(options) - used) { - break; - } - used += size_t(written); - } - LocalFree(argv); + std::format_to(std::back_inserter(line), "Codepage : ANSI {}, OEM {}\n", GetACP(), GetOEMCP()); + Write_Message_Locked(line.data(), line.size(), false); + line.clear(); + +#else + std::string system; + std::string uname; + +#if defined(__APPLE__) + // Hidden file provides real OS information on Big Sur and later: + system = Get_PLIST_Version("/System/Library/CoreServices/.SystemVersionPlatform.plist"); + if (system.empty()) { + system = Get_PLIST_Version("/System/Library/CoreServices/SystemVersion.plist"); + } + if (system.empty()) { + system = Get_PLIST_Version("/System/Library/CoreServices/ServerVersion.plist"); + } +#else + system = Get_OS_Release_Version(u8"/etc/os-release"); + if (system.empty()) { + system = Get_OS_Release_Version(u8"/usr/lib/os-release"); + } +#endif + uname = Get_UNAME(); + + if (system.empty() && !uname.empty()) { + std::swap(system, uname); + } + if (system.empty()) { + system = "unknown"; + } + + std::format_to(std::back_inserter(line), "System : {}\n", system); + Write_Message_Locked(line.data(), line.size(), false); + line.clear(); + + if (!uname.empty()) { + std::format_to(std::back_inserter(line), "uname -a : {}\n", uname); + Write_Message_Locked(line.data(), line.size(), false); + line.clear(); } +#endif - snprintf(line, sizeof(line), "Options : %s\n", options); - Write_Message_Locked(line, false); + std::format_to(std::back_inserter(line), "Options : {}\n", std::string_view((const char *)ArgsFullCommandLine.data(), ArgsFullCommandLine.size())); + Write_Message_Locked(line.data(), line.size(), false); + line.clear(); - Write_Message_Locked("--------------------------------------------------------------------------------\n", false); + static char const Footer[] = "--------------------------------------------------------------------------------\n"; + Write_Message_Locked(Footer, sizeof(Footer) - 1, false); } /// -/// Takes the logging lock and reports one finished message. +/// Takes the logging lock and reports one finished message. Can be called before Debug_Init(), +/// but the messages will only be logged after Debug_Init() is called. The string buffer +/// must be zero-terminated for OutputDebugString() to work correctly. /// -static void Emit(char const * buffer, bool with_prefix) +/// String buffer to write. Must be zero-terminated. +/// Length of the string in the provided buffer. +/// Whether or not to stamp the message. +void DebugPrint::Emit(char const * buffer, size_t length, bool with_prefix) { - DWORD const self = GetCurrentThreadId(); + std::lock_guard lock(Lock); + Write_Message_Locked(buffer, length, with_prefix); +} - // A fault raised inside a logging call brings the handler back here on the same thread, - // where taking the lock again would deadlock. Such a message reaches the debugger only. - if (DebugLockOwner == self) { - if (IsDebuggerPresent()) { - OutputDebugString(buffer); - } + +/// +/// Prepares the debug log and, when the command line asks for it, the debug console. +/// Messages may be logged before this function is called, but they will only be emitted +/// after Debug_Init() is invoked to configure the location of the logging directory. +/// This is the variant for use with main(). The data in argv[] should be encoded in UTF-8. +/// +void Debug_Init(int argc, char const * argv[]) +{ + DebugPrint & dbg = DebugPrint::instance(); + if (dbg.Destroyed) { return; } + std::lock_guard lock(dbg.Lock); - AcquireSRWLockExclusive(&DebugLock); - DebugLockOwner = self; - - Init_Locked(); - Write_Message_Locked(buffer, with_prefix); - - DebugLockOwner = 0; - ReleaseSRWLockExclusive(&DebugLock); + if (!dbg.Initialized) { + dbg.Debug_Command_Line_Parse(argc, (const char8_t **)argv); + dbg.Init_Locked(); + } } +#ifdef _WIN32 + /// -/// Runs first time initialisation under the logging lock. +/// Prepares the debug log and, when the command line asks for it, the debug console. +/// Messages may be logged before this function is called, but they will only be emitted +/// after Debug_Init() is invoked to configure the location of the logging directory. +/// This is the variant for use with wmain(). /// -static void Init_Once(bool with_console) +void Debug_Init(int argc, wchar_t const * argv[]) { - AcquireSRWLockExclusive(&DebugLock); - DebugLockOwner = GetCurrentThreadId(); - - Init_Locked(); - if (with_console) { - Init_Console_Locked(); + DebugPrint & dbg = DebugPrint::instance(); + if (dbg.Destroyed) { + return; } + std::lock_guard lock(dbg.Lock); - DebugLockOwner = 0; - ReleaseSRWLockExclusive(&DebugLock); + if (!dbg.Initialized) { + dbg.Debug_Command_Line_Parse(argc, argv); + dbg.Init_Locked(); + } } - /// -/// Prepares the debug log and, when the command line asks for it, the debug console. Logging -/// works without this call, but calling it early fixes the log's timestamp at process start. +/// Prepares the debug log and, when the command line asks for it, the debug console. +/// Messages may be logged before this function is called, but they will only be emitted +/// after Debug_Init() is invoked to configure the location of the logging directory. +/// This is the variant for use with WinMain() and wWinMain(). /// void Debug_Init(void) { - Init_Once(false); + DebugPrint & dbg = DebugPrint::instance(); + if (dbg.Destroyed) { + return; + } + std::lock_guard lock(dbg.Lock); + + if (!dbg.Initialized) { + int argc = 0; + LPWSTR * argv = CommandLineToArgvW(GetCommandLineW(), &argc); + + dbg.Debug_Command_Line_Parse(argc, (const wchar_t **)argv); + LocalFree(argv); + + dbg.Init_Locked(); + } } +#endif + /// /// Opens the debug console if it is not open already, starting it with the text logged so far. +/// The Debug_Init() function needs to be called first in order to process command-line arguments. /// -void Debug_Init_Console(void) +bool Debug_Enable_Console(void) { - Init_Once(true); + DebugPrint & dbg = DebugPrint::instance(); + if (dbg.Destroyed) { + return false; + } + std::lock_guard lock(dbg.Lock); + + return dbg.Enable_Console_Locked(); } /// /// Waits for a keypress when the debug console is open, so that text written just before the -/// process exits stays readable. Does nothing when there is no console. +/// process exits stays readable. Does nothing when there is no console. Also does nothing +/// on non-Windows OSes, since console windows there generally don't disappear on program exit. /// void Debug_Console_Hold(void) { - if (!ConsoleActive) { +#ifdef _WIN32 + DebugPrint & dbg = DebugPrint::instance(); + if (dbg.Destroyed) { return; } + // Lock scope + { + std::lock_guard lock(dbg.Lock); - DebugString("Press any key to close this window.\n"); + if (!dbg.ConsoleActive) { + return; + } + } + std::cout << "Press any key to close this window." << std::endl; _getch(); +#endif } /// -/// Returns the full path of this run's debug log, or an empty string when no log could be +/// Returns the full path of this run's debug log, or an empty path when no log could be /// opened. Intended for startup code and user interface text; never call it from a crash /// handler, because it takes the logging lock. /// -char const * Debug_Log_File_Name(void) +std::filesystem::path Debug_Log_File_Path(void) { - Init_Once(false); - return(DebugFileName); + DebugPrint & dbg = DebugPrint::instance(); + if (dbg.Destroyed) { + return ""; + } + std::lock_guard lock(dbg.Lock); + + return (dbg.FilePath); } /// -/// Returns the folder where per-run diagnostic files belong, or an empty string when it could +/// Returns the folder where per-run diagnostic files belong, or an empty path when it could /// not be created. Shared by callers that write their own files beside the debug log. /// -char const * Debug_Directory(void) +std::filesystem::path Debug_Directory(void) { - Init_Once(false); - return(DebugDirectory); + DebugPrint & dbg = DebugPrint::instance(); + if (dbg.Destroyed) { + return ""; + } + std::lock_guard lock(dbg.Lock); + + return (dbg.Directory); } +class PrintfBuffer +{ + public: + PrintfBuffer() : Destroyed(false) {} + ~PrintfBuffer() { Destroyed = true; } + + std::vector Vec; + bool Destroyed; +}; + /// -/// Reports a formatted message to the debug log, the debugger, and the debug console. A -/// message that starts a line is stamped with the time it was reported. +/// Reports a formatted message to the debug log, the debugger, and the debug console. +/// This is the internal function used by DebugString() and DebugStringNoPrefix(), +/// it works best with messages shorter than DEBUG_MESSAGE_MAX, but it is able +/// to handle longer messages too (with a performance cost). +/// +/// Whether or not to stamp the message. +/// The printf style format string to report. +/// Variable argument list to be used with vsnprintf(). +static void DebugString_Perform(bool with_prefix, char const * fmt, va_list va_in) +{ + DebugPrint & dbg = DebugPrint::instance(); + if (dbg.Destroyed) { + return; + } + + static thread_local PrintfBuffer t_PrintfBuf; + int printf_bytes; + + if (t_PrintfBuf.Destroyed) { + return; + } + + if (t_PrintfBuf.Vec.size() < DEBUG_MESSAGE_MAX) { + + // Take an initial performance hit on the first message to avoid reallocs and memsets on subsequent ones. + t_PrintfBuf.Vec.reserve(DEBUG_MESSAGE_MAX); + t_PrintfBuf.Vec.resize(DEBUG_MESSAGE_MAX); + } + + va_list va; + va_copy(va, va_in); + printf_bytes = vsnprintf((t_PrintfBuf.Vec.size() != 0) ? t_PrintfBuf.Vec.data() : NULL, t_PrintfBuf.Vec.size(), fmt, va); + va_end(va); + + if (printf_bytes < 0 && t_PrintfBuf.Vec.size() > 0) { + // Older versions of Windows don't report the required buffer size on truncation + va_copy(va, va_in); + printf_bytes = vsnprintf(NULL, 0, fmt, va); + va_end(va); + } + + if (printf_bytes > 0 && (size_t)(printf_bytes + 1) > t_PrintfBuf.Vec.size()) { + // Text data in buffer truncated + t_PrintfBuf.Vec.resize(printf_bytes + 1); + + va_copy(va, va_in); + printf_bytes = vsnprintf(t_PrintfBuf.Vec.data(), t_PrintfBuf.Vec.size(), fmt, va); + va_end(va); + } + + if (printf_bytes > 0 && t_PrintfBuf.Vec.size() > 0) { + std::vector::size_type printf_bytes_u = printf_bytes; + std::vector::size_type text_bytes = std::min(printf_bytes_u, t_PrintfBuf.Vec.size() - 1); + t_PrintfBuf.Vec[text_bytes] = '\0'; + + dbg.Emit(t_PrintfBuf.Vec.data(), text_bytes, with_prefix); + } + + // Prevent uncontrolled balooning of the buffer's size. + if (t_PrintfBuf.Vec.size() > DEBUG_MESSAGE_MAX * 2) { + t_PrintfBuf.Vec.resize(DEBUG_MESSAGE_MAX); + t_PrintfBuf.Vec.shrink_to_fit(); + } +} + + +/// +/// Reports a formatted message to the debug log, the debugger, and the debug console. +/// A message that starts a line is stamped with the time it was reported. +/// Can be called before Debug_Init(), but the messages will only be logged after Debug_Init() is called. /// /// The printf style format string to report. -void __cdecl DebugString(char const * string, ...) +void __cdecl DebugString(char const * fmt, ...) { - // Callers report an error and then branch on it, so logging must not disturb it. +#ifdef _WIN32 DWORD const last_error = GetLastError(); +#endif int const last_errno = errno; - char buffer[DEBUG_MESSAGE_MAX]; - va_list va; - va_start(va, string); - vsnprintf(buffer, sizeof(buffer), string, va); + va_start(va, fmt); + DebugString_Perform(true, fmt, va); va_end(va); - Emit(buffer, true); - errno = last_errno; +#ifdef _WIN32 SetLastError(last_error); +#endif } @@ -595,27 +1339,30 @@ void __cdecl DebugString(char const * string, ...) /// Reports a formatted message with no identifying prefix, so the text appears exactly as /// given. Callers use it to continue a line another call began, and for text such as the /// startup banner that reads better unstamped. It reaches the same places DebugString does. +/// Can be called before Debug_Init(), but the messages will only be logged after Debug_Init() is called. /// /// The printf style format string to report. -void __cdecl DebugStringNoPrefix(char const * string, ...) +void __cdecl DebugStringNoPrefix(char const * fmt, ...) { +#ifdef _WIN32 DWORD const last_error = GetLastError(); +#endif int const last_errno = errno; - char buffer[DEBUG_MESSAGE_MAX]; - va_list va; - va_start(va, string); - vsnprintf(buffer, sizeof(buffer), string, va); + va_start(va, fmt); + DebugString_Perform(false, fmt, va); va_end(va); - Emit(buffer, false); - errno = last_errno; +#ifdef _WIN32 SetLastError(last_error); +#endif } +#ifdef _WIN32 + /// /// Returns the system message text for a Win32 error code, in a buffer owned by the calling /// thread. @@ -625,11 +1372,11 @@ char const * Last_Error_Text(unsigned long error) { static thread_local char message_buffer[256]; - if (FormatMessage(FORMAT_MESSAGE_FROM_SYSTEM, NULL, error, - MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT), - message_buffer, sizeof(message_buffer), NULL) == 0) { + if (FormatMessage(FORMAT_MESSAGE_FROM_SYSTEM, NULL, error, MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT), message_buffer, sizeof(message_buffer), NULL) == 0) { message_buffer[0] = '\0'; } - return(message_buffer); + return (message_buffer); } + +#endif diff --git a/code/dbgprint.h b/code/dbgprint.h index e24a002d2..52845503d 100644 --- a/code/dbgprint.h +++ b/code/dbgprint.h @@ -13,10 +13,24 @@ #pragma once +#include + #if defined(_WIN32) #include +// Initialization function with support for UTF-16 command-line arguments, +// for use with wmain(). +void Debug_Init(int argc, wchar_t const * argv[]); + +// WinMain() doesn't provide command-line arguments in the typical format, +// but they can be retrieved with a function call. This is a convenience wrapper +// for Debug_Init() used in WinMain(). +void Debug_Init(void); + +// Dedicated reporting function for GetLastError() on Windows. +char const * Last_Error_Text(unsigned long error); + #else // The annotation and the calling convention are the compiler's own. Off Windows @@ -26,14 +40,19 @@ #endif -void Debug_Init(void); -void Debug_Init_Console(void); -void Debug_Console_Hold(void); -char const * Debug_Log_File_Name(void); -char const * Debug_Directory(void); -bool Delete_Files_Older_Than(char const * directory, char const * pattern, unsigned days); +#if defined(__GNUC__) +// printf() formatting attribute supported by clang and gcc +#define DEBUG_PRINTF_ATTR __attribute__((format(printf, 1, 2))) +#else +#define DEBUG_PRINTF_ATTR +#endif -void __cdecl DebugString(_Printf_format_string_ char const * string, ...); -void __cdecl DebugStringNoPrefix(_Printf_format_string_ char const * string, ...); +void Debug_Init(int argc, char const * argv[]); +bool Debug_Enable_Console(void); +void Debug_Console_Hold(void); +std::filesystem::path Debug_Log_File_Path(void); +std::filesystem::path Debug_Directory(void); +bool Delete_Files_Older_Than(const std::filesystem::path & directory, const std::string_view & pattern, unsigned int days); -char const * Last_Error_Text(unsigned long error); +void __cdecl DebugString(_Printf_format_string_ char const * string, ...) DEBUG_PRINTF_ATTR; +void __cdecl DebugStringNoPrefix(_Printf_format_string_ char const * string, ...) DEBUG_PRINTF_ATTR; diff --git a/code/globals.cpp b/code/globals.cpp index 537f8c33e..7968fabac 100644 --- a/code/globals.cpp +++ b/code/globals.cpp @@ -114,7 +114,6 @@ bool Debug_Check_Map = false; // true = validate the map each frame bool Debug_Playtest = false; bool Debug_Trap_Check_Heap = false; // true = check the Heap bool Debug_Print_Events = false; // true = print event & packet processing -bool Debug_Console = false; bool Debug_MultipleInstances = false; // true = let this copy run beside another one diff --git a/code/globals.h b/code/globals.h index 7c73a61f1..b315b084a 100644 --- a/code/globals.h +++ b/code/globals.h @@ -122,7 +122,6 @@ extern bool Debug_Check_Map; extern bool Debug_Playtest; extern bool Debug_Trap_Check_Heap; extern bool Debug_Print_Events; -extern bool Debug_Console; extern bool Debug_MultipleInstances; extern ParticleSystemClass *GasSystem; diff --git a/code/init.cpp b/code/init.cpp index d10661f39..d1e4bb765 100644 --- a/code/init.cpp +++ b/code/init.cpp @@ -1461,7 +1461,7 @@ bool Parse_Command_Line(int argc, char * argv[]) */ if (stricmp("/?", string) == 0 || stricmp("-?", string) == 0 || stricmp("-h", string) == 0 || stricmp("/h", string) == 0) { #ifdef _DEBUG - Debug_Init_Console(); + Debug_Enable_Console(); #endif /* @@ -1677,8 +1677,7 @@ bool Parse_Command_Line(int argc, char * argv[]) * Enable debug output to a console. */ case 'C': - Debug_Console = true; - Debug_Init_Console(); + /* Argument already processed by dbgprint module. */ break; /* @@ -1690,7 +1689,7 @@ bool Parse_Command_Line(int argc, char * argv[]) default: #ifdef _DEBUG - Debug_Init_Console(); + Debug_Enable_Console(); #endif puts(Fetch_String(TXT_INVALID)); return(false); diff --git a/code/startup.cpp b/code/startup.cpp index c0e51e5d9..ce330a655 100644 --- a/code/startup.cpp +++ b/code/startup.cpp @@ -458,7 +458,7 @@ int CALLBACK WinMain ( HINSTANCE instance , HINSTANCE , char * , int ) // Handed over now because the exception path may not ask the logger for anything: the // thread that crashed may be the one holding the logger's lock. - Exception_Register_Log_File(Debug_Log_File_Name()); + Exception_Register_Log_File((const char *)Debug_Log_File_Path().u8string().c_str()); // LZO asks for this before any codec call. It validates rather than initializes, and a // vendored static build cannot fail it, but thirdparty/lzo is upgraded in place and a @@ -507,7 +507,7 @@ int CALLBACK WinMain ( HINSTANCE instance , HINSTANCE , char * , int ) #ifdef _DEBUG // Debug builds show the console without -XC, except to a headless run, which shows nothing. if (!Headless::Is_Active()) { - Debug_Init_Console(); + Debug_Enable_Console(); } #endif diff --git a/code/syncreport.cpp b/code/syncreport.cpp index 626ffbf2b..4d789ba5e 100644 --- a/code/syncreport.cpp +++ b/code/syncreport.cpp @@ -194,13 +194,13 @@ void Print_CRCs(EventClass const * events, int count, unsigned const * crc_ring, unsigned int GameCRC = 0; char filename[512]; - char const * debug_dir = Debug_Directory(); - if (debug_dir != NULL && debug_dir[0] != '\0') { + std::filesystem::path debug_dir = Debug_Directory(); + if (!debug_dir.empty()) { SYSTEMTIME now; GetLocalTime(&now); - Delete_Files_Older_Than(debug_dir, "SYNC_*.LOG", SYNC_REPORT_MAX_AGE_DAYS); + Delete_Files_Older_Than(debug_dir, "SYNC_.*\\.LOG", SYNC_REPORT_MAX_AGE_DAYS); snprintf(filename, sizeof(filename), "%s\\SYNC_H%d_%02u-%02u-%04u_%02u-%02u-%02u_F%d.LOG", - debug_dir, PlayerPtr->HeapID, + (const char *)debug_dir.u8string().c_str(), PlayerPtr->HeapID, now.wDay, now.wMonth, now.wYear, now.wHour, now.wMinute, now.wSecond, Frame); } else { snprintf(filename, sizeof(filename), "SYNC%01d.TXT", PlayerPtr->HeapID); diff --git a/manual/changes/debug-log-user-dir.md b/manual/changes/debug-log-user-dir.md new file mode 100644 index 000000000..fe4ea5ede --- /dev/null +++ b/manual/changes/debug-log-user-dir.md @@ -0,0 +1,17 @@ +--- +title: Store logs into the user directory when specified +category: feature +release: 0.3.0 +targets: +- type: command + id: launch:console-debug + effect: changed +credit: [DaliborFox] +--- + +Previously, logs were always stored in the `Debug` folder beside the game executable. +Since it's quite likely for the game not to have write access to this folder, it now +stores the logs in a `Debug` folder in the user directory when the +[`-USERDIR`](/using/command-line/#user-directory) command-line option is provided. + +See [Debug logs and console](/using/debug-logging/) for specific details. diff --git a/manual/content/using/debug-logging.md b/manual/content/using/debug-logging.md index eadc29060..12f6e2d73 100644 --- a/manual/content/using/debug-logging.md +++ b/manual/content/using/debug-logging.md @@ -15,7 +15,7 @@ related: ## Where the log is written -Every run, in Release and Debug builds alike, writes a new log to a `Debug` folder in the directory that holds the executable. The file is named for the local time the process started: +Every run, in Release and Debug builds alike, writes a new log to a `Debug` folder in the user directory. The file is named for the local time the process started: ``` Debug/DEBUG_17-08-2026_06-00-35.LOG @@ -23,7 +23,7 @@ Debug/DEBUG_17-08-2026_06-00-35.LOG Because each run gets its own file, the log from a run that crashed is still there after the next launch. When two processes start within the same second, the second adds its process id to the name. -The log stays beside the executable when [`-USERDIR`](/using/command-line/#user-directory) names a user directory, so the game needs write access to the executable's directory to keep a log. If the folder or the file cannot be created, the game still runs, and its output still reaches the console and an attached debugger. +When the user directory is not specified, i.e. no [`-USERDIR`](/using/command-line/#user-directory) command-line option is provided, the log is placed into a platform-dependent default directory. For Windows, this is the directory that holds the executable. On Linux, it is `$XDG_STATE_HOME/OpenTS/` (or `$HOME/.local/state/OpenTS/` in case `$XDG_STATE_HOME` is not specified), and on Mac, it is `$HOME/Library/Logs/OpenTS/`. In case the game doesn't have write access to this directory (especially on Windows), the [`-USERDIR`](/using/command-line/#user-directory) command-line option should be used. At startup, the game deletes logs last written more than 14 days ago. A single log stops growing at 64 MB, and its last line then says that the size limit was reached. diff --git a/tests/deploymentconfig/deploymentconfigcontract.cpp b/tests/deploymentconfig/deploymentconfigcontract.cpp index ac4c71480..b6bcf9b9d 100644 --- a/tests/deploymentconfig/deploymentconfigcontract.cpp +++ b/tests/deploymentconfig/deploymentconfigcontract.cpp @@ -17,6 +17,7 @@ #include #include +#include "dbgprint.h" #include "_deploymentconfig.h" #include "deploymentconfig.h" #include "rawfile.h" @@ -123,6 +124,7 @@ TEST_CASE_FIXTURE(RootFixture, "with no file the INI, MIX and Maps folders are s TEST_CASE_FIXTURE(RootFixture, "a file beside the game is read, and the folders it names replace the default") { + Debug_Init(0, (const char **)NULL); DeploymentConfigClass config; Write_File(Root + "\\OPENTS.INI", "[Paths]\nSearchPaths=Data,More\n"); @@ -146,6 +148,7 @@ TEST_CASE_FIXTURE(RootFixture, "a file beside the game is read, and the folders TEST_CASE_FIXTURE(RootFixture, "the file is looked for beside the game, then in INI, then in MIX") { + Debug_Init(0, (const char **)NULL); DeploymentConfigClass config; Write_File(Root + "\\MIX\\OPENTS.INI", "[Paths]\nSearchPaths=FromMix\n"); @@ -168,6 +171,7 @@ TEST_CASE_FIXTURE(RootFixture, "the file is looked for beside the game, then in TEST_CASE_FIXTURE(RootFixture, "the file is read from the directory named, and what it names is taken from there") { + Debug_Init(0, (const char **)NULL); DeploymentConfigClass config; std::string const data = Root + "\\Data\\"; @@ -184,6 +188,7 @@ TEST_CASE_FIXTURE(RootFixture, "the file is read from the directory named, and w TEST_CASE_FIXTURE(RootFixture, "a read starts over, so with the file gone every setting returns to its default") { + Debug_Init(0, (const char **)NULL); DeploymentConfigClass config; Write_File(Root + "\\OPENTS.INI", "[Paths]\nSearchPaths=Data\n"); @@ -197,6 +202,7 @@ TEST_CASE_FIXTURE(RootFixture, "a read starts over, so with the file gone every TEST_CASE_FIXTURE(RootFixture, "a save carries the scenario file only when the file asks for it") { + Debug_Init(0, (const char **)NULL); DeploymentConfigClass config; CHECK_MESSAGE(!config.CarryScenarioFile, "with no file a save carries no scenario file"); @@ -223,6 +229,7 @@ TEST_CASE_FIXTURE(RootFixture, "a save carries the scenario file only when the f TEST_CASE_FIXTURE(RootFixture, "with no file the rules, multiplayer rules and settings come from their shipped files") { + Debug_Init(0, (const char **)NULL); DeploymentConfigClass config; CHECK_MESSAGE(config.RulesFile == "RULES.INI", "with no file the rules come from RULES.INI"); @@ -261,6 +268,7 @@ TEST_CASE_FIXTURE(RootFixture, "with no file the rules, multiplayer rules and se TEST_CASE_FIXTURE(RootFixture, "the expansion rules have their shipped names, and a name the file writes is taken") { + Debug_Init(0, (const char **)NULL); DeploymentConfigClass config; CHECK_MESSAGE(config.RulesExpansionFile == "FIRESTRM.INI", "with no file the expansion rules are FIRESTRM.INI"); @@ -289,6 +297,7 @@ TEST_CASE_FIXTURE(RootFixture, "the expansion rules have their shipped names, an TEST_CASE_FIXTURE(RootFixture, "the scheme and starting palettes have their shipped names, and names the file writes are taken") { + Debug_Init(0, (const char **)NULL); DeploymentConfigClass config; CHECK_MESSAGE(config.SchemePaletteFile == "UNITSNO.PAL", "with no file the scheme palette is UNITSNO.PAL"); diff --git a/tests/gamedirs/gamedirscontract.cpp b/tests/gamedirs/gamedirscontract.cpp index 234f68002..a628dac43 100644 --- a/tests/gamedirs/gamedirscontract.cpp +++ b/tests/gamedirs/gamedirscontract.cpp @@ -18,6 +18,7 @@ #include #include "cdfile.h" +#include "dbgprint.h" #include "deploymentconfig.h" #include "gamedirs.h" #include "rawfile.h" @@ -108,6 +109,7 @@ void Remove_Directory(std::string const & path) */ void Reset(void) { + Debug_Init(0, (const char **)NULL); CDFileClass::Clear_Search_Drives(); Set_Data_Directory(""); Set_User_Directory(""); diff --git a/tests/ini/inicontract.cpp b/tests/ini/inicontract.cpp index 6b9fb2bf9..508d9e56a 100644 --- a/tests/ini/inicontract.cpp +++ b/tests/ini/inicontract.cpp @@ -70,7 +70,11 @@ std::string Save_Bytes(INIClass const & ini) // diagnostics a load produced by taking the count before and after it. int Log_Lines(char const * needle) { - FILE * handle = std::fopen(Debug_Log_File_Name(), "rb"); +#ifdef _WIN32 + FILE * handle = _wfopen(Debug_Log_File_Path().c_str(), L"rb"); +#else + FILE * handle = std::fopen(Debug_Log_File_Path().c_str(), "rb"); +#endif if (handle == NULL) { return(0); } @@ -240,7 +244,7 @@ struct Fixture { Fixture(void) { - Debug_Init(); + Debug_Init(0, (const char **)NULL); } }; diff --git a/tests/logstress/logstress.cpp b/tests/logstress/logstress.cpp index ce1f9987c..3a550423c 100644 --- a/tests/logstress/logstress.cpp +++ b/tests/logstress/logstress.cpp @@ -83,9 +83,9 @@ TEST_CASE("the logger keeps up with many threads and writes every record whole, // The timings below describe the sinks a released game actually runs with, so the console // stays shut until they are done. - Debug_Init(); + Debug_Init(0, (const char **)NULL); - std::string const log = Debug_Log_File_Name(); + std::filesystem::path const log = Debug_Log_File_Path(); REQUIRE_MESSAGE(!log.empty(), "the log file opened"); // A record assembled from several calls must come out as one stamped line. @@ -175,7 +175,11 @@ TEST_CASE("the logger keeps up with many threads and writes every record whole, CHECK_MESSAGE(p999_us <= 50000.0, "contended p99.9 call latency within 50 ms"); // Every line must have survived intact, and every message must be present. +#ifdef _WIN32 + FILE * handle = _wfopen(log.c_str(), L"rb"); +#else FILE * handle = std::fopen(log.c_str(), "rb"); +#endif REQUIRE_MESSAGE(handle != NULL, "the log is readable while the game holds it open"); int intact = 0; @@ -244,23 +248,23 @@ TEST_CASE("the logger keeps up with many threads and writes every record whole, // Pruning must leave a file that is younger than the threshold alone. -TEST_CASE("pruning keeps a recent log and refuses an absurd age or a null directory") +TEST_CASE("pruning keeps a recent log and refuses a null directory") { - std::string const directory = Log_Directory(); - CreateDirectoryA(directory.c_str(), NULL); + std::filesystem::path const directory = Log_Directory(); + CreateDirectoryW(directory.c_str(), NULL); - std::string const keep = directory + "\\DEBUG_keepme.LOG"; - FILE * young = std::fopen(keep.c_str(), "wb"); + std::filesystem::path const keep = directory / u8"DEBUG_keepme.LOG"; + FILE * young = _wfopen(keep.c_str(), L"wb"); if (young != NULL) { std::fputs("young\n", young); std::fclose(young); } - Delete_Files_Older_Than(directory.c_str(), "DEBUG_*.LOG", 14); - CHECK(GetFileAttributesA(keep.c_str()) != INVALID_FILE_ATTRIBUTES); - DeleteFileA(keep.c_str()); + Delete_Files_Older_Than(directory, "DEBUG_.*\\.LOG", 14); + CHECK(GetFileAttributesW(keep.c_str()) != INVALID_FILE_ATTRIBUTES); + DeleteFileW(keep.c_str()); - CHECK_MESSAGE(!Delete_Files_Older_Than(directory.c_str(), "DEBUG_*.LOG", 91), "an absurd age is refused"); - CHECK_MESSAGE(!Delete_Files_Older_Than(NULL, "DEBUG_*.LOG", 14), "a null directory is refused"); + CHECK_MESSAGE(Delete_Files_Older_Than(directory, "DEBUG_.*\\.LOG", 9001), "an absurd age should not be refused anymore"); + CHECK_MESSAGE(!Delete_Files_Older_Than("", "DEBUG_.*\\.LOG", 14), "a null directory is refused"); } @@ -269,7 +273,8 @@ TEST_CASE("the console sink allocates a console with its close button disabled") { // A console subsystem program already owns a console, which would turn AllocConsole away. FreeConsole(); - Debug_Init_Console(); + Debug_Init(0, (const char **)NULL); + Debug_Enable_Console(); DebugString("the console sink is reachable\n"); HWND const console = GetConsoleWindow(); diff --git a/tests/soundini/soundini.cpp b/tests/soundini/soundini.cpp index b3a83f210..bdea6bcb8 100644 --- a/tests/soundini/soundini.cpp +++ b/tests/soundini/soundini.cpp @@ -13,6 +13,7 @@ #include "audio/audiodefs.hh" #include "audio/audioevent.h" +#include "dbgprint.h" #include "ini.h" #include "voc.h" #include "xstraw.h" @@ -316,6 +317,7 @@ TEST_CASE_FIXTURE(ViniferaFixture, "SHROUDED is the hidden type, with an integer TEST_CASE("a priority is a name or clamped points, and anything else keeps the fallback") { + Debug_Init(0, (const char **)NULL); CHECK(Sound_Parse_Priority("LOWEST", 7) == 0); CHECK(Sound_Parse_Priority("low", 7) == 10); CHECK(Sound_Parse_Priority("Normal", 7) == 50); @@ -343,6 +345,7 @@ TEST_CASE("a volume is a fraction or a percentage, clamped, and anything else ke TEST_CASE("type flags combine, unknown ones are ignored, and an empty type keeps the fallback") { + Debug_Init(0, (const char **)NULL); CHECK_MESSAGE(Sound_Parse_Type("NORMAL", 99) == 0u, "NORMAL is no flags"); CHECK(Sound_Parse_Type("SCREEN SHROUD", 99) == (SOUND_TYPE_SCREEN | SOUND_TYPE_SHROUD)); CHECK(Sound_Parse_Type("SCREEN WIBBLE", 99) == SOUND_TYPE_SCREEN); diff --git a/tests/themeini/themeini.cpp b/tests/themeini/themeini.cpp index fb3aa4964..6b7064848 100644 --- a/tests/themeini/themeini.cpp +++ b/tests/themeini/themeini.cpp @@ -10,6 +10,7 @@ // Reads music track sections shaped like the shipped THEME.INI and with the // keys OpenTS adds, and checks what each key becomes. Needs no game data. +#include "dbgprint.h" #include "ini.h" #include "side.h" #include "theme.h" @@ -161,6 +162,7 @@ TEST_CASE_FIXTURE(NewKeysFixture, "a Volume= above 1 is a percentage, and one th TEST_CASE_FIXTURE(SidesFixture, "Side= names one side or a list, skipping a side the rules do not declare") { + Debug_Init(0, (const char **)NULL); ThemeControl one = Track(ini, "ONE"); CHECK(one.Allows_Side(SIDE_GDI)); CHECK_FALSE(one.Allows_Side(SIDE_NOD)); @@ -179,6 +181,7 @@ TEST_CASE_FIXTURE(SidesFixture, "Side= names one side or a list, skipping a side TEST_CASE_FIXTURE(SidesFixture, "a list naming no declared side keeps the sides before it") { + Debug_Init(0, (const char **)NULL); ThemeControl bad; std::strcpy(bad.Name, "BAD"); bad.Owners.push_back(SIDE_NOD); diff --git a/tests/tutorial/tutorialcontract.cpp b/tests/tutorial/tutorialcontract.cpp index a206123f9..822f5dfad 100644 --- a/tests/tutorial/tutorialcontract.cpp +++ b/tests/tutorial/tutorialcontract.cpp @@ -14,6 +14,7 @@ #include #include +#include "dbgprint.h" #include "ini.h" #include "tutorial.h" #include "xstraw.h" @@ -78,6 +79,7 @@ TEST_CASE("a second base read layers on top") // Anything else is refused rather than read as the number in front of it. TEST_CASE("an entry name has to be a whole number") { + Debug_Init(0, (const char **)NULL); INIClass ini; Read(ini, "[Tutorial]\n"