-
Notifications
You must be signed in to change notification settings - Fork 1.8k
Add CCM (CMTrace) log file format option #6284
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. Weβll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: master
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -2,8 +2,13 @@ | |
| // Licensed under the MIT License. | ||
| #include "pch.h" | ||
| #include "TestCommon.h" | ||
| #include "TestSettings.h" | ||
| #include "TestHooks.h" | ||
| #include <AppInstallerFileLogger.h> | ||
| #include <AppInstallerStrings.h> | ||
| #include <winget/Settings.h> | ||
|
|
||
| #include <regex> | ||
|
|
||
| using namespace AppInstaller::Logging; | ||
| using namespace AppInstaller::Utility; | ||
|
|
@@ -206,6 +211,44 @@ TEST_CASE("FileLogger_MaximumSize", "[logging]") | |
| FileLogger_MaximumSize_Test(tagState, sizeState); | ||
| } | ||
|
|
||
| TEST_CASE("FileLogger_CCMFormat", "[logging]") | ||
| { | ||
| // The CCM/CMTrace log format is opt-in via the "logging.format" user setting; override it for this test. | ||
| auto settingsGuard = DeleteUserSettingsFiles(); | ||
| SetSetting(AppInstaller::Settings::Stream::PrimaryUserSettings, R"({ "logging": { "format": "ccm" } })"); | ||
| UserSettingsTest userSettings; | ||
| TestHook::SetUserSettings_Override userSettingsOverride{ userSettings }; | ||
|
Comment on lines
+217
to
+220
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This appears to be both writing the actual settings file and overriding it via the hook. You should just use the hook if you can. (Although with a different |
||
|
|
||
| // CCM type: 1=Info/Verbose, 2=Warning, 3=Error/Critical. | ||
| Level level = Level::Info; | ||
| int expectedType = 1; | ||
| SECTION("Verbose maps to type 1") { level = Level::Verbose; expectedType = 1; } | ||
| SECTION("Info maps to type 1") { level = Level::Info; expectedType = 1; } | ||
| SECTION("Warning maps to type 2") { level = Level::Warning; expectedType = 2; } | ||
| SECTION("Error maps to type 3") { level = Level::Error; expectedType = 3; } | ||
| SECTION("Crit maps to type 3") { level = Level::Crit; expectedType = 3; } | ||
|
|
||
| const std::string message = "CCM format test message"; | ||
|
|
||
| TempFile tempFile{ "FileLogger_CCM", ".log" }; | ||
| INFO("File: " << tempFile.GetPath().u8string()); | ||
| { | ||
| FileLogger logger{ tempFile }; | ||
| logger.Write(DefaultChannel, level, message); | ||
| } | ||
|
|
||
| std::ifstream fileStream{ tempFile.GetPath(), std::ios::binary }; | ||
| auto fileContents = ReadEntireStream(fileStream); | ||
| INFO("File contents: " << fileContents); | ||
|
|
||
| // Expected: <![LOG[<message>]LOG]!><time="HH:MM:SS.mmm+<bias>" date="MM-DD-YYYY" component="<channel>" context="" type="<N>" thread="<id>" file=""> | ||
| std::regex ccmPattern{ | ||
| R"(^<!\[LOG\[CCM format test message\]LOG\]!><time="\d{2}:\d{2}:\d{2}\.\d{3}\+-?\d+" date="\d{2}-\d{2}-\d{4}" component="[^"]*" context="" type=")" | ||
| + std::to_string(expectedType) | ||
| + R"(" thread="\d+" file="">)" }; | ||
| REQUIRE(std::regex_search(fileContents, ccmPattern)); | ||
| } | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. It feels like we should be using an XML parser here and actually validating the time/date/thread etc. |
||
|
|
||
| TEST_CASE("FileLogger_MaximumSize_ManyWraps", "[logging]") | ||
| { | ||
| TempFile tempFile{ "FileLogger_ManyWraps", ".log" }; | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -29,6 +29,52 @@ namespace AppInstaller::Logging | |
| return std::move(strstr).str(); | ||
| } | ||
|
|
||
| // Formats a log line in CCM (CMTrace-compatible) format. | ||
| std::string ToCCMLogLine(Channel channel, Level level, std::string_view message) | ||
| { | ||
| auto now = std::chrono::system_clock::now(); | ||
| auto tt = std::chrono::system_clock::to_time_t(now); | ||
| tm localTime{}; | ||
| _localtime64_s(&localTime, &tt); | ||
|
|
||
| auto sinceEpoch = now.time_since_epoch(); | ||
| auto leftoverMillis = std::chrono::duration_cast<std::chrono::milliseconds>(sinceEpoch) - std::chrono::duration_cast<std::chrono::seconds>(sinceEpoch); | ||
|
|
||
| // Get UTC bias in minutes (positive means west of UTC, CMTrace uses positive for west) | ||
| long timezoneBiasSeconds = 0; | ||
| _get_timezone(&timezoneBiasSeconds); | ||
| long biasMins = timezoneBiasSeconds / 60; | ||
|
|
||
| // CCM type: 1=Info/Verbose, 2=Warning, 3=Error/Critical | ||
| int type; | ||
| switch (level) | ||
| { | ||
| case Level::Warning: type = 2; break; | ||
| case Level::Error: | ||
| case Level::Crit: type = 3; break; | ||
| default: type = 1; break; | ||
| } | ||
|
|
||
| std::stringstream strstr; | ||
| strstr << "<![LOG[" << message << "]LOG]!>" | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Is there any mechanism to escape |
||
| << "<time=\"" | ||
| << std::setw(2) << std::setfill('0') << localTime.tm_hour << ":" | ||
| << std::setw(2) << std::setfill('0') << localTime.tm_min << ":" | ||
| << std::setw(2) << std::setfill('0') << localTime.tm_sec << "." | ||
| << std::setw(3) << std::setfill('0') << leftoverMillis.count() | ||
| << "+" << biasMins << "\"" | ||
| << " date=\"" | ||
| << std::setw(2) << std::setfill('0') << (1 + localTime.tm_mon) << "-" | ||
| << std::setw(2) << std::setfill('0') << localTime.tm_mday << "-" | ||
| << (1900 + localTime.tm_year) << "\"" | ||
| << " component=\"" << GetChannelName(channel) << "\"" | ||
| << " context=\"\"" | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Might be an opportunity to include a correlation vector or similar here. |
||
| << " type=\"" << type << "\"" | ||
| << " thread=\"" << GetCurrentThreadId() << "\"" | ||
| << " file=\"\">"; | ||
| 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) | ||
| { | ||
|
|
@@ -94,7 +140,15 @@ namespace AppInstaller::Logging | |
|
|
||
| void FileLogger::Write(Channel channel, Level level, std::string_view message) noexcept try | ||
| { | ||
| std::string log = ToLogLine(channel, level, message); | ||
| std::string log; | ||
| if (Settings::User().Get<Settings::Setting::LoggingFormat>() == LogFileFormat::CCM) | ||
| { | ||
| log = ToCCMLogLine(channel, level, message); | ||
| } | ||
| else | ||
| { | ||
| log = ToLogLine(channel, level, message); | ||
| } | ||
|
Comment on lines
+144
to
+151
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I would prefer the CCM logger to be its own type. It should be as easy as deriving from |
||
| WriteDirect(channel, level, log); | ||
| } | ||
| catch (...) {} | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Not sure this test and the new imports are necessary, since there isn't one for the existing format. Figured I'd submit just in case
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think this and more tests should be present if we are writing to a defined format that needs to be parseable. The existing format is just "some text" that happens to have a logical format, but doesn't need to be computer readable.
I would want more unit tests that ensure the specifics of the automatic fields and more extensive coverage on the text portion's escaping.
I would also suggest some mechanism to force the entire E2E run in the pipeline to additionally generate CCM logs that could have a post-run validation applied to ensure compat.