diff --git a/.github/actions/spelling/expect.txt b/.github/actions/spelling/expect.txt index 94c2f5da15..7dba473dbb 100644 --- a/.github/actions/spelling/expect.txt +++ b/.github/actions/spelling/expect.txt @@ -499,6 +499,7 @@ Scm sddl secureobject securestring +seekp seof servercert servercertificate @@ -548,6 +549,7 @@ Tagit TARG taskhostw tcs +tellp temppath testexampleinstaller thiscouldbeapc diff --git a/doc/Settings.md b/doc/Settings.md index 9593346539..5eb1ff765e 100644 --- a/doc/Settings.md +++ b/doc/Settings.md @@ -286,6 +286,35 @@ In addition, there are special values that cover multiple channels. `default` i }, ``` +### file + +The `file` settings control the log files generated by winget during operation. These settings apply to the automatic cleanup that happens whenever a Windows Package Manager process is run. +They only apply to the default log location, which contains winget logs, AppInstaller logs (the MSIX install UI), and is the default location where installer logs are placed. +The automatic cleanup happens at the beginning of the process, so the log file(s) generated by the current process will not be considered in the limits. + +|Setting|Description|Default|Note| +|---|---|---|---| +|`ageLimitInDays`|The maximum age, in days, of files in the log directory; older files are deleted.|7 (days)|Set to 0 to disable this limit.| +|`totalSizeLimitInMB`|The maximum size, in megabytes, of all files in the log directory; the oldest files are deleted first.|128 (MB)|Set to 0 to disable this limit.| +|`countLimit`|The maximum number of files in the log directory; the oldest files are deleted first.|0|Set to 0 (the default) to disable this limit.| + +These settings apply to the log files that winget writes, only as they are being written. They do not apply to files written by installers or the AppInstaller UI. + +|Setting|Description|Default|Note| +|---|---|---|---| +|`individualSizeLimitInMB`|The maximum size, in megabytes, of an individual log file. If a file would exceed this limit, the logs will wrap. Note that this limit is approximate and the actual files may exceed it by a few bytes.|16 (MB)|Set to 0 to disable this limit.| + +```json + "logging": { + "file": { + "ageLimitInDays": 7, + "totalSizeLimitInMB": 128, + "countLimit": 0, + "individualSizeLimitInMB": 16, + } + }, +``` + ## Network The `network` settings influence how winget uses the network to retrieve packages and metadata. diff --git a/schemas/JSON/settings/settings.schema.0.2.json b/schemas/JSON/settings/settings.schema.0.2.json index bb5f3fce28..750ba6da92 100644 --- a/schemas/JSON/settings/settings.schema.0.2.json +++ b/schemas/JSON/settings/settings.schema.0.2.json @@ -80,6 +80,35 @@ }, "minItems": 0, "maxItems": 20 + }, + "file": { + "description": "The file settings control the log files generated by winget during operation.", + "type": "object", + "properties": { + "ageLimitInDays": { + "description": "The maximum age, in days, of a log file before it is deleted. Set to 0 to disable automatic deletion based on age.", + "type": "integer", + "default": 7, + "minimum": 0 + }, + "totalSizeLimitInMB": { + "description": "The maximum total size, in megabytes, of all log files. If the total size exceeds this limit, the oldest files will be deleted first. Set to 0 to disable this limit.", + "type": "integer", + "default": 128, + "minimum": 0 + }, + "countLimit": { + "description": "The maximum number of log files to retain. If the number of log files exceeds this limit, the oldest files will be deleted first. Set to 0 (the default) to disable this limit.", + "type": "integer", + "default": 0, + "minimum": 0 + }, + "individualSizeLimitInMB": { + "description": "The maximum size, in megabytes, of an individual log file. If a file would exceed this limit, new log lines will overwrite the file from the beginning. Set to 0 to disable this limit.", + "type": "integer", + "default": 16, + "minimum": 0 + } } } }, diff --git a/src/AppInstallerCLITests/AppInstallerCLITests.vcxproj b/src/AppInstallerCLITests/AppInstallerCLITests.vcxproj index 2a1e53f16d..4923d10ce6 100644 --- a/src/AppInstallerCLITests/AppInstallerCLITests.vcxproj +++ b/src/AppInstallerCLITests/AppInstallerCLITests.vcxproj @@ -243,6 +243,7 @@ + diff --git a/src/AppInstallerCLITests/AppInstallerCLITests.vcxproj.filters b/src/AppInstallerCLITests/AppInstallerCLITests.vcxproj.filters index 061cb29eae..c63e833b68 100644 --- a/src/AppInstallerCLITests/AppInstallerCLITests.vcxproj.filters +++ b/src/AppInstallerCLITests/AppInstallerCLITests.vcxproj.filters @@ -389,6 +389,9 @@ Source Files\Repository + + Source Files\Common + diff --git a/src/AppInstallerCLITests/FileLogger.cpp b/src/AppInstallerCLITests/FileLogger.cpp new file mode 100644 index 0000000000..c44e7fb6bf --- /dev/null +++ b/src/AppInstallerCLITests/FileLogger.cpp @@ -0,0 +1,245 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. +#include "pch.h" +#include "TestCommon.h" +#include +#include + +using namespace AppInstaller::Logging; +using namespace AppInstaller::Utility; +using namespace TestCommon; + + +std::string GetHeaderString() +{ + return "TIME [CHAN] Header Message"; +} + +std::string GetLargeString() +{ + return "[===|Clearly defined start to large string|===]\r\n" + "While this string does not need to be particularly unique, it is still good if it is not easily duplicated by any other random set of data.\r\n" + "It should also end in a character that is not used in any other way within these tests, so please don't include that character when writing tests.\r\n" + "That character is &"; +} + +namespace +{ +#define WINGET_DEFINE_STRING_ENUM(_enum_,_value_) constexpr std::string_view _enum_##_##_value_ = #_value_##sv + + WINGET_DEFINE_STRING_ENUM(TagState, Unset); + WINGET_DEFINE_STRING_ENUM(TagState, SetAtStart); + WINGET_DEFINE_STRING_ENUM(TagState, SetAfterLogging); + + WINGET_DEFINE_STRING_ENUM(MaximumSizeState, Zero); + WINGET_DEFINE_STRING_ENUM(MaximumSizeState, SmallerThanLargeString); + WINGET_DEFINE_STRING_ENUM(MaximumSizeState, EqualToLargeString); + WINGET_DEFINE_STRING_ENUM(MaximumSizeState, SlightlyLargerThanLargeString); + WINGET_DEFINE_STRING_ENUM(MaximumSizeState, MuchLargerThanLargeString); + + constexpr std::string_view WrapIndicator = "--- log file has wrapped ---"sv; + // The amount of extra size that is allowed (total indicator size + newline + newlines from test strings) + constexpr size_t ExtraAllowedSize = 68; + + constexpr size_t NewLineCharacterCount = 2; + constexpr size_t SmallDifferenceSize = 10; + constexpr AppInstaller::Logging::Channel DefaultChannel = AppInstaller::Logging::Channel::Core; + constexpr AppInstaller::Logging::Level DefaultLevel = AppInstaller::Logging::Level::Info; + + void ValidateFileContents(const std::filesystem::path& file, const std::vector& expectedContents, size_t maximumSize) + { + std::ifstream fileStream{ file, std::ios::binary }; + auto fileContents = ReadEntireStream(fileStream); + std::string_view fileContentsView = fileContents; + + std::string fileContentsCopy = fileContents; + FindAndReplace(fileContentsCopy, "\r", "\\r"); + FindAndReplace(fileContentsCopy, "\n", "\\n"); + INFO("File contents:\n" << fileContentsCopy); + + if (maximumSize) + { + REQUIRE(maximumSize + ExtraAllowedSize >= fileContents.size()); + } + + size_t currentPosition = 0; + for (std::string_view expectedContent : expectedContents) + { + REQUIRE(currentPosition < fileContents.size()); + + if (expectedContent == WrapIndicator) + { + auto endLinePosition = fileContentsView.find('\n', currentPosition); + REQUIRE(endLinePosition != -1); + REQUIRE(endLinePosition >= expectedContent.size() + NewLineCharacterCount); + auto actualContent = fileContentsView.substr(endLinePosition + 1 - expectedContent.size() - NewLineCharacterCount, expectedContent.size()); + REQUIRE(expectedContent == actualContent); + currentPosition = endLinePosition + 1; + } + else + { + auto actualContent = fileContentsView.substr(currentPosition, expectedContent.size()); + REQUIRE(expectedContent == actualContent); + currentPosition += expectedContent.size() + NewLineCharacterCount; + } + } + } + + void FileLogger_MaximumSize_Test(std::string_view tagState, std::string_view sizeState) + { + auto headerString = GetHeaderString(); + auto largeString = GetLargeString(); + + // Determine maximum size + size_t maximumSize = 0; + + if (sizeState == MaximumSizeState_SmallerThanLargeString) + { + maximumSize = largeString.size() - SmallDifferenceSize; + } + else if (sizeState == MaximumSizeState_EqualToLargeString) + { + maximumSize = largeString.size(); + } + else if (sizeState == MaximumSizeState_SlightlyLargerThanLargeString) + { + maximumSize = largeString.size() + SmallDifferenceSize; + } + else if (sizeState == MaximumSizeState_MuchLargerThanLargeString) + { + maximumSize = largeString.size() * 2; + } + + INFO("Tag State: " << tagState << ", Size State: " << sizeState << "[" << maximumSize << "]"); + + TempFile tempFile{ "FileLogger_MaximumSize", ".log" }; + FileLogger logger{ tempFile }; + + INFO("File: " << tempFile.GetPath().u8string()); + + logger.SetMaximumSize(wil::safe_cast(maximumSize)); + + // Set tag and log strings + size_t tagPosition = 0; + if (tagState == TagState_SetAtStart) + { + logger.SetTag(Tag::HeadersComplete); + } + + logger.WriteDirect(DefaultChannel, DefaultLevel, headerString); + + if (tagState == TagState_SetAfterLogging) + { + logger.SetTag(Tag::HeadersComplete); + tagPosition = headerString.size() + NewLineCharacterCount; + } + + // Due to text output in the logger, log with \n only + std::string largeStringWithoutCarriageReturn = largeString; + FindAndReplace(largeStringWithoutCarriageReturn, "\r\n", "\n"); + + logger.WriteDirect(DefaultChannel, DefaultLevel, largeStringWithoutCarriageReturn); + + // Calculate current state + size_t maximumAvailableSpace = std::numeric_limits::max(); + size_t currentAvailableSpace = std::numeric_limits::max(); + if (maximumSize) + { + maximumAvailableSpace = maximumSize - tagPosition; + currentAvailableSpace = maximumSize - headerString.size() - NewLineCharacterCount; + } + + bool shouldWrap = largeString.size() > currentAvailableSpace; + + INFO("Maximum Available: " << maximumAvailableSpace << ", Current Available: " << currentAvailableSpace << ", ShouldWrap: " << shouldWrap); + + std::vector expectedFileContents; + + if (tagPosition || !shouldWrap) + { + expectedFileContents.push_back(headerString); + } + + if (shouldWrap) + { + expectedFileContents.push_back(WrapIndicator); + } + + std::string_view largeStringView = largeString; + expectedFileContents.push_back(largeStringView.substr(0, std::min(largeString.size(), maximumAvailableSpace))); + + ValidateFileContents(tempFile, expectedFileContents, maximumSize); + + // Log again + INFO("Second time logging large string"); + logger.WriteDirect(DefaultChannel, DefaultLevel, largeStringWithoutCarriageReturn); + + // The maximum size is twice the large log, so anything with a limit will wrap + shouldWrap = maximumSize != 0; + + expectedFileContents.clear(); + + if (tagPosition || !shouldWrap) + { + expectedFileContents.push_back(headerString); + } + + if (shouldWrap) + { + expectedFileContents.push_back(WrapIndicator); + } + else + { + expectedFileContents.push_back(largeStringView); + } + + expectedFileContents.push_back(largeStringView.substr(0, std::min(largeString.size(), maximumAvailableSpace))); + + ValidateFileContents(tempFile, expectedFileContents, maximumSize); + } +} + +TEST_CASE("FileLogger_MaximumSize", "[logging]") +{ + auto tagState = GENERATE(TagState_Unset, TagState_SetAtStart, TagState_SetAfterLogging); + auto sizeState = GENERATE(MaximumSizeState_Zero, MaximumSizeState_SmallerThanLargeString, MaximumSizeState_EqualToLargeString, MaximumSizeState_SlightlyLargerThanLargeString, MaximumSizeState_MuchLargerThanLargeString); + FileLogger_MaximumSize_Test(tagState, sizeState); +} + +TEST_CASE("FileLogger_MaximumSize_ManyWraps", "[logging]") +{ + TempFile tempFile{ "FileLogger_ManyWraps", ".log" }; + FileLogger logger{ tempFile }; + + INFO("File: " << tempFile.GetPath().u8string()); + + size_t maximumSize = 1000; + logger.SetMaximumSize(static_cast(maximumSize)); + + std::string header = GetHeaderString(); + header += " !Now with more header!"; + std::string largeString = "[*=INIT=*]Now we just need another few dozen characters, which shouldn't be that hard to get. Wow, made it already."; + std::string_view largeStringView = largeString; + size_t initSize = 10; + + logger.WriteDirect(DefaultChannel, DefaultLevel, header); + logger.SetTag(Tag::HeadersComplete); + + // Use the default seed value as we want arbitrary but reproducible results + std::default_random_engine randomEngine; + std::uniform_int_distribution<> sizeDistribution(static_cast(initSize), 100); + + // We should expect ~500 wraps on average + for (size_t i = 0; i < 9999; ++i) + { + logger.WriteDirect(DefaultChannel, DefaultLevel, largeStringView.substr(0, sizeDistribution(randomEngine))); + } + + // We want the header to be preserved, followed by the wrap indicator, and at a minimum we should see the first few characters in the log string + std::vector expectedFileContents; + expectedFileContents.push_back(header); + expectedFileContents.push_back(WrapIndicator); + expectedFileContents.push_back(largeStringView.substr(0, initSize)); + + ValidateFileContents(tempFile, expectedFileContents, maximumSize); +} diff --git a/src/AppInstallerCLITests/Filesystem.cpp b/src/AppInstallerCLITests/Filesystem.cpp index 38fda9fff6..ae032b4ed5 100644 --- a/src/AppInstallerCLITests/Filesystem.cpp +++ b/src/AppInstallerCLITests/Filesystem.cpp @@ -223,3 +223,207 @@ TEST_CASE("PathTree_VisitIf_Correct", "[filesystem][pathtree]") pathTree.VisitIf(L"C:", check_input, if_input); } + +TEST_CASE("GetFileInfoFor", "[filesystem]") +{ + TestCommon::TempDirectory tempDirectory{ "GetFileInfoFor" }; + + auto now = std::filesystem::file_time_type::clock::now(); + + std::this_thread::sleep_for(1s); + auto file1 = tempDirectory.CreateTempFile("c.txt"); + std::string file1Content = "File 1 Content!"; + std::ofstream{ file1 } << file1Content; + std::this_thread::sleep_for(1s); + auto file2 = tempDirectory.CreateTempFile("b.txt"); + std::string file2Content = "More Content! Better Content!"; + std::ofstream{ file2 } << file2Content; + std::this_thread::sleep_for(1s); + auto file3 = tempDirectory.CreateTempFile("a.txt"); + std::string file3Content = "Maybe less is better?"; + std::ofstream{ file3 } << file3Content; + + auto fileInfo = GetFileInfoFor(tempDirectory); + REQUIRE(3 == fileInfo.size()); + + // Sort with oldest first + std::sort(fileInfo.begin(), fileInfo.end(), [](const FileInfo& a, const FileInfo& b) { return a.LastWriteTime < b.LastWriteTime; }); + + REQUIRE(fileInfo[0].Path == file1.GetPath()); + REQUIRE(fileInfo[0].LastWriteTime > now); + REQUIRE(fileInfo[0].Size == file1Content.size()); + + REQUIRE(fileInfo[1].Path == file2.GetPath()); + REQUIRE(fileInfo[1].LastWriteTime > fileInfo[0].LastWriteTime); + REQUIRE(fileInfo[1].Size == file2Content.size()); + + REQUIRE(fileInfo[2].Path == file3.GetPath()); + REQUIRE(fileInfo[2].LastWriteTime > fileInfo[1].LastWriteTime); + REQUIRE(fileInfo[2].Size == file3Content.size()); +} + +void RequireFilePaths(const std::vector& files, std::initializer_list paths) +{ + REQUIRE(paths.size() == files.size()); + size_t i = 0; + for (const char* val : paths) + { + REQUIRE(val == files[i++].Path.u8string()); + } +} + +TEST_CASE("FilterToFilesExceedingLimits", "[filesystem]") +{ + auto now = std::filesystem::file_time_type::clock::now(); + + std::vector files + { + { "a", now, 42 }, + { "b", now - 32min, 45321 }, + { "c", now - 84min, 24567 }, + { "d", now - 4h, 876312 }, + { "e", now - 18h, 2908534 }, + { "f", now - 47h, 312 }, + { "g", now - 132h, 74321 }, + { "h", now - 4567h, 6573423 }, + }; + + // Give the sort inside FilterToFilesExceedingLimits something to do + std::shuffle(files.begin(), files.end(), std::mt19937{}); + FileLimits limits{}; + + SECTION("No limits") + { + FilterToFilesExceedingLimits(files, limits); + // Without limits, nothing exceeds them + REQUIRE(files.empty()); + } + SECTION("Age - 1h") + { + limits.Age = 1h; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e", "d", "c" }); + } + SECTION("Age - 2h") + { + limits.Age = 2h; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e", "d" }); + } + SECTION("Age - 24h") + { + limits.Age = 24h; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f" }); + } + SECTION("Age - 7d") + { + limits.Age = 7 * 24h; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h" }); + } + SECTION("Age - 365d") + { + limits.Age = 365 * 24h; + FilterToFilesExceedingLimits(files, limits); + REQUIRE(files.empty()); + } + SECTION("Size - 1MB") + { + limits.TotalSizeInMB = 1; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e" }); + } + SECTION("Size - 2MB") + { + limits.TotalSizeInMB = 2; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e" }); + } + SECTION("Size - 3MB") + { + limits.TotalSizeInMB = 3; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e" }); + } + SECTION("Size - 4MB") + { + limits.TotalSizeInMB = 4; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h" }); + } + SECTION("Size - 100MB") + { + limits.TotalSizeInMB = 100; + FilterToFilesExceedingLimits(files, limits); + REQUIRE(files.empty()); + } + SECTION("Count - 1") + { + limits.Count = 1; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e", "d", "c", "b" }); + } + SECTION("Count - 2") + { + limits.Count = 2; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e", "d", "c" }); + } + SECTION("Count - 4") + { + limits.Count = 4; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e" }); + } + SECTION("Count - 7") + { + limits.Count = 7; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h" }); + } + SECTION("Count - 8") + { + limits.Count = 8; + FilterToFilesExceedingLimits(files, limits); + REQUIRE(files.empty()); + } + SECTION("Count - 100") + { + limits.Count = 100; + FilterToFilesExceedingLimits(files, limits); + REQUIRE(files.empty()); + } + SECTION("Mix - 24h - 2MB - 4") + { + limits.Age = 24h; + limits.TotalSizeInMB = 2; + limits.Count = 4; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e" }); + } + SECTION("Mix - 2h - 2MB - 4") + { + limits.Age = 2h; + limits.TotalSizeInMB = 2; + limits.Count = 4; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e", "d" }); + } + SECTION("Mix - 24h - 1MB - 4") + { + limits.Age = 24h; + limits.TotalSizeInMB = 1; + limits.Count = 4; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e" }); + } + SECTION("Mix - 24h - 2MB - 2") + { + limits.Age = 24h; + limits.TotalSizeInMB = 2; + limits.Count = 2; + FilterToFilesExceedingLimits(files, limits); + RequireFilePaths(files, { "h", "g", "f", "e", "d", "c" }); + } +} diff --git a/src/AppInstallerCLITests/TestCommon.cpp b/src/AppInstallerCLITests/TestCommon.cpp index 1a924d9b85..1b83319edd 100644 --- a/src/AppInstallerCLITests/TestCommon.cpp +++ b/src/AppInstallerCLITests/TestCommon.cpp @@ -153,6 +153,16 @@ namespace TestCommon } } + TempFile TempDirectory::CreateTempFile(const std::string& baseName, const std::string& baseExt) + { + return { _filepath, baseName, baseExt }; + } + + TempFile TempDirectory::CreateTempFile(const std::string& name) + { + return { _filepath / name }; + } + std::filesystem::path TestDataFile::GetPath() const { std::filesystem::path result = s_TestDataFileBasePath; diff --git a/src/AppInstallerCLITests/TestCommon.h b/src/AppInstallerCLITests/TestCommon.h index d56184c376..9b85a30aa9 100644 --- a/src/AppInstallerCLITests/TestCommon.h +++ b/src/AppInstallerCLITests/TestCommon.h @@ -64,6 +64,9 @@ namespace TestCommon struct TempDirectory : public TempFile { TempDirectory(const std::string& baseName, bool create = true); + + TempFile CreateTempFile(const std::string& baseName, const std::string& baseExt); + TempFile CreateTempFile(const std::string& name); }; // Use this to find a test data file when testing. diff --git a/src/AppInstallerCLITests/main.cpp b/src/AppInstallerCLITests/main.cpp index 0ad079dc45..7c74746106 100644 --- a/src/AppInstallerCLITests/main.cpp +++ b/src/AppInstallerCLITests/main.cpp @@ -4,7 +4,7 @@ #include #include #include -#include +#include #include #include "TestCommon.h" #include "TestSettings.h" @@ -84,13 +84,17 @@ int main(int argc, char** argv) } else if ("-log"s == argv[i]) { - Logging::FileLogger::Add(); + auto logger = std::make_unique(); + logger->SetMaximumSize(0); + Logging::Log().AddLogger(std::move(logger)); } else if ("-logto"s == argv[i]) { - if (++i < argc) + if (++i < argc) { - Logging::FileLogger::Add(std::filesystem::path{ argv[i] }); + auto logger = std::make_unique(std::filesystem::path{ argv[i] }); + logger->SetMaximumSize(0); + Logging::Log().AddLogger(std::move(logger)); } } else if ("-tdd"s == argv[i]) @@ -117,7 +121,7 @@ int main(int argc, char** argv) { if (++i < argc) { - Debugging::EnableSelfInitiatedMinidump(std::filesystem::path{ argv[i] }); + Debugging::EnableSelfInitiatedMinidump(std::filesystem::path{ argv[i] }); } } else diff --git a/src/AppInstallerCLITests/pch.h b/src/AppInstallerCLITests/pch.h index 6971336a45..e6ca25b743 100644 --- a/src/AppInstallerCLITests/pch.h +++ b/src/AppInstallerCLITests/pch.h @@ -31,9 +31,11 @@ #include #include -#include +#include +#include #include +#include #include #include #include @@ -41,6 +43,7 @@ #include #include #include +#include #include #include #include diff --git a/src/AppInstallerCommonCore/AppInstallerTelemetry.cpp b/src/AppInstallerCommonCore/AppInstallerTelemetry.cpp index 6b4211f840..bfefd72d9e 100644 --- a/src/AppInstallerCommonCore/AppInstallerTelemetry.cpp +++ b/src/AppInstallerCommonCore/AppInstallerTelemetry.cpp @@ -259,6 +259,8 @@ namespace AppInstaller::Logging AICLI_LOG(Core, Info, << "Package: " << packageVersion); } AICLI_LOG(Core, Info, << "IsCOMCall:" << isCOMCall << "; Caller: " << m_caller); + + Log().SetTag(Tag::HeadersComplete); } void TelemetryTraceLogger::LogCommand(std::string_view commandName) const noexcept diff --git a/src/AppInstallerCommonCore/FileLogger.cpp b/src/AppInstallerCommonCore/FileLogger.cpp index ca73083f5a..f4b3c6e936 100644 --- a/src/AppInstallerCommonCore/FileLogger.cpp +++ b/src/AppInstallerCommonCore/FileLogger.cpp @@ -6,6 +6,8 @@ #include "Public/AppInstallerRuntime.h" #include "Public/AppInstallerStrings.h" #include "Public/AppInstallerDateTime.h" +#include "Public/winget/UserSettings.h" +#include #include @@ -14,8 +16,26 @@ namespace AppInstaller::Logging using namespace std::string_view_literals; using namespace std::chrono_literals; - static constexpr std::string_view s_fileLoggerDefaultFilePrefix = "WinGet"sv; - static constexpr std::string_view s_fileLoggerDefaultFileExt = ".log"sv; + namespace + { + static constexpr std::string_view s_fileLoggerDefaultFilePrefix = "WinGet"sv; + static constexpr std::string_view s_fileLoggerDefaultFileExt = ".log"sv; + + // Send to a string first to create a single block to write to a file. + std::string ToLogLine(Channel channel, std::string_view message) + { + std::stringstream strstr; + strstr << std::chrono::system_clock::now() << " [" << std::setw(GetMaxChannelNameLength()) << std::left << std::setfill(' ') << GetChannelName(channel) << "] " << message; + return std::move(strstr).str(); + } + + // Determines the difference between the given position and the maximum as an offset. + std::ofstream::off_type CalculateDiff(const std::ofstream::pos_type& position, std::ofstream::off_type maximum) + { + auto offsetPosition = static_cast(position); + return maximum > offsetPosition ? maximum - offsetPosition : 0; + } + } FileLogger::FileLogger() : FileLogger(s_fileLoggerDefaultFilePrefix) {} @@ -23,6 +43,7 @@ namespace AppInstaller::Logging { m_name = GetNameForPath(filePath); m_filePath = filePath; + InitializeDefaultMaximumFileSize(); OpenFileLoggerStream(); } @@ -31,6 +52,7 @@ namespace AppInstaller::Logging m_name = "file"; m_filePath = Runtime::GetPathTo(Runtime::PathName::DefaultLogLocation); m_filePath /= fileNamePrefix.data() + ('-' + Utility::GetCurrentTimeForFilename() + s_fileLoggerDefaultFileExt.data()); + InitializeDefaultMaximumFileSize(); OpenFileLoggerStream(); } @@ -42,6 +64,13 @@ namespace AppInstaller::Logging m_stream.close(); } + FileLogger& FileLogger::SetMaximumSize(std::ofstream::off_type maximumSize) + { + THROW_HR_IF(E_INVALIDARG, maximumSize < 0); + m_maximumSize = maximumSize; + return *this; + } + std::string FileLogger::GetNameForPath(const std::filesystem::path& filePath) { using namespace std::string_literals; @@ -63,26 +92,32 @@ namespace AppInstaller::Logging return m_name; } - void FileLogger::Write(Channel channel, Level, std::string_view message) noexcept try - { - // Send to a string first to create a single block to write to a file. - std::stringstream strstr; - strstr << std::chrono::system_clock::now() << " [" << std::setw(GetMaxChannelNameLength()) << std::left << std::setfill(' ') << GetChannelName(channel) << "] " << message; - m_stream << strstr.str() << std::endl; - } - catch (...) + void FileLogger::Write(Channel channel, Level level, std::string_view message) noexcept try { - // Just eat any exceptions here; better than losing logs + std::string log = ToLogLine(channel, message); + WriteDirect(channel, level, log); } + catch (...) {} void FileLogger::WriteDirect(Channel, Level, std::string_view message) noexcept try { + HandleMaximumFileSize(message); m_stream << message << std::endl; } - catch (...) + catch (...) {} + + void FileLogger::SetTag(Tag tag) noexcept try { - // Just eat any exceptions here; better than losing logs + if (tag == Tag::HeadersComplete) + { + auto currentPosition = m_stream.tellp(); + if (currentPosition != std::ofstream::pos_type{ -1 }) + { + m_headersEnd = currentPosition; + } + } } + catch (...) {} void FileLogger::Add() { @@ -110,16 +145,19 @@ namespace AppInstaller::Logging { try { - auto now = std::filesystem::file_time_type::clock::now(); + const auto& settings = Settings::User(); + + Filesystem::FileLimits fileLimits; + fileLimits.Age = settings.Get(); + fileLimits.TotalSizeInMB = settings.Get(); + fileLimits.Count = settings.Get(); - // Remove all files that are older than 7 days from the standard log location. - for (auto& file : std::filesystem::directory_iterator{ filePath }) + auto filesInPath = Filesystem::GetFileInfoFor(filePath); + Filesystem::FilterToFilesExceedingLimits(filesInPath, fileLimits); + + for (const auto& file : filesInPath) { - if (file.is_regular_file() && - now - file.last_write_time() > (7 * 24h)) - { - std::filesystem::remove(file.path()); - } + std::filesystem::remove(file.Path); } } // Just throw out everything @@ -148,4 +186,49 @@ namespace AppInstaller::Logging throw std::system_error(errno, std::generic_category()); } } + + void FileLogger::InitializeDefaultMaximumFileSize() + { + m_maximumSize = static_cast(Settings::User().Get()) << 20; + } + + void FileLogger::HandleMaximumFileSize(std::string_view& currentLog) + { + if (m_maximumSize == 0) + { + return; + } + + auto maximumLogSize = static_cast(CalculateDiff(m_headersEnd, m_maximumSize)); + + // In the event that a single log is larger than the maximum + if (currentLog.size() > maximumLogSize) + { + currentLog = currentLog.substr(0, maximumLogSize); + WrapLogFile(); + return; + } + + auto currentPosition = m_stream.tellp(); + if (currentPosition == std::ofstream::pos_type{ -1 }) + { + // The expectation is that if the stream is in an error state the write won't actually happen. + return; + } + + auto availableSpace = static_cast(CalculateDiff(currentPosition, m_maximumSize)); + + if (currentLog.size() > availableSpace) + { + WrapLogFile(); + return; + } + } + + void FileLogger::WrapLogFile() + { + m_stream.seekp(m_headersEnd); + // Yes, we may go over the size limit slightly due to this and the unaccounted for newlines + m_stream << ToLogLine(Channel::Core, "--- log file has wrapped ---") << std::endl; + } } diff --git a/src/AppInstallerCommonCore/Public/AppInstallerFileLogger.h b/src/AppInstallerCommonCore/Public/AppInstallerFileLogger.h index 83e2c162f5..18d20c7b1e 100644 --- a/src/AppInstallerCommonCore/Public/AppInstallerFileLogger.h +++ b/src/AppInstallerCommonCore/Public/AppInstallerFileLogger.h @@ -25,6 +25,10 @@ namespace AppInstaller::Logging FileLogger(FileLogger&&) = default; FileLogger& operator=(FileLogger&&) = default; + // The default value for the maximum size comes from settings. + // Setting the maximum size to 0 will disable the maximum. + FileLogger& SetMaximumSize(std::ofstream::off_type maximumSize); + static std::string GetNameForPath(const std::filesystem::path& filePath); static std::string_view DefaultPrefix(); @@ -37,6 +41,8 @@ namespace AppInstaller::Logging void WriteDirect(Channel channel, Level level, std::string_view message) noexcept override; + void SetTag(Tag tag) noexcept override; + // Adds a FileLogger to the current Log static void Add(); static void Add(const std::filesystem::path& filePath); @@ -50,7 +56,19 @@ namespace AppInstaller::Logging std::string m_name; std::filesystem::path m_filePath; std::ofstream m_stream; + std::ofstream::pos_type m_headersEnd = 0; + std::ofstream::off_type m_maximumSize = 0; void OpenFileLoggerStream(); + + // Initializes the default maximum file size. + void InitializeDefaultMaximumFileSize(); + + // Determines if the logger needs to wrap back to the beginning, doing so when needed. + // May also shrink the given view if it exceeds the overall maximum. + void HandleMaximumFileSize(std::string_view& currentLog); + + // Resets the log file state so that it will overwrite the data portion. + void WrapLogFile(); }; } diff --git a/src/AppInstallerCommonCore/Public/winget/UserSettings.h b/src/AppInstallerCommonCore/Public/winget/UserSettings.h index b06bc57170..10b0c8f36b 100644 --- a/src/AppInstallerCommonCore/Public/winget/UserSettings.h +++ b/src/AppInstallerCommonCore/Public/winget/UserSettings.h @@ -101,6 +101,10 @@ namespace AppInstaller::Settings // Logging LoggingLevelPreference, LoggingChannelPreference, + LoggingFileAgeLimitInDays, + LoggingFileTotalSizeLimitInMB, + LoggingFileIndividualSizeLimitInMB, + LoggingFileCountLimit, // Uninstall behavior UninstallPurgePortablePackage, // Download behavior @@ -196,6 +200,10 @@ namespace AppInstaller::Settings // Logging SETTINGMAPPING_SPECIALIZATION(Setting::LoggingLevelPreference, std::string, Logging::Level, Logging::Level::Info, ".logging.level"sv); SETTINGMAPPING_SPECIALIZATION(Setting::LoggingChannelPreference, std::vector, Logging::Channel, Logging::Channel::Defaults, ".logging.channels"sv); + SETTINGMAPPING_SPECIALIZATION(Setting::LoggingFileAgeLimitInDays, uint32_t, std::chrono::hours, (7 * 24h), ".logging.file.ageLimitInDays"sv); + SETTINGMAPPING_SPECIALIZATION(Setting::LoggingFileTotalSizeLimitInMB, uint32_t, uint32_t, 128, ".logging.file.totalSizeLimitInMB"sv); + SETTINGMAPPING_SPECIALIZATION(Setting::LoggingFileIndividualSizeLimitInMB, uint32_t, uint32_t, 16, ".logging.file.individualSizeLimitInMB"sv); + SETTINGMAPPING_SPECIALIZATION(Setting::LoggingFileCountLimit, uint32_t, uint32_t, 0, ".logging.file.countLimit"sv); // Interactivity SETTINGMAPPING_SPECIALIZATION(Setting::InteractivityDisable, bool, bool, false, ".interactivity.disable"sv); diff --git a/src/AppInstallerCommonCore/UserSettings.cpp b/src/AppInstallerCommonCore/UserSettings.cpp index 5d7b000949..f220ec3c2c 100644 --- a/src/AppInstallerCommonCore/UserSettings.cpp +++ b/src/AppInstallerCommonCore/UserSettings.cpp @@ -275,6 +275,9 @@ namespace AppInstaller::Settings WINGET_VALIDATE_PASS_THROUGH(UninstallPurgePortablePackage) WINGET_VALIDATE_PASS_THROUGH(NetworkWingetAlternateSourceURL) WINGET_VALIDATE_PASS_THROUGH(MaxResumes) + WINGET_VALIDATE_PASS_THROUGH(LoggingFileTotalSizeLimitInMB) + WINGET_VALIDATE_PASS_THROUGH(LoggingFileIndividualSizeLimitInMB) + WINGET_VALIDATE_PASS_THROUGH(LoggingFileCountLimit) #ifndef AICLI_DISABLE_TEST_HOOKS WINGET_VALIDATE_PASS_THROUGH(EnableSelfInitiatedMinidump) @@ -473,6 +476,11 @@ namespace AppInstaller::Settings return result; } + + WINGET_VALIDATE_SIGNATURE(LoggingFileAgeLimitInDays) + { + return value * 24h; + } } #ifndef AICLI_DISABLE_TEST_HOOKS diff --git a/src/AppInstallerSharedLib/AppInstallerLogging.cpp b/src/AppInstallerSharedLib/AppInstallerLogging.cpp index a1c4933119..7ea18be478 100644 --- a/src/AppInstallerSharedLib/AppInstallerLogging.cpp +++ b/src/AppInstallerSharedLib/AppInstallerLogging.cpp @@ -177,6 +177,14 @@ namespace AppInstaller::Logging } } + void DiagnosticLogger::SetTag(Tag tag) + { + for (auto& logger : m_loggers) + { + logger->SetTag(tag); + } + } + DiagnosticLogger& Log() { ThreadLocalStorage::ThreadGlobals* pThreadGlobals = ThreadLocalStorage::ThreadGlobals::GetForCurrentThread(); diff --git a/src/AppInstallerSharedLib/Filesystem.cpp b/src/AppInstallerSharedLib/Filesystem.cpp index eb6790d68a..f29fb21b75 100644 --- a/src/AppInstallerSharedLib/Filesystem.cpp +++ b/src/AppInstallerSharedLib/Filesystem.cpp @@ -509,4 +509,60 @@ namespace AppInstaller::Filesystem return {}; } + + std::vector GetFileInfoFor(const std::filesystem::path& directory) + { + std::vector result; + + for (const auto& file : std::filesystem::directory_iterator{ directory }) + { + if (file.is_regular_file()) + { + result.emplace_back(FileInfo{ file.path(), file.last_write_time(), file.file_size() }); + } + } + + return result; + } + + void FilterToFilesExceedingLimits(std::vector& files, const FileLimits& limits) + { + auto now = std::filesystem::file_time_type::clock::now(); + std::chrono::hours ageLimit = limits.Age; + static_assert(sizeof(uintmax_t) >= 8); + uintmax_t totalSizeLimit = static_cast(limits.TotalSizeInMB) << 20; + size_t countLimit = limits.Count; + + // Sort with oldest first so that we can work backward to find the cutoff + std::sort(files.begin(), files.end(), [](const FileInfo& a, const FileInfo& b) { return a.LastWriteTime < b.LastWriteTime; }); + + // Walk the list backward until we find the first entry that goes over one of the limits + size_t i = files.size(); + uintmax_t totalSize = 0; + for (; i > 0; --i) + { + const FileInfo& current = files[i - 1]; + + if (totalSizeLimit != 0) + { + totalSize += current.Size; + if (totalSize > totalSizeLimit) + { + break; + } + } + + if (countLimit != 0 && (files.size() - i + 1) > countLimit) + { + break; + } + + if (ageLimit != 0h && now - current.LastWriteTime > ageLimit) + { + break; + } + } + + files.resize(i); + } } diff --git a/src/AppInstallerSharedLib/Public/AppInstallerLogging.h b/src/AppInstallerSharedLib/Public/AppInstallerLogging.h index 81bd5a5e6e..90e8511990 100644 --- a/src/AppInstallerSharedLib/Public/AppInstallerLogging.h +++ b/src/AppInstallerSharedLib/Public/AppInstallerLogging.h @@ -83,6 +83,13 @@ namespace AppInstaller::Logging Crit, }; + // Indicates a location of significance in the logging stream. + enum class Tag + { + // The initial set of logging has been completed. + HeadersComplete, + }; + // The interface that a log target must implement. struct ILogger { @@ -96,6 +103,9 @@ namespace AppInstaller::Logging // Informs the logger of the given log with the intention that no buffering occurs (in winget code). virtual void WriteDirect(Channel channel, Level level, std::string_view message) noexcept = 0; + + // Indicates that the given tag location has occurred. + virtual void SetTag(Tag) noexcept {} }; // This type contains the set of loggers that diagnostic logging will be sent to. @@ -161,6 +171,9 @@ namespace AppInstaller::Logging // Use to make large logs more efficient by writing directly to the output streams. void WriteDirect(Channel channel, Level level, std::string_view message); + // Indicates that the given tag location has occurred. + void SetTag(Tag tag); + private: std::vector> m_loggers; diff --git a/src/AppInstallerSharedLib/Public/winget/Filesystem.h b/src/AppInstallerSharedLib/Public/winget/Filesystem.h index 5a8ea199e2..ea1f5ce815 100644 --- a/src/AppInstallerSharedLib/Public/winget/Filesystem.h +++ b/src/AppInstallerSharedLib/Public/winget/Filesystem.h @@ -4,8 +4,11 @@ #include #include #include +#include #include +using namespace std::chrono_literals; + namespace AppInstaller::Filesystem { // Checks if the file system at path supports named streams/ADS @@ -122,4 +125,27 @@ namespace AppInstaller::Filesystem // Gets the path to the executable for the given process. std::filesystem::path GetExecutablePathForProcess(HANDLE process); + + // Information about a specific file. + struct FileInfo + { + std::filesystem::path Path; + std::filesystem::file_time_type LastWriteTime{}; + uintmax_t Size = 0; + }; + + // Gets the FileInfo for each regular file directly under the given directory. + std::vector GetFileInfoFor(const std::filesystem::path& directory); + + // Limitations on a set of files. + // Any value that is 0 is treated as no limit. + struct FileLimits + { + std::chrono::hours Age = 0h; + uint32_t TotalSizeInMB = 0; + size_t Count = 0; + }; + + // Modifies the given files to only include those that exceed the limits that are provided. + void FilterToFilesExceedingLimits(std::vector& files, const FileLimits& limits); }