~aleteoryx/muditaos

b0860034f99923d84e4e9211957fdf3a11665583 — Piotr Tański 4 years ago c847fde
[EGD-7418] Log rotation implemented

Implemented a log rotation functionality.
M module-utils/log/Logger.cpp => module-utils/log/Logger.cpp +70 -11
@@ 6,10 6,26 @@
#include <gsl/util>
#include "LockGuard.hpp"
#include <Logger.hpp>
#include <module-utils/Utils.hpp>
#include "macros.h"

namespace Log
{
    namespace
    {
        std::string getRotatedLogFileExtension(int count)
        {
            return ".log." + utils::to_string(count);
        }

        std::filesystem::path getRotatedFilePath(const std::filesystem::path &source, int rotationCount)
        {
            auto path = source;
            path.replace_extension(getRotatedLogFileExtension(rotationCount));
            return path;
        }
    } // namespace

    std::map<std::string, logger_level> Logger::filtered = {{"ApplicationManager", logger_level::LOGINFO},
                                                            {"CellularMux", logger_level::LOGINFO},
                                                            {"ServiceCellular", logger_level::LOGINFO},


@@ 23,6 39,13 @@ namespace Log
                                                            {IRQ_STR, logger_level::LOGTRACE}};
    const char *Logger::levelNames[]                     = {"TRACE", "DEBUG", "INFO", "WARN", "ERROR", "FATAL"};

    std::ostream &operator<<(std::ostream &stream, const Application &application)
    {
        stream << application.name << ' ' << application.revision << ", " << application.tag << ", "
               << application.branch << '\n';
        return stream;
    }

    Logger::Logger() : circularBuffer(circularBufferSize)
    {}



@@ 57,8 80,11 @@ namespace Log
        return logs;
    }

    void Logger::init()
    void Logger::init(Application app, size_t fileSize, int filesCount)
    {
        application      = std::move(app);
        maxFileSize      = fileSize;
        maxRotationIndex = filesCount - 1;
#if LOG_USE_COLOR == 1
        enableColors(true);
#else


@@ 125,24 151,30 @@ namespace Log
    /// @return:   1 - log flush successflul
    auto Logger::dumpToFile(std::filesystem::path logPath) -> int
    {
        int status = 0;
        const bool dumpLog =
            !(std::filesystem::exists(logPath) && std::filesystem::file_size(logPath) > MAX_LOG_FILE_SIZE);
        if (!dumpLog) {
            LOG_DEBUG("Flush skipped");
            return 0;
        auto firstDump = !std::filesystem::exists(logPath);
        if (const bool maxSizeExceeded = !firstDump && std::filesystem::file_size(logPath) > maxFileSize;
            maxSizeExceeded) {
            LOG_DEBUG("Max log file size exceeded. Rotating log files...");
            {
                LockGuard lock(logFileMutex);
                rotateLogFile(logPath);
            }
            firstDump = true;
        }

        int status = 1;
        {
            status = 1;
            const auto &logs = getLogs();

            LockGuard lock(flushMutex);
            std::fstream logFile(logPath, std::fstream::out | std::fstream::app);
            LockGuard lock(logFileMutex);
            std::ofstream logFile(logPath, std::fstream::out | std::fstream::app);
            if (!logFile.good()) {
                status = -EIO;
            }

            if (firstDump) {
                addFileHeader(logFile);
            }
            logFile.write(logs.data(), logs.size());
            if (logFile.bad()) {
                status = -EIO;


@@ 154,4 186,31 @@ namespace Log
        return status;
    }

}; // namespace Log
    void Logger::rotateLogFile(const std::filesystem::path &logPath)
    {
        for (int i = currentRotationIndex; i > 0; --i) {
            std::filesystem::path src = getRotatedFilePath(logPath, i);
            if (i == maxRotationIndex) {
                std::filesystem::remove(src);
                continue;
            }
            std::filesystem::path dest = getRotatedFilePath(logPath, i + 1);
            std::filesystem::rename(src, dest);
        }
        auto rotatedLogPath = getRotatedFilePath(logPath, 1);
        std::filesystem::rename(logPath, rotatedLogPath);
        onLogRotationFinished();
    }

    void Logger::onLogRotationFinished() noexcept
    {
        if (currentRotationIndex < maxRotationIndex) {
            ++currentRotationIndex;
        }
    }

    void Logger::addFileHeader(std::ofstream &file) const
    {
        file << application;
    }
} // namespace Log

M module-utils/log/Logger.hpp => module-utils/log/Logger.hpp +19 -2
@@ 21,6 21,15 @@ namespace Log
        SEGGER_RTT
    };

    struct Application
    {
        std::string name;
        std::string revision;
        std::string tag;
        std::string branch;
    };
    std::ostream &operator<<(std::ostream &stream, const Application &application);

    class Logger
    {
      public:


@@ 31,7 40,7 @@ namespace Log
            return logger;
        }
        auto getLogs() -> std::string;
        void init();
        void init(Application app, size_t fileSize = MAX_LOG_FILE_SIZE, int filesCount = MAX_LOG_FILES_COUNT);
        auto log(Device device, const char *fmt, va_list args) -> int;
        auto log(logger_level level, const char *file, int line, const char *function, const char *fmt, va_list args)
            -> int;


@@ 64,13 73,21 @@ namespace Log
            return sizeLeft;
        }

        void addFileHeader(std::ofstream &file) const;
        void rotateLogFile(const std::filesystem::path &logPath);
        void onLogRotationFinished() noexcept;

        cpp_freertos::MutexStandard mutex;
        cpp_freertos::MutexStandard flushMutex;
        cpp_freertos::MutexStandard logFileMutex;
        logger_level level{LOGTRACE};
        const LogColors *logColors            = &logColorsOff;
        char loggerBuffer[LOGGER_BUFFER_SIZE] = {0};
        size_t loggerBufferCurrentPos         = 0;
        size_t maxFileSize                    = MAX_LOG_FILE_SIZE;
        int currentRotationIndex              = 0;
        int maxRotationIndex                  = 0;

        Application application;
        LoggerBuffer circularBuffer;
        static constexpr size_t circularBufferSize = 1000;


M module-utils/log/log.hpp => module-utils/log/log.hpp +2 -1
@@ 90,7 90,8 @@ extern "C"
#pragma GCC diagnostic ignored "-Wunused-variable"
static const size_t LOGGER_BUFFER_SIZE  = 8192;
static const char *LOG_FILE_NAME        = "MuditaOS.log";
static const size_t MAX_LOG_FILE_SIZE   = 1024 * 1024 * 50; // 50 MB
static const int MAX_LOG_FILES_COUNT    = 3;
static const size_t MAX_LOG_FILE_SIZE   = 1024 * 1024 * 15; // 15 MB
#pragma GCC diagnostic pop

#endif /* LOG_LOG_H_ */

M module-utils/test/CMakeLists.txt => module-utils/test/CMakeLists.txt +11 -0
@@ 38,6 38,17 @@ add_catch2_executable(
        module-utils
)

# Log dumps tests
add_catch2_executable(
    NAME
        utils-logdumps
    SRCS
        test_logDumps.cpp
    LIBS
        module-utils
    USE_FS
)

# Logger buffer tests
add_catch2_executable(
    NAME

A module-utils/test/test_logDumps.cpp => module-utils/test/test_logDumps.cpp +119 -0
@@ 0,0 1,119 @@
// Copyright (c) 2017-2021, Mudita Sp. z.o.o. All rights reserved.
// For licensing, see https://github.com/mudita/MuditaOS/LICENSE.md

#define CATCH_CONFIG_MAIN // This tells Catch to provide a main() - only do this in one cpp file
#include <catch2/catch.hpp>

#include <string>

#include <module-utils/log/Logger.hpp>

namespace
{
    int countFiles(const std::filesystem::path &dir)
    {
        int sum = 0;
        for ([[maybe_unused]] auto const &entry : std::filesystem::directory_iterator{dir}) {
            ++sum;
        }
        return sum;
    }

    bool checkIfLogFilesExist(const std::filesystem::path &path, int expectedFilesCount)
    {
        for (int i = 0; i < expectedFilesCount; ++i) {
            auto filePath = path;
            if (i > 0) {
                filePath.replace_extension(".log." + std::to_string(i));
            }
            if (!std::filesystem::exists(filePath)) {
                return false;
            }
        }
        return true;
    }
} // namespace

TEST_CASE("Test if logs are dumped to a file without rotation")
{
    auto app                            = Log::Application{"TestApp", "rev", "tag", "branch"};
    constexpr auto MaxFileSize          = 1024 * 1024; // 1 MB
    constexpr auto MaxFilesCount        = 3;
    constexpr auto TestLog              = "12345678";
    const std::filesystem::path logsDir = "./ut_logs";
    const auto testLogFile              = logsDir / "TestApp.log";

    // Prepare the environment.
    if (std::filesystem::exists(logsDir)) {
        std::filesystem::remove_all(logsDir);
    }
    std::filesystem::create_directory(logsDir);

    // Initialize the logger with test parameters.
    Log::Logger::get().init(std::move(app), MaxFileSize, MaxFilesCount);
    REQUIRE(countFiles(logsDir) == 0);

    // Dump logs.
    LOG_ERROR(TestLog);
    Log::Logger::get().dumpToFile(testLogFile);
    REQUIRE(countFiles(logsDir) == 1);
    REQUIRE(checkIfLogFilesExist(testLogFile, 1));

    LOG_ERROR(TestLog);
    Log::Logger::get().dumpToFile(testLogFile);
    REQUIRE(countFiles(logsDir) == 1);
    REQUIRE(checkIfLogFilesExist(testLogFile, 1));

    // Clean-up the environment
    std::filesystem::remove_all(logsDir);
}

TEST_CASE("Test if log files rotate")
{
    auto app                            = Log::Application{"TestApp", "rev", "tag", "branch"};
    constexpr auto MaxFileSize          = 10; // 10 bytes
    constexpr auto MaxFilesCount        = 3;
    constexpr auto TestLog              = "12345678";
    const std::filesystem::path logsDir = "./ut_logs";
    const auto testLogFile              = logsDir / "TestApp.log";

    // Prepare the environment.
    if (std::filesystem::exists(logsDir)) {
        std::filesystem::remove_all(logsDir);
    }
    std::filesystem::create_directory(logsDir);

    // Initialize the logger with test parameters.
    Log::Logger::get().init(std::move(app), MaxFileSize, MaxFilesCount);
    REQUIRE(countFiles(logsDir) == 0);

    // Dump logs.
    // Dumping logs to a file causes a log rotation.
    LOG_ERROR(TestLog);
    Log::Logger::get().dumpToFile(testLogFile);
    REQUIRE(countFiles(logsDir) == 1);
    REQUIRE(checkIfLogFilesExist(testLogFile, 1));

    LOG_ERROR(TestLog);
    Log::Logger::get().dumpToFile(testLogFile);
    REQUIRE(countFiles(logsDir) == 2);
    REQUIRE(checkIfLogFilesExist(testLogFile, 2));

    LOG_ERROR(TestLog);
    Log::Logger::get().dumpToFile(testLogFile);
    REQUIRE(countFiles(logsDir) == 3);
    REQUIRE(checkIfLogFilesExist(testLogFile, 3));

    LOG_ERROR(TestLog);
    Log::Logger::get().dumpToFile(testLogFile);
    REQUIRE(countFiles(logsDir) == 3);
    REQUIRE(checkIfLogFilesExist(testLogFile, 3));

    LOG_ERROR(TestLog);
    Log::Logger::get().dumpToFile(testLogFile);
    REQUIRE(countFiles(logsDir) == 3);
    REQUIRE(checkIfLogFilesExist(testLogFile, 3));

    // Clean-up the environment
    std::filesystem::remove_all(logsDir);
}

M products/BellHybrid/BellHybridMain.cpp => products/BellHybrid/BellHybridMain.cpp +3 -2
@@ 36,6 36,7 @@

int main()
{
    constexpr auto ApplicationName = "BellHybrid";

#if SYSTEM_VIEW_ENABLED
    SEGGER_SYSVIEW_Conf();


@@ 81,7 82,7 @@ int main()
                abort();
            }

            Log::Logger::get().init();
            Log::Logger::get().init(Log::Application{ApplicationName, GIT_REV, GIT_TAG, GIT_BRANCH});
            /// force initialization of PhonenumberUtil because of its stack usage
            /// otherwise we would end up with an init race and PhonenumberUtil could
            /// be initiated in a task with stack not big enough to handle it


@@ 102,7 103,7 @@ int main()
                sysmgr.get());
        });

    LOG_PRINTF("Launching BellHybrid \n");
    LOG_PRINTF("Launching %s \n", ApplicationName);
    LOG_PRINTF("commit: %s tag: %s branch: %s\n", GIT_REV, GIT_TAG, GIT_BRANCH);
    cpp_freertos::Thread::StartScheduler();


M products/PurePhone/PurePhoneMain.cpp => products/PurePhone/PurePhoneMain.cpp +3 -2
@@ 61,6 61,7 @@

int main()
{
    constexpr auto ApplicationName = "PurePhone";

#if SYSTEM_VIEW_ENABLED
    SEGGER_SYSVIEW_Conf();


@@ 114,7 115,7 @@ int main()
                abort();
            }

            Log::Logger::get().init();
            Log::Logger::get().init(Log::Application{ApplicationName, GIT_REV, GIT_TAG, GIT_BRANCH});
            /// force initialization of PhonenumberUtil because of its stack usage
            /// otherwise we would end up with an init race and PhonenumberUtil could
            /// be initiated in a task with stack not big enough to handle it


@@ 179,7 180,7 @@ int main()
                sysmgr.get());
        });

    LOG_PRINTF("Launching PurePhone \n");
    LOG_PRINTF("Launching %s \n", ApplicationName);
    LOG_PRINTF("commit: %s tag: %s branch: %s\n", GIT_REV, GIT_TAG, GIT_BRANCH);
    cpp_freertos::Thread::StartScheduler();


M test/CMakeLists.txt => test/CMakeLists.txt +6 -4
@@ 144,10 144,12 @@ function(add_catch2_executable)
    target_link_options(${_TESTNAME} PUBLIC "-fsanitize=address")

    # disable logs in unit tests
    if (NOT ${ENABLE_TEST_LOGS} AND NOT ${_TESTNAME} STREQUAL "catch2-utils-log")
        target_sources(${_TESTNAME} PRIVATE ${ROOT_TEST_DIR}/mock-logs.cpp)
        target_sources(${_TESTNAME} PRIVATE ${ROOT_TEST_DIR}/mock-freertos-tls.cpp)
    endif (NOT ${ENABLE_TEST_LOGS} AND NOT ${_TESTNAME} STREQUAL "catch2-utils-log")
    if (NOT ${ENABLE_TEST_LOGS})
        if (NOT ${_TESTNAME} STREQUAL "catch2-utils-log" AND NOT ${_TESTNAME} STREQUAL "catch2-utils-logdumps")
            target_sources(${_TESTNAME} PRIVATE ${ROOT_TEST_DIR}/mock-logs.cpp)
            target_sources(${_TESTNAME} PRIVATE ${ROOT_TEST_DIR}/mock-freertos-tls.cpp)
        endif(NOT ${_TESTNAME} STREQUAL "catch2-utils-log" AND NOT ${_TESTNAME} STREQUAL "catch2-utils-logdumps")
    endif (NOT ${ENABLE_TEST_LOGS})

    set(_TEST_LABELS "")
    if(_TEST_ARGS_USE_FS)