commit d15d6e3ae082b186148412e05e7aff8780430b6a
parent 6d56420ddd18623b3d8c225abd83fdcc673ce40c
Author: JohnMcPMS <johnmcp@microsoft.com>
Date: Mon, 20 Sep 2021 18:04:46 -0700
Fix logging of large REST response (#1489)
Diffstat:
8 files changed, 71 insertions(+), 1 deletion(-)
diff --git a/src/AppInstallerCommonCore/AppInstallerLogging.cpp b/src/AppInstallerCommonCore/AppInstallerLogging.cpp
@@ -125,6 +125,19 @@ namespace AppInstaller::Logging
}
}
+ void DiagnosticLogger::WriteDirect(Channel channel, Level level, std::string_view message)
+ {
+ THROW_HR_IF_MSG(E_INVALIDARG, channel == Channel::All, "Cannot write to all channels");
+
+ if (IsEnabled(channel, level))
+ {
+ for (auto& logger : m_loggers)
+ {
+ logger->WriteDirect(message);
+ }
+ }
+ }
+
DiagnosticLogger& Log()
{
ThreadLocalStorage::ThreadGlobals* pThreadGlobals = ThreadLocalStorage::ThreadGlobals::GetForCurrentThread();
diff --git a/src/AppInstallerCommonCore/FileLogger.cpp b/src/AppInstallerCommonCore/FileLogger.cpp
@@ -73,6 +73,15 @@ namespace AppInstaller::Logging
// Just eat any exceptions here; better than losing logs
}
+ void FileLogger::WriteDirect(std::string_view message) noexcept try
+ {
+ m_stream << message << std::endl;
+ }
+ catch (...)
+ {
+ // Just eat any exceptions here; better than losing logs
+ }
+
void FileLogger::BeginCleanup(const std::filesystem::path& filePath)
{
std::thread([filePath]()
diff --git a/src/AppInstallerCommonCore/Manifest/ManifestValidation.cpp b/src/AppInstallerCommonCore/Manifest/ManifestValidation.cpp
@@ -1,6 +1,7 @@
// Copyright (c) Microsoft Corporation.
// Licensed under the MIT License.
#include "pch.h"
+#include "AppInstallerLogging.h"
#include "winget/ManifestValidation.h"
#include "winget/Locale.h"
@@ -72,6 +73,10 @@ namespace AppInstaller::Manifest
if (!duplicateInstallerFound && !installerSet.insert(installer).second)
{
+ AICLI_LOG(Core, Error, << "Duplicate installer: Type[" << InstallerTypeToString(installer.InstallerType) <<
+ "] Architecture[" << Utility::ToString(installer.Arch) << "] Locale[" << installer.Locale <<
+ "] Scope[" << ScopeToString(installer.Scope) << "]");
+
resultErrors.emplace_back(ManifestError::DuplicateInstallerEntry);
duplicateInstallerFound = true;
}
diff --git a/src/AppInstallerCommonCore/Public/AppInstallerFileLogger.h b/src/AppInstallerCommonCore/Public/AppInstallerFileLogger.h
@@ -35,6 +35,8 @@ namespace AppInstaller::Logging
void Write(Channel channel, Level level, std::string_view message) noexcept override;
+ void WriteDirect(std::string_view message) noexcept override;
+
// Starts a background task to clean up old log files.
static void BeginCleanup(const std::filesystem::path& filePath);
diff --git a/src/AppInstallerCommonCore/Public/AppInstallerLogging.h b/src/AppInstallerCommonCore/Public/AppInstallerLogging.h
@@ -23,6 +23,22 @@
} \
} while (0, 0)
+// Consider using this macro when the string might be larger than 4K.
+// The normal macro has some buffering that occurs; it can cut off larger strings and is slower.
+#define AICLI_LOG_LARGE_STRING(_channel_,_level_,_headerStream_,_largeString_) \
+ do { \
+ auto _aicli_log_channel = AppInstaller::Logging::Channel:: _channel_; \
+ auto _aicli_log_level = AppInstaller::Logging::Level:: _level_; \
+ auto& _aicli_log_log = AppInstaller::Logging::Log(); \
+ if (_aicli_log_log.IsEnabled(_aicli_log_channel, _aicli_log_level)) \
+ { \
+ AppInstaller::Logging::LoggingStream _aicli_log_strstr; \
+ _aicli_log_strstr _headerStream_; \
+ _aicli_log_log.Write(_aicli_log_channel, _aicli_log_level, _aicli_log_strstr.str()); \
+ _aicli_log_log.WriteDirect(_aicli_log_channel, _aicli_log_level, _largeString_); \
+ } \
+ } while (0, 0)
+
namespace AppInstaller::Logging
{
// The channel that the log is from.
@@ -65,6 +81,9 @@ namespace AppInstaller::Logging
// Informs the logger of the given log.
virtual void Write(Channel channel, Level level, std::string_view message) noexcept = 0;
+
+ // Informs the logger of the given log with the intention that no buffering occurs (in winget code).
+ virtual void WriteDirect(std::string_view message) noexcept = 0;
};
// This type contains the set of loggers that diagnostic logging will be sent to.
@@ -120,6 +139,10 @@ namespace AppInstaller::Logging
// Writes a log line, if the given channel and level are enabled.
void Write(Channel channel, Level level, std::string_view message);
+ // Writes a log line, if the given channel and level are enabled.
+ // Use to make large logs more efficient by writing directly to the output streams.
+ void WriteDirect(Channel channel, Level level, std::string_view message);
+
private:
std::vector<std::unique_ptr<ILogger>> m_loggers;
diff --git a/src/AppInstallerCommonCore/Public/winget/TraceLogger.h b/src/AppInstallerCommonCore/Public/winget/TraceLogger.h
@@ -19,6 +19,9 @@ namespace AppInstaller::Logging
// ILogger
std::string GetName() const override;
+
void Write(Channel channel, Level, std::string_view message) noexcept override;
+
+ void WriteDirect(std::string_view message) noexcept override;
};
}
diff --git a/src/AppInstallerCommonCore/TraceLogger.cpp b/src/AppInstallerCommonCore/TraceLogger.cpp
@@ -24,6 +24,19 @@ namespace AppInstaller::Logging
// Just eat any exceptions here; better to lose logs than functionality
}
+ void TraceLogger::WriteDirect(std::string_view message) noexcept try
+ {
+ TraceLoggingWriteActivity(g_hTraceProvider,
+ "Diagnostics",
+ nullptr, // TODO: ActivityId of the Global and COMContext telemetry to be logged in future
+ nullptr,
+ TraceLoggingCountedUtf8String(message.data(), static_cast<ULONG>(message.size()), "LogMessage"));
+ }
+ catch (...)
+ {
+ // Just eat any exceptions here; better to lose logs than functionality
+ }
+
std::string TraceLogger::GetName() const
{
return "Trace";
diff --git a/src/AppInstallerRepositoryCore/Rest/Schema/HttpClientHelper.cpp b/src/AppInstallerRepositoryCore/Rest/Schema/HttpClientHelper.cpp
@@ -86,7 +86,9 @@ namespace AppInstaller::Repository::Rest::Schema
std::optional<web::json::value> HttpClientHelper::ValidateAndExtractResponse(const web::http::http_response& response) const
{
AICLI_LOG(Repo, Info, << "Response status: " << response.status_code());
- AICLI_LOG(Repo, Verbose, << "Response details: " << utility::conversions::to_utf8string(response.to_string()));
+ // Ensure that we wait for the content to be ready before we log it; otherwise it will be truncated.
+ AICLI_LOG_LARGE_STRING(Repo, Verbose, << "Response details:",
+ response.content_ready().then([&](const web::http::http_response&) { return utility::conversions::to_utf8string(response.to_string()); }).get());
std::optional<web::json::value> result;
switch (response.status_code())
