From bf09852285941e20a04731443d03c693e3f8ba2d Mon Sep 17 00:00:00 2001 From: Emma Miler Date: Sat, 12 Nov 2022 15:39:39 +0100 Subject: Logging improvements + Colours (new) (#320) * log colours :) * commend the freopen stuff (it causes problems) * formatting * add explanatory comment * gaming maybe * move set pattern * ok this works now i think * trailing space :) * Revert "Merge branch 'main' into log-colours" This reverts commit d40b6496b7bd3b3f20f51cc2311b0369aeabe735, reversing changes made to a98bcc22e8961b325806f6a9ca85e64353fd574c. * Revert "Revert "Merge branch 'main' into log-colours"" This reverts commit da792245b1cd7d0ac9e22d5633770142a43ce10c. * fix shit maybe * fix shit but better * initial, still WIP * Add GetContextName_Short * colours for in game console * working, time to improve code * rename var + add a colour or two * whoops * change rpak filesystem to RP NATIVE * add RP NATIVE and NORTHSTAR tags * clang-format off because formatting * formatting 2 * formatting 3: the formattening * bruh * revert unnecessary change * improve comment * Set console title to show profile * pain * Made code not shit * Formatting and remove warning box * Update main.cpp * Formatting * More format changes * Again * Fix small things from code review * Remove empty line * renamed NATIVE_EN -> NATIVE_ENGINE * Update logging.cpp * Update sourceconsole.cpp Co-authored-by: ASpoonPlaysGames <66967891+ASpoonPlaysGames@users.noreply.github.com> --- NorthstarDLL/NorthstarDLL.vcxproj | 3 + NorthstarDLL/NorthstarDLL.vcxproj.filters | 9 + NorthstarDLL/color.cpp | 26 +++ NorthstarDLL/color.h | 64 +++++- NorthstarDLL/dllmain.cpp | 6 +- NorthstarDLL/filesystem.cpp | 4 +- NorthstarDLL/logging.cpp | 350 ++++++++++++------------------ NorthstarDLL/logging.h | 127 +++++++++++ NorthstarDLL/loghooks.cpp | 262 ++++++++++++++++++++++ NorthstarDLL/loghooks.h | 1 + NorthstarDLL/nsprefix.cpp | 3 + NorthstarDLL/pch.h | 3 +- NorthstarDLL/rpakfilesystem.cpp | 10 +- NorthstarDLL/sourceconsole.cpp | 29 ++- NorthstarDLL/sourceconsole.h | 41 +--- NorthstarDLL/squirrel.cpp | 58 ++++- NorthstarDLL/squirrel.h | 3 + 17 files changed, 740 insertions(+), 259 deletions(-) create mode 100644 NorthstarDLL/color.cpp create mode 100644 NorthstarDLL/loghooks.cpp create mode 100644 NorthstarDLL/loghooks.h diff --git a/NorthstarDLL/NorthstarDLL.vcxproj b/NorthstarDLL/NorthstarDLL.vcxproj index 90dced09..11f42d64 100644 --- a/NorthstarDLL/NorthstarDLL.vcxproj +++ b/NorthstarDLL/NorthstarDLL.vcxproj @@ -122,6 +122,7 @@ + @@ -576,6 +577,8 @@ + + diff --git a/NorthstarDLL/NorthstarDLL.vcxproj.filters b/NorthstarDLL/NorthstarDLL.vcxproj.filters index 8dfbe685..168b4751 100644 --- a/NorthstarDLL/NorthstarDLL.vcxproj.filters +++ b/NorthstarDLL/NorthstarDLL.vcxproj.filters @@ -1491,6 +1491,9 @@ Header Files + + Header Files\Console + @@ -1703,6 +1706,12 @@ Source Files + + Source Files\Math + + + Source Files\Console + diff --git a/NorthstarDLL/color.cpp b/NorthstarDLL/color.cpp new file mode 100644 index 00000000..05cf645f --- /dev/null +++ b/NorthstarDLL/color.cpp @@ -0,0 +1,26 @@ +#include "pch.h" + +// clang-format off +namespace NS::Colors +{ + Color SCRIPT_UI (100, 255, 255); + Color SCRIPT_CL (100, 255, 100); + Color SCRIPT_SV (255, 100, 255); + Color NATIVE_UI (50 , 150, 150); + Color NATIVE_CL (50 , 150, 50 ); + Color NATIVE_SV (150, 50 , 150); + Color NATIVE_ENGINE (252, 133, 153); + Color FILESYSTEM (0 , 150, 150); + Color RPAK (255, 190, 0 ); + Color NORTHSTAR (66 , 72 , 128); + Color ECHO (150, 150, 159); + + Color TRACE (0 , 255, 255); + Color DEBUG (0 , 255, 255); + Color INFO (16 , 160, 16 ); + Color WARN (255, 255, 0 ); + Color ERR (255, 50 , 50 ); + Color CRIT (255, 0 , 0 ); + Color OFF (0 , 0 , 0 ); +}; +// clang-format on diff --git a/NorthstarDLL/color.h b/NorthstarDLL/color.h index e2c1ebba..4dc9b36e 100644 --- a/NorthstarDLL/color.h +++ b/NorthstarDLL/color.h @@ -27,6 +27,30 @@ typedef struct color32_s uint8_t r, g, b, a; } color32; +struct SourceColor +{ + unsigned char R; + unsigned char G; + unsigned char B; + unsigned char A; + + SourceColor(unsigned char r, unsigned char g, unsigned char b, unsigned char a) + { + R = r; + G = g; + B = b; + A = a; + } + + SourceColor() + { + R = 0; + G = 0; + B = 0; + A = 0; + } +}; + //----------------------------------------------------------------------------- // Purpose: Basic handler for an rgb set of colors // This class is fully inline @@ -34,7 +58,7 @@ typedef struct color32_s class Color { public: - Color(int r, int g, int b, int a) + Color(int r, int g, int b, int a = 255) { _color[0] = (unsigned char)r; _color[1] = (unsigned char)g; @@ -130,6 +154,44 @@ class Color return newColor; } + std::string ToANSIColor() + { + std::string out = "\033[38;2;"; + out += std::to_string(_color[0]) + ";"; + out += std::to_string(_color[1]) + ";"; + out += std::to_string(_color[2]) + ";"; + out += "49m"; + return out; + } + + SourceColor ToSourceColor() + { + return SourceColor(_color[0], _color[1], _color[2], _color[3]); + } + private: unsigned char _color[4]; }; + +namespace NS::Colors +{ + extern Color SCRIPT_UI; + extern Color SCRIPT_CL; + extern Color SCRIPT_SV; + extern Color NATIVE_UI; + extern Color NATIVE_CL; + extern Color NATIVE_SV; + extern Color NATIVE_ENGINE; + extern Color FILESYSTEM; + extern Color RPAK; + extern Color NORTHSTAR; + extern Color ECHO; + + extern Color TRACE; + extern Color DEBUG; + extern Color INFO; + extern Color WARN; + extern Color ERR; + extern Color CRIT; + extern Color OFF; +}; // namespace NS::Colors diff --git a/NorthstarDLL/dllmain.cpp b/NorthstarDLL/dllmain.cpp index 8d78ee2c..2251d41d 100644 --- a/NorthstarDLL/dllmain.cpp +++ b/NorthstarDLL/dllmain.cpp @@ -145,6 +145,11 @@ bool InitialiseNorthstar() bInitialised = true; + // initialise the console if needed (-northstar needs this) + InitialiseConsole(); + // initialise logging before most other things so that they can use spdlog and it have the proper formatting + InitialiseLogging(); + InitialiseNorthstarPrefix(); InitialiseVersion(); @@ -154,7 +159,6 @@ bool InitialiseNorthstar() curl_global_init_mem(CURL_GLOBAL_DEFAULT, _malloc_base, _free_base, _realloc_base, _strdup_base, _calloc_base); InitialiseCrashHandler(); - InitialiseLogging(); InstallInitialHooks(); CreateLogFiles(); diff --git a/NorthstarDLL/filesystem.cpp b/NorthstarDLL/filesystem.cpp index e6c6f49a..6ac6cc43 100644 --- a/NorthstarDLL/filesystem.cpp +++ b/NorthstarDLL/filesystem.cpp @@ -74,7 +74,7 @@ void SetNewModSearchPaths(Mod* mod) { if ((fs::absolute(mod->m_ModDirectory) / MOD_OVERRIDE_DIR).string().compare(sCurrentModPath)) { - spdlog::info("changing mod search path from {} to {}", sCurrentModPath, mod->m_ModDirectory.string()); + NS::log::fs->info("Changing mod search path from {} to {}", sCurrentModPath, mod->m_ModDirectory.string()); AddSearchPath( &*(*g_pFilesystem), (fs::absolute(mod->m_ModDirectory) / MOD_OVERRIDE_DIR).string().c_str(), "GAME", PATH_ADD_TO_HEAD); @@ -144,7 +144,7 @@ FileHandle_t, __fastcall, (IFileSystem* filesystem, const char* pPath, const cha HOOK(MountVPKHook, MountVPK, VPKData*, , (IFileSystem * fileSystem, const char* pVpkPath)) { - spdlog::info("MountVPK {}", pVpkPath); + NS::log::fs->info("MountVPK {}", pVpkPath); VPKData* ret = MountVPK(fileSystem, pVpkPath); for (Mod mod : g_pModManager->m_LoadedMods) diff --git a/NorthstarDLL/logging.cpp b/NorthstarDLL/logging.cpp index 01775428..233c360e 100644 --- a/NorthstarDLL/logging.cpp +++ b/NorthstarDLL/logging.cpp @@ -3,7 +3,6 @@ #include "convar.h" #include "concommand.h" #include "nsprefix.h" -#include "bitbuf.h" #include "tier0.h" #include "spdlog/sinks/basic_file_sink.h" @@ -12,257 +11,192 @@ AUTOHOOK_INIT() -ConVar* Cvar_spewlog_enable; +std::vector> loggers {}; -enum class SpewType_t +namespace NS::log { - SPEW_MESSAGE = 0, + std::shared_ptr SCRIPT_UI; + std::shared_ptr SCRIPT_CL; + std::shared_ptr SCRIPT_SV; - SPEW_WARNING, - SPEW_ASSERT, - SPEW_ERROR, - SPEW_LOG, + std::shared_ptr NATIVE_UI; + std::shared_ptr NATIVE_CL; + std::shared_ptr NATIVE_SV; + std::shared_ptr NATIVE_EN; - SPEW_TYPE_COUNT -}; - -const std::unordered_map PrintSpewTypes = { - {SpewType_t::SPEW_MESSAGE, "SPEW_MESSAGE"}, - {SpewType_t::SPEW_WARNING, "SPEW_WARNING"}, - {SpewType_t::SPEW_ASSERT, "SPEW_ASSERT"}, - {SpewType_t::SPEW_ERROR, "SPEW_ERROR"}, - {SpewType_t::SPEW_LOG, "SPEW_LOG"}}; - -// clang-format off -AUTOHOOK(EngineSpewFunc, engine.dll + 0x11CA80, -void, __fastcall, (void* pEngineServer, SpewType_t type, const char* format, va_list args)) -// clang-format on -{ - if (!Cvar_spewlog_enable->GetBool()) - return; + std::shared_ptr fs; + std::shared_ptr rpak; + std::shared_ptr echo; - const char* typeStr = PrintSpewTypes.at(type); - char formatted[2048] = {0}; - bool bShouldFormat = true; + std::shared_ptr NORTHSTAR; +}; // namespace NS::log - // because titanfall 2 is quite possibly the worst thing to yet exist, it sometimes gives invalid specifiers which will crash - // ttf2sdk had a way to prevent them from crashing but it doesnt work in debug builds - // so we use this instead - for (int i = 0; format[i]; i++) +// This needs to be called after hooks are loaded so we can access the command line args +void CreateLogFiles() +{ + if (strstr(GetCommandLineA(), "-disablelogs")) { - if (format[i] == '%') - { - switch (format[i + 1]) - { - // this is fucking awful lol - case 'd': - case 'i': - case 'u': - case 'x': - case 'X': - case 'f': - case 'F': - case 'g': - case 'G': - case 'a': - case 'A': - case 'c': - case 's': - case 'p': - case 'n': - case '%': - case '-': - case '+': - case ' ': - case '#': - case '*': - case '0': - case '1': - case '2': - case '3': - case '4': - case '5': - case '6': - case '7': - case '8': - case '9': - break; - - default: - { - bShouldFormat = false; - break; - } - } - } + spdlog::default_logger()->set_level(spdlog::level::off); } - - if (bShouldFormat) - vsnprintf(formatted, sizeof(formatted), format, args); else - spdlog::warn("Failed to format {} \"{}\"", typeStr, format); - - auto endpos = strlen(formatted); - if (formatted[endpos - 1] == '\n') - formatted[endpos - 1] = '\0'; // cut off repeated newline + { + try + { + // todo: might be good to delete logs that are too old + time_t time = std::time(nullptr); + tm currentTime = *std::localtime(&time); + std::stringstream stream; - spdlog::info("[SERVER {}] {}", typeStr, formatted); + stream << std::put_time(¤tTime, (GetNorthstarPrefix() + "/logs/nslog%Y-%m-%d %H-%M-%S.txt").c_str()); + auto sink = std::make_shared(stream.str(), false); + sink->set_pattern("[%H:%M:%S] [%n] [%l] %v"); + spdlog::default_logger()->sinks().push_back(sink); + spdlog::flush_on(spdlog::level::info); + } + catch (...) + { + spdlog::error("Failed creating log file!"); + MessageBoxA( + 0, "Failed creating log file! Make sure the profile directory is writable.", "Northstar Warning", MB_ICONWARNING | MB_OK); + } + } } -// used for printing the output of status -// clang-format off -AUTOHOOK(Status_ConMsg, engine.dll + 0x15ABD0, -void,, (const char* text, ...)) -// clang-format on +void ExternalConsoleSink::sink_it_(const spdlog::details::log_msg& msg) { - char formatted[2048]; - va_list list; - - va_start(list, text); - vsprintf_s(formatted, text, list); - va_end(list); - - auto endpos = strlen(formatted); - if (formatted[endpos - 1] == '\n') - formatted[endpos - 1] = '\0'; // cut off repeated newline - - spdlog::info(formatted); + throw std::runtime_error("sink_it_ called on SourceConsoleSink with pure log_msg. This is an error!"); } -// clang-format off -AUTOHOOK(CClientState_ProcessPrint, engine.dll + 0x1A1530, -bool,, (void* thisptr, uintptr_t msg)) -// clang-format on +void ExternalConsoleSink::custom_sink_it_(const custom_log_msg& msg) { - char* text = *(char**)(msg + 0x20); + spdlog::memory_buf_t formatted; + spdlog::sinks::base_sink::formatter_->format(msg, formatted); - auto endpos = strlen(text); - if (text[endpos - 1] == '\n') - text[endpos - 1] = '\0'; // cut off repeated newline + std::string out = ""; + // if ansi colour is turned off, just use WriteConsoleA and return + if (!g_bSpdLog_UseAnsiColor) + { + out += fmt::to_string(formatted); + } - spdlog::info(text); - return true; -} + // print to the console with colours + else + { + // get message string + std::string str = fmt::to_string(formatted); -ConVar* Cvar_cl_showtextmsg; + std::string levelColor = m_LogColours[msg.level]; + std::string name {msg.logger_name.begin(), msg.logger_name.end()}; -class ICenterPrint -{ - public: - virtual void ctor() = 0; - virtual void Clear(void) = 0; - virtual void ColorPrint(int r, int g, int b, int a, wchar_t* text) = 0; - virtual void ColorPrint(int r, int g, int b, int a, char* text) = 0; - virtual void Print(wchar_t* text) = 0; - virtual void Print(char* text) = 0; - virtual void SetTextColor(int r, int g, int b, int a) = 0; -}; + std::string name_str = "[NAME]"; + int name_pos = str.find(name_str); + str.replace(name_pos, name_str.length(), msg.origin->ANSIColor + "[" + name + "]" + default_color); -ICenterPrint* pInternalCenterPrint = NULL; + std::string level_str = "[LVL]"; + int level_pos = str.find(level_str); + str.replace(level_pos, level_str.length(), levelColor + "[" + std::string(level_names[msg.level]) + "]" + default_color); -enum class TextMsgPrintType_t -{ - HUD_PRINTNOTIFY = 1, - HUD_PRINTCONSOLE, - HUD_PRINTTALK, - HUD_PRINTCENTER -}; + out += str; + } + // print the string to the console - this is definitely bad i think + HANDLE handle = GetStdHandle(STD_OUTPUT_HANDLE); + auto ignored = WriteConsoleA(handle, out.c_str(), std::strlen(out.c_str()), nullptr, nullptr); + (void)ignored; +} -// clang-format off -AUTOHOOK(TextMsg, client.dll + 0x198710, -void,, (BFRead* msg)) -// clang-format on +void ExternalConsoleSink::flush_() { - TextMsgPrintType_t msg_dest = (TextMsgPrintType_t)msg->ReadByte(); - - char text[256]; - msg->ReadString(text, sizeof(text)); - - if (!Cvar_cl_showtextmsg->GetBool()) - return; - - switch (msg_dest) - { - case TextMsgPrintType_t::HUD_PRINTCENTER: - pInternalCenterPrint->Print(text); - break; - - default: - spdlog::warn("Unimplemented TextMsg type {}! printing to console", msg_dest); - [[fallthrough]]; - - case TextMsgPrintType_t::HUD_PRINTCONSOLE: - auto endpos = strlen(text); - if (text[endpos - 1] == '\n') - text[endpos - 1] = '\0'; // cut off repeated newline - - spdlog::info(text); - break; - } + std::cout << std::flush; } -// clang-format off -AUTOHOOK(ConCommand_echo, engine.dll + 0x123680, -void,, (const CCommand& arg)) -// clang-format on +void CustomSink::custom_log(const custom_log_msg& msg) { - if (arg.ArgC() >= 2) - spdlog::info("[echo] {}", arg.ArgS()); + std::lock_guard lock(mutex_); + custom_sink_it_(msg); } -// This needs to be called after hooks are loaded so we can access the command line args -void CreateLogFiles() +void InitialiseConsole() { - if (strstr(GetCommandLineA(), "-disablelogs")) + if (AllocConsole() == FALSE) { - spdlog::default_logger()->set_level(spdlog::level::off); + std::cout << "[*] Failed to create a console window, maybe a console already exists?" << std::endl; } else { - try - { - // todo: might be good to delete logs that are too old - time_t time = std::time(nullptr); - tm currentTime = *std::localtime(&time); - std::stringstream stream; + freopen("CONOUT$", "w", stdout); + freopen("CONOUT$", "w", stderr); + } - stream << std::put_time(¤tTime, (GetNorthstarPrefix() + "/logs/nslog%Y-%m-%d %H-%M-%S.txt").c_str()); - spdlog::default_logger()->sinks().push_back(std::make_shared(stream.str(), false)); - spdlog::flush_on(spdlog::level::info); - } - catch (...) + // this if statement is adapted from r5sdk + if (!strstr(GetCommandLineA(), "-noansiclr")) + { + g_bSpdLog_UseAnsiColor = true; + DWORD dwMode = NULL; + HANDLE hOutput = GetStdHandle(STD_OUTPUT_HANDLE); + + GetConsoleMode(hOutput, &dwMode); + dwMode |= ENABLE_PROCESSED_OUTPUT | ENABLE_VIRTUAL_TERMINAL_PROCESSING; + + if (!SetConsoleMode(hOutput, dwMode)) // Some editions of Windows have 'VirtualTerminalLevel' disabled by default. { - spdlog::error("Failed creating log file!"); - MessageBoxA( - 0, "Failed creating log file! Make sure the profile directory is writable.", "Northstar Warning", MB_ICONWARNING | MB_OK); + // If 'VirtualTerminalLevel' can't be set, just disable ANSI color, since it wouldnt work anyway. + spdlog::warn("could not set VirtualTerminalLevel. Disabling color output"); + g_bSpdLog_UseAnsiColor = false; } } } -void InitialiseLogging() +void RegisterCustomSink(std::shared_ptr sink) { - AllocConsole(); - - // Bind stdout to receive console output. - // these two lines are responsible for stuff to not show up in the console sometimes, from talking about it on discord - // apparently they were meant to make logging work when using -northstar, however from testing it seems that it doesnt - // work regardless of these two lines - // freopen("CONOUT$", "w", stdout); - // freopen("CONOUT$", "w", stderr); - spdlog::default_logger()->set_pattern("[%H:%M:%S] [%l] %v"); -} + for (auto& logger : loggers) + { + logger->custom_sinks_.push_back(sink); + } +}; -ON_DLL_LOAD_RELIESON("engine.dll", EngineSpewFuncHooks, ConVar, (CModule module)) +void InitialiseLogging() { - AUTOHOOK_DISPATCH_MODULE(engine.dll) + // create a logger, and set it to default + NS::log::NORTHSTAR = std::make_shared("NORTHSTAR", NS::Colors::NORTHSTAR, true); + NS::log::NORTHSTAR->sinks().clear(); + loggers.push_back(NS::log::NORTHSTAR); + spdlog::set_default_logger(NS::log::NORTHSTAR); + + // create our console sink + auto sink = std::make_shared(); + // set the pattern + if (g_bSpdLog_UseAnsiColor) + // dont put the log level in the pattern if we are using colours, as the colour will show the log level + sink->set_pattern("[%H:%M:%S] [NAME] [LVL] %v"); + else + sink->set_pattern("[%H:%M:%S] [%n] [%l] %v"); - Cvar_spewlog_enable = new ConVar("spewlog_enable", "1", FCVAR_NONE, "Enables/disables whether the engine spewfunc should be logged"); -} + // add our sink to the logger + NS::log::NORTHSTAR->custom_sinks_.push_back(sink); -ON_DLL_LOAD_CLIENT_RELIESON("client.dll", ClientPrintHooks, ConVar, (CModule module)) -{ - AUTOHOOK_DISPATCH_MODULE(client.dll) + NS::log::SCRIPT_UI = std::make_shared("SCRIPT UI", NS::Colors::SCRIPT_UI); + NS::log::SCRIPT_CL = std::make_shared("SCRIPT CL", NS::Colors::SCRIPT_CL); + NS::log::SCRIPT_SV = std::make_shared("SCRIPT SV", NS::Colors::SCRIPT_SV); + + NS::log::NATIVE_UI = std::make_shared("NATIVE UI", NS::Colors::NATIVE_UI); + NS::log::NATIVE_CL = std::make_shared("NATIVE CL", NS::Colors::NATIVE_CL); + NS::log::NATIVE_SV = std::make_shared("NATIVE SV", NS::Colors::NATIVE_SV); + NS::log::NATIVE_EN = std::make_shared("NATIVE EN", NS::Colors::NATIVE_ENGINE); + + NS::log::fs = std::make_shared("FILESYSTM", NS::Colors::FILESYSTEM); + NS::log::rpak = std::make_shared("RPAK_FSYS", NS::Colors::RPAK); + NS::log::echo = std::make_shared("ECHO", NS::Colors::ECHO); + + loggers.push_back(NS::log::SCRIPT_UI); + loggers.push_back(NS::log::SCRIPT_CL); + loggers.push_back(NS::log::SCRIPT_SV); + + loggers.push_back(NS::log::NATIVE_UI); + loggers.push_back(NS::log::NATIVE_CL); + loggers.push_back(NS::log::NATIVE_SV); + loggers.push_back(NS::log::NATIVE_EN); - Cvar_cl_showtextmsg = new ConVar("cl_showtextmsg", "1", FCVAR_NONE, "Enable/disable text messages printing on the screen."); - pInternalCenterPrint = module.Offset(0x216E940).As(); + loggers.push_back(NS::log::fs); + loggers.push_back(NS::log::rpak); + loggers.push_back(NS::log::echo); } diff --git a/NorthstarDLL/logging.h b/NorthstarDLL/logging.h index 83fd0c12..a75dce91 100644 --- a/NorthstarDLL/logging.h +++ b/NorthstarDLL/logging.h @@ -1,4 +1,131 @@ #pragma once +#include "pch.h" +#include "spdlog/sinks/base_sink.h" +#include "spdlog/logger.h" +#include "squirrel.h" +#include "color.h" void CreateLogFiles(); void InitialiseLogging(); +void InitialiseConsole(); + +class ColoredLogger; + +struct custom_log_msg : spdlog::details::log_msg +{ + public: + custom_log_msg(ColoredLogger* origin, spdlog::details::log_msg msg) : origin(origin), spdlog::details::log_msg(msg) {} + + ColoredLogger* origin; +}; + +class CustomSink : public spdlog::sinks::base_sink +{ + public: + void custom_log(const custom_log_msg& msg); + virtual void custom_sink_it_(const custom_log_msg& msg) + { + throw std::runtime_error("Pure virtual call to CustomSink::custom_sink_it_"); + } +}; + +class ColoredLogger : public spdlog::logger +{ + public: + std::string ANSIColor; + SourceColor SRCColor; + + std::vector> custom_sinks_; + + ColoredLogger(std::string name, Color color, bool first = false) : spdlog::logger(*spdlog::default_logger()) + { + name_ = std::move(name); + if (!first) + { + custom_sinks_ = dynamic_pointer_cast(spdlog::default_logger())->custom_sinks_; + } + + ANSIColor = color.ToANSIColor(); + SRCColor = color.ToSourceColor(); + } + + void sink_it_(const spdlog::details::log_msg& msg) + { + custom_log_msg custom_msg {this, msg}; + + // Ugh + for (auto& sink : sinks_) + { + SPDLOG_TRY + { + sink->log(custom_msg); + } + SPDLOG_LOGGER_CATCH() + } + + for (auto& sink : custom_sinks_) + { + SPDLOG_TRY + { + sink->custom_log(custom_msg); + } + SPDLOG_LOGGER_CATCH() + } + + if (should_flush_(custom_msg)) + { + flush_(); + } + } +}; + +namespace NS::log +{ + // Squirrel + extern std::shared_ptr SCRIPT_UI; + extern std::shared_ptr SCRIPT_CL; + extern std::shared_ptr SCRIPT_SV; + + // Native code + extern std::shared_ptr NATIVE_UI; + extern std::shared_ptr NATIVE_CL; + extern std::shared_ptr NATIVE_SV; + extern std::shared_ptr NATIVE_EN; + + // File system + extern std::shared_ptr fs; + // RPak + extern std::shared_ptr rpak; + // Echo + extern std::shared_ptr echo; + + extern std::shared_ptr NORTHSTAR; +}; // namespace NS::log + +void RegisterCustomSink(std::shared_ptr sink); + +inline bool g_bSpdLog_UseAnsiColor = true; + +// Could maybe use some different names here, idk +static const char* level_names[] {"trac", "dbug", "info", "warn", "errr", "crit", "off"}; + +// spdlog logger, for cool colour things +class ExternalConsoleSink : public CustomSink +{ + private: + std::map m_LogColours = { + {spdlog::level::trace, NS::Colors::TRACE.ToANSIColor()}, + {spdlog::level::debug, NS::Colors::DEBUG.ToANSIColor()}, + {spdlog::level::info, NS::Colors::INFO.ToANSIColor()}, + {spdlog::level::warn, NS::Colors::WARN.ToANSIColor()}, + {spdlog::level::err, NS::Colors::ERR.ToANSIColor()}, + {spdlog::level::critical, NS::Colors::CRIT.ToANSIColor()}, + {spdlog::level::off, NS::Colors::OFF.ToANSIColor()}}; + + std::string default_color = "\033[39;49m"; + + protected: + void sink_it_(const spdlog::details::log_msg& msg) override; + void custom_sink_it_(const custom_log_msg& msg); + void flush_() override; +}; diff --git a/NorthstarDLL/loghooks.cpp b/NorthstarDLL/loghooks.cpp new file mode 100644 index 00000000..316d34ae --- /dev/null +++ b/NorthstarDLL/loghooks.cpp @@ -0,0 +1,262 @@ +#include "pch.h" +#include "logging.h" +#include "loghooks.h" +#include "convar.h" +#include "concommand.h" +#include "bitbuf.h" +#include "nsprefix.h" +#include "tier0.h" + +#include +#include + +AUTOHOOK_INIT() + +ConVar* Cvar_spewlog_enable; +ConVar* Cvar_cl_showtextmsg; + +enum class TextMsgPrintType_t +{ + HUD_PRINTNOTIFY = 1, + HUD_PRINTCONSOLE, + HUD_PRINTTALK, + HUD_PRINTCENTER +}; + +class ICenterPrint +{ + public: + virtual void ctor() = 0; + virtual void Clear(void) = 0; + virtual void ColorPrint(int r, int g, int b, int a, wchar_t* text) = 0; + virtual void ColorPrint(int r, int g, int b, int a, char* text) = 0; + virtual void Print(wchar_t* text) = 0; + virtual void Print(char* text) = 0; + virtual void SetTextColor(int r, int g, int b, int a) = 0; +}; + +enum class SpewType_t +{ + SPEW_MESSAGE = 0, + + SPEW_WARNING, + SPEW_ASSERT, + SPEW_ERROR, + SPEW_LOG, + + SPEW_TYPE_COUNT +}; + +const std::unordered_map PrintSpewTypes = { + {SpewType_t::SPEW_MESSAGE, "SPEW_MESSAGE"}, + {SpewType_t::SPEW_WARNING, "SPEW_WARNING"}, + {SpewType_t::SPEW_ASSERT, "SPEW_ASSERT"}, + {SpewType_t::SPEW_ERROR, "SPEW_ERROR"}, + {SpewType_t::SPEW_LOG, "SPEW_LOG"}}; + +// these are used to define the base text colour for these things +const std::unordered_map PrintSpewLevels = { + {SpewType_t::SPEW_MESSAGE, spdlog::level::level_enum::info}, + {SpewType_t::SPEW_WARNING, spdlog::level::level_enum::warn}, + {SpewType_t::SPEW_ASSERT, spdlog::level::level_enum::err}, + {SpewType_t::SPEW_ERROR, spdlog::level::level_enum::err}, + {SpewType_t::SPEW_LOG, spdlog::level::level_enum::info}}; + +const std::unordered_map PrintSpewTypes_Short = { + {SpewType_t::SPEW_MESSAGE, 'M'}, + {SpewType_t::SPEW_WARNING, 'W'}, + {SpewType_t::SPEW_ASSERT, 'A'}, + {SpewType_t::SPEW_ERROR, 'E'}, + {SpewType_t::SPEW_LOG, 'L'}}; + +ICenterPrint* pInternalCenterPrint = NULL; + +// clang-format off +AUTOHOOK(TextMsg, client.dll + 0x198710, +void,, (BFRead* msg)) +// clang-format on +{ + TextMsgPrintType_t msg_dest = (TextMsgPrintType_t)msg->ReadByte(); + + char text[256]; + msg->ReadString(text, sizeof(text)); + + if (!Cvar_cl_showtextmsg->GetBool()) + return; + + switch (msg_dest) + { + case TextMsgPrintType_t::HUD_PRINTCENTER: + pInternalCenterPrint->Print(text); + break; + + default: + spdlog::warn("Unimplemented TextMsg type {}! printing to console", msg_dest); + [[fallthrough]]; + + case TextMsgPrintType_t::HUD_PRINTCONSOLE: + auto endpos = strlen(text); + if (text[endpos - 1] == '\n') + text[endpos - 1] = '\0'; // cut off repeated newline + + spdlog::info(text); + break; + } +} + +// clang-format off +AUTOHOOK(Hook_fprintf, engine.dll + 0x51B1F0, +int,, (void* const stream, const char* const format, ...)) +// clang-format on +{ + va_list va; + va_start(va, format); + + SQChar buf[1024]; + int charsWritten = vsnprintf_s(buf, _TRUNCATE, format, va); + + if (charsWritten > 0) + { + if (buf[charsWritten - 1] == '\n') + buf[charsWritten - 1] = '\0'; + NS::log::NATIVE_EN->info("{}", buf); + } + + va_end(va); + return 0; +} + +// clang-format off +AUTOHOOK(ConCommand_echo, engine.dll + 0x123680, +void,, (const CCommand& arg)) +// clang-format on +{ + if (arg.ArgC() >= 2) + NS::log::echo->info("{}", arg.ArgS()); +} + +// clang-format off +AUTOHOOK(EngineSpewFunc, engine.dll + 0x11CA80, +void, __fastcall, (void* pEngineServer, SpewType_t type, const char* format, va_list args)) +// clang-format on +{ + if (!Cvar_spewlog_enable->GetBool()) + return; + + const char* typeStr = PrintSpewTypes.at(type); + char formatted[2048] = {0}; + bool bShouldFormat = true; + + // because titanfall 2 is quite possibly the worst thing to yet exist, it sometimes gives invalid specifiers which will crash + // ttf2sdk had a way to prevent them from crashing but it doesnt work in debug builds + // so we use this instead + for (int i = 0; format[i]; i++) + { + if (format[i] == '%') + { + switch (format[i + 1]) + { + // this is fucking awful lol + case 'd': + case 'i': + case 'u': + case 'x': + case 'X': + case 'f': + case 'F': + case 'g': + case 'G': + case 'a': + case 'A': + case 'c': + case 's': + case 'p': + case 'n': + case '%': + case '-': + case '+': + case ' ': + case '#': + case '*': + case '0': + case '1': + case '2': + case '3': + case '4': + case '5': + case '6': + case '7': + case '8': + case '9': + break; + + default: + { + bShouldFormat = false; + break; + } + } + } + } + + if (bShouldFormat) + vsnprintf(formatted, sizeof(formatted), format, args); + else + spdlog::warn("Failed to format {} \"{}\"", typeStr, format); + + auto endpos = strlen(formatted); + if (formatted[endpos - 1] == '\n') + formatted[endpos - 1] = '\0'; // cut off repeated newline + + NS::log::NATIVE_SV->log(PrintSpewLevels.at(type), "{}", formatted); +} + +// used for printing the output of status +// clang-format off +AUTOHOOK(Status_ConMsg, engine.dll + 0x15ABD0, +void,, (const char* text, ...)) +// clang-format on +{ + char formatted[2048]; + va_list list; + + va_start(list, text); + vsprintf_s(formatted, text, list); + va_end(list); + + auto endpos = strlen(formatted); + if (formatted[endpos - 1] == '\n') + formatted[endpos - 1] = '\0'; // cut off repeated newline + + spdlog::info(formatted); +} + +// clang-format off +AUTOHOOK(CClientState_ProcessPrint, engine.dll + 0x1A1530, +bool,, (void* thisptr, uintptr_t msg)) +// clang-format on +{ + char* text = *(char**)(msg + 0x20); + + auto endpos = strlen(text); + if (text[endpos - 1] == '\n') + text[endpos - 1] = '\0'; // cut off repeated newline + + spdlog::info(text); + return true; +} + +ON_DLL_LOAD_RELIESON("engine.dll", EngineSpewFuncHooks, ConVar, (CModule module)) +{ + AUTOHOOK_DISPATCH_MODULE(engine.dll) + + Cvar_spewlog_enable = new ConVar("spewlog_enable", "1", FCVAR_NONE, "Enables/disables whether the engine spewfunc should be logged"); +} + +ON_DLL_LOAD_CLIENT_RELIESON("client.dll", ClientPrintHooks, ConVar, (CModule module)) +{ + AUTOHOOK_DISPATCH_MODULE(client.dll) + + Cvar_cl_showtextmsg = new ConVar("cl_showtextmsg", "1", FCVAR_NONE, "Enable/disable text messages printing on the screen."); + pInternalCenterPrint = module.Offset(0x216E940).As(); +} diff --git a/NorthstarDLL/loghooks.h b/NorthstarDLL/loghooks.h new file mode 100644 index 00000000..6f70f09b --- /dev/null +++ b/NorthstarDLL/loghooks.h @@ -0,0 +1 @@ +#pragma once diff --git a/NorthstarDLL/nsprefix.cpp b/NorthstarDLL/nsprefix.cpp index 64a9d1f1..9c2e22c9 100644 --- a/NorthstarDLL/nsprefix.cpp +++ b/NorthstarDLL/nsprefix.cpp @@ -35,4 +35,7 @@ void InitialiseNorthstarPrefix() spdlog::info("Profile was not found in command line arguments. Using default: R2Northstar"); NORTHSTAR_FOLDER_PREFIX = "R2Northstar"; } + + // set the console title to show the current profile + SetConsoleTitleA((std::string("NorthstarLauncher | ") + NORTHSTAR_FOLDER_PREFIX).c_str()); } diff --git a/NorthstarDLL/pch.h b/NorthstarDLL/pch.h index e23d6a9b..e07c5598 100644 --- a/NorthstarDLL/pch.h +++ b/NorthstarDLL/pch.h @@ -20,9 +20,10 @@ namespace fs = std::filesystem; +#include "color.h" +#include "spdlog/spdlog.h" #include "logging.h" #include "MinHook.h" -#include "spdlog/spdlog.h" #include "libcurl/include/curl/curl.h" #include "hooks.h" #include "memory.h" diff --git a/NorthstarDLL/rpakfilesystem.cpp b/NorthstarDLL/rpakfilesystem.cpp index 0fffd99b..f6de514b 100644 --- a/NorthstarDLL/rpakfilesystem.cpp +++ b/NorthstarDLL/rpakfilesystem.cpp @@ -216,13 +216,13 @@ int, __fastcall, (char* pPath, void* unknownSingleton, int flags, void* pCallbac if (bNeedToFreePakName) delete[] pPath; - spdlog::info("Not loading pak {} for dedicated server", originalPath); + NS::log::rpak->info("Not loading pak {} for dedicated server", originalPath); return -1; } } int iPakHandle = LoadPakAsync(pPath, unknownSingleton, flags, pCallback0, pCallback1); - spdlog::info("LoadPakAsync {} {}", pPath, iPakHandle); + NS::log::rpak->info("LoadPakAsync {} {}", pPath, iPakHandle); // trak the pak g_pPakLoadManager->TrackLoadedPak(ePakLoadSource::UNTRACKED, iPakHandle, nPathHash); @@ -250,7 +250,7 @@ void*, __fastcall, (int nPakHandle, void* pCallback)) bShouldUnloadPaks = true; } - spdlog::info("UnloadPak {}", nPakHandle); + NS::log::rpak->info("UnloadPak {}", nPakHandle); return UnloadPak(nPakHandle, pCallback); } @@ -267,7 +267,7 @@ void*, __fastcall, (const char* pPath, void* pCallback)) if (path.extension() == ".stbsp") { - spdlog::info("LoadStreamBsp: {}", filename.string()); + NS::log::rpak->info("LoadStreamBsp: {}", filename.string()); // resolve modded stbsp path so we can load mod stbsps auto modFile = g_pModManager->m_ModFiles.find(g_pModManager->NormaliseModFilePath(fs::path("maps" / filename))); @@ -321,7 +321,7 @@ void*, __fastcall, (const char* pPath, void* pCallback)) } LOG_STARPAK: - spdlog::info("LoadStreamPak: {}", filename.string()); + NS::log::rpak->info("LoadStreamPak: {}", filename.string()); } return ReadFileAsync(pPath, pCallback); diff --git a/NorthstarDLL/sourceconsole.cpp b/NorthstarDLL/sourceconsole.cpp index ad31e09d..0048ac4c 100644 --- a/NorthstarDLL/sourceconsole.cpp +++ b/NorthstarDLL/sourceconsole.cpp @@ -25,14 +25,30 @@ void ConCommand_hideconsole(const CCommand& arg) (*g_pSourceGameConsole)->Hide(); } -void SourceConsoleSink::sink_it_(const spdlog::details::log_msg& msg) +void SourceConsoleSink::custom_sink_it_(const custom_log_msg& msg) { if (!(*g_pSourceGameConsole)->m_bInitialized) return; spdlog::memory_buf_t formatted; spdlog::sinks::base_sink::formatter_->format(msg, formatted); - (*g_pSourceGameConsole)->m_pConsole->m_pConsolePanel->ColorPrint(m_LogColours[msg.level], fmt::to_string(formatted).c_str()); + + // get message string + std::string str = fmt::to_string(formatted); + + SourceColor levelColor = m_LogColours[msg.level]; + std::string name {msg.logger_name.begin(), msg.logger_name.end()}; + + (*g_pSourceGameConsole)->m_pConsole->m_pConsolePanel->ColorPrint(msg.origin->SRCColor, ("[" + name + "]").c_str()); + (*g_pSourceGameConsole)->m_pConsole->m_pConsolePanel->Print(" "); + (*g_pSourceGameConsole)->m_pConsole->m_pConsolePanel->ColorPrint(levelColor, ("[" + std::string(level_names[msg.level]) + "]").c_str()); + (*g_pSourceGameConsole)->m_pConsole->m_pConsolePanel->Print(" "); + (*g_pSourceGameConsole)->m_pConsole->m_pConsolePanel->Print(fmt::to_string(formatted).c_str()); +} + +void SourceConsoleSink::sink_it_(const spdlog::details::log_msg& msg) +{ + throw std::runtime_error("sink_it_ called on SourceConsoleSink with pure log_msg. This is an error!"); } void SourceConsoleSink::flush_() {} @@ -58,9 +74,12 @@ void InitialiseConsoleOnInterfaceCreation() // hook OnCommandSubmitted so we print inputted commands OnCommandSubmittedHook.Dispatch((*g_pSourceGameConsole)->m_pConsole->m_vtable->OnCommandSubmitted); - auto consoleLogger = std::make_shared(); - consoleLogger->set_pattern("[%l] %v"); - spdlog::default_logger()->sinks().push_back(consoleLogger); + auto consoleSink = std::make_shared(); + if (g_bSpdLog_UseAnsiColor) + consoleSink->set_pattern("%v"); // no need to include the level in the game console, the text colour signifies it anyway + else + consoleSink->set_pattern("[%n] [%l] %v"); // no colour, so we should show the level for colourblind people + RegisterCustomSink(consoleSink); } ON_DLL_LOAD_CLIENT_RELIESON("client.dll", SourceConsole, ConCommand, (CModule module)) diff --git a/NorthstarDLL/sourceconsole.h b/NorthstarDLL/sourceconsole.h index e811f523..b22ef2d3 100644 --- a/NorthstarDLL/sourceconsole.h +++ b/NorthstarDLL/sourceconsole.h @@ -11,30 +11,6 @@ class EditablePanel unsigned char unknown[0x2B0]; }; -struct SourceColor -{ - unsigned char R; - unsigned char G; - unsigned char B; - unsigned char A; - - SourceColor(unsigned char r, unsigned char g, unsigned char b, unsigned char a) - { - R = r; - G = g; - B = b; - A = a; - } - - SourceColor() - { - R = 0; - G = 0; - B = 0; - A = 0; - } -}; - class IConsoleDisplayFunc { public: @@ -89,19 +65,20 @@ class CGameConsole extern SourceInterface* g_pSourceGameConsole; // spdlog logger -class SourceConsoleSink : public spdlog::sinks::base_sink +class SourceConsoleSink : public CustomSink { private: std::map m_LogColours = { - {spdlog::level::trace, SourceColor(0, 255, 255, 255)}, - {spdlog::level::debug, SourceColor(0, 255, 255, 255)}, - {spdlog::level::info, SourceColor(255, 255, 255, 255)}, - {spdlog::level::warn, SourceColor(255, 255, 0, 255)}, - {spdlog::level::err, SourceColor(255, 0, 0, 255)}, - {spdlog::level::critical, SourceColor(255, 0, 0, 255)}, - {spdlog::level::off, SourceColor(0, 0, 0, 0)}}; + {spdlog::level::trace, NS::Colors::TRACE.ToSourceColor()}, + {spdlog::level::debug, NS::Colors::DEBUG.ToSourceColor()}, + {spdlog::level::info, NS::Colors::INFO.ToSourceColor()}, + {spdlog::level::warn, NS::Colors::WARN.ToSourceColor()}, + {spdlog::level::err, NS::Colors::ERR.ToSourceColor()}, + {spdlog::level::critical, NS::Colors::CRIT.ToSourceColor()}, + {spdlog::level::off, NS::Colors::OFF.ToSourceColor()}}; protected: + void custom_sink_it_(const custom_log_msg& msg); void sink_it_(const spdlog::details::log_msg& msg) override; void flush_() override; }; diff --git a/NorthstarDLL/squirrel.cpp b/NorthstarDLL/squirrel.cpp index be0dceeb..c90b2d7f 100644 --- a/NorthstarDLL/squirrel.cpp +++ b/NorthstarDLL/squirrel.cpp @@ -8,6 +8,35 @@ AUTOHOOK_INIT() +std::shared_ptr getSquirrelLoggerByContext(ScriptContext context) +{ + switch (context) + { + case ScriptContext::UI: + return NS::log::SCRIPT_UI; + case ScriptContext::CLIENT: + return NS::log::SCRIPT_CL; + case ScriptContext::SERVER: + return NS::log::SCRIPT_SV; + default: + throw std::runtime_error("getSquirrelLoggerByContext called with invalid context"); + return nullptr; + } +} + +namespace NS::log +{ + template std::shared_ptr squirrel_logger() + { + // Switch statements can't be constexpr afaik + // clang-format off + if constexpr (context == ScriptContext::UI) { return SCRIPT_UI; } + if constexpr (context == ScriptContext::CLIENT) { return SCRIPT_CL; } + if constexpr (context == ScriptContext::SERVER) { return SCRIPT_SV; } + // clang-format on + } +}; // namespace NS::log + const char* GetContextName(ScriptContext context) { switch (context) @@ -23,6 +52,21 @@ const char* GetContextName(ScriptContext context) } } +const char* GetContextName_Short(ScriptContext context) +{ + switch (context) + { + case ScriptContext::CLIENT: + return "CL"; + case ScriptContext::SERVER: + return "SV"; + case ScriptContext::UI: + return "UI"; + default: + return "??"; + } +} + eSQReturnType SQReturnTypeFromString(const char* pReturnType) { static const std::map sqReturnTypeNameToString = { @@ -230,8 +274,7 @@ template SQInteger SQPrintHook(HSquirrelVM* sqvm, const { if (buf[charsWritten - 1] == '\n') buf[charsWritten - 1] = '\0'; - - spdlog::info("[{} SCRIPT] {}", GetContextName(context), buf); + g_pSquirrel->logger->info("{}", buf); } va_end(va); @@ -279,8 +322,10 @@ void __fastcall ScriptCompileErrorHook(HSquirrelVM* sqvm, const char* error, con bIsFatalError = g_pSquirrel->m_bFatalCompilationErrors; } - spdlog::error("{} SCRIPT COMPILE ERROR {}", GetContextName(realContext), error); - spdlog::error("{} line [{}] column [{}]", file, line, column); + auto logger = getSquirrelLoggerByContext(realContext); + + logger->error("COMPILE ERROR {}", error); + logger->error("{} line [{}] column [{}]", file, line, column); // use disconnect to display an error message for the compile error, but only if the compilation error was fatal // todo, we could get this from sqvm itself probably, rather than hooking sq_compiler_create @@ -518,6 +563,9 @@ ON_DLL_LOAD_RELIESON("client.dll", ClientSquirrel, ConCommand, (CModule module)) &g_pSquirrel->RegisterSquirrelFunc); g_pSquirrel->RegisterSquirrelFunc = g_pSquirrel->RegisterSquirrelFunc; + g_pSquirrel->logger = NS::log::SCRIPT_CL; + g_pSquirrel->logger = NS::log::SCRIPT_UI; + // uiscript_reset concommand: don't loop forever if compilation fails module.Offset(0x3C6E4C).NOP(6); @@ -582,6 +630,8 @@ ON_DLL_LOAD_RELIESON("server.dll", ServerSquirrel, ConCommand, (CModule module)) g_pSquirrel->__sq_GetEntityConstant_CBaseEntity = module.Offset(0x418AF0).As(); g_pSquirrel->__sq_getentityfrominstance = module.Offset(0x1E920).As(); + g_pSquirrel->logger = NS::log::SCRIPT_SV; + MAKEHOOK( module.Offset(0x1DD10), &RegisterSquirrelFunctionHook, diff --git a/NorthstarDLL/squirrel.h b/NorthstarDLL/squirrel.h index a3a214de..a157b1af 100644 --- a/NorthstarDLL/squirrel.h +++ b/NorthstarDLL/squirrel.h @@ -83,6 +83,7 @@ enum class ScriptContext : int }; const char* GetContextName(ScriptContext context); +const char* GetContextName_Short(ScriptContext context); eSQReturnType SQReturnTypeFromString(const char* pReturnType); const char* SQTypeNameFromID(const int iTypeId); @@ -144,6 +145,8 @@ template class SquirrelManager bool m_bFatalCompilationErrors = false; + std::shared_ptr logger; + #pragma region SQVM funcs RegisterSquirrelFuncType RegisterSquirrelFunc; sq_defconstType __sq_defconst; -- cgit v1.2.3