diff --git a/.github/actions/setup-build-env/action.yml b/.github/actions/setup-build-env/action.yml index e4bc8ec58..1411cd13c 100644 --- a/.github/actions/setup-build-env/action.yml +++ b/.github/actions/setup-build-env/action.yml @@ -8,7 +8,7 @@ runs: shell: bash run: | sudo apt-get update - sudo apt-get install gperf build-essential bison flex libfl-dev libreadline-dev gawk tcl-dev libffi-dev git graphviz xdot pkg-config python3 libboost-system-dev libboost-python-dev libboost-filesystem-dev zlib1g-dev libbz2-dev libgtest-dev + sudo apt-get install -y gperf build-essential bison flex libfl-dev libreadline-dev gawk tcl-dev libffi-dev git graphviz xdot pkg-config python3 libboost-system-dev libboost-python-dev libboost-filesystem-dev zlib1g-dev libbz2-dev libgtest-dev libgmock-dev - name: Install macOS Dependencies if: runner.os == 'macOS' diff --git a/.github/workflows/test-verific.yml b/.github/workflows/test-verific.yml index 503d6c31b..f47326de0 100644 --- a/.github/workflows/test-verific.yml +++ b/.github/workflows/test-verific.yml @@ -36,8 +36,7 @@ jobs: persist-credentials: false submodules: true - name: Runtime environment - run: | - echo "procs=$(nproc)" >> $GITHUB_ENV + uses: ./.github/actions/setup-build-env - name: Build Yosys run: | diff --git a/kernel/log.cc b/kernel/log.cc index 34e56f8ac..5d0c67dc4 100644 --- a/kernel/log.cc +++ b/kernel/log.cc @@ -40,6 +40,7 @@ YOSYS_NAMESPACE_BEGIN std::vector log_files; std::vector log_streams; +std::vector log_sinks; std::vector log_scratchpads; std::map> log_hdump; std::vector log_warn_regexes, log_nowarn_regexes, log_werror_regexes; @@ -100,7 +101,7 @@ int gettimeofday(struct timeval *tv, struct timezone *tz) } #endif -static void logv_string(std::string_view format, std::string str) { +static void logv_string(std::string_view format, std::string str, LogSeverity severity = LogSeverity::LOG_INFO) { size_t remove_leading = 0; while (format.size() > 1 && format[0] == '\n') { logv_string("\n", "\n"); @@ -164,6 +165,10 @@ static void logv_string(std::string_view format, std::string str) { for (auto f : log_streams) *f << str; + LogMessage log_msg(severity, str); + for (LogSink* sink : log_sinks) + sink->log(log_msg); + RTLIL::Design *design = yosys_get_design(); if (design != nullptr) for (auto &scratchpad : log_scratchpads) @@ -201,11 +206,11 @@ static void logv_string(std::string_view format, std::string str) { } } -void log_formatted_string(std::string_view format, std::string str) +void log_formatted_string(std::string_view format, std::string str, LogSeverity severity) { if (log_make_debug && !ys_debug(1)) return; - logv_string(format, std::move(str)); + logv_string(format, std::move(str), severity); } void log_formatted_header(RTLIL::Design *design, std::string_view format, std::string str) @@ -291,7 +296,7 @@ void log_formatted_warning(std::string_view prefix, std::string message) if (log_errfile != NULL && !log_quiet_warnings) log_files.push_back(log_errfile); - log("%s%s", prefix, message); + log_formatted_string("%s", stringf("%s%s", prefix, message), LogSeverity::LOG_WARNING); log_flush(); if (log_errfile != NULL && !log_quiet_warnings) @@ -339,7 +344,7 @@ static void log_error_with_prefix(std::string_view prefix, std::string str) } log_last_error = std::move(str); - log("%s%s", prefix, log_last_error); + log_formatted_string("%s", stringf("%s%s", prefix, log_last_error), LogSeverity::LOG_ERROR); log_flush(); log_make_debug = bak_log_make_debug; @@ -425,7 +430,7 @@ void log_formatted_cmd_error(std::string str) pop_errfile = true; } - log("ERROR: %s", log_last_error); + log_formatted_string("%s", stringf("ERROR: %s", log_last_error), LogSeverity::LOG_ERROR); log_flush(); if (pop_errfile) diff --git a/kernel/log.h b/kernel/log.h index 144570026..4192be5ae 100644 --- a/kernel/log.h +++ b/kernel/log.h @@ -94,8 +94,28 @@ YOSYS_NAMESPACE_BEGIN struct log_cmd_error_exception { }; +enum LogSeverity { + LOG_INFO, + LOG_WARNING, + LOG_ERROR +}; + +struct LogMessage { + LogMessage(LogSeverity severity, std::string_view message) : + severity(severity), timestamp(std::time(nullptr)), message(message) {} + LogSeverity severity; + std::time_t timestamp; + std::string message; +}; + +class LogSink { + public: + virtual void log(const LogMessage& message) = 0; +}; + extern std::vector log_files; extern std::vector log_streams; +extern std::vector log_sinks; extern std::vector log_scratchpads; extern std::map> log_hdump; extern std::vector log_warn_regexes, log_nowarn_regexes, log_werror_regexes; @@ -132,12 +152,10 @@ static inline bool ys_debug(int = 0) { return false; } #endif # define log_debug(...) do { if (ys_debug(1)) log(__VA_ARGS__); } while (0) -void log_formatted_string(std::string_view format, std::string str); +void log_formatted_string(std::string_view format, std::string str, LogSeverity severity = LogSeverity::LOG_INFO); template inline void log(FmtString...> fmt, const Args &... args) { - if (log_make_debug && !ys_debug(1)) - return; log_formatted_string(fmt.format_string(), fmt.format(args...)); } diff --git a/tests/unit/Makefile b/tests/unit/Makefile index eee60ef9f..53cd92909 100644 --- a/tests/unit/Makefile +++ b/tests/unit/Makefile @@ -4,10 +4,10 @@ UNAME_S := $(shell uname -s) GTEST_PREFIX := $(shell brew --prefix googletest 2>/dev/null) ifeq ($(GTEST_PREFIX),) GTEST_CXXFLAGS := - GTEST_LDFLAGS := -lgtest -lgtest_main + GTEST_LDFLAGS := -lgtest -lgtest_main -lgmock else GTEST_CXXFLAGS := -I$(GTEST_PREFIX)/include - GTEST_LDFLAGS := -L$(GTEST_PREFIX)/lib -lgtest -lgtest_main + GTEST_LDFLAGS := -L$(GTEST_PREFIX)/lib -lgtest -lgtest_main -lgmock endif ifeq ($(UNAME_S),Darwin) diff --git a/tests/unit/kernel/logTest.cc b/tests/unit/kernel/logTest.cc index 62b4f3b98..c24389e94 100644 --- a/tests/unit/kernel/logTest.cc +++ b/tests/unit/kernel/logTest.cc @@ -1,3 +1,4 @@ +#include #include #include "kernel/yosys.h" @@ -11,4 +12,38 @@ TEST(KernelLogTest, logvValidValues) EXPECT_EQ(7, 7); } +class TestSink : public LogSink { + public: + void log(const LogMessage& message) override { + messages_.push_back(message); + } + std::vector messages_; +}; + +TEST(KernelLogTest, logToSink) +{ + TestSink sink; + log_sinks.push_back(&sink); + log("test info log"); + log_warning("test warning log"); + + std::vector expected{ + LogMessage(LogSeverity::LOG_INFO, "test info log"), + LogMessage(LogSeverity::LOG_WARNING, "test warning log"), + }; + // Certain calls to the log.h interface may prepend a string to + // the provided string. We should ensure that the expected string + // is a subset of the actual string. Additionally, we don't want to + // compare timestamps. So, we use a custom comparator. + for (const LogMessage& expected_msg : expected) { + EXPECT_THAT(sink.messages_, ::testing::Contains(::testing::Truly( + [&](const LogMessage& actual) { + return actual.severity == expected_msg.severity && + actual.message.find(expected_msg.message) != std::string::npos; + } + ))); + } + EXPECT_NE(sink.messages_[0].timestamp, 0); +} + YOSYS_NAMESPACE_END