~aleteoryx/muditaos

def5dbcfa99639957c3769bbb2eca550e287fc8c — Mateusz Grzegorzek 4 years ago 25584f2
[EGD-5908] Fix bug in Logger + add log unit test

Because `vsnprintf` return value means:
"
The number of characters that would have been
written if n had been sufficiently large,
not counting the terminating null character.
If an encoding error occurs, a negative number is returned.
"

`Logger` crashed when log msg was longer than LOGGER_BUFFER_SIZE.
Checking `vsnprintf` return value solves this issue.
M enabled_unittests => enabled_unittests +4 -0
@@ 287,6 287,10 @@ TESTS_LIST["catch2-utils-duration"]="
    Duration - display;
"
#---------
TESTS_LIST["catch2-utils-log"]="
    Log tests;
"
#---------
TESTS_LIST["catch2-utils-loggerbuffer"]="
    LoggerBuffer tests;
"

M module-utils/log/Logger.cpp => module-utils/log/Logger.cpp +24 -10
@@ 68,31 68,45 @@ namespace Log
        auto _ = gsl::finally([this] { unlock(); });

        loggerBufferCurrentPos = 0;
        loggerBufferCurrentPos += vsnprintf(&loggerBuffer[loggerBufferCurrentPos], loggerBufferSizeLeft(), fmt, args);
        logToDevice(device, loggerBuffer, loggerBufferCurrentPos);

        return loggerBufferCurrentPos;
        const auto sizeLeft = loggerBufferSizeLeft();
        const auto result   = vsnprintf(&loggerBuffer[loggerBufferCurrentPos], sizeLeft, fmt, args);
        if (0 <= result) {
            const auto numOfBytesAddedToBuffer = static_cast<size_t>(result);
            loggerBufferCurrentPos += (numOfBytesAddedToBuffer < sizeLeft) ? numOfBytesAddedToBuffer : (sizeLeft - 1);

            logToDevice(device, loggerBuffer, loggerBufferCurrentPos);
            return loggerBufferCurrentPos;
        }
        return -1;
    }

    void Logger::log(
        logger_level level, const char *file, int line, const char *function, const char *fmt, va_list args)
    auto Logger::log(
        logger_level level, const char *file, int line, const char *function, const char *fmt, va_list args) -> int
    {
        if (!filterLogs(level)) {
            return;
            return -1;
        }

        if (!lock()) {
            return;
            return -1;
        }
        auto _ = gsl::finally([this] { unlock(); });

        loggerBufferCurrentPos = 0;
        addLogHeader(level, file, line, function);

        loggerBufferCurrentPos += vsnprintf(&loggerBuffer[loggerBufferCurrentPos], loggerBufferSizeLeft(), fmt, args);
        loggerBufferCurrentPos += snprintf(&loggerBuffer[loggerBufferCurrentPos], loggerBufferSizeLeft(), "\n");
        const auto sizeLeft = loggerBufferSizeLeft();
        const auto result   = vsnprintf(&loggerBuffer[loggerBufferCurrentPos], sizeLeft, fmt, args);
        if (0 <= result) {
            const auto numOfBytesAddedToBuffer = static_cast<size_t>(result);
            loggerBufferCurrentPos += (numOfBytesAddedToBuffer < sizeLeft) ? numOfBytesAddedToBuffer : (sizeLeft - 1);
            loggerBufferCurrentPos += snprintf(&loggerBuffer[loggerBufferCurrentPos], loggerBufferSizeLeft(), "\n");

        logToDevice(Device::DEFAULT, loggerBuffer, loggerBufferCurrentPos);
            logToDevice(Device::DEFAULT, loggerBuffer, loggerBufferCurrentPos);
            return loggerBufferCurrentPos;
        }
        return -1;
    }

    auto Logger::logAssert(const char *fmt, va_list args) -> int

M module-utils/log/Logger.hpp => module-utils/log/Logger.hpp +2 -1
@@ 30,7 30,8 @@ namespace Log
        }
        void init();
        auto log(Device device, const char *fmt, va_list args) -> int;
        void log(logger_level level, const char *file, int line, const char *function, const char *fmt, va_list args);
        auto log(logger_level level, const char *file, int line, const char *function, const char *fmt, va_list args)
            -> int;
        auto logAssert(const char *fmt, va_list args) -> int;

        static constexpr auto CRIT_STR = "CRIT";

M module-utils/log/log.cpp => module-utils/log/log.cpp +6 -4
@@ 7,20 7,22 @@

using Log::Logger;

void log_Printf(const char *fmt, ...)
int log_Printf(const char *fmt, ...)
{
    va_list args;
    va_start(args, fmt);
    Logger::get().log(Log::Device::DEFAULT, fmt, args);
    const int result = Logger::get().log(Log::Device::DEFAULT, fmt, args);
    va_end(args);
    return result;
}

void log_Log(logger_level level, const char *file, int line, const char *function, const char *fmt, ...)
int log_Log(logger_level level, const char *file, int line, const char *function, const char *fmt, ...)
{
    va_list args;
    va_start(args, fmt);
    Logger::get().log(level, file, line, function, fmt, args);
    const int result = Logger::get().log(level, file, line, function, fmt, args);
    va_end(args);
    return result;
}

extern "C"

M module-utils/log/log.hpp => module-utils/log/log.hpp +2 -2
@@ 60,9 60,9 @@ extern "C"
    /**
     * Forward declarations
     */
    void log_Log(logger_level level, const char *file, int line, const char *function, const char *fmt, ...)
    int log_Log(logger_level level, const char *file, int line, const char *function, const char *fmt, ...)
        __attribute__((format(printf, 5, 6)));
    void log_Printf(const char *fmt, ...) __attribute__((format(printf, 1, 2)));
    int log_Printf(const char *fmt, ...) __attribute__((format(printf, 1, 2)));
    void log_WriteToDevice(const uint8_t *pBuffer, unsigned NumBytes);

/**

M module-utils/test/CMakeLists.txt => module-utils/test/CMakeLists.txt +10 -18
@@ 90,6 90,16 @@ add_catch2_executable(
        module-utils
)

# Log tests
add_catch2_executable(
    NAME
        utils-log
    SRCS
        test_log.cpp
    LIBS
        module-utils
)

# Logger buffer tests
add_catch2_executable(
    NAME


@@ 122,24 132,6 @@ add_catch2_executable(
)

###########################################
# Log functional tests project
project(test_module-utils_log VERSION 1.0
    DESCRIPTION "Module-utils log functional tests")

add_executable( ${PROJECT_NAME} EXCLUDE_FROM_ALL
    test_log.cpp
    test_log2.cpp
)
add_test(NAME ${PROJECT_NAME}
    COMMAND ${PROJECT_NAME}
    WORKING_DIRECTORY ${CMAKE_BINARY_DIR}
    )
add_dependencies(check ${PROJECT_NAME})

target_include_directories(${PROJECT_NAME} PRIVATE "${CMAKE_CURRENT_LIST_DIR}/..")
target_link_libraries(${PROJECT_NAME} PRIVATE module-utils)

###########################################
# UTF8 functional tests projeet
project(test_module-utils_utf8 VERSION 1.0
    DESCRIPTION "Module-utils utf8 functional tests")

M module-utils/test/test_log.cpp => module-utils/test/test_log.cpp +36 -25
@@ 1,35 1,46 @@
// Copyright (c) 2017-2020, Mudita Sp. z.o.o. All rights reserved.
// Copyright (c) 2017-2021, Mudita Sp. z.o.o. All rights reserved.
// For licensing, see https://github.com/mudita/MuditaOS/LICENSE.md

/*
 * unittest_log.cpp
 *
 *  Created on: 29 kwi 2019
 *      Author: robert
 */
#define CATCH_CONFIG_MAIN // This tells Catch to provide a main() - only do this in one cpp file
#include <catch2/catch.hpp>

#include "log/log.hpp"

#include <iostream>
#include <string>

#include "test_log2.h"

using namespace std;

int main()
TEST_CASE("Log tests")
{

    cout << "RUNNING UNIT TEST FOR LOG" << endl;

    LOG_TRACE("This should be blue");
    LOG_DEBUG("This should be navy blue");
    LOG_INFO("This should be green");
    LOG_WARN("This should be yellow");
    LOG_ERROR("This should be red");
    LOG_FATAL("This should be purple");

    log_test_function();

    return 0;
    int value                     = -423;
    const char *carray            = "carray";
    string str                    = "string";
    double double_value           = 6.5323;
    unsigned int unsigned_value   = 7821;
    constexpr auto big_array_size = LOGGER_BUFFER_SIZE + 2;
    char big_array[big_array_size];
    memset(big_array, 'X', big_array_size);
    big_array[big_array_size - 1] = '\0';

    int loggerBufferSize = static_cast<int>(LOGGER_BUFFER_SIZE);
    int result           = LOG_TRACE("value: %d", value);
    REQUIRE(0 < result);
    REQUIRE(result <= loggerBufferSize);
    result = LOG_DEBUG("carray: %s", carray);
    REQUIRE(0 < result);
    REQUIRE(result <= loggerBufferSize);
    result = LOG_INFO("str: %s", str.c_str());
    REQUIRE(0 < result);
    REQUIRE(result <= loggerBufferSize);
    result = LOG_WARN("double_value: %f", double_value);
    REQUIRE(0 < result);
    REQUIRE(result <= loggerBufferSize);
    result = LOG_ERROR("unsigned_value: %u", unsigned_value);
    REQUIRE(0 < result);
    REQUIRE(result <= loggerBufferSize);
    result = LOG_FATAL("big_array: %s", big_array);
    REQUIRE(0 < result);
    REQUIRE(result <= loggerBufferSize);
    result = LOG_PRINTF("value: %d, carray: %s, double_value: %f", value, carray, double_value);
    REQUIRE(0 < result);
    REQUIRE(result <= loggerBufferSize);
}

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

/*
 * unittest_log2.cpp
 *
 *  Created on: 29 kwi 2019
 *      Author: robert
 */

#include "log/log.hpp"

#include <iostream>
#include <string>

using namespace std;

int log_test_function()
{

    LOG_TRACE("This should be blue");
    LOG_DEBUG("This should be navy blue");
    LOG_INFO("This should be green");
    LOG_WARN("This should be yellow");
    LOG_ERROR("This should be red");
    LOG_FATAL("This should be purple");

    return 0;
}

D module-utils/test/test_log2.h => module-utils/test/test_log2.h +0 -16
@@ 1,16 0,0 @@
// Copyright (c) 2017-2020, Mudita Sp. z.o.o. All rights reserved.
// For licensing, see https://github.com/mudita/MuditaOS/LICENSE.md

/*
 * unittest2_log.h
 *
 *  Created on: 29 kwi 2019
 *      Author: robert
 */

#ifndef TEST_UNITTEST_LOG2_H_
#define TEST_UNITTEST_LOG2_H_

int log_test_function();

#endif /* TEST_UNITTEST_LOG2_H_ */

M test/CMakeLists.txt => test/CMakeLists.txt +3 -3
@@ 84,7 84,7 @@ function(add_catch2_executable)
    set(_TESTNAME "catch2-${_TEST_ARGS_NAME}")

    if(NOT _TEST_ARGS_SRCS)
	message(FATAL_ERROR "You must provide test sources for ${_TESTNAME}")
	    message(FATAL_ERROR "You must provide test sources for ${_TESTNAME}")
    endif(NOT _TEST_ARGS_SRCS)

    add_executable(${_TESTNAME} EXCLUDE_FROM_ALL ${_TEST_ARGS_SRCS})


@@ 93,10 93,10 @@ function(add_catch2_executable)
    target_link_options(${_TESTNAME} PUBLIC "-fsanitize=address")

    # disable logs in unit tests
    if (NOT ${ENABLE_TEST_LOGS})
    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})
    endif (NOT ${ENABLE_TEST_LOGS} AND NOT ${_TESTNAME} STREQUAL "catch2-utils-log")

    target_link_libraries(${_TESTNAME} PRIVATE Catch2::Catch2)
    foreach(lib ${_TEST_ARGS_LIBS})

M test/mock-logs.cpp => test/mock-logs.cpp +4 -2
@@ 3,17 3,19 @@

#include <log/log.hpp>
#include <cstdarg>
__attribute__((weak)) void log_Log(
__attribute__((weak)) int log_Log(
    logger_level level, const char *file, int line, const char *function, const char *fmt, ...)
{
    va_list args;
    va_start(args, fmt);
    va_end(args);
    return 0;
}

__attribute__((weak)) void log_Printf(const char *fmt, ...)
__attribute__((weak)) int log_Printf(const char *fmt, ...)
{
    va_list args;
    va_start(args, fmt);
    va_end(args);
    return 0;
}

M test/pytest/test_dom_dump.py => test/pytest/test_dom_dump.py +0 -1
@@ 1,7 1,6 @@
import pytest
from harness import log

@pytest.mark.skip("not working ;/")
def test_get_dom(harness):
    body = {"ui": True, "getWindow": True}
    result = harness.endpoint_request("developerMode", "get", body)