From e158ea20979165c1bac4c5c4027cf53255e57baa Mon Sep 17 00:00:00 2001 From: Clifford Wolf Date: Mon, 22 Apr 2019 17:25:52 +0200 Subject: [PATCH] Add log_debug() framework Signed-off-by: Clifford Wolf --- frontends/aiger/aigerparse.cc | 2 - kernel/driver.cc | 8 +++- kernel/log.cc | 7 ++++ kernel/log.h | 43 +++++++++++++++++++ kernel/register.cc | 1 + passes/cmds/trace.cc | 34 +++++++++++++++ passes/opt/opt_clean.cc | 11 ++--- passes/opt/opt_expr.cc | 79 ++++++++++++++++++++--------------- passes/opt/opt_merge.cc | 8 ++-- passes/opt/opt_muxtree.cc | 6 +-- passes/techmap/techmap.cc | 37 +++++++++++++--- 11 files changed, 183 insertions(+), 53 deletions(-) diff --git a/frontends/aiger/aigerparse.cc b/frontends/aiger/aigerparse.cc index cf7950c85..2e4774dfd 100644 --- a/frontends/aiger/aigerparse.cc +++ b/frontends/aiger/aigerparse.cc @@ -33,8 +33,6 @@ YOSYS_NAMESPACE_BEGIN -#define log_debug log - AigerReader::AigerReader(RTLIL::Design *design, std::istream &f, RTLIL::IdString module_name, RTLIL::IdString clk_name) : design(design), f(f), clk_name(clk_name) { diff --git a/kernel/driver.cc b/kernel/driver.cc index c539ba569..1bc7a5935 100644 --- a/kernel/driver.cc +++ b/kernel/driver.cc @@ -295,6 +295,9 @@ int main(int argc, char **argv) printf(" -E \n"); printf(" write a Makefile dependencies file with in- and output file names\n"); printf("\n"); + printf(" -g\n"); + printf(" globally enable debug log messages\n"); + printf("\n"); printf(" -V\n"); printf(" print version information and exit\n"); printf("\n"); @@ -315,7 +318,7 @@ int main(int argc, char **argv) } int opt; - while ((opt = getopt(argc, argv, "MXAQTVSm:f:Hh:b:o:p:l:L:qv:tds:c:W:w:e:D:P:E:")) != -1) + while ((opt = getopt(argc, argv, "MXAQTVSgm:f:Hh:b:o:p:l:L:qv:tds:c:W:w:e:D:P:E:")) != -1) { switch (opt) { @@ -340,6 +343,9 @@ int main(int argc, char **argv) case 'S': passes_commands.push_back("synth"); break; + case 'g': + log_force_debug++; + break; case 'm': plugin_filenames.push_back(optarg); break; diff --git a/kernel/log.cc b/kernel/log.cc index 400a549dd..9a9104e26 100644 --- a/kernel/log.cc +++ b/kernel/log.cc @@ -56,6 +56,10 @@ int log_verbose_level; string log_last_error; void (*log_error_atexit)() = NULL; +int log_make_debug = 0; +int log_force_debug = 0; +int log_debug_suppressed = 0; + vector header_count; pool log_id_cache; vector string_buf; @@ -92,6 +96,9 @@ void logv(const char *format, va_list ap) format++; } + if (log_make_debug && !ys_debug(1)) + return; + std::string str = vstringf(format, ap); if (str.empty()) diff --git a/kernel/log.h b/kernel/log.h index 759939025..e6afae716 100644 --- a/kernel/log.h +++ b/kernel/log.h @@ -64,6 +64,10 @@ extern int log_verbose_level; extern string log_last_error; extern void (*log_error_atexit)(); +extern int log_make_debug; +extern int log_force_debug; +extern int log_debug_suppressed; + void logv(const char *format, va_list ap); void logv_header(RTLIL::Design *design, const char *format, va_list ap); void logv_warning(const char *format, va_list ap); @@ -82,6 +86,45 @@ YS_NORETURN void log_error(const char *format, ...) YS_ATTRIBUTE(format(printf, void log_file_error(const string &filename, int lineno, const char *format, ...) YS_ATTRIBUTE(format(printf, 3, 4), noreturn); YS_NORETURN void log_cmd_error(const char *format, ...) YS_ATTRIBUTE(format(printf, 1, 2), noreturn); +#ifndef NDEBUG +static inline bool ys_debug(int n = 0) { if (log_force_debug) return true; log_debug_suppressed += n; return false; } +# define log_debug(...) do { if (ys_debug(1)) log(__VA_ARGS__); } while (0) +#else +static inline bool ys_debug(int n = 0) { return false; } +# define log_debug(_fmt, ...) do { } while (0) +#endif + +static inline void log_suppressed() { + if (log_debug_suppressed && !log_make_debug) { + log("\n", log_debug_suppressed); + log_debug_suppressed = 0; + } +} + +struct LogMakeDebugHdl { + bool status = false; + LogMakeDebugHdl(bool start_on = false) { + if (start_on) + on(); + } + ~LogMakeDebugHdl() { + off(); + } + void on() { + if (status) return; + status=true; + log_make_debug++; + } + void off_silent() { + if (!status) return; + status=false; + log_make_debug--; + } + void off() { + off_silent(); + } +}; + void log_spacer(); void log_push(); void log_pop(); diff --git a/kernel/register.cc b/kernel/register.cc index 64956401f..71eb6b187 100644 --- a/kernel/register.cc +++ b/kernel/register.cc @@ -87,6 +87,7 @@ Pass::pre_post_exec_state_t Pass::pre_execute() void Pass::post_execute(Pass::pre_post_exec_state_t state) { IdString::checkpoint(); + log_suppressed(); int64_t time_ns = PerformanceTimer::query() - state.begin_ns; runtime_ns += time_ns; diff --git a/passes/cmds/trace.cc b/passes/cmds/trace.cc index f5305cde9..cf3e46ace 100644 --- a/passes/cmds/trace.cc +++ b/passes/cmds/trace.cc @@ -94,4 +94,38 @@ struct TracePass : public Pass { } } TracePass; +struct DebugPass : public Pass { + DebugPass() : Pass("debug", "run command with debug log messages enabled") { } + void help() YS_OVERRIDE + { + // |---v---|---v---|---v---|---v---|---v---|---v---|---v---|---v---|---v---|---v---| + log("\n"); + log(" debug cmd\n"); + log("\n"); + log("Execute the specified command with debug log messages enabled\n"); + log("\n"); + } + void execute(std::vector args, RTLIL::Design *design) YS_OVERRIDE + { + size_t argidx; + for (argidx = 1; argidx < args.size(); argidx++) + { + // .. parse options .. + break; + } + + log_force_debug++; + + try { + std::vector new_args(args.begin() + argidx, args.end()); + Pass::call(design, new_args); + } catch (...) { + log_force_debug--; + throw; + } + + log_force_debug--; + } +} DebugPass; + PRIVATE_NAMESPACE_END diff --git a/passes/opt/opt_clean.cc b/passes/opt/opt_clean.cc index c3b13acaf..c38e9df5e 100644 --- a/passes/opt/opt_clean.cc +++ b/passes/opt/opt_clean.cc @@ -137,7 +137,7 @@ void rmunused_module_cells(Module *module, bool verbose) for (auto cell : unused) { if (verbose) - log(" removing unused `%s' cell `%s'.\n", cell->type.c_str(), cell->name.c_str()); + log_debug(" removing unused `%s' cell `%s'.\n", cell->type.c_str(), cell->name.c_str()); module->design->scratchpad_set_bool("opt.did_something", true); module->remove(cell); count_rm_cells++; @@ -326,7 +326,7 @@ void rmunused_module_signals(RTLIL::Module *module, bool purge_mode, bool verbos for (auto wire : maybe_del_wires) if (!used_signals.check_any(RTLIL::SigSpec(wire))) { if (check_public_name(wire->name) && verbose) { - log(" removing unused non-port wire %s.\n", wire->name.c_str()); + log_debug(" removing unused non-port wire %s.\n", wire->name.c_str()); } del_wires.insert(wire); del_wires_count++; @@ -336,7 +336,7 @@ void rmunused_module_signals(RTLIL::Module *module, bool purge_mode, bool verbos count_rm_wires += del_wires.size(); if (verbose && del_wires_count > 0) - log(" removed %d unused temporary wires.\n", del_wires_count); + log_debug(" removed %d unused temporary wires.\n", del_wires_count); } bool rmunused_module_init(RTLIL::Module *module, bool purge_mode, bool verbose) @@ -399,7 +399,7 @@ bool rmunused_module_init(RTLIL::Module *module, bool purge_mode, bool verbose) } if (verbose) - log(" removing redundant init attribute on %s.\n", log_id(wire)); + log_debug(" removing redundant init attribute on %s.\n", log_id(wire)); wire->attributes.erase("\\init"); did_something = true; @@ -426,7 +426,7 @@ void rmunused_module(RTLIL::Module *module, bool purge_mode, bool verbose, bool } for (auto cell : delcells) { if (verbose) - log(" removing buffer cell `%s': %s = %s\n", cell->name.c_str(), + log_debug(" removing buffer cell `%s': %s = %s\n", cell->name.c_str(), log_signal(cell->getPort("\\Y")), log_signal(cell->getPort("\\A"))); module->remove(cell); } @@ -551,6 +551,7 @@ struct CleanPass : public Pass { rmunused_module(module, purge_mode, false, false); } + log_suppressed(); if (count_rm_cells > 0 || count_rm_wires > 0) log("Removed %d unused cells and %d unused wires.\n", count_rm_cells, count_rm_wires); diff --git a/passes/opt/opt_expr.cc b/passes/opt/opt_expr.cc index a05db2a4f..af6d352af 100644 --- a/passes/opt/opt_expr.cc +++ b/passes/opt/opt_expr.cc @@ -67,7 +67,7 @@ void replace_undriven(RTLIL::Design *design, RTLIL::Module *module) if (sig.size() == 0) continue; - log("Setting undriven signal in %s to undef: %s\n", RTLIL::id2cstr(module->name), log_signal(c)); + log_debug("Setting undriven signal in %s to undef: %s\n", RTLIL::id2cstr(module->name), log_signal(c)); module->connect(RTLIL::SigSig(c, RTLIL::SigSpec(RTLIL::State::Sx, c.width))); did_something = true; } @@ -78,7 +78,7 @@ void replace_cell(SigMap &assign_map, RTLIL::Module *module, RTLIL::Cell *cell, RTLIL::SigSpec Y = cell->getPort(out_port); out_val.extend_u0(Y.size(), false); - log("Replacing %s cell `%s' (%s) in module `%s' with constant driver `%s = %s'.\n", + log_debug("Replacing %s cell `%s' (%s) in module `%s' with constant driver `%s = %s'.\n", cell->type.c_str(), cell->name.c_str(), info.c_str(), module->name.c_str(), log_signal(Y), log_signal(out_val)); // log_cell(cell); @@ -134,7 +134,7 @@ bool group_cell_inputs(RTLIL::Module *module, RTLIL::Cell *cell, bool commutativ if (GetSize(grouped_bits[i]) == GetSize(bits_y)) return false; - log("Replacing %s cell `%s' in module `%s' with cells using grouped bits:\n", + log_debug("Replacing %s cell `%s' in module `%s' with cells using grouped bits:\n", log_id(cell->type), log_id(cell), log_id(module)); for (int i = 0; i < GRP_N; i++) @@ -156,7 +156,7 @@ bool group_cell_inputs(RTLIL::Module *module, RTLIL::Cell *cell, bool commutativ } if (cell->type.in("$and", "$or") && i == GRP_CONST_A) { - log(" Direct Connection: %s (%s with %s)\n", log_signal(new_b), log_id(cell->type), log_signal(new_a)); + log_debug(" Direct Connection: %s (%s with %s)\n", log_signal(new_b), log_id(cell->type), log_signal(new_a)); module->connect(new_y, new_b); module->connect(new_conn); continue; @@ -180,10 +180,10 @@ bool group_cell_inputs(RTLIL::Module *module, RTLIL::Cell *cell, bool commutativ module->connect(new_conn); - log(" New cell `%s': A=%s", log_id(c), log_signal(new_a)); + log_debug(" New cell `%s': A=%s", log_id(c), log_signal(new_a)); if (b_name == "\\B") - log(", B=%s", log_signal(new_b)); - log("\n"); + log_debug(", B=%s", log_signal(new_b)); + log_debug("\n"); } cover_list("opt.opt_expr.fine.group", "$not", "$pos", "$and", "$or", "$xor", "$xnor", cell->type.str()); @@ -197,7 +197,7 @@ void handle_polarity_inv(Cell *cell, IdString port, IdString param, const SigMap { SigSpec sig = assign_map(cell->getPort(port)); if (invert_map.count(sig)) { - log("Inverting %s of %s cell `%s' in module `%s': %s -> %s\n", + log_debug("Inverting %s of %s cell `%s' in module `%s': %s -> %s\n", log_id(port), log_id(cell->type), log_id(cell), log_id(cell->module), log_signal(sig), log_signal(invert_map.at(sig))); cell->setPort(port, (invert_map.at(sig))); @@ -226,7 +226,7 @@ void handle_clkpol_celltype_swap(Cell *cell, string type1, string type2, IdStrin if (cell->type.in(type1, type2)) { SigSpec sig = assign_map(cell->getPort(port)); if (invert_map.count(sig)) { - log("Inverting %s of %s cell `%s' in module `%s': %s -> %s\n", + log_debug("Inverting %s of %s cell `%s' in module `%s': %s -> %s\n", log_id(port), log_id(cell->type), log_id(cell), log_id(cell->module), log_signal(sig), log_signal(invert_map.at(sig))); cell->setPort(port, (invert_map.at(sig))); @@ -455,9 +455,10 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons { if (cell->type == "$reduce_xnor") { cover("opt.opt_expr.reduce_xnor_not"); - log("Replacing %s cell `%s' in module `%s' with $not cell.\n", + log_debug("Replacing %s cell `%s' in module `%s' with $not cell.\n", log_id(cell->type), log_id(cell->name), log_id(module)); cell->type = "$not"; + did_something = true; } else { cover("opt.opt_expr.unary_buffer"); replace_cell(assign_map, module, cell, "unary_buffer", "\\Y", cell->getPort("\\A")); @@ -488,7 +489,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if (GetSize(new_sig_a) < GetSize(sig_a)) { cover_list("opt.opt_expr.fine.neutral_A", "$logic_not", "$logic_and", "$logic_or", "$reduce_or", "$reduce_and", "$reduce_bool", cell->type.str()); - log("Replacing port A of %s cell `%s' in module `%s' with shorter expression: %s -> %s\n", + log_debug("Replacing port A of %s cell `%s' in module `%s' with shorter expression: %s -> %s\n", cell->type.c_str(), cell->name.c_str(), module->name.c_str(), log_signal(sig_a), log_signal(new_sig_a)); cell->setPort("\\A", new_sig_a); cell->parameters.at("\\A_WIDTH") = GetSize(new_sig_a); @@ -511,7 +512,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if (GetSize(new_sig_b) < GetSize(sig_b)) { cover_list("opt.opt_expr.fine.neutral_B", "$logic_and", "$logic_or", cell->type.str()); - log("Replacing port B of %s cell `%s' in module `%s' with shorter expression: %s -> %s\n", + log_debug("Replacing port B of %s cell `%s' in module `%s' with shorter expression: %s -> %s\n", cell->type.c_str(), cell->name.c_str(), module->name.c_str(), log_signal(sig_b), log_signal(new_sig_b)); cell->setPort("\\B", new_sig_b); cell->parameters.at("\\B_WIDTH") = GetSize(new_sig_b); @@ -537,7 +538,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if (new_a != RTLIL::State::Sm && RTLIL::SigSpec(new_a) != sig_a) { cover("opt.opt_expr.fine.$reduce_and"); - log("Replacing port A of %s cell `%s' in module `%s' with constant driver: %s -> %s\n", + log_debug("Replacing port A of %s cell `%s' in module `%s' with constant driver: %s -> %s\n", cell->type.c_str(), cell->name.c_str(), module->name.c_str(), log_signal(sig_a), log_signal(new_a)); cell->setPort("\\A", sig_a = new_a); cell->parameters.at("\\A_WIDTH") = 1; @@ -563,7 +564,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if (new_a != RTLIL::State::Sm && RTLIL::SigSpec(new_a) != sig_a) { cover_list("opt.opt_expr.fine.A", "$logic_not", "$logic_and", "$logic_or", "$reduce_or", "$reduce_bool", cell->type.str()); - log("Replacing port A of %s cell `%s' in module `%s' with constant driver: %s -> %s\n", + log_debug("Replacing port A of %s cell `%s' in module `%s' with constant driver: %s -> %s\n", cell->type.c_str(), cell->name.c_str(), module->name.c_str(), log_signal(sig_a), log_signal(new_a)); cell->setPort("\\A", sig_a = new_a); cell->parameters.at("\\A_WIDTH") = 1; @@ -589,7 +590,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if (new_b != RTLIL::State::Sm && RTLIL::SigSpec(new_b) != sig_b) { cover_list("opt.opt_expr.fine.B", "$logic_and", "$logic_or", cell->type.str()); - log("Replacing port B of %s cell `%s' in module `%s' with constant driver: %s -> %s\n", + log_debug("Replacing port B of %s cell `%s' in module `%s' with constant driver: %s -> %s\n", cell->type.c_str(), cell->name.c_str(), module->name.c_str(), log_signal(sig_b), log_signal(new_b)); cell->setPort("\\B", sig_b = new_b); cell->parameters.at("\\B_WIDTH") = 1; @@ -640,7 +641,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if ((cell->type == "$_MUX_" || cell->type == "$mux") && invert_map.count(assign_map(cell->getPort("\\S"))) != 0) { cover_list("opt.opt_expr.invert.muxsel", "$_MUX_", "$mux", cell->type.str()); - log("Optimizing away select inverter for %s cell `%s' in module `%s'.\n", log_id(cell->type), log_id(cell), log_id(module)); + log_debug("Optimizing away select inverter for %s cell `%s' in module `%s'.\n", log_id(cell->type), log_id(cell), log_id(module)); RTLIL::SigSpec tmp = cell->getPort("\\A"); cell->setPort("\\A", cell->getPort("\\B")); cell->setPort("\\B", tmp); @@ -750,7 +751,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons ACTION_DO("\\Y", cell->getPort("\\A")); if (input == State::S0 && !a.is_fully_undef()) { cover("opt.opt_expr.action_" S__LINE__); - log("Replacing data input of %s cell `%s' in module `%s' with constant undef.\n", + log_debug("Replacing data input of %s cell `%s' in module `%s' with constant undef.\n", cell->type.c_str(), cell->name.c_str(), module->name.c_str()); cell->setPort("\\A", SigSpec(State::Sx, GetSize(a))); did_something = true; @@ -822,7 +823,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons ACTION_DO("\\Y", cell->getPort("\\A")); } else { cover_list("opt.opt_expr.eqneq.isnot", "$eq", "$ne", cell->type.str()); - log("Replacing %s cell `%s' in module `%s' with inverter.\n", log_id(cell->type), log_id(cell), log_id(module)); + log_debug("Replacing %s cell `%s' in module `%s' with inverter.\n", log_id(cell->type), log_id(cell), log_id(module)); cell->type = "$not"; cell->parameters.erase("\\B_WIDTH"); cell->parameters.erase("\\B_SIGNED"); @@ -837,7 +838,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons (assign_map(cell->getPort("\\A")).is_fully_zero() || assign_map(cell->getPort("\\B")).is_fully_zero())) { cover_list("opt.opt_expr.eqneq.cmpzero", "$eq", "$ne", cell->type.str()); - log("Replacing %s cell `%s' in module `%s' with %s.\n", log_id(cell->type), log_id(cell), + log_debug("Replacing %s cell `%s' in module `%s' with %s.\n", log_id(cell->type), log_id(cell), log_id(module), "$eq" ? "$logic_not" : "$reduce_bool"); cell->type = cell->type == "$eq" ? "$logic_not" : "$reduce_bool"; if (assign_map(cell->getPort("\\A")).is_fully_zero()) { @@ -876,7 +877,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons cover_list("opt.opt_expr.constshift", "$shl", "$shr", "$sshl", "$sshr", "$shift", "$shiftx", cell->type.str()); - log("Replacing %s cell `%s' (B=%s, SHR=%d) in module `%s' with fixed wiring: %s\n", + log_debug("Replacing %s cell `%s' (B=%s, SHR=%d) in module `%s' with fixed wiring: %s\n", log_id(cell->type), log_id(cell), log_signal(assign_map(cell->getPort("\\B"))), shift_bits, log_id(module), log_signal(sig_y)); module->connect(cell->getPort("\\Y"), sig_y); @@ -939,7 +940,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if (identity_wrt_b) cover_list("opt.opt_expr.identwrt.b", "$add", "$sub", "$or", "$xor", "$shl", "$shr", "$sshl", "$sshr", "$shift", "$shiftx", "$mul", "$div", cell->type.str()); - log("Replacing %s cell `%s' in module `%s' with identity for port %c.\n", + log_debug("Replacing %s cell `%s' in module `%s' with identity for port %c.\n", cell->type.c_str(), cell->name.c_str(), module->name.c_str(), identity_wrt_a ? 'A' : 'B'); if (!identity_wrt_a) { @@ -969,7 +970,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if (mux_bool && (cell->type == "$mux" || cell->type == "$_MUX_") && cell->getPort("\\A") == RTLIL::SigSpec(1, 1) && cell->getPort("\\B") == RTLIL::SigSpec(0, 1)) { cover_list("opt.opt_expr.mux_invert", "$mux", "$_MUX_", cell->type.str()); - log("Replacing %s cell `%s' in module `%s' with inverter.\n", log_id(cell->type), log_id(cell), log_id(module)); + log_debug("Replacing %s cell `%s' in module `%s' with inverter.\n", log_id(cell->type), log_id(cell), log_id(module)); cell->setPort("\\A", cell->getPort("\\S")); cell->unsetPort("\\B"); cell->unsetPort("\\S"); @@ -988,7 +989,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if (consume_x && mux_bool && (cell->type == "$mux" || cell->type == "$_MUX_") && cell->getPort("\\A") == RTLIL::SigSpec(0, 1)) { cover_list("opt.opt_expr.mux_and", "$mux", "$_MUX_", cell->type.str()); - log("Replacing %s cell `%s' in module `%s' with and-gate.\n", log_id(cell->type), log_id(cell), log_id(module)); + log_debug("Replacing %s cell `%s' in module `%s' with and-gate.\n", log_id(cell->type), log_id(cell), log_id(module)); cell->setPort("\\A", cell->getPort("\\S")); cell->unsetPort("\\S"); if (cell->type == "$mux") { @@ -1008,7 +1009,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if (consume_x && mux_bool && (cell->type == "$mux" || cell->type == "$_MUX_") && cell->getPort("\\B") == RTLIL::SigSpec(1, 1)) { cover_list("opt.opt_expr.mux_or", "$mux", "$_MUX_", cell->type.str()); - log("Replacing %s cell `%s' in module `%s' with or-gate.\n", log_id(cell->type), log_id(cell), log_id(module)); + log_debug("Replacing %s cell `%s' in module `%s' with or-gate.\n", log_id(cell->type), log_id(cell), log_id(module)); cell->setPort("\\B", cell->getPort("\\S")); cell->unsetPort("\\S"); if (cell->type == "$mux") { @@ -1061,7 +1062,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons } if (cell->getPort("\\S").size() != new_s.size()) { cover_list("opt.opt_expr.mux_reduce", "$mux", "$pmux", cell->type.str()); - log("Optimized away %d select inputs of %s cell `%s' in module `%s'.\n", + log_debug("Optimized away %d select inputs of %s cell `%s' in module `%s'.\n", GetSize(cell->getPort("\\S")) - GetSize(new_s), log_id(cell->type), log_id(cell), log_id(module)); cell->setPort("\\A", new_a); cell->setPort("\\B", new_b); @@ -1179,7 +1180,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons { cover("opt.opt_expr.mul_shift.zero"); - log("Replacing multiply-by-zero cell `%s' in module `%s' with zero-driver.\n", + log_debug("Replacing multiply-by-zero cell `%s' in module `%s' with zero-driver.\n", cell->name.c_str(), module->name.c_str()); module->connect(RTLIL::SigSig(sig_y, RTLIL::SigSpec(0, sig_y.size()))); @@ -1197,7 +1198,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons else cover("opt.opt_expr.mul_shift.unswapped"); - log("Replacing multiply-by-%d cell `%s' in module `%s' with shift-by-%d.\n", + log_debug("Replacing multiply-by-%d cell `%s' in module `%s' with shift-by-%d.\n", a_val, cell->name.c_str(), module->name.c_str(), i); if (!swapped_ab) { @@ -1237,7 +1238,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons { cover("opt.opt_expr.divmod_zero"); - log("Replacing divide-by-zero cell `%s' in module `%s' with undef-driver.\n", + log_debug("Replacing divide-by-zero cell `%s' in module `%s' with undef-driver.\n", cell->name.c_str(), module->name.c_str()); module->connect(RTLIL::SigSig(sig_y, RTLIL::SigSpec(State::Sx, sig_y.size()))); @@ -1254,7 +1255,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons { cover("opt.opt_expr.div_shift"); - log("Replacing divide-by-%d cell `%s' in module `%s' with shift-by-%d.\n", + log_debug("Replacing divide-by-%d cell `%s' in module `%s' with shift-by-%d.\n", b_val, cell->name.c_str(), module->name.c_str(), i); std::vector new_b = RTLIL::SigSpec(i, 6); @@ -1272,7 +1273,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons { cover("opt.opt_expr.mod_mask"); - log("Replacing modulo-by-%d cell `%s' in module `%s' with bitmask.\n", + log_debug("Replacing modulo-by-%d cell `%s' in module `%s' with bitmask.\n", b_val, cell->name.c_str(), module->name.c_str()); std::vector new_b = RTLIL::SigSpec(State::S1, i); @@ -1342,7 +1343,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons SigSpec y_sig = cell->getPort("\\Y"); Const y_value(cell->type.in("$eq", "$eqx") ? 0 : 1, GetSize(y_sig)); - log("Replacing cell `%s' in module `%s' with constant driver %s.\n", + log_debug("Replacing cell `%s' in module `%s' with constant driver %s.\n", log_id(cell), log_id(module), log_signal(y_value)); module->connect(y_sig, y_value); @@ -1354,7 +1355,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if (redundant_bits) { - log("Removed %d redundant input bits from %s cell `%s' in module `%s'.\n", + log_debug("Removed %d redundant input bits from %s cell `%s' in module `%s'.\n", redundant_bits, log_id(cell->type), log_id(cell), log_id(module)); cell->setPort("\\A", sig_a); @@ -1493,7 +1494,7 @@ void replace_const_cells(RTLIL::Design *design, RTLIL::Module *module, bool cons if (replace || remove) { - log("Replacing %s cell `%s' (implementing %s) with %s.\n", + log_debug("Replacing %s cell `%s' (implementing %s) with %s.\n", log_id(cell->type), log_id(cell), condition.c_str(), replacement.c_str()); if (replace) module->connect(cell->getPort("\\Y"), replace_sig); @@ -1599,8 +1600,14 @@ struct OptExprPass : public Pass { for (auto module : design->selected_modules()) { - if (undriven) + log("Optimizing module %s.\n", log_id(module)); + + if (undriven) { + did_something = false; replace_undriven(design, module); + if (did_something) + design->scratchpad_set_bool("opt.did_something", true); + } do { do { @@ -1610,7 +1617,11 @@ struct OptExprPass : public Pass { design->scratchpad_set_bool("opt.did_something", true); } while (did_something); replace_const_cells(design, module, true, mux_undef, mux_bool, do_fine, keepdc, clkinv); + if (did_something) + design->scratchpad_set_bool("opt.did_something", true); } while (did_something); + + log_suppressed(); } log_pop(); diff --git a/passes/opt/opt_merge.cc b/passes/opt/opt_merge.cc index eedf88904..7567d4657 100644 --- a/passes/opt/opt_merge.cc +++ b/passes/opt/opt_merge.cc @@ -315,17 +315,17 @@ struct OptMergeWorker { if (sharemap.count(cell) > 0) { did_something = true; - log(" Cell `%s' is identical to cell `%s'.\n", cell->name.c_str(), sharemap[cell]->name.c_str()); + log_debug(" Cell `%s' is identical to cell `%s'.\n", cell->name.c_str(), sharemap[cell]->name.c_str()); for (auto &it : cell->connections()) { if (cell->output(it.first)) { RTLIL::SigSpec other_sig = sharemap[cell]->getPort(it.first); - log(" Redirecting output %s: %s = %s\n", it.first.c_str(), + log_debug(" Redirecting output %s: %s = %s\n", it.first.c_str(), log_signal(it.second), log_signal(other_sig)); module->connect(RTLIL::SigSig(it.second, other_sig)); assign_map.add(it.second, other_sig); } } - log(" Removing %s cell `%s' from module `%s'.\n", cell->type.c_str(), cell->name.c_str(), module->name.c_str()); + log_debug(" Removing %s cell `%s' from module `%s'.\n", cell->type.c_str(), cell->name.c_str(), module->name.c_str()); #ifdef USE_CELL_HASH_CACHE cell_hash_cache.erase(cell); #endif @@ -336,6 +336,8 @@ struct OptMergeWorker } } } + + log_suppressed(); } }; diff --git a/passes/opt/opt_muxtree.cc b/passes/opt/opt_muxtree.cc index 375697dc8..dbebf21e0 100644 --- a/passes/opt/opt_muxtree.cc +++ b/passes/opt/opt_muxtree.cc @@ -181,14 +181,14 @@ struct OptMuxtreeWorker for (int mux_idx = 0; mux_idx < GetSize(root_muxes); mux_idx++) if (root_muxes.at(mux_idx)) { - log(" Root of a mux tree: %s%s\n", log_id(mux2info[mux_idx].cell), root_enable_muxes.at(mux_idx) ? " (pure)" : ""); + log_debug(" Root of a mux tree: %s%s\n", log_id(mux2info[mux_idx].cell), root_enable_muxes.at(mux_idx) ? " (pure)" : ""); root_mux_rerun.erase(mux_idx); eval_root_mux(mux_idx); } while (!root_mux_rerun.empty()) { int mux_idx = *root_mux_rerun.begin(); - log(" Root of a mux tree: %s (rerun as non-pure)\n", log_id(mux2info[mux_idx].cell)); + log_debug(" Root of a mux tree: %s (rerun as non-pure)\n", log_id(mux2info[mux_idx].cell)); log_assert(root_enable_muxes.at(mux_idx)); root_mux_rerun.erase(mux_idx); eval_root_mux(mux_idx); @@ -326,7 +326,7 @@ struct OptMuxtreeWorker if (abort_count == 0) { root_mux_rerun.insert(m); root_enable_muxes.at(m) = true; - log(" Removing pure flag from root mux %s.\n", log_id(mux2info[m].cell)); + log_debug(" Removing pure flag from root mux %s.\n", log_id(mux2info[m].cell)); } else eval_mux(knowledge, m, false, do_enable_ports, abort_count - 1); } else diff --git a/passes/techmap/techmap.cc b/passes/techmap/techmap.cc index 1a4318460..ab0bd3b54 100644 --- a/passes/techmap/techmap.cc +++ b/passes/techmap/techmap.cc @@ -72,6 +72,8 @@ struct TechmapWorker pool flatten_done_list; pool flatten_keep_list; + pool log_msg_cache; + struct TechmapWireData { RTLIL::Wire *wire; RTLIL::SigSpec value; @@ -390,6 +392,7 @@ struct TechmapWorker bool log_continue = false; bool did_something = false; + LogMakeDebugHdl mkdebug; SigMap sigmap(module); @@ -547,6 +550,7 @@ struct TechmapWorker if (extmapper_name == "wrap") { std::string cmd_string = tpl->attributes.at("\\techmap_wrap").decode_string(); log("Running \"%s\" on wrapper %s.\n", cmd_string.c_str(), log_id(extmapper_module)); + mkdebug.on(); Pass::call_on_module(extmapper_design, extmapper_module, cmd_string); log_continue = true; } @@ -560,11 +564,21 @@ struct TechmapWorker goto use_wrapper_tpl; } - log("%s %s.%s (%s) to %s.\n", mapmsg_prefix.c_str(), log_id(module), log_id(cell), log_id(cell->type), log_id(extmapper_module)); + auto msg = stringf("Using extmapper %s for cells of type %s.", log_id(extmapper_module), log_id(cell->type)); + if (!log_msg_cache.count(msg)) { + log_msg_cache.insert(msg); + log("%s\n", msg.c_str()); + } + log_debug("%s %s.%s (%s) to %s.\n", mapmsg_prefix.c_str(), log_id(module), log_id(cell), log_id(cell->type), log_id(extmapper_module)); } else { - log("%s %s.%s (%s) with %s.\n", mapmsg_prefix.c_str(), log_id(module), log_id(cell), log_id(cell->type), extmapper_name.c_str()); + auto msg = stringf("Using extmapper %s for cells of type %s.", extmapper_name.c_str(), log_id(cell->type)); + if (!log_msg_cache.count(msg)) { + log_msg_cache.insert(msg); + log("%s\n", msg.c_str()); + } + log_debug("%s %s.%s (%s) with %s.\n", mapmsg_prefix.c_str(), log_id(module), log_id(cell), log_id(cell->type), extmapper_name.c_str()); if (extmapper_name == "simplemap") { if (simplemap_mappers.count(cell->type) == 0) @@ -662,6 +676,7 @@ struct TechmapWorker tpl = techmap_cache[key]; } else { if (parameters.size() != 0) { + mkdebug.on(); derived_name = tpl->derive(map, dict(parameters.begin(), parameters.end())); tpl = map->module(derived_name); log_continue = true; @@ -831,6 +846,7 @@ struct TechmapWorker if (log_continue) { log_header(design, "Continuing TECHMAP pass.\n"); log_continue = false; + mkdebug.off(); } while (techmap_module(map, tpl, map, handled_cells, celltypeMap, true)) { } } @@ -842,6 +858,7 @@ struct TechmapWorker if (log_continue) { log_header(design, "Continuing TECHMAP pass.\n"); log_continue = false; + mkdebug.off(); } if (extern_mode && !in_recursion) @@ -861,13 +878,18 @@ struct TechmapWorker module_queue.insert(m); } - log("%s %s.%s to imported %s.\n", mapmsg_prefix.c_str(), log_id(module), log_id(cell), log_id(m_name)); + log_debug("%s %s.%s to imported %s.\n", mapmsg_prefix.c_str(), log_id(module), log_id(cell), log_id(m_name)); cell->type = m_name; cell->parameters.clear(); } else { - log("%s %s.%s using %s.\n", mapmsg_prefix.c_str(), log_id(module), log_id(cell), log_id(tpl)); + auto msg = stringf("Using template %s for cells of type %s.", log_id(tpl), log_id(cell->type)); + if (!log_msg_cache.count(msg)) { + log_msg_cache.insert(msg); + log("%s\n", msg.c_str()); + } + log_debug("%s %s.%s (%s) using %s.\n", mapmsg_prefix.c_str(), log_id(module), log_id(cell), log_id(cell->type), log_id(tpl)); techmap_module_worker(design, module, cell, tpl); cell = NULL; } @@ -885,6 +907,7 @@ struct TechmapWorker if (log_continue) { log_header(design, "Continuing TECHMAP pass.\n"); log_continue = false; + mkdebug.off(); } return did_something; @@ -1085,7 +1108,7 @@ struct TechmapPass : public Pass { if (map_files.empty()) { std::istringstream f(stdcells_code); Frontend::frontend_call(map, &f, "", verilog_frontend); - } else + } else { for (auto &fn : map_files) if (fn.substr(0, 1) == "%") { if (!saved_designs.count(fn.substr(1))) { @@ -1104,6 +1127,9 @@ struct TechmapPass : public Pass { log_cmd_error("Can't open map file `%s'\n", fn.c_str()); Frontend::frontend_call(map, &f, fn, (fn.size() > 3 && fn.substr(fn.size()-3) == ".il") ? "ilang" : verilog_frontend); } + } + + log_header(design, "Continuing TECHMAP pass.\n"); std::map> celltypeMap; for (auto &it : map->modules_) { @@ -1211,6 +1237,7 @@ struct FlattenPass : public Pass { } } + log_suppressed(); log("No more expansions possible.\n"); if (top_mod != NULL) -- 2.30.2