From 734a9fb952839fe40820534a66ef987b26b01b85 Mon Sep 17 00:00:00 2001 From: Mateusz Hoppe Date: Thu, 24 Nov 2022 14:52:53 +0000 Subject: [PATCH] feature: Allow redirecting debugger logs to log file - enhacement for logging debug messages to file Signed-off-by: Mateusz Hoppe --- .../debug_settings/debug_settings_manager.cpp | 5 ++ .../debug_settings/debug_settings_manager.h | 41 +++++++++++--- shared/source/utilities/logger.cpp | 10 ++++ shared/source/utilities/logger.h | 2 + .../debug_settings_manager_tests.cpp | 56 +++++++++++++++++++ .../test/unit_test/utilities/logger_tests.cpp | 18 ++++++ 6 files changed, 125 insertions(+), 7 deletions(-) diff --git a/shared/source/debug_settings/debug_settings_manager.cpp b/shared/source/debug_settings/debug_settings_manager.cpp index c4c9d9a9f0..fceb3600cc 100644 --- a/shared/source/debug_settings/debug_settings_manager.cpp +++ b/shared/source/debug_settings/debug_settings_manager.cpp @@ -12,6 +12,7 @@ #include "shared/source/helpers/debug_helpers.h" #include "shared/source/helpers/string.h" #include "shared/source/utilities/debug_settings_reader_creator.h" +#include "shared/source/utilities/logger.h" #include #include @@ -133,6 +134,10 @@ void DebugSettingsManager::injectSettingsFromReader() { #undef DECLARE_DEBUG_VARIABLE } +void logDebugString(std::string_view debugString) { + NEO::fileLoggerInstance().logDebugString(true, debugString); +} + template class DebugSettingsManager; template class DebugSettingsManager; template class DebugSettingsManager; diff --git a/shared/source/debug_settings/debug_settings_manager.h b/shared/source/debug_settings/debug_settings_manager.h index b63cce4b97..ce742e95f4 100644 --- a/shared/source/debug_settings/debug_settings_manager.h +++ b/shared/source/debug_settings/debug_settings_manager.h @@ -6,6 +6,8 @@ */ #pragma once +#include "shared/source/helpers/string.h" + #include #include #include @@ -29,6 +31,9 @@ constexpr DebugFunctionalityLevel globalDebugFunctionalityLevel = DebugFunctiona NEO::printDebugString(flag, __VA_ARGS__); namespace NEO { +template +class FileLogger; +extern FileLogger &fileLoggerInstance(); template void flushDebugStream(StreamT stream, Args &&...args) { @@ -43,6 +48,8 @@ void printDebugString(bool showDebugLogs, Args &&...args) { } } +void logDebugString(std::string_view debugString); + #if defined(__clang__) #define NO_SANITIZE __attribute__((no_sanitize("undefined"))) #else @@ -76,11 +83,12 @@ struct DebugVarBase { struct DebugVariables { // NOLINT(clang-analyzer-optin.performance.Padding) struct DEBUGGER_LOG_BITMASK { - constexpr static int32_t LOG_INFO{1}; // NOLINT(readability-identifier-naming) - constexpr static int32_t LOG_ERROR{1 << 1}; // NOLINT(readability-identifier-naming) - constexpr static int32_t LOG_THREADS{1 << 2}; // NOLINT(readability-identifier-naming) - constexpr static int32_t LOG_MEM{1 << 3}; // NOLINT(readability-identifier-naming) - constexpr static int32_t DUMP_ELF{1 << 10}; // NOLINT(readability-identifier-naming) + constexpr static int32_t LOG_INFO{1}; // NOLINT(readability-identifier-naming) + constexpr static int32_t LOG_ERROR{1 << 1}; // NOLINT(readability-identifier-naming) + constexpr static int32_t LOG_THREADS{1 << 2}; // NOLINT(readability-identifier-naming) + constexpr static int32_t LOG_MEM{1 << 3}; // NOLINT(readability-identifier-naming) + constexpr static int32_t DUMP_ELF{1 << 10}; // NOLINT(readability-identifier-naming) + constexpr static int32_t DUMP_TO_FILE{1 << 16}; // NOLINT(readability-identifier-naming) }; #define DECLARE_DEBUG_VARIABLE(dataType, variableName, defaultValue, description) \ @@ -127,6 +135,13 @@ class DebugSettingsManager { void getStringWithFlags(std::string &allFlags, std::string &changedFlags) const; + template + void logLazyEvaluateArgs(FT &&callable) { + if (!disabled()) { + callable(); + } + } + protected: std::unique_ptr readerImpl; bool isLoopAtDriverInitEnabled() const { @@ -142,8 +157,20 @@ class DebugSettingsManager { extern DebugSettingsManager DebugManager; -#define PRINT_DEBUGGER_LOG(OUT, STR, ...) \ - NEO::printDebugString(true, OUT, STR, __VA_ARGS__); +#define PRINT_DEBUGGER_LOG_TO_FILE(...) \ + NEO::DebugManager.logLazyEvaluateArgs([&] { \ + char temp[4000]; \ + snprintf_s(temp, sizeof(temp), sizeof(temp), __VA_ARGS__); \ + temp[sizeof(temp) - 1] = '\0'; \ + NEO::logDebugString(temp); \ + }); + +#define PRINT_DEBUGGER_LOG(OUT, ...) \ + if (NEO::DebugManager.flags.DebuggerLogBitmask.get() & NEO::DebugVariables::DEBUGGER_LOG_BITMASK::DUMP_TO_FILE) { \ + PRINT_DEBUGGER_LOG_TO_FILE(__VA_ARGS__) \ + } else { \ + NEO::printDebugString(true, OUT, __VA_ARGS__); \ + } #define PRINT_DEBUGGER_INFO_LOG(STR, ...) \ if (NEO::DebugManager.flags.DebuggerLogBitmask.get() & NEO::DebugVariables::DEBUGGER_LOG_BITMASK::LOG_INFO) { \ diff --git a/shared/source/utilities/logger.cpp b/shared/source/utilities/logger.cpp index 64af4ef4b5..323eea6ddb 100644 --- a/shared/source/utilities/logger.cpp +++ b/shared/source/utilities/logger.cpp @@ -9,6 +9,7 @@ #include "shared/source/debug_settings/debug_settings_manager.h" #include "shared/source/helpers/timestamp_packet.h" +#include "shared/source/utilities/io_functions.h" #include #include @@ -46,6 +47,15 @@ void FileLogger::writeToFile(std::string filename, const char *str, } } +template +void FileLogger::logDebugString(bool enableLog, std::string_view debugString) { + if (enabled()) { + if (enableLog) { + writeToFile(logFileName, debugString.data(), debugString.size(), std::ios::app); + } + } +} + template void FileLogger::dumpKernel(const std::string &name, const std::string &src) { if (false == enabled()) { diff --git a/shared/source/utilities/logger.h b/shared/source/utilities/logger.h index 19d18475ba..361cc50de4 100644 --- a/shared/source/utilities/logger.h +++ b/shared/source/utilities/logger.h @@ -127,6 +127,8 @@ class FileLogger { } } + void logDebugString(bool enableLog, std::string_view debugString); + const char *getLogFileName() { return logFileName.c_str(); } diff --git a/shared/test/unit_test/debug_settings/debug_settings_manager_tests.cpp b/shared/test/unit_test/debug_settings/debug_settings_manager_tests.cpp index 4eb0a34121..b75e7c6f49 100644 --- a/shared/test/unit_test/debug_settings/debug_settings_manager_tests.cpp +++ b/shared/test/unit_test/debug_settings/debug_settings_manager_tests.cpp @@ -8,8 +8,11 @@ #include "shared/source/memory_manager/graphics_allocation.h" #include "shared/source/memory_manager/memory_manager.h" #include "shared/source/utilities/debug_file_reader.h" +#include "shared/source/utilities/logger.h" #include "shared/test/common/debug_settings/debug_settings_manager_fixture.h" #include "shared/test/common/helpers/debug_manager_state_restore.h" +#include "shared/test/common/helpers/variable_backup.h" +#include "shared/test/common/mocks/mock_io_functions.h" #include "shared/test/common/test_macros/test.h" #include "shared/test/common/utilities/base_object_utils.h" @@ -201,3 +204,56 @@ TEST(DebugSettingsManager, givenEnabledDebugManagerWhenCreateThenAllVariablesAre remove(SettingsReader::settingsFileName); } } + +TEST(DebugSettingsManager, GivenLogsEnabledAndDumpToFileWhenPrintDebuggerLogCalledThenStringPrintedToFile) { + if (NEO::DebugManager.disabled()) { + GTEST_SKIP(); + } + DebugManagerStateRestore restorer; + NEO::DebugManager.flags.DebuggerLogBitmask.set(NEO::DebugVariables::DEBUGGER_LOG_BITMASK::DUMP_TO_FILE); + + auto logFile = NEO::fileLoggerInstance().getLogFileName(); + + std::remove(logFile); + + ::testing::internal::CaptureStdout(); + PRINT_DEBUGGER_LOG(stdout, "test %s", "log"); + auto output = ::testing::internal::GetCapturedStdout(); + EXPECT_EQ(0u, output.size()); + + auto logFileExists = fileExists(logFile); + EXPECT_TRUE(logFileExists); + + size_t retSize; + auto data = loadDataFromFile(logFile, retSize); + + EXPECT_STREQ("test log", data.get()); + std::remove(logFile); +} + +TEST(DebugSettingsManager, GivenLogsDisabledAndDumpToFileWhenPrintDebuggerLogCalledThenStringIsNotPrintedToFile) { + if (!NEO::DebugManager.disabled()) { + GTEST_SKIP(); + } + DebugManagerStateRestore restorer; + NEO::DebugManager.flags.DebuggerLogBitmask.set(NEO::DebugVariables::DEBUGGER_LOG_BITMASK::DUMP_TO_FILE); + + auto logFile = NEO::fileLoggerInstance().getLogFileName(); + std::remove(logFile); + + ::testing::internal::CaptureStdout(); + PRINT_DEBUGGER_LOG(stdout, "test %s", "log"); + + auto output = ::testing::internal::GetCapturedStdout(); + EXPECT_EQ(0u, output.size()); + + auto logFileExists = fileExists(logFile); + ASSERT_FALSE(logFileExists); +} + +TEST(DebugLog, WhenLogDebugStringCalledThenNothingIsPrintedToStdout) { + ::testing::internal::CaptureStdout(); + logDebugString("test log"); + auto output = ::testing::internal::GetCapturedStdout(); + EXPECT_EQ(0u, output.size()); +} diff --git a/shared/test/unit_test/utilities/logger_tests.cpp b/shared/test/unit_test/utilities/logger_tests.cpp index d79018a2d4..0b4da17928 100644 --- a/shared/test/unit_test/utilities/logger_tests.cpp +++ b/shared/test/unit_test/utilities/logger_tests.cpp @@ -395,6 +395,24 @@ TEST(FileLogger, whenFullyEnabledThenAllDebugFunctionalityIsAvailableAtCompileTi static_assert(true == fileLogger.enabled(), ""); } +TEST(FileLogger, givenEnabledLogWhenLogDebugStringCalledThenStringIsWrittenToFile) { + std::string testFile = "testfile"; + DebugVariables flags; + FullyEnabledFileLogger fileLogger(testFile, flags); + + fileLogger.logDebugString(true, "test log"); + EXPECT_EQ(std::string("test log"), fileLogger.getFileString(testFile)); +} + +TEST(FileLogger, givenDisabledLogWhenLogDebugStringCalledThenStringIsNotWrittenToFile) { + std::string testFile = "testfile"; + DebugVariables flags; + FullyEnabledFileLogger fileLogger(testFile, flags); + + fileLogger.logDebugString(false, "test log"); + EXPECT_EQ(0u, fileLogger.getFileString(testFile).size()); +} + TEST(AllocationTypeLogging, givenGraphicsAllocationTypeWhenConvertingToStringThenCorrectStringIsReturned) { std::string testFile = "testfile"; DebugVariables flags;