Add Workflow logs and fix installed version workflow bug (#4432)

Fixes #4425 ## Change This adds a `Workflow` channel (disabled by default) that has the entry to tasks and the `Get`/`Add`/`Contains` calls logged to it. This enables a view into a flow that can be collected by a third party. It also fixes a behavior change with the side-by-side code path for selecting the installed version that would lead to no data item being inserted, when the previous behavior was that a `nullptr` would be inserted when no version is installed.
microsoft · May 1, 2024 · 2b185be · 2b185be
1 parent c2781b0
commit 2b185be
Show file tree

Hide file tree

Showing 10 changed files with 94 additions and 8 deletions.
diff --git a/.github/actions/spelling/allow.txt b/.github/actions/spelling/allow.txt
@@ -375,6 +375,7 @@ wcsicmp
 webpage
 WHOLECHAIN
 wil
+windbg
 wincrypt
 WINEVENT
 winget

diff --git a/.github/actions/spelling/expect.txt b/.github/actions/spelling/expect.txt
@@ -295,7 +295,7 @@ NESTEDINSTALLER
 netfx
 netlify
 NETSDK
-Newtonsoft
+Newtonsoft
 nlohmann
 NNS
 NOAGGREGATION

diff --git a/src/AppInstallerCLICore/ExecutionContext.cpp b/src/AppInstallerCLICore/ExecutionContext.cpp
@@ -487,6 +487,24 @@ namespace AppInstaller::CLI::Execution
     }
 #endif
 
+    void ContextEnumBasedVariantMapActionCallback(const void* map, Data data, EnumBasedVariantMapAction action)
+    {
+        switch (action)
+        {
+        case EnumBasedVariantMapAction::Add:
+            AICLI_LOG(Workflow, Info, << "Setting data item: " << data);
+            break;
+        case EnumBasedVariantMapAction::Contains:
+            AICLI_LOG(Workflow, Info, << "Checking data item: " << data);
+            break;
+        case EnumBasedVariantMapAction::Get:
+            AICLI_LOG(Workflow, Info, << "Getting data item: " << data);
+            break;
+        }
+
+        UNREFERENCED_PARAMETER(map);
+    }
+
     std::string Context::GetResumeId()
     {
         return m_checkpointManager->GetResumeId();

diff --git a/src/AppInstallerCLICore/ExecutionContext.h b/src/AppInstallerCLICore/ExecutionContext.h
@@ -85,10 +85,13 @@ namespace AppInstaller::CLI::Execution
     bool WaitForAppShutdownEvent();
 #endif
 
+    // Callback to log data actions.
+    void ContextEnumBasedVariantMapActionCallback(const void* map, Data data, EnumBasedVariantMapAction action);
+
     // The context within which all commands execute.
     // Contains input/output via Execution::Reporter and
     // arguments via Execution::Args.
-    struct Context : EnumBasedVariantMap<Data, details::DataMapping>
+    struct Context : EnumBasedVariantMap<Data, details::DataMapping, ContextEnumBasedVariantMapActionCallback>
     {
         Context(std::ostream& out, std::istream& in) : Reporter(out, in) {}
 

diff --git a/src/AppInstallerCLICore/Workflows/WorkflowBase.cpp b/src/AppInstallerCLICore/Workflows/WorkflowBase.cpp
@@ -13,6 +13,8 @@
 #include <winget/Runtime.h>
 #include <winget/PackageVersionSelection.h>
 
+EXTERN_C IMAGE_DOS_HEADER __ImageBase;
+
 using namespace std::string_literals;
 using namespace AppInstaller::Utility::literals;
 using namespace AppInstaller::Pinning;
@@ -259,6 +261,19 @@ namespace AppInstaller::CLI::Workflow
         m_func(context);
     }
 
+    void WorkflowTask::Log() const
+    {
+        if (m_isFunc)
+        {
+            // Using `00000001`80000000` as base address default when loading dll into windbg as dump file.
+            AICLI_LOG(Workflow, Info, << "Running task: 0x" << m_func << " [ln 00000001`80000000+" << std::hex << (reinterpret_cast<char*>(m_func) - reinterpret_cast<char*>(&__ImageBase)) << "]");
+        }
+        else
+        {
+            AICLI_LOG(Workflow, Info, << "Running task: " << m_name);
+        }
+    }
+
     Repository::PredefinedSource DetermineInstalledSource(const Execution::Context& context)
     {
         Repository::PredefinedSource installedSource = Repository::PredefinedSource::Installed;
@@ -1368,10 +1383,10 @@ namespace AppInstaller::CLI::Workflow
 
     void GetInstalledPackageVersion(Execution::Context& context)
     {
-        std::shared_ptr<IPackage> installed = context.Get<Execution::Data::Package>()->GetInstalled();
-
         if (ExperimentalFeature::IsEnabled(ExperimentalFeature::Feature::SideBySide))
         {
+            std::shared_ptr<IPackage> installed = context.Get<Execution::Data::Package>()->GetInstalled();
+
             if (installed)
             {
                 // TODO: This may need to be expanded dramatically to enable targeting across a variety of dimensions (architecture, etc.)
@@ -1395,6 +1410,10 @@ namespace AppInstaller::CLI::Workflow
                     context.Add<Execution::Data::InstalledPackageVersion>(installed->GetLatestVersion());
                 }
             }
+            else
+            {
+                context.Add<Execution::Data::InstalledPackageVersion>(nullptr);
+            }
         }
         else
         {
@@ -1433,6 +1452,7 @@ AppInstaller::CLI::Execution::Context& operator<<(AppInstaller::CLI::Execution::
         if (context.ShouldExecuteWorkflowTask(task))
 #endif
         {
+            task.Log();
             task(context);
         }
     }

diff --git a/src/AppInstallerCLICore/Workflows/WorkflowBase.h b/src/AppInstallerCLICore/Workflows/WorkflowBase.h
@@ -69,6 +69,7 @@ namespace AppInstaller::CLI::Workflow
         bool IsFunction() const { return m_isFunc; }
         Func Function() const { return m_func; }
         bool ExecuteAlways() const { return m_executeAlways; }
+        void Log() const;
 
     private:
         bool m_isFunc = false;

diff --git a/src/AppInstallerRepositoryCore/CompositeSource.cpp b/src/AppInstallerRepositoryCore/CompositeSource.cpp
@@ -10,7 +10,7 @@ namespace AppInstaller::Repository
 {
     using namespace std::string_view_literals;
 
-    namespace
+    namespace anon
     {
         Utility::VersionAndChannel GetVACFromVersion(IPackageVersion* packageVersion)
         {
@@ -1365,6 +1365,8 @@ namespace AppInstaller::Repository
         }
     }
 
+    using namespace anon;
+
     CompositeSource::CompositeSource(std::string identifier)
     {
         m_details.Identifier = std::move(identifier);

diff --git a/src/AppInstallerSharedLib/AppInstallerLogging.cpp b/src/AppInstallerSharedLib/AppInstallerLogging.cpp
@@ -20,6 +20,7 @@ namespace AppInstaller::Logging
         case Channel::Core:   return "CORE";
         case Channel::Test:   return "TEST";
         case Channel::Config: return "CONF";
+        case Channel::Workflow: return "WORK";
         default:              return "NONE";
         }
     }
@@ -60,6 +61,10 @@ namespace AppInstaller::Logging
         {
             return Channel::Config;
         }
+        else if (lowerChannel == "workflow")
+        {
+            return Channel::Workflow;
+        }
         else if (lowerChannel == "default" || lowerChannel == "defaults")
         {
             return Channel::Defaults;

diff --git a/src/AppInstallerSharedLib/Public/AppInstallerLanguageUtilities.h b/src/AppInstallerSharedLib/Public/AppInstallerLanguageUtilities.h
@@ -89,8 +89,20 @@ namespace AppInstaller
         static constexpr inline size_t Index(Enum e) { return static_cast<size_t>(e) + 1; }
     };
 
+    // An action that can be taken on an EnumBasedVariantMap.
+    enum class EnumBasedVariantMapAction
+    {
+        Add,
+        Contains,
+        Get,
+    };
+
+    // A callback function that can be used for logging map actions.
+    template <typename Enum>
+    using EnumBasedVariantMapActionCallback = void (*)(const void* map, Enum value, EnumBasedVariantMapAction action);
+
     // Provides a map of the Enum to the mapped types.
-    template <typename Enum, template<Enum> typename Mapping>
+    template <typename Enum, template<Enum> typename Mapping, EnumBasedVariantMapActionCallback<Enum> Callback = nullptr>
     struct EnumBasedVariantMap
     {
         using Variant = EnumBasedVariant<Enum, Mapping>;
@@ -103,28 +115,51 @@ namespace AppInstaller
         template <Enum E>
         void Add(mapping_t<E>&& v)
         {
+            if constexpr (Callback)
+            {
+                Callback(this, E, EnumBasedVariantMapAction::Add);
+            }
             m_data[E].emplace<Variant::Index(E)>(std::move(std::forward<mapping_t<E>>(v)));
         }
 
         template <Enum E>
         void Add(const mapping_t<E>& v)
         {
+            if constexpr (Callback)
+            {
+                Callback(this, E, EnumBasedVariantMapAction::Add);
+            }
             m_data[E].emplace<Variant::Index(E)>(v);
         }
 
         // Return a value indicating whether the given enum is stored in the map.
-        bool Contains(Enum e) const { return (m_data.find(e) != m_data.end()); }
+        bool Contains(Enum e) const
+        {
+            if constexpr (Callback)
+            {
+                Callback(this, e, EnumBasedVariantMapAction::Contains);
+            }
+            return (m_data.find(e) != m_data.end());
+        }
 
         // Gets the value.
         template <Enum E>
         mapping_t<E>& Get()
         {
+            if constexpr (Callback)
+            {
+                Callback(this, E, EnumBasedVariantMapAction::Get);
+            }
             return std::get<Variant::Index(E)>(GetVariant(E));
         }
 
         template <Enum E>
         const mapping_t<E>& Get() const
         {
+            if constexpr (Callback)
+            {
+                Callback(this, E, EnumBasedVariantMapAction::Get);
+            }
             return std::get<Variant::Index(E)>(GetVariant(E));
         }
 

diff --git a/src/AppInstallerSharedLib/Public/AppInstallerLogging.h b/src/AppInstallerSharedLib/Public/AppInstallerLogging.h
@@ -56,9 +56,10 @@ namespace AppInstaller::Logging
         Core = 0x20,
         Test = 0x40,
         Config = 0x80,
+        Workflow = 0x100,
         None = 0,
         All = 0xFFFFFFFF,
-        Defaults = All & ~SQL,
+        Defaults = All & ~(SQL | Workflow),
     };
 
     DEFINE_ENUM_FLAG_OPERATORS(Channel);