From 25ccc2a6db72b88daab6447668f1437eb61649ad Mon Sep 17 00:00:00 2001 From: JohnMcPMS Date: Tue, 19 Nov 2024 16:17:23 -0800 Subject: [PATCH] Add ODS logger and use it during init (#4969) ## Change The user settings (and then group policy) initialization happen before we get the file logger set up. To be able to see into what is happening there more easily, this change creates a logger that uses `OutputDebugString` and uses it during the initial file logger creation. --- src/AppInstallerCLICore/COMContext.cpp | 8 +++ src/AppInstallerCLICore/Core.cpp | 44 +++++++++++++--- .../AppInstallerCommonCore.vcxproj | 2 + .../AppInstallerCommonCore.vcxproj.filters | 6 +++ .../OutputDebugStringLogger.cpp | 50 +++++++++++++++++++ .../Public/winget/OutputDebugStringLogger.h | 29 +++++++++++ 6 files changed, 131 insertions(+), 8 deletions(-) create mode 100644 src/AppInstallerCommonCore/OutputDebugStringLogger.cpp create mode 100644 src/AppInstallerCommonCore/Public/winget/OutputDebugStringLogger.h diff --git a/src/AppInstallerCLICore/COMContext.cpp b/src/AppInstallerCLICore/COMContext.cpp index 2eae8694d7..a76bcf2e61 100644 --- a/src/AppInstallerCLICore/COMContext.cpp +++ b/src/AppInstallerCLICore/COMContext.cpp @@ -4,6 +4,7 @@ #include "COMContext.h" #include #include +#include namespace AppInstaller::CLI::Execution { @@ -77,12 +78,19 @@ namespace AppInstaller::CLI::Execution void COMContext::SetLoggers(std::optional channel, std::optional level) { + // Set up debug string logging during initialization + Logging::OutputDebugStringLogger::Add(); + Logging::Log().EnableChannel(Logging::Channel::All); + Logging::Log().SetLevel(Logging::Level::Verbose); + Logging::Log().EnableChannel(channel.has_value() ? channel.value() : Settings::User().Get()); Logging::Log().SetLevel(level.has_value() ? level.value() : Settings::User().Get()); // TODO: Log to file for COM API calls only when debugging in visual studio Logging::FileLogger::Add(s_comLogFileNamePrefix); + Logging::OutputDebugStringLogger::Remove(); + #ifndef AICLI_DISABLE_TEST_HOOKS if (!Settings::User().Get()) #endif diff --git a/src/AppInstallerCLICore/Core.cpp b/src/AppInstallerCLICore/Core.cpp index 4f92ce39f9..f75193f9ec 100644 --- a/src/AppInstallerCLICore/Core.cpp +++ b/src/AppInstallerCLICore/Core.cpp @@ -9,6 +9,7 @@ #include "Commands/InstallCommand.h" #include "COMContext.h" #include +#include #ifndef AICLI_DISABLE_TEST_HOOKS #include @@ -66,21 +67,34 @@ namespace AppInstaller::CLI init_apartment(); -#ifndef AICLI_DISABLE_TEST_HOOKS +#ifndef AICLI_DISABLE_TEST_HOOKS + // We have to do this here so the auto minidump config initialization gets caught + Logging::OutputDebugStringLogger::Add(); + Logging::Log().EnableChannel(Logging::Channel::All); + Logging::Log().SetLevel(Logging::Level::Verbose); + if (Settings::User().Get()) { Debugging::EnableSelfInitiatedMinidump(); - } + } + + Logging::OutputDebugStringLogger::Remove(); #endif Logging::UseGlobalTelemetryLoggerActivityIdOnly(); Execution::Context context{ std::cout, std::cin }; - auto previousThreadGlobals = context.SetForCurrentThread(); + auto previousThreadGlobals = context.SetForCurrentThread(); + + // Set up debug string logging during initialization + Logging::OutputDebugStringLogger::Add(); + Logging::Log().EnableChannel(Logging::Channel::All); + Logging::Log().SetLevel(Logging::Level::Verbose); Logging::Log().EnableChannel(Settings::User().Get()); Logging::Log().SetLevel(Settings::User().Get()); - Logging::FileLogger::Add(); + Logging::FileLogger::Add(); + Logging::OutputDebugStringLogger::Remove(); Logging::EnableWilFailureTelemetry(); // Set output to UTF8 @@ -171,11 +185,18 @@ namespace AppInstaller::CLI void ServerInitialize() { -#ifndef AICLI_DISABLE_TEST_HOOKS +#ifndef AICLI_DISABLE_TEST_HOOKS + // We have to do this here so the auto minidump config initialization gets caught + Logging::OutputDebugStringLogger::Add(); + Logging::Log().EnableChannel(Logging::Channel::All); + Logging::Log().SetLevel(Logging::Level::Verbose); + if (Settings::User().Get()) { Debugging::EnableSelfInitiatedMinidump(); - } + } + + Logging::OutputDebugStringLogger::Remove(); #endif AppInstaller::CLI::Execution::COMContext::SetLoggers(); @@ -183,11 +204,18 @@ namespace AppInstaller::CLI void InProcInitialize() { -#ifndef AICLI_DISABLE_TEST_HOOKS +#ifndef AICLI_DISABLE_TEST_HOOKS + // We have to do this here so the auto minidump config initialization gets caught + Logging::OutputDebugStringLogger::Add(); + Logging::Log().EnableChannel(Logging::Channel::All); + Logging::Log().SetLevel(Logging::Level::Verbose); + if (Settings::User().Get()) { Debugging::EnableSelfInitiatedMinidump(); - } + } + + Logging::OutputDebugStringLogger::Remove(); #endif // Explicitly set default channel and level before user settings from PackageManagerSettings diff --git a/src/AppInstallerCommonCore/AppInstallerCommonCore.vcxproj b/src/AppInstallerCommonCore/AppInstallerCommonCore.vcxproj index 927547fc8f..bfaf4d6669 100644 --- a/src/AppInstallerCommonCore/AppInstallerCommonCore.vcxproj +++ b/src/AppInstallerCommonCore/AppInstallerCommonCore.vcxproj @@ -448,6 +448,7 @@ + @@ -504,6 +505,7 @@ + diff --git a/src/AppInstallerCommonCore/AppInstallerCommonCore.vcxproj.filters b/src/AppInstallerCommonCore/AppInstallerCommonCore.vcxproj.filters index 1cb64a4d0e..2c5d80bc70 100644 --- a/src/AppInstallerCommonCore/AppInstallerCommonCore.vcxproj.filters +++ b/src/AppInstallerCommonCore/AppInstallerCommonCore.vcxproj.filters @@ -207,6 +207,9 @@ Public\winget + + Public\winget + @@ -374,6 +377,9 @@ Source Files + + Source Files + diff --git a/src/AppInstallerCommonCore/OutputDebugStringLogger.cpp b/src/AppInstallerCommonCore/OutputDebugStringLogger.cpp new file mode 100644 index 0000000000..08103bbfd8 --- /dev/null +++ b/src/AppInstallerCommonCore/OutputDebugStringLogger.cpp @@ -0,0 +1,50 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. +#include "pch.h" +#include "winget/OutputDebugStringLogger.h" + +namespace AppInstaller::Logging +{ + namespace + { + static constexpr std::string_view s_OutputDebugStringLoggerName = "OutputDebugStringLogger"; + } + + std::string OutputDebugStringLogger::GetName() const + { + return std::string{ s_OutputDebugStringLoggerName }; + } + + void OutputDebugStringLogger::Write(Channel channel, Level, std::string_view message) noexcept try + { + std::stringstream strstr; + strstr << "[" << std::setw(GetMaxChannelNameLength()) << std::left << std::setfill(' ') << GetChannelName(channel) << "] " << message << std::endl; + std::string formattedMessage = std::move(strstr).str(); + + OutputDebugStringA(formattedMessage.c_str()); + } + catch (...) + { + // Just eat any exceptions here; better than losing logs + } + + void OutputDebugStringLogger::WriteDirect(Channel, Level, std::string_view message) noexcept try + { + std::string nullTerminatedMessage{ message }; + OutputDebugStringA(nullTerminatedMessage.c_str()); + } + catch (...) + { + // Just eat any exceptions here; better than losing logs + } + + void OutputDebugStringLogger::Add() + { + Log().AddLogger(std::make_unique()); + } + + void OutputDebugStringLogger::Remove() + { + Log().RemoveLogger(std::string{ s_OutputDebugStringLoggerName }); + } +} diff --git a/src/AppInstallerCommonCore/Public/winget/OutputDebugStringLogger.h b/src/AppInstallerCommonCore/Public/winget/OutputDebugStringLogger.h new file mode 100644 index 0000000000..751bf4b1f8 --- /dev/null +++ b/src/AppInstallerCommonCore/Public/winget/OutputDebugStringLogger.h @@ -0,0 +1,29 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. +#pragma once +#include + +namespace AppInstaller::Logging +{ + // Sends logs to the OutputDebugString function. + // Intended for use during initialization debugging. + struct OutputDebugStringLogger : ILogger + { + OutputDebugStringLogger() = default; + + ~OutputDebugStringLogger() = default; + + // ILogger + std::string GetName() const override; + + void Write(Channel channel, Level, std::string_view message) noexcept override; + + void WriteDirect(Channel channel, Level level, std::string_view message) noexcept override; + + // Adds OutputDebugStringLogger to the current Log + static void Add(); + + // Removes OutputDebugStringLogger from the current Log + static void Remove(); + }; +}