Saner logging

.gitmodules

@@ -35,3 +35,6 @@
 [submodule "thirdparty/openal_soft"]
 	path = thirdparty/openal_soft
 	url = https://github.com/kcat/openal-soft.git
+[submodule "thirdparty/spdlog"]
+	path = thirdparty/spdlog
+	url = https://github.com/gabime/spdlog.git

src/Application/Game.cpp

@@ -1313,9 +1313,9 @@ void Game::processQueuedMessages() {
                     continue;
                 } else {
                     if (pParty->uFlags & PARTY_FLAGS_1_AIRBORNE)
-                        logger->verbose("Party is airborne");
+                        logger->trace("Party is airborne");
                     if (pParty->uFlags & PARTY_FLAGS_1_STANDING_ON_WATER)
-                        logger->verbose("Party on water");
+                        logger->trace("Party on water");
                 }
 
                 if (pParty->bTurnBasedModeOn) {

src/Application/Game.h

@@ -8,7 +8,6 @@
 #include "GameIocContainer.h"
 
 #include "Engine/Engine.h"
-#include "Engine/EngineIocContainer.h"
 
 #include "Io/KeyboardInputHandler.h"
 #include "Io/Mouse.h"

src/Application/GameConfig.cpp

@@ -1,9 +1,5 @@
 #include "GameConfig.h"
 
-#include <filesystem>
-
-#include "Engine/EngineIocContainer.h"
-
 #include "Library/Logger/Logger.h"
 #include "Library/Serialization/EnumSerialization.h"
 
@@ -21,15 +17,6 @@ MM_DEFINE_ENUM_SERIALIZATION_FUNCTIONS(PlatformWindowMode, CASE_INSENSITIVE, {
     {WINDOW_MODE_FULLSCREEN_BORDERLESS, "3"}
 })
 
-MM_DEFINE_ENUM_SERIALIZATION_FUNCTIONS(PlatformLogLevel, CASE_INSENSITIVE, {
-    {LOG_VERBOSE, "verbose"},
-    {LOG_DEBUG, "debug"},
-    {LOG_INFO, "info"},
-    {LOG_WARNING, "warning"},
-    {LOG_ERROR, "error"},
-    {LOG_CRITICAL, "critical"},
-})
-
 MM_DEFINE_ENUM_SERIALIZATION_FUNCTIONS(RandomEngineType, CASE_INSENSITIVE, {
     {RANDOM_ENGINE_MERSENNE_TWISTER, "mersenne_twister"},
     {RANDOM_ENGINE_SEQUENTIAL, "sequential"}

src/Application/GameConfig.h

@@ -7,10 +7,9 @@
 
 #include "Io/Key.h"
 
-#include "Platform/PlatformEnums.h"
-
 #include "Library/Config/Config.h"
 #include "Library/Random/RandomEngineEnums.h"
+#include "Library/Logger/LogEnums.h"
 
 #ifdef __ANDROID__
 #define ConfigRenderer RENDERER_OPENGL_ES
@@ -21,7 +20,6 @@
 #endif
 
 MM_DECLARE_SERIALIZATION_FUNCTIONS(PlatformWindowMode)
-MM_DECLARE_SERIALIZATION_FUNCTIONS(PlatformLogLevel)
 MM_DECLARE_SERIALIZATION_FUNCTIONS(RandomEngineType)
 
 class GameConfig : public Config {
@@ -83,8 +81,8 @@ class GameConfig : public Config {
 
         Bool NoMargaret = {this, "no_margareth", false, "Disable Margaret's tour messages on Emerald Island."};
 
-        ConfigEntry<PlatformLogLevel> LogLevel = {this, "log_level", LOG_ERROR,
-                                                  "Default log level. One of 'verbose', 'debug', 'info', 'warning', 'error' and 'critical'."};
+        ConfigEntry<LogLevel> LogLevel = {this, "log_level", LOG_ERROR,
+                                          "Default log level. One of 'verbose', 'debug', 'info', 'warning', 'error' and 'critical'."};
 
         Int TraceFrameTimeMs = {this, "trace_frame_time_ms", 50, &ValidateFrameTime,
                                 "Number of milliseconds per frame when recording game traces."};

src/Application/GamePathResolver.cpp

@@ -2,7 +2,6 @@
 
 #include "Application/GamePathResolver.h"
 
-#include "Engine/EngineIocContainer.h"
 #include "Library/Logger/Logger.h"
 #include "Platform/Platform.h"
 

src/Application/GameStarter.cpp

@@ -4,14 +4,14 @@
 #include <filesystem>
 #include <string>
 
-#include "Engine/EngineIocContainer.h"
 #include "Engine/Engine.h"
 #include "Engine/EngineGlobals.h"
 
 #include "Library/Application/PlatformApplication.h"
 #include "Library/Logger/Logger.h"
+#include "Library/Logger/LogSink.h"
+#include "Library/Logger/BufferLogSink.h"
 
-#include "Platform/PlatformLogger.h"
 #include "Platform/Platform.h"
 #include "Platform/Null/NullPlatform.h"
 
@@ -21,47 +21,41 @@
 
 GameStarter::GameStarter(GameStarterOptions options): _options(std::move(options)) {
     // Init logger.
-    _logger = PlatformLogger::createStandardLogger();
-    auto setLogLevel = [logger = _logger.get()](PlatformLogLevel level) {
-        logger->setLogLevel(APPLICATION_LOG, level);
-        logger->setLogLevel(PLATFORM_LOG, level);
-    };
-    if (_options.logLevel)
-        setLogLevel(*_options.logLevel);
-    _globalLogger = std::make_unique<Logger>(_logger.get());
-    ::logger = _globalLogger.get();
+    _bufferSink = std::make_unique<BufferLogSink>();
+    _defaultSink = LogSink::createDefaultSink();
+    _logger = std::make_unique<Logger>(LOG_TRACE, _bufferSink.get());
+    Engine::LogEngineBuildInfo();
 
     // Create platform & init data paths.
     if (_options.headless) {
         _platform = std::make_unique<NullPlatform>(NullPlatformOptions());
     } else {
-        // TODO(captainurist): this can't use log level from config. Introduce a buffer logger, log into a buffer,
-        //                     dump into the real logger when it is constructed.
         _platform = Platform::createStandardPlatform(_logger.get());
     }
     resolveDefaults(_platform.get(), &_options);
 
     // Init config - needs data paths initialized.
     _config = std::make_shared<GameConfig>();
-    std::string configLogMessage;
     if (_options.useConfig) {
         if (std::filesystem::exists(_options.configPath)) {
             _config->load(_options.configPath);
-            configLogMessage = fmt::format("Configuration file '{}' loaded!", _options.configPath);
+            _logger->info("Configuration file '{}' loaded!", _options.configPath);
         } else {
             _config->reset();
-            configLogMessage = fmt::format("Could not read configuration file '{}'! Loaded default configuration instead!", _options.configPath);
+            _logger->info("Could not read configuration file '{}'! Loaded default configuration instead!", _options.configPath);
         }
     }
-    if (!_options.logLevel)
-        setLogLevel(_config->debug.LogLevel.value());
     if (_options.headless)
         _config->graphics.Renderer.setValue(RENDERER_NULL); // TODO(captainurist): we shouldn't be writing to config here.
 
-    // Write the first log messages.
-    Engine::LogEngineBuildInfo();
-    if (!configLogMessage.empty())
-        logger->info("{}", configLogMessage);
+    // Finish logger init now that we know the desired log level.
+    if (_options.logLevel) {
+        _logger->setLevel(*_options.logLevel);
+    } else {
+        _logger->setLevel(_config->debug.LogLevel.value());
+    }
+    _logger->setSink(_defaultSink.get());
+    _bufferSink->flush(_logger.get());
 
     // Validate data paths.
     ::platform = _platform.get(); // TODO(captainurist): a hack to make validateDataPath work.

src/Application/GameStarter.h

@@ -7,6 +7,8 @@
 class Platform;
 class PlatformLogger;
 class Logger;
+class BufferLogSink;
+class LogSink;
 class PlatformApplication;
 class GameConfig;
 class Game;
@@ -31,8 +33,9 @@ class GameStarter {
 
  private:
     GameStarterOptions _options;
-    std::unique_ptr<PlatformLogger> _logger;
-    std::unique_ptr<Logger> _globalLogger;
+    std::unique_ptr<BufferLogSink> _bufferSink;
+    std::unique_ptr<LogSink> _defaultSink;
+    std::unique_ptr<Logger> _logger;
     std::unique_ptr<Platform> _platform;
     std::unique_ptr<PlatformApplication> _application;
     std::shared_ptr<GameConfig> _config;

src/Application/GameStarterOptions.h

@@ -5,12 +5,12 @@
 
 #include "Engine/Graphics/RenderEnums.h"
 
-#include "Platform/PlatformEnums.h"
+#include "Library/Logger/LogEnums.h"
 
 struct GameStarterOptions {
     bool useConfig = true; // Load external config & save it on exit?
     std::string configPath; // Path to config, empty means use default.
     std::string dataPath; // Path to game data, empty means use default.
-    std::optional<PlatformLogLevel> logLevel; // Override log level.
+    std::optional<LogLevel> logLevel; // Override log level.
     bool headless = false; // Run in headless mode.
 };

src/Bin/OpenEnroth/OpenEnrothOptions.cpp

@@ -3,7 +3,6 @@
 #include <memory>
 
 #include "Application/GamePathResolver.h"
-#include "Application/GameConfig.h" // For PlatformLogLevel serialization.
 
 #include "Library/Cli/CliApp.h"
 
@@ -24,10 +23,10 @@ OpenEnrothOptions OpenEnrothOptions::parse(int argc, char **argv) {
         "Path to OpenEnroth config file, default is 'openenroth.ini' in data folder.")->option_text("PATH");
     app->add_option(
         "--log-level", result.logLevel,
-        "Log level, one of 'verbose', 'debug', 'info', 'warning', 'error', 'critical'.")->option_text("LOG_LEVEL");
+        "Log level, one of 'trace', 'debug', 'info', 'warning', 'error', 'critical'.")->option_text("LOG_LEVEL");
     app->add_flag_callback(
-        "-v,--verbose", [&] { result.logLevel = LOG_VERBOSE; },
-        "Set log level to 'verbose'.");
+        "-v,--verbose", [&] { result.logLevel = LOG_TRACE; },
+        "Set log level to 'trace'.");
     app->set_help_flag("-h,--help", "Print help and exit.");
 
     CLI::App *retrace = app->add_subcommand("retrace", "Retrace traces and exit.", result.subcommand, SUBCOMMAND_RETRACE)->fallthrough();

src/Engine/AssetsManager.cpp

@@ -4,7 +4,6 @@
 
 #include "Engine/Graphics/ImageLoader.h"
 #include "Engine/Graphics/Image.h"
-#include "Engine/EngineIocContainer.h"
 #include "Engine/LodTextureCache.h"
 #include "Engine/LodSpriteCache.h"
 
@@ -17,7 +16,7 @@
 AssetsManager *assets = new AssetsManager();
 
 void AssetsManager::releaseAllTextures() {
-    logger->verbose("Render - Releasing Textures.");
+    logger->trace("Render - Releasing Textures.");
     // clears any textures from gpu
     for (auto img : images) {
         img.second->releaseRenderId();

src/Engine/Components/Trace/EngineTraceRecorder.cpp

@@ -8,7 +8,6 @@
 #include "Application/GameKeyboardController.h" // TODO(captainurist): Engine -> Application dependency
 
 #include "Engine/Engine.h"
-#include "Engine/EngineIocContainer.h"
 #include "Engine/Components/Control/EngineController.h"
 #include "Engine/Components/Deterministic/EngineDeterministicComponent.h"
 

src/Engine/EngineIocContainer.cpp

@@ -9,14 +9,10 @@
 #include "Engine/Objects/Character.h"
 #include "Engine/Objects/SpriteObject.h"
 
-#include "Library/Logger/Logger.h"
-
 #include "Io/Mouse.h"
 
 using Io::Mouse;
 
-Logger *logger = nullptr;
-
 DecalBuilder *EngineIocContainer::ResolveDecalBuilder() {
     if (!decal_builder) {
         decal_builder = new DecalBuilder();

src/Engine/EngineIocContainer.h

@@ -4,7 +4,6 @@
 
 struct BloodsplatContainer;
 struct DecalBuilder;
-class Logger;
 namespace Io {
 class Mouse;
 }
@@ -32,5 +31,3 @@ class EngineIocContainer {
      static std::shared_ptr<ParticleEngine> particle_engine;
      static Vis *vis;
 };
-
-extern Logger *logger;

src/Engine/Events/EventMap.cpp

@@ -5,7 +5,6 @@
 
 #include "Engine/Party.h"
 #include "Engine/Engine.h"
-#include "Engine/EngineIocContainer.h"
 
 #include "Library/Logger/Logger.h"
 
@@ -115,12 +114,12 @@ std::string EventMap::hint(int eventId) const {
 void EventMap::dump(int eventId) const {
     const auto *events = valuePtr(_eventsById, eventId);
     if (events) {
-        logger->verbose("Event: {}", eventId);
+        logger->trace("Event: {}", eventId);
         for (const EventIR &ir : *events) {
-            logger->verbose("{}", ir.toString());
+            logger->trace("{}", ir.toString());
         }
     } else {
-        logger->verbose("Event {} not found", eventId);
+        logger->trace("Event {} not found", eventId);
     }
 }
 

src/Engine/Events/Processor.cpp

@@ -1,8 +1,6 @@
 #include <vector>
-#include <algorithm>
 
 #include "Engine/Engine.h"
-#include "Engine/EngineIocContainer.h"
 #include "Engine/Localization.h"
 #include "Engine/mm7_data.h"
 #include "Engine/Graphics/LocationFunctions.h"
@@ -158,7 +156,7 @@ void eventProcessor(int eventId, Pid targetObj, bool canShowMessages, int startS
 
     EventInterpreter interpreter;
     bool mapExitTriggered = false;
-    logger->verbose("Executing regular event starting from step {}", startStep);
+    logger->trace("Executing regular event starting from step {}", startStep);
     if (activeLevelDecoration) {
         engine->_globalEventMap.dump(eventId);
         interpreter.prepare(engine->_globalEventMap, eventId, targetObj, canShowMessages);
@@ -179,7 +177,7 @@ bool npcDialogueEventProcessor(int eventId, int startStep) {
 
     EventInterpreter interpreter;
 
-    logger->verbose("Executing NPC dialogue event starting from step {}", startStep);
+    logger->trace("Executing NPC dialogue event starting from step {}", startStep);
     LevelDecoration *oldDecoration = activeLevelDecoration;
     activeLevelDecoration = (LevelDecoration *)1; // Required for correct printing of messages
     engine->_globalEventMap.dump(eventId);

src/Engine/Graphics/ClippingFunctions.cpp

@@ -1,12 +1,9 @@
 #include "Engine/Graphics/ClippingFunctions.h"
 
 #include "Engine/Engine.h"
-#include "Engine/EngineIocContainer.h"
 
 #include "Library/Logger/Logger.h"
 
-#include "Camera.h"
-
 //----- (00498377) --------------------------------------------------------
 bool ClippingFunctions::ClipVertsToPortal(RenderVertexSoft *pPortalBounding,  // test skipping this
                                           unsigned int uNumfrust,

src/Engine/Graphics/ImageLoader.cpp

@@ -4,7 +4,6 @@
 #include <string_view>
 #include <memory>
 
-#include "Engine/EngineIocContainer.h"
 #include "Engine/Graphics/IRender.h"
 #include "Engine/Graphics/Sprites.h"
 #include "Engine/Graphics/Texture_MM7.h"

src/Engine/Graphics/Indoor.cpp

@@ -1114,7 +1114,7 @@ int BLV_GetFloorLevel(const Vec3i &pos, int uSectorID, int *pFaceID) {
 
     // no face found - probably wrong sector supplied
     if (!FacesFound) {
-        logger->verbose("Floorlvl fail: {} {} {}", pos.x, pos.y, pos.z);
+        logger->trace("Floorlvl fail: {} {} {}", pos.x, pos.y, pos.z);
 
         if (pFaceID)
             *pFaceID = -1;

src/Engine/Graphics/LightsStack.cpp

@@ -1,7 +1,6 @@
 #include "Library/Logger/Logger.h"
 
 #include "Engine/Graphics/LightsStack.h"
-#include "Engine/EngineIocContainer.h"
 
 LightsStack_StationaryLight_::LightsStack_StationaryLight_() {
     this->uNumLightsActive = 0;

src/Engine/Graphics/Nuklear.cpp

@@ -9,7 +9,6 @@
 #include "Engine/AssetsManager.h"
 #include "Engine/Engine.h"
 #include "Engine/EngineGlobals.h"
-#include "Engine/EngineIocContainer.h"
 #include "Engine/GameResourceManager.h"
 
 #include "Engine/Graphics/Nuklear.h"
@@ -797,7 +796,7 @@ void Nuklear::Release(WindowType winType, bool is_reload) {
             if ((*it)->asset) {
                 render->NuklearImageFree((*it)->asset);
                 (*it)->asset->Release();
-                logger->verbose("Nuklear: [{}] asset {} unloaded", wins[winType].tmpl, i);
+                logger->trace("Nuklear: [{}] asset {} unloaded", wins[winType].tmpl, i);
                 delete *it;
             }
         }
@@ -822,7 +821,7 @@ void Nuklear::Release(WindowType winType, bool is_reload) {
         if (!is_reload && (wins[winType].state == WINDOW_INITIALIZED || wins[winType].state == WINDOW_TEMPLATE_ERROR))
             wins[winType].state = WINDOW_NOT_LOADED;
 
-        logger->verbose("Nuklear: [{}] template unloaded", wins[winType].tmpl);
+        logger->trace("Nuklear: [{}] template unloaded", wins[winType].tmpl);
     } else {
         logger->warning("Nuklear: [{}] template is not loaded", wins[winType].tmpl);
     }