Merge pull request #714 from Laupetin/feature/asset-creation-logging

feat: more detailed logs about what is being loaded

src/Linking/Linker.cpp

@@ -155,7 +155,7 @@ namespace
     class LinkerImpl final : public Linker
     {
     public:
-        LinkerImpl(LinkerArgs args)
+        explicit LinkerImpl(LinkerArgs args)
             : m_args(std::move(args))
         {
         }
@@ -187,6 +187,8 @@ namespace
 
             UnloadZones();
 
+            Summarize(result);
+
             return result;
         }
 
@@ -464,6 +466,12 @@ namespace
             return true;
         }
 
+        static void Summarize(const bool result)
+        {
+            const char* resultStr = result ? "Finished" : "Failed";
+            con::info("{} with {} warnings, {} errors", resultStr, con::warning_count(), con::error_count());
+        }
+
         LinkerArgs m_args;
         std::vector<std::unique_ptr<Zone>> m_loaded_zones;
     };

src/ObjLoading/Asset/AssetCreationContext.cpp

@@ -66,6 +66,7 @@ std::unique_ptr<XAssetInfoGeneric> GenericAssetRegistration::CreateXAssetInfo()
 AssetCreationContext::AssetCreationContext(Zone& zone, const AssetCreatorCollection* creators, const IgnoredAssetLookup* ignoredAssetLookup)
     : ZoneAssetCreationStateContainer(zone),
       m_zone(zone),
+      m_game(*IGame::GetGameById(zone.m_game_id)),
       m_forced_asset_pools(std::make_unique<ZoneAssetPools>(zone, zone.m_priority)),
       m_creators(creators),
       m_ignored_asset_lookup(ignoredAssetLookup),
@@ -141,6 +142,8 @@ XAssetInfoGeneric* AssetCreationContext::LoadDependencyGeneric(const asset_type_
         return LoadDefaultAssetDependency(assetType, std::format(",{}", assetName));
     }
 
+    const auto assetTypeName = m_game.GetAssetTypeName(assetType).value_or("unknown");
+
     if (m_ignored_asset_lookup->IsAssetIgnored(assetType, assetName))
         return LoadDefaultAssetDependency(assetType, std::format(",{}", assetName));
 
@@ -148,13 +151,16 @@ XAssetInfoGeneric* AssetCreationContext::LoadDependencyGeneric(const asset_type_
     if (result.HasTakenAction())
     {
         if (!result.HasFailed())
+        {
+            con::info(R"(Loaded {} "{}")", assetTypeName, assetName);
             return result.GetAssetInfo();
+        }
 
-        con::error(R"(Could not load asset "{}" of type "{}")", assetName, *IGame::GetGameById(m_zone.m_game_id)->GetAssetTypeName(assetType));
+        con::error(R"(Could not load asset "{}" of type "{}")", assetName, assetTypeName);
     }
     else if (required)
     {
-        con::error(R"(Missing asset "{}" of type "{}")", assetName, *IGame::GetGameById(m_zone.m_game_id)->GetAssetTypeName(assetType));
+        con::error(R"(Missing asset "{}" of type "{}")", assetName, assetTypeName);
     }
 
     return nullptr;
@@ -167,17 +173,22 @@ XAssetInfoGeneric* AssetCreationContext::LoadSubAssetGeneric(const asset_type_t
     if (alreadyLoadedSubAsset)
         return alreadyLoadedSubAsset;
 
+    const auto subAssetTypeName = m_game.GetSubAssetTypeName(subAssetType).value_or("unknown");
+
     const auto result = m_creators->CreateSubAsset(subAssetType, assetName, *this);
     if (result.HasTakenAction())
     {
         if (!result.HasFailed())
+        {
+            con::debug(R"(Loaded {} "{}")", subAssetTypeName, assetName);
             return result.GetAssetInfo();
+        }
 
-        con::error(R"(Could not load sub asset "{}" of type "{}")", assetName, *IGame::GetGameById(m_zone.m_game_id)->GetSubAssetTypeName(subAssetType));
+        con::error(R"(Could not load sub asset "{}" of type "{}")", assetName, subAssetTypeName);
     }
     else
     {
-        con::error(R"(Missing sub asset "{}" of type "{}")", assetName, *IGame::GetGameById(m_zone.m_game_id)->GetSubAssetTypeName(subAssetType));
+        con::error(R"(Missing sub asset "{}" of type "{}")", assetName, subAssetTypeName);
     }
 
     return nullptr;
@@ -192,12 +203,17 @@ IndirectAssetReference AssetCreationContext::LoadIndirectAssetReferenceGeneric(c
     if (m_ignored_asset_lookup->IsAssetIgnored(assetType, assetName))
         return IndirectAssetReference(assetType, assetName);
 
+    const auto assetTypeName = m_game.GetAssetTypeName(assetType).value_or("unknown");
     const auto result = m_creators->CreateAsset(assetType, assetName, *this);
-    if (!result.HasTakenAction() && !result.HasFailed())
+    if (result.HasTakenAction() && !result.HasFailed())
     {
-        con::warn(
+        con::info(R"(Loaded {} "{}")", assetTypeName, assetName);
-            R"(Could not load indirectly referenced asset "{}" of type "{}")", assetName, *IGame::GetGameById(m_zone.m_game_id)->GetAssetTypeName(assetType));
     }
+    else if (!result.HasTakenAction() && !result.HasFailed())
+    {
+        con::warn(R"(Could not load indirectly referenced asset "{}" of type "{}")", assetName, assetTypeName);
+    }
+
     return IndirectAssetReference(assetType, assetName);
 }
 
@@ -227,16 +243,21 @@ XAssetInfoGeneric* AssetCreationContext::ForceLoadDependencyGeneric(const asset_
     else
         result = m_creators->CreateAsset(assetType, assetName, *this);
 
+    const auto assetTypeName = m_game.GetAssetTypeName(assetType).value_or("unknown");
+
     if (result.HasTakenAction())
     {
         if (!result.HasFailed())
+        {
+            con::info(R"(Loaded {} "{}")", assetTypeName, assetName);
             return result.GetAssetInfo();
+        }
 
-        con::error(R"(Could not load asset "{}" of type "{}")", assetName, *IGame::GetGameById(m_zone.m_game_id)->GetAssetTypeName(assetType));
+        con::error(R"(Could not load asset "{}" of type "{}")", assetName, assetTypeName);
     }
     else
     {
-        con::error(R"(Missing asset "{}" of type "{}")", assetName, *IGame::GetGameById(m_zone.m_game_id)->GetAssetTypeName(assetType));
+        con::error(R"(Missing asset "{}" of type "{}")", assetName, assetTypeName);
     }
 
     return nullptr;

src/ObjLoading/Asset/AssetCreationContext.h

@@ -3,6 +3,7 @@
 #include "Asset/IZoneAssetCreationState.h"
 #include "AssetRegistration.h"
 #include "Game/IAsset.h"
+#include "Game/IGame.h"
 #include "Pool/AssetPool.h"
 #include "Pool/XAssetInfo.h"
 #include "Zone/AssetList/AssetList.h"
@@ -99,6 +100,7 @@ private:
     [[nodiscard]] XAssetInfoGeneric* LoadDefaultAssetDependency(asset_type_t assetType, const std::string& assetName);
 
     Zone& m_zone;
+    IGame& m_game;
     std::unique_ptr<ZoneAssetPools> m_forced_asset_pools;
     std::vector<std::unique_ptr<AssetPool>> m_sub_asset_pools;
     const AssetCreatorCollection* m_creators;

src/ObjWriting/Dumping/AbstractAssetDumper.h

@@ -3,6 +3,7 @@
 #include "Game/IAsset.h"
 #include "IAssetDumper.h"
 #include "Pool/AssetPool.h"
+#include "Utils/Logging/Log.h"
 
 template<AssetDefinition Asset_t> class AbstractAssetDumper : public IAssetDumper
 {
@@ -21,6 +22,8 @@ public:
 
     void Dump(AssetDumpingContext& context) override
     {
+        const auto assetTypeName = IGame::GetGameById(context.m_zone.m_game_id)->GetAssetTypeName(Asset_t::EnumEntry).value_or("unknown");
+
         for (const auto* assetInfo : context.m_zone.m_pools.PoolAssets<Asset_t>())
         {
             if (assetInfo->IsReference() || !ShouldDump(*assetInfo))
@@ -30,6 +33,7 @@ public:
             }
 
             DumpAsset(context, *assetInfo);
+            con::info("Dumped {} \"{}\"", assetTypeName, assetInfo->m_name);
             context.IncrementProgress();
         }
     }

src/Unlinking/Unlinker.cpp

@@ -42,6 +42,9 @@ namespace
             const auto result = UnlinkZones(paths);
 
             UnloadZones();
+
+            Summarize(result);
+
             return result;
         }
 
@@ -307,6 +310,12 @@ namespace
             return true;
         }
 
+        static void Summarize(const bool result)
+        {
+            const char* resultStr = result ? "Finished" : "Failed";
+            con::info("{} with {} warnings, {} errors", resultStr, con::warning_count(), con::error_count());
+        }
+
         UnlinkerArgs m_args;
         std::vector<std::unique_ptr<Zone>> m_loaded_zones;
     };

src/Utils/Utils/Logging/Log.cpp

@@ -48,6 +48,8 @@ namespace
 namespace con
 {
     LogLevel _globalLogLevel = LogLevel::INFO;
+    std::atomic_size_t _warningCount(0);
+    std::atomic_size_t _errorCount(0);
 
     void init()
     {
@@ -70,6 +72,22 @@ namespace con
         globalUseColor = value && CanUseColor();
     }
 
+    void reset_counts()
+    {
+        _warningCount = 0;
+        _errorCount = 0;
+    }
+
+    size_t warning_count()
+    {
+        return _warningCount;
+    }
+
+    size_t error_count()
+    {
+        return _errorCount;
+    }
+
     void _debug_internal(const std::string& str)
     {
         if (globalUseColor)
@@ -89,16 +107,16 @@ namespace con
     void _warn_internal(const std::string& str)
     {
         if (globalUseColor)
-            std::cout << std::format("\x1B[33m{}\x1B[0m\n", str);
+            std::cout << std::format("\x1B[33mWARN: {}\x1B[0m\n", str);
         else
-            std::cout << std::format("{}\n", str);
+            std::cout << std::format("WARN: {}\n", str);
     }
 
     void _error_internal(const std::string& str)
     {
         if (globalUseColor)
-            std::cerr << std::format("\x1B[31m{}\x1B[0m\n", str);
+            std::cerr << std::format("\x1B[31mERROR: {}\x1B[0m\n", str);
         else
-            std::cerr << std::format("{}\n", str);
+            std::cerr << std::format("ERROR: {}\n", str);
     }
 } // namespace con

src/Utils/Utils/Logging/Log.h

@@ -1,5 +1,6 @@
 #pragma once
 
+#include <atomic>
 #include <cstdint>
 #include <format>
 #include <string>
@@ -15,11 +16,17 @@ namespace con
     };
 
     extern LogLevel _globalLogLevel;
+    extern std::atomic_size_t _warningCount;
+    extern std::atomic_size_t _errorCount;
 
     void init();
     void set_log_level(LogLevel value);
     void set_use_color(bool value);
 
+    void reset_counts();
+    [[nodiscard]] size_t warning_count();
+    [[nodiscard]] size_t error_count();
+
     void _debug_internal(const std::string& str);
     void _info_internal(const std::string& str);
     void _warn_internal(const std::string& str);
@@ -55,6 +62,7 @@ namespace con
 
     inline void warn(const std::string& str)
     {
+        ++_warningCount;
         if (static_cast<unsigned>(_globalLogLevel) > static_cast<unsigned>(LogLevel::WARN))
             return;
         _warn_internal(str);
@@ -62,6 +70,7 @@ namespace con
 
     template<class Arg0, class... OtherArgs> void warn(std::format_string<Arg0, OtherArgs...> fmt, Arg0&& arg0, OtherArgs&&... otherArgs)
     {
+        ++_warningCount;
         if (static_cast<unsigned>(_globalLogLevel) > static_cast<unsigned>(LogLevel::WARN))
             return;
         _warn_internal(std::vformat(fmt.get(), std::make_format_args(arg0, otherArgs...)));
@@ -69,11 +78,13 @@ namespace con
 
     inline void error(const std::string& str)
     {
+        ++_errorCount;
         _error_internal(str);
     }
 
     template<class Arg0, class... OtherArgs> void error(std::format_string<Arg0, OtherArgs...> fmt, Arg0&& arg0, OtherArgs&&... otherArgs)
     {
+        ++_errorCount;
         _error_internal(std::vformat(fmt.get(), std::make_format_args(arg0, otherArgs...)));
     }
 } // namespace con