diff --git a/CHANGELOG b/CHANGELOG index e0b0eb05e..18f82bdd1 100644 --- a/CHANGELOG +++ b/CHANGELOG @@ -62,6 +62,7 @@ Yosys 0.9 .. Yosys 0.9-dev - Added "synth_xilinx -dff" - Improved support of $readmem[hb] Memory Content File inclusion - Added "opt_lut_ins" pass + - Added "logger" pass Yosys 0.8 .. Yosys 0.9 ---------------------- diff --git a/kernel/driver.cc b/kernel/driver.cc index 9040408bc..398c89e03 100644 --- a/kernel/driver.cc +++ b/kernel/driver.cc @@ -558,6 +558,10 @@ int main(int argc, char **argv) fprintf(f, "\n"); } + if (log_expect_no_warnings && log_warnings_count_noexpect) + log_error("Unexpected warnings found: %d unique messages, %d total, %d expected\n", GetSize(log_warnings), + log_warnings_count, log_warnings_count - log_warnings_count_noexpect); + if (print_stats) { std::string hash = log_hasher->final().substr(0, 10); @@ -664,6 +668,8 @@ int main(int argc, char **argv) } #endif + log_check_expected(); + yosys_atexit(); memhasher_off(); diff --git a/kernel/log.cc b/kernel/log.cc index f5d6c488e..72181ebe8 100644 --- a/kernel/log.cc +++ b/kernel/log.cc @@ -42,8 +42,11 @@ std::vector log_files; std::vector log_streams; std::map> log_hdump; std::vector log_warn_regexes, log_nowarn_regexes, log_werror_regexes; +std::vector> log_expect_log, log_expect_warning, log_expect_error; std::set log_warnings, log_experimentals, log_experimentals_ignored; int log_warnings_count = 0; +int log_warnings_count_noexpect = 0; +bool log_expect_no_warnings = false; bool log_hdump_all = false; FILE *log_errfile = NULL; SHA1 *log_hasher = NULL; @@ -68,6 +71,8 @@ int string_buf_index = -1; static struct timeval initial_tv = { 0, 0 }; static bool next_print_log = false; static int log_newline_count = 0; +static bool check_expected_logs = true; +static bool display_error_log_msg = true; static void log_id_cache_clear() { @@ -162,7 +167,7 @@ void logv(const char *format, va_list ap) { log_warn_regex_recusion_guard = true; - if (log_warn_regexes.empty()) + if (log_warn_regexes.empty() && log_expect_log.empty()) { linebuffer.clear(); } @@ -174,6 +179,11 @@ void logv(const char *format, va_list ap) for (auto &re : log_warn_regexes) if (std::regex_search(linebuffer, re)) log_warning("Found log message matching -W regex:\n%s", str.c_str()); + + for (auto &item : log_expect_log) + if (std::regex_search(linebuffer, item.first)) + item.second.current_count++; + linebuffer.clear(); } } @@ -244,6 +254,13 @@ static void logv_warning_with_prefix(const char *prefix, if (std::regex_search(message, re)) log_error("%s", message.c_str()); + bool warning_match = false; + for (auto &item : log_expect_warning) + if (std::regex_search(message, item.first)) { + item.second.current_count++; + warning_match = true; + } + if (log_warnings.count(message)) { log("%s%s", prefix, message.c_str()); @@ -263,6 +280,8 @@ static void logv_warning_with_prefix(const char *prefix, log_warnings.insert(message); } + if (!warning_match) + log_warnings_count_noexpect++; log_warnings_count++; log_make_debug = bak_log_make_debug; } @@ -320,7 +339,8 @@ static void logv_error_with_prefix(const char *prefix, f = stderr; log_last_error = vstringf(format, ap); - log("%s%s", prefix, log_last_error.c_str()); + if (display_error_log_msg) + log("%s%s", prefix, log_last_error.c_str()); log_flush(); log_make_debug = bak_log_make_debug; @@ -328,6 +348,12 @@ static void logv_error_with_prefix(const char *prefix, if (log_error_atexit) log_error_atexit(); + for (auto &item : log_expect_error) + if (std::regex_search(log_last_error, item.first)) + item.second.current_count++; + + if (check_expected_logs) + log_check_expected(); #ifdef EMSCRIPTEN log_files = backup_log_files; throw 0; @@ -636,6 +662,53 @@ void log_wire(RTLIL::Wire *wire, std::string indent) log("%s", buf.str().c_str()); } +void log_check_expected() +{ + check_expected_logs = false; + + for (auto &item : log_expect_warning) { + if (item.second.current_count == 0) { + log_warn_regexes.clear(); + log_error("Expected warning pattern '%s' not found !\n", item.second.pattern.c_str()); + } + if (item.second.current_count != item.second.expected_count) { + log_warn_regexes.clear(); + log_error("Expected warning pattern '%s' found %d time(s), instead of %d time(s) !\n", + item.second.pattern.c_str(), item.second.current_count, item.second.expected_count); + } + } + + for (auto &item : log_expect_log) { + if (item.second.current_count == 0) { + log_warn_regexes.clear(); + log_error("Expected log pattern '%s' not found !\n", item.second.pattern.c_str()); + } + if (item.second.current_count != item.second.expected_count) { + log_warn_regexes.clear(); + log_error("Expected log pattern '%s' found %d time(s), instead of %d time(s) !\n", + item.second.pattern.c_str(), item.second.current_count, item.second.expected_count); + } + } + + for (auto &item : log_expect_error) + if (item.second.current_count == item.second.expected_count) { + log_warn_regexes.clear(); + log("Expected error pattern '%s' found !!!\n", item.second.pattern.c_str()); + #ifdef EMSCRIPTEN + log_files = backup_log_files; + throw 0; + #elif defined(_MSC_VER) + _exit(0); + #else + _Exit(0); + #endif + } else { + display_error_log_msg = false; + log_warn_regexes.clear(); + log_error("Expected error pattern '%s' not found !\n", item.second.pattern.c_str()); + } +} + // --------------------------------------------------- // This is the magic behind the code coverage counters // --------------------------------------------------- diff --git a/kernel/log.h b/kernel/log.h index 9db8efaa5..603938f4c 100644 --- a/kernel/log.h +++ b/kernel/log.h @@ -52,6 +52,8 @@ extern std::map> log_hdump; extern std::vector log_warn_regexes, log_nowarn_regexes, log_werror_regexes; extern std::set log_warnings, log_experimentals, log_experimentals_ignored; extern int log_warnings_count; +extern int log_warnings_count_noexpect; +extern bool log_expect_no_warnings; extern bool log_hdump_all; extern FILE *log_errfile; extern SHA1 *log_hasher; @@ -135,6 +137,23 @@ void log_backtrace(const char *prefix, int levels); void log_reset_stack(); void log_flush(); +struct LogExpectedItem +{ + LogExpectedItem(std::string pattern, int expected) : + expected_count(expected), + current_count(0), + pattern(pattern) + { + } + + int expected_count; + int current_count; + std::string pattern; +}; + +extern std::vector> log_expect_log, log_expect_warning, log_expect_error; +void log_check_expected(); + const char *log_signal(const RTLIL::SigSpec &sig, bool autoint = true); const char *log_const(const RTLIL::Const &value, bool autoint = true); const char *log_id(RTLIL::IdString id); diff --git a/passes/cmds/Makefile.inc b/passes/cmds/Makefile.inc index 07a5d3ddc..20b38bf8e 100644 --- a/passes/cmds/Makefile.inc +++ b/passes/cmds/Makefile.inc @@ -33,3 +33,4 @@ OBJS += passes/cmds/blackbox.o OBJS += passes/cmds/ltp.o OBJS += passes/cmds/bugpoint.o OBJS += passes/cmds/scratchpad.o +OBJS += passes/cmds/logger.o diff --git a/passes/cmds/logger.cc b/passes/cmds/logger.cc new file mode 100644 index 000000000..bd1038a7e --- /dev/null +++ b/passes/cmds/logger.cc @@ -0,0 +1,201 @@ +/* + * yosys -- Yosys Open SYnthesis Suite + * + * Copyright (C) 2020 Miodrag Milanovic + * + * Permission to use, copy, modify, and/or distribute this software for any + * purpose with or without fee is hereby granted, provided that the above + * copyright notice and this permission notice appear in all copies. + * + * THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES + * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF + * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR + * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES + * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN + * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF + * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE. + * + */ + +#include "kernel/register.h" +#include "kernel/log.h" + +USING_YOSYS_NAMESPACE +PRIVATE_NAMESPACE_BEGIN + +struct LoggerPass : public Pass { + LoggerPass() : Pass("logger", "set logger properties") { } + void help() YS_OVERRIDE + { + // |---v---|---v---|---v---|---v---|---v---|---v---|---v---|---v---|---v---|---v---| + log("\n"); + log(" logger [options]\n"); + log("\n"); + log("This command sets global logger properties, also available using command line\n"); + log("options.\n"); + log("\n"); + log(" -[no]time\n"); + log(" enable/disable display of timestamp in log output.\n"); + log("\n"); + log(" -[no]stderr\n"); + log(" enable/disable logging errors to stderr.\n"); + log("\n"); + log(" -warn regex\n"); + log(" print a warning for all log messages matching the regex.\n"); + log("\n"); + log(" -nowarn regex\n"); + log(" if a warning message matches the regex, it is printed as regular\n"); + log(" message instead.\n"); + log("\n"); + log(" -werror regex\n"); + log(" if a warning message matches the regex, it is printed as error\n"); + log(" message instead and the tool terminates with a nonzero return code.\n"); + log("\n"); + log(" -[no]debug\n"); + log(" globally enable/disable debug log messages.\n"); + log("\n"); + log(" -experimental \n"); + log(" do not print warnings for the specified experimental feature\n"); + log("\n"); + log(" -expect \n"); + log(" expect log,warning or error to appear. In case of error return code is 0.\n"); + log("\n"); + log(" -expect-no-warnings\n"); + log(" gives error in case there is at least one warning that is not expected.\n"); + log("\n"); + } + + void execute(std::vector args, RTLIL::Design * design) YS_OVERRIDE + { + size_t argidx; + for (argidx = 1; argidx < args.size(); argidx++) + { + + if (args[argidx] == "-time") { + log_time = true; + log("Enabled timestamp in logs.\n"); + continue; + } + if (args[argidx] == "-notime") { + log_time = false; + log("Disabled timestamp in logs.\n"); + continue; + } + if (args[argidx] == "-stderr") { + log_error_stderr = true; + log("Enabled loggint errors to stderr.\n"); + continue; + } + if (args[argidx] == "-nostderr") { + log_error_stderr = false; + log("Disabled loggint errors to stderr.\n"); + continue; + } + if (args[argidx] == "-warn" && argidx+1 < args.size()) { + std::string pattern = args[++argidx]; + if (pattern.front() == '\"' && pattern.back() == '\"') pattern = pattern.substr(1, pattern.size() - 2); + try { + log("Added regex '%s' for warnings to warn list.\n", pattern.c_str()); + log_warn_regexes.push_back(std::regex(pattern, + std::regex_constants::nosubs | + std::regex_constants::optimize | + std::regex_constants::egrep)); + } + catch (const std::regex_error& e) { + log_cmd_error("Error in regex expression '%s' !\n", pattern.c_str()); + } + continue; + } + if (args[argidx] == "-nowarn" && argidx+1 < args.size()) { + std::string pattern = args[++argidx]; + if (pattern.front() == '\"' && pattern.back() == '\"') pattern = pattern.substr(1, pattern.size() - 2); + try { + log("Added regex '%s' for warnings to nowarn list.\n", pattern.c_str()); + log_nowarn_regexes.push_back(std::regex(pattern, + std::regex_constants::nosubs | + std::regex_constants::optimize | + std::regex_constants::egrep)); + } + catch (const std::regex_error& e) { + log_cmd_error("Error in regex expression '%s' !\n", pattern.c_str()); + } + continue; + } + if (args[argidx] == "-werror" && argidx+1 < args.size()) { + std::string pattern = args[++argidx]; + if (pattern.front() == '\"' && pattern.back() == '\"') pattern = pattern.substr(1, pattern.size() - 2); + try { + log("Added regex '%s' for warnings to werror list.\n", pattern.c_str()); + log_werror_regexes.push_back(std::regex(pattern, + std::regex_constants::nosubs | + std::regex_constants::optimize | + std::regex_constants::egrep)); + } + catch (const std::regex_error& e) { + log_cmd_error("Error in regex expression '%s' !\n", pattern.c_str()); + } + continue; + } + if (args[argidx] == "-debug") { + log_force_debug = 1; + log("Enabled debug log messages.\n"); + continue; + } + if (args[argidx] == "-nodebug") { + log_force_debug = 0; + log("Disabled debug log messages.\n"); + continue; + } + if (args[argidx] == "-experimental" && argidx+1 < args.size()) { + std::string value = args[++argidx]; + log("Added '%s' experimental ignore list.\n", value.c_str()); + log_experimentals_ignored.insert(value); + continue; + } + if (args[argidx] == "-expect" && argidx+3 < args.size()) { + std::string type = args[++argidx]; + if (type!="error" && type!="warning" && type!="log") + log_cmd_error("Expect command require type to be 'log', 'warning' or 'error' !\n"); + if (type=="error" && log_expect_error.size()>0) + log_cmd_error("Only single error message can be expected !\n"); + std::string pattern = args[++argidx]; + if (pattern.front() == '\"' && pattern.back() == '\"') pattern = pattern.substr(1, pattern.size() - 2); + int count = atoi(args[++argidx].c_str()); + if (count<=0) + log_cmd_error("Number of expected messages must be higher then 0 !\n"); + if (type=="error" && count!=1) + log_cmd_error("Expected error message occurrences must be 1 !\n"); + log("Added regex '%s' for warnings to expected %s list.\n", pattern.c_str(), type.c_str()); + try { + if (type=="error") + log_expect_error.push_back(std::make_pair(std::regex(pattern, + std::regex_constants::nosubs | + std::regex_constants::optimize | + std::regex_constants::egrep), LogExpectedItem(pattern, count))); + else if (type=="warning") + log_expect_warning.push_back(std::make_pair(std::regex(pattern, + std::regex_constants::nosubs | + std::regex_constants::optimize | + std::regex_constants::egrep), LogExpectedItem(pattern, count))); + else + log_expect_log.push_back(std::make_pair(std::regex(pattern, + std::regex_constants::nosubs | + std::regex_constants::optimize | + std::regex_constants::egrep), LogExpectedItem(pattern, count))); + } + catch (const std::regex_error& e) { + log_cmd_error("Error in regex expression '%s' !\n", pattern.c_str()); + } + continue; + } + if (args[argidx] == "-expect-no-warnings") { + log_expect_no_warnings = true; + continue; + } + break; + } + extra_args(args, argidx, design, false); + } +} LoggerPass; + +PRIVATE_NAMESPACE_END