From 0ba2a2b1fa898e48feffa23b8958255d9ed0834c Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Thu, 13 Feb 2020 13:35:29 +0100 Subject: [PATCH 01/15] Add new logger pass --- passes/cmds/Makefile.inc | 1 + passes/cmds/logger.cc | 141 +++++++++++++++++++++++++++++++++++++++ 2 files changed, 142 insertions(+) create mode 100644 passes/cmds/logger.cc 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..3feef7dc5 --- /dev/null +++ b/passes/cmds/logger.cc @@ -0,0 +1,141 @@ +/* + * 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"); + } + + 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."); + continue; + } + if (args[argidx] == "-notime") { + log_time = false; + log("Disabled timestamp in logs."); + continue; + } + if (args[argidx] == "-stderr") { + log_error_stderr = true; + log("Enabled loggint errors to stderr."); + continue; + } + if (args[argidx] == "-nostderr") { + log_error_stderr = false; + log("Disabled loggint errors to stderr."); + 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); + log("Added regex '%s' for warnings to warn list.", pattern.c_str()); + log_warn_regexes.push_back(std::regex(pattern, + std::regex_constants::nosubs | + std::regex_constants::optimize | + std::regex_constants::egrep)); + 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); + log("Added regex '%s' for warnings to nowarn list.", pattern.c_str()); + log_nowarn_regexes.push_back(std::regex(pattern, + std::regex_constants::nosubs | + std::regex_constants::optimize | + std::regex_constants::egrep)); + 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); + log("Added regex '%s' for warnings to werror list.", pattern.c_str()); + log_werror_regexes.push_back(std::regex(pattern, + std::regex_constants::nosubs | + std::regex_constants::optimize | + std::regex_constants::egrep)); + continue; + } + if (args[argidx] == "-debug") { + log_force_debug = 1; + log("Enabled debug log messages."); + continue; + } + if (args[argidx] == "-nodebug") { + log_force_debug = 0; + log("Disabled debug log messages."); + continue; + } + break; + if (args[argidx] == "-experimental" && argidx+1 < args.size()) { + std::string value = args[++argidx]; + log("Added '%s' experimental ignore list.", value.c_str()); + log_experimentals_ignored.insert(value); + continue; + } + break; + } + extra_args(args, argidx, design, false); + } +} LoggerPass; + +PRIVATE_NAMESPACE_END From 31b7a9c3127560ea0c488b88e93077e08600652f Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Fri, 14 Feb 2020 12:21:16 +0100 Subject: [PATCH 02/15] Add expect option to logger command --- kernel/driver.cc | 4 ++- kernel/log.cc | 59 ++++++++++++++++++++++++++++++++++++++++++- kernel/log.h | 17 +++++++++++++ passes/cmds/logger.cc | 36 +++++++++++++++++++++++++- 4 files changed, 113 insertions(+), 3 deletions(-) diff --git a/kernel/driver.cc b/kernel/driver.cc index 9040408bc..1802e8aac 100644 --- a/kernel/driver.cc +++ b/kernel/driver.cc @@ -664,13 +664,15 @@ int main(int argc, char **argv) } #endif + log_check_expected(); + yosys_atexit(); memhasher_off(); if (call_abort) abort(); - log_flush(); + log_flush(); #if defined(_MSC_VER) _exit(0); #elif defined(_WIN32) diff --git a/kernel/log.cc b/kernel/log.cc index f5d6c488e..997c39c64 100644 --- a/kernel/log.cc +++ b/kernel/log.cc @@ -42,6 +42,7 @@ 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; bool log_hdump_all = false; @@ -68,6 +69,7 @@ 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 void log_id_cache_clear() { @@ -162,7 +164,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 +176,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 +251,10 @@ static void logv_warning_with_prefix(const char *prefix, if (std::regex_search(message, re)) log_error("%s", message.c_str()); + for (auto &item : log_expect_warning) + if (std::regex_search(message, item.first)) + item.second.current_count++; + if (log_warnings.count(message)) { log("%s%s", prefix, message.c_str()); @@ -328,6 +339,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 +653,46 @@ 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 != item.second.expected_count) { + log_error("Expected warning pattern '%s' not found !\n", item.second.pattern.c_str()); + } + if (item.second.current_count != item.second.expected_count) { + 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_error("Expected log pattern '%s' not found !\n", item.second.pattern.c_str()); + } + if (item.second.current_count != item.second.expected_count) { + 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("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 { + 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..0f912fccb 100644 --- a/kernel/log.h +++ b/kernel/log.h @@ -135,6 +135,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/logger.cc b/passes/cmds/logger.cc index 3feef7dc5..30768980e 100644 --- a/passes/cmds/logger.cc +++ b/passes/cmds/logger.cc @@ -57,6 +57,9 @@ struct LoggerPass : public Pass { 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"); } void execute(std::vector args, RTLIL::Design * design) YS_OVERRIDE @@ -125,13 +128,44 @@ struct LoggerPass : public Pass { log("Disabled debug log messages."); continue; } - break; if (args[argidx] == "-experimental" && argidx+1 < args.size()) { std::string value = args[++argidx]; log("Added '%s' experimental ignore list.", 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()); + 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))); + + continue; + } break; } extra_args(args, argidx, design, false); From 6b396e64556ad556eb3260db714c1f824ee4f458 Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Fri, 14 Feb 2020 13:12:05 +0100 Subject: [PATCH 03/15] remove whitespace --- kernel/driver.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/kernel/driver.cc b/kernel/driver.cc index 1802e8aac..2917586ea 100644 --- a/kernel/driver.cc +++ b/kernel/driver.cc @@ -672,7 +672,7 @@ int main(int argc, char **argv) if (call_abort) abort(); - log_flush(); + log_flush(); #if defined(_MSC_VER) _exit(0); #elif defined(_WIN32) From be977cf7eb76e10866555543aef4809264b393de Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Mon, 17 Feb 2020 12:54:36 +0100 Subject: [PATCH 04/15] No new error if already failing --- kernel/log.cc | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/kernel/log.cc b/kernel/log.cc index 997c39c64..89a403e63 100644 --- a/kernel/log.cc +++ b/kernel/log.cc @@ -331,7 +331,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 (check_expected_logs) + log("%s%s", prefix, log_last_error.c_str()); log_flush(); log_make_debug = bak_log_make_debug; From d8735b291365a2a6e8fb8c768f61ad41f0763f96 Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Mon, 17 Feb 2020 15:08:35 +0100 Subject: [PATCH 05/15] Add to changelog --- CHANGELOG | 1 + 1 file changed, 1 insertion(+) 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 ---------------------- From 5641b0248fe0781ee62fa3bc903f8db95e80b0c4 Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Mon, 17 Feb 2020 15:36:06 +0100 Subject: [PATCH 06/15] Option to expect no warnings --- kernel/driver.cc | 3 +++ kernel/log.cc | 1 + kernel/log.h | 1 + passes/cmds/logger.cc | 7 +++++++ 4 files changed, 12 insertions(+) diff --git a/kernel/driver.cc b/kernel/driver.cc index 2917586ea..74f53901e 100644 --- a/kernel/driver.cc +++ b/kernel/driver.cc @@ -558,6 +558,9 @@ int main(int argc, char **argv) fprintf(f, "\n"); } + if (log_expect_no_warnings && log_warnings_count) + log_error("Warnings: %d unique messages, %d total\n", GetSize(log_warnings), log_warnings_count); + if (print_stats) { std::string hash = log_hasher->final().substr(0, 10); diff --git a/kernel/log.cc b/kernel/log.cc index 89a403e63..1575b4fed 100644 --- a/kernel/log.cc +++ b/kernel/log.cc @@ -45,6 +45,7 @@ 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; +bool log_expect_no_warnings = false; bool log_hdump_all = false; FILE *log_errfile = NULL; SHA1 *log_hasher = NULL; diff --git a/kernel/log.h b/kernel/log.h index 0f912fccb..79de1a20a 100644 --- a/kernel/log.h +++ b/kernel/log.h @@ -52,6 +52,7 @@ 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 bool log_expect_no_warnings; extern bool log_hdump_all; extern FILE *log_errfile; extern SHA1 *log_hasher; diff --git a/passes/cmds/logger.cc b/passes/cmds/logger.cc index 30768980e..947b178c5 100644 --- a/passes/cmds/logger.cc +++ b/passes/cmds/logger.cc @@ -60,6 +60,9 @@ struct LoggerPass : public Pass { 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.\n"); + log("\n"); } void execute(std::vector args, RTLIL::Design * design) YS_OVERRIDE @@ -166,6 +169,10 @@ struct LoggerPass : public Pass { continue; } + if (args[argidx] == "-expect-no-warnings") { + log_expect_no_warnings = true; + continue; + } break; } extra_args(args, argidx, design, false); From 70db8e92003fab959ec5d14b51ac2a9209d16b30 Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Mon, 17 Feb 2020 16:46:34 +0100 Subject: [PATCH 07/15] Prevent double error message --- kernel/log.cc | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/kernel/log.cc b/kernel/log.cc index 1575b4fed..9e103855f 100644 --- a/kernel/log.cc +++ b/kernel/log.cc @@ -71,6 +71,7 @@ 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() { @@ -332,7 +333,7 @@ static void logv_error_with_prefix(const char *prefix, f = stderr; log_last_error = vstringf(format, ap); - if (check_expected_logs) + if (display_error_log_msg) log("%s%s", prefix, log_last_error.c_str()); log_flush(); @@ -691,6 +692,7 @@ void log_check_expected() _Exit(0); #endif } else { + display_error_log_msg = false; log_error("Expected error pattern '%s' not found !\n", item.second.pattern.c_str()); } } From 419e67c1706367a3a10feb70a1d7a2f9cafb591b Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Thu, 20 Feb 2020 11:41:37 +0100 Subject: [PATCH 08/15] check for regex errors --- passes/cmds/logger.cc | 36 ++++++++++++++++++++---------------- 1 file changed, 20 insertions(+), 16 deletions(-) diff --git a/passes/cmds/logger.cc b/passes/cmds/logger.cc index 947b178c5..3abe4e93b 100644 --- a/passes/cmds/logger.cc +++ b/passes/cmds/logger.cc @@ -151,22 +151,26 @@ struct LoggerPass : public Pass { 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()); - 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))); - + 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") { From 596bb2d443a589df4deede4cc86783249e3bb09c Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Sat, 22 Feb 2020 10:31:56 +0100 Subject: [PATCH 09/15] Check other regex parameters --- passes/cmds/logger.cc | 45 ++++++++++++++++++++++++++++--------------- 1 file changed, 30 insertions(+), 15 deletions(-) diff --git a/passes/cmds/logger.cc b/passes/cmds/logger.cc index 3abe4e93b..018a3e6cf 100644 --- a/passes/cmds/logger.cc +++ b/passes/cmds/logger.cc @@ -94,31 +94,46 @@ struct LoggerPass : public Pass { 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); - log("Added regex '%s' for warnings to warn list.", pattern.c_str()); - log_warn_regexes.push_back(std::regex(pattern, - std::regex_constants::nosubs | - std::regex_constants::optimize | - std::regex_constants::egrep)); + try { + log("Added regex '%s' for warnings to warn list.", 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); - log("Added regex '%s' for warnings to nowarn list.", pattern.c_str()); - log_nowarn_regexes.push_back(std::regex(pattern, - std::regex_constants::nosubs | - std::regex_constants::optimize | - std::regex_constants::egrep)); + try { + log("Added regex '%s' for warnings to nowarn list.", 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); - log("Added regex '%s' for warnings to werror list.", pattern.c_str()); - log_werror_regexes.push_back(std::regex(pattern, - std::regex_constants::nosubs | - std::regex_constants::optimize | - std::regex_constants::egrep)); + try { + log("Added regex '%s' for warnings to werror list.", 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") { From d079ab9d19b7d18134f5b6f30da9a6666f30ad97 Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Sat, 22 Feb 2020 10:52:46 +0100 Subject: [PATCH 10/15] Handle expect no warnings together with expected --- kernel/driver.cc | 5 +++-- kernel/log.cc | 10 ++++++++-- kernel/log.h | 1 + 3 files changed, 12 insertions(+), 4 deletions(-) diff --git a/kernel/driver.cc b/kernel/driver.cc index 74f53901e..398c89e03 100644 --- a/kernel/driver.cc +++ b/kernel/driver.cc @@ -558,8 +558,9 @@ int main(int argc, char **argv) fprintf(f, "\n"); } - if (log_expect_no_warnings && log_warnings_count) - log_error("Warnings: %d unique messages, %d total\n", GetSize(log_warnings), log_warnings_count); + 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) { diff --git a/kernel/log.cc b/kernel/log.cc index 9e103855f..1785809e4 100644 --- a/kernel/log.cc +++ b/kernel/log.cc @@ -45,6 +45,7 @@ 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; @@ -253,9 +254,12 @@ 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)) + if (std::regex_search(message, item.first)) { item.second.current_count++; + warning_match = true; + } if (log_warnings.count(message)) { @@ -276,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; } @@ -661,7 +667,7 @@ void log_check_expected() check_expected_logs = false; for (auto &item : log_expect_warning) { - if (item.second.current_count != item.second.expected_count) { + if (item.second.current_count == 0) { log_error("Expected warning pattern '%s' not found !\n", item.second.pattern.c_str()); } if (item.second.current_count != item.second.expected_count) { diff --git a/kernel/log.h b/kernel/log.h index 79de1a20a..603938f4c 100644 --- a/kernel/log.h +++ b/kernel/log.h @@ -52,6 +52,7 @@ 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; From 010d6514501f9f2df1c34ca3fe615a941d6a9cad Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Sat, 22 Feb 2020 10:53:23 +0100 Subject: [PATCH 11/15] Update explanation for expect-no-warnings --- passes/cmds/logger.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/passes/cmds/logger.cc b/passes/cmds/logger.cc index 018a3e6cf..ac1cd306c 100644 --- a/passes/cmds/logger.cc +++ b/passes/cmds/logger.cc @@ -61,7 +61,7 @@ struct LoggerPass : public Pass { 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.\n"); + log(" gives error in case there is at least one warning that is not expected.\n"); log("\n"); } From 48eed2860c83593f7a074ae27fbd98588a3a062b Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Sun, 23 Feb 2020 10:05:21 +0100 Subject: [PATCH 12/15] Fix line endings --- passes/cmds/logger.cc | 20 ++++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-) diff --git a/passes/cmds/logger.cc b/passes/cmds/logger.cc index ac1cd306c..bd1038a7e 100644 --- a/passes/cmds/logger.cc +++ b/passes/cmds/logger.cc @@ -73,29 +73,29 @@ struct LoggerPass : public Pass { if (args[argidx] == "-time") { log_time = true; - log("Enabled timestamp in logs."); + log("Enabled timestamp in logs.\n"); continue; } if (args[argidx] == "-notime") { log_time = false; - log("Disabled timestamp in logs."); + log("Disabled timestamp in logs.\n"); continue; } if (args[argidx] == "-stderr") { log_error_stderr = true; - log("Enabled loggint errors to stderr."); + log("Enabled loggint errors to stderr.\n"); continue; } if (args[argidx] == "-nostderr") { log_error_stderr = false; - log("Disabled loggint errors to stderr."); + 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.", pattern.c_str()); + 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 | @@ -110,7 +110,7 @@ struct LoggerPass : public Pass { 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.", pattern.c_str()); + 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 | @@ -125,7 +125,7 @@ struct LoggerPass : public Pass { 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.", pattern.c_str()); + 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 | @@ -138,17 +138,17 @@ struct LoggerPass : public Pass { } if (args[argidx] == "-debug") { log_force_debug = 1; - log("Enabled debug log messages."); + log("Enabled debug log messages.\n"); continue; } if (args[argidx] == "-nodebug") { log_force_debug = 0; - log("Disabled debug log messages."); + 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.", value.c_str()); + log("Added '%s' experimental ignore list.\n", value.c_str()); log_experimentals_ignored.insert(value); continue; } From 1c569fe06aba3850e557eb44895a522cc4167de2 Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Sun, 23 Feb 2020 10:56:27 +0100 Subject: [PATCH 13/15] Remove duplicate warning detection --- kernel/log.cc | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/kernel/log.cc b/kernel/log.cc index 1785809e4..72181ebe8 100644 --- a/kernel/log.cc +++ b/kernel/log.cc @@ -668,9 +668,11 @@ void log_check_expected() 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); } @@ -678,9 +680,11 @@ void log_check_expected() 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); } @@ -688,6 +692,7 @@ void log_check_expected() 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; @@ -699,6 +704,7 @@ void log_check_expected() #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()); } } From c1cee15d64ec2da29672d0f94610830d12793191 Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Sun, 23 Feb 2020 10:56:39 +0100 Subject: [PATCH 14/15] Add tests for logger pass --- tests/various/logger_error.ys | 6 ++++++ tests/various/logger_nowarning.ys | 6 ++++++ tests/various/logger_warn.ys | 6 ++++++ tests/various/logger_warning.ys | 6 ++++++ 4 files changed, 24 insertions(+) create mode 100644 tests/various/logger_error.ys create mode 100644 tests/various/logger_nowarning.ys create mode 100644 tests/various/logger_warn.ys create mode 100644 tests/various/logger_warning.ys diff --git a/tests/various/logger_error.ys b/tests/various/logger_error.ys new file mode 100644 index 000000000..46fe7f506 --- /dev/null +++ b/tests/various/logger_error.ys @@ -0,0 +1,6 @@ +logger -werror "is implicitly declared." -expect error "is implicitly declared." 1 +read_verilog << EOF +module top(...); + assign b = w; +endmodule +EOF diff --git a/tests/various/logger_nowarning.ys b/tests/various/logger_nowarning.ys new file mode 100644 index 000000000..87cbbc644 --- /dev/null +++ b/tests/various/logger_nowarning.ys @@ -0,0 +1,6 @@ +logger -expect-no-warnings -nowarn "is implicitly declared." +read_verilog << EOF +module top(...); + assign b = w; +endmodule +EOF diff --git a/tests/various/logger_warn.ys b/tests/various/logger_warn.ys new file mode 100644 index 000000000..2316ae4c6 --- /dev/null +++ b/tests/various/logger_warn.ys @@ -0,0 +1,6 @@ +logger -warn "Successfully finished Verilog frontend." -expect warning "Successfully finished Verilog frontend." 1 +read_verilog << EOF +module top(...); + assign b = w; +endmodule +EOF diff --git a/tests/various/logger_warning.ys b/tests/various/logger_warning.ys new file mode 100644 index 000000000..642b1b97b --- /dev/null +++ b/tests/various/logger_warning.ys @@ -0,0 +1,6 @@ +logger -expect warning "is implicitly declared." 2 +read_verilog << EOF +module top(...); + assign b = w; +endmodule +EOF From 80656ad17836a222f2359576d72f0b451c4ddfe6 Mon Sep 17 00:00:00 2001 From: Miodrag Milanovic Date: Wed, 26 Feb 2020 09:49:41 +0100 Subject: [PATCH 15/15] Remove tests for now --- tests/various/logger_error.ys | 6 ------ tests/various/logger_nowarning.ys | 6 ------ tests/various/logger_warn.ys | 6 ------ tests/various/logger_warning.ys | 6 ------ 4 files changed, 24 deletions(-) delete mode 100644 tests/various/logger_error.ys delete mode 100644 tests/various/logger_nowarning.ys delete mode 100644 tests/various/logger_warn.ys delete mode 100644 tests/various/logger_warning.ys diff --git a/tests/various/logger_error.ys b/tests/various/logger_error.ys deleted file mode 100644 index 46fe7f506..000000000 --- a/tests/various/logger_error.ys +++ /dev/null @@ -1,6 +0,0 @@ -logger -werror "is implicitly declared." -expect error "is implicitly declared." 1 -read_verilog << EOF -module top(...); - assign b = w; -endmodule -EOF diff --git a/tests/various/logger_nowarning.ys b/tests/various/logger_nowarning.ys deleted file mode 100644 index 87cbbc644..000000000 --- a/tests/various/logger_nowarning.ys +++ /dev/null @@ -1,6 +0,0 @@ -logger -expect-no-warnings -nowarn "is implicitly declared." -read_verilog << EOF -module top(...); - assign b = w; -endmodule -EOF diff --git a/tests/various/logger_warn.ys b/tests/various/logger_warn.ys deleted file mode 100644 index 2316ae4c6..000000000 --- a/tests/various/logger_warn.ys +++ /dev/null @@ -1,6 +0,0 @@ -logger -warn "Successfully finished Verilog frontend." -expect warning "Successfully finished Verilog frontend." 1 -read_verilog << EOF -module top(...); - assign b = w; -endmodule -EOF diff --git a/tests/various/logger_warning.ys b/tests/various/logger_warning.ys deleted file mode 100644 index 642b1b97b..000000000 --- a/tests/various/logger_warning.ys +++ /dev/null @@ -1,6 +0,0 @@ -logger -expect warning "is implicitly declared." 2 -read_verilog << EOF -module top(...); - assign b = w; -endmodule -EOF