logger: do not emit partial log messages

backends/aiger2/aiger.cc

@@ -1807,7 +1807,7 @@ struct Aiger2Backend : Backend {
 		log("\n");
 		log("This command is able to ingest all combinational cells except for:\n");
 		log("\n");
-		log("    ");
+		std::string message;
 		int col = 0;
 		for (size_t i = 0; i < StaticCellTypes::builder.count; i++) {
 			auto &cell = StaticCellTypes::builder.cells[i];
@@ -1819,17 +1819,19 @@ struct Aiger2Backend : Backend {
 				continue;
 			std::string name = cell.type.unescape();
 			if (col + name.size() + 2 > 72) {
-				log("\n    ");
+				log("    %s\n", message);
+				message = "";
 				col = 0;
 			}
 			col += name.size() + 2;
-			log("%s, ", name.c_str());
+			message += stringf("%s, ", name.c_str());
 		}
-		log("\n");
+		if (!message.empty())
+			log("    %s\n", message);		
 		log("\n");
 		log("And all combinational gates except for:\n");
 		log("\n");
-		log("    ");
+		message = "";
 		col = 0;
 		for (size_t i = 0; i < StaticCellTypes::builder.count; i++) {
 			auto &cell = StaticCellTypes::builder.cells[i];
@@ -1841,12 +1843,15 @@ struct Aiger2Backend : Backend {
 				continue;
 			std::string name = cell.type.unescape();
 			if (col + name.size() + 2 > 72) {
-				log("\n    ");
+				log("    %s\n", message);
+				message = "";
 				col = 0;
 			}
 			col += name.size() + 2;
-			log("%s, ", name.c_str());
+			message += stringf("%s, ", name.c_str());
 		}
+		if (!message.empty())
+			log("    %s\n", message);		
 		log("\n");
 	}
 

backends/btor/btor.cc

@@ -746,7 +746,7 @@ struct BtorWorker
 		}
 
 		if (cell->type.in(ID($allconst), ID($allseq)))
-			log_error("Unsupported cell type %s for cell %s.%s",
+			log_error("Unsupported cell type %s for cell %s.%s\n",
 					cell->type.unescape(), module, cell);
 
 
@@ -1276,7 +1276,7 @@ struct BtorWorker
 						cell->type.unescape(), module, cell);
 
 			if (cell->type.in(ID($live), ID($fair), ID($equiv)))
-				log_error("Unsupported cell type %s for cell %s.%s",
+				log_error("Unsupported cell type %s for cell %s.%s\n",
 						cell->type.unescape(), module, cell);
 
 			if (cell->type == ID($assume))

backends/smt2/smt2.cc

@@ -1111,7 +1111,7 @@ struct Smt2Worker
 				log_error("Unsupported cell type %s for cell %s.%s -- please run `async2sync` or `clk2fflogic` before `write_smt2`.\n",
 						cell->type.unescape(), module, cell);
 			if (cell->type.in(ID($live), ID($fair), ID($equiv)))
-				log_error("Unsupported cell type %s for cell %s.%s",
+				log_error("Unsupported cell type %s for cell %s.%s\n",
 						cell->type.unescape(), module, cell);
 
 			if (cell->type.in(ID($assert), ID($assume), ID($cover)))

frontends/verific/verific.cc

@@ -3230,7 +3230,7 @@ struct VerificPass : public Pass {
 		log("\n");
 		log("Load the specified Liberty files into Verific.\n");
 		log("Default library when -work is not present is one specified in liberty file.\n");
-		log("To use from SystemVerilog or VHDL use -L to specify liberty library.");
+		log("To use from SystemVerilog or VHDL use -L to specify liberty library.\n");
 		log("\n");
 		log("    -lib\n");
 		log("        only create empty blackbox modules\n");

kernel/driver.cc

@@ -790,16 +790,17 @@ int main(int argc, char **argv)
 		else
 		{
 			int out_count = 0;
-			log("Time spent:");
+			std::string message = "Time spent:";
 			for (auto it = timedat.rbegin(); it != timedat.rend() && out_count < 4; it++, out_count++) {
 				if (out_count >= 2 && (std::get<0>(*it) < 1000000000 || int(100*std::get<0>(*it) / total_ns) < 20)) {
-					log(", ...");
+					message += ", ...";
 					break;
 				}
-				log("%s %d%% %dx %s (%d sec)", out_count ? "," : "", int(100*std::get<0>(*it) / total_ns),
+				message += stringf("%s %d%% %dx %s (%d sec)", out_count ? "," : "", int(100*std::get<0>(*it) / total_ns),
 						std::get<1>(*it), std::get<2>(*it).c_str(), int(std::get<0>(*it) / 1000000000));
 			}
-			log("%s\n", out_count ? "" : " no commands executed");
+			message += out_count ? "" : " no commands executed";
+			log("%s\n", message);
 		}
 		if(!perffile.empty())
 		{

kernel/log_help.cc

@@ -114,9 +114,9 @@ void log_body_str(const std::string &pass_str, std::string indent_str, bool lead
 	if (leading_newline)
 		log("\n");
 	for (std::string line; std::getline(iss, line);) {
-		log("%s", indent_str);
+		std::string message = indent_str;
 		if (is_formatted) {
-			log("%s", line);
+			message += line;
 		} else {
 			auto curr_len = indent_str.length();
 			std::istringstream lss(line);
@@ -125,15 +125,15 @@ void log_body_str(const std::string &pass_str, std::string indent_str, bool lead
 					word = word.substr(1, word.length()-2);
 				if (curr_len + word.length() >= MAX_LINE_LEN-1) {
 					curr_len = 0;
-					log("\n%s", indent_str);
+					message += "\n" + indent_str;
 				}
 				if (word.length()) {
-					log("%s ", word);
+					message += word + " ";
 					curr_len += word.length() + 1;
 				}
 			}
 		}
-		log("\n");
+		log("%s\n", message);
 	}
 }
 void log_body(const ContentListing &content, int indent=0, bool leading_newline=false) {

kernel/register.cc

@@ -279,10 +279,10 @@ void Pass::call(RTLIL::Design *design, std::vector<std::string> args)
 		return;
 
 	if (echo_mode) {
-		log("%s", create_prompt(design, 0));
+		std::string message = stringf("%s", create_prompt(design, 0));
 		for (size_t i = 0; i < args.size(); i++)
-			log("%s%s", i ? " " : "", args[i]);
-		log("\n");
+			message += stringf("%s%s", i ? " " : "", args[i]);
+		log("%s\n", message);
 	}
 
 	if (pass_register.count(args[0]) == 0)
@@ -1080,9 +1080,10 @@ struct HelpPass : public Pass {
 				for (auto &it : pass_register) {
 					log("\n\n");
 					log("%s  --  %s\n", it.first, it.second->short_help);
+					std::string msg;
 					for (size_t i = 0; i < it.first.size() + it.second->short_help.size() + 6; i++)
-						log("=");
-					log("\n");
+						msg += '=';
+					log("%s\n", msg);
 					it.second->help();
 					log_warning_flags(it.second);
 				}

passes/cmds/abstract.cc

@@ -328,7 +328,7 @@ struct AbstractPass : public Pass {
 		log("during formal verification. The mode and options control when a signal should\n");
 		log("be abstracted and how it should affect FFs present in the design.\n");
 		log("\n");
-		log("Modes:");
+		log("Modes:\n");
 		log("\n");
 		log("    -state\n");
 		log("        The selected FFs will be modified to load a new abstract value on every\n");

passes/cmds/portarcs.cc

@@ -266,27 +266,27 @@ struct PortarcsPass : Pass {
 					max_delay = 1;
 
 				log("Delay legend:\n\n");
-				log("    ");
+				std::string message = "    ";
 				for (int i = 0; i < 24; i++)
-					log("\033[48;5;%dm ", 232+i);
-				log("\033[0m\n");
-				log("    |%22s|\n", "");
-				log("    0%22s%d\n", "", max_delay);
-				log("\n");
+					message += stringf("\033[48;5;%dm ", 232+i);
+				message += "\033[0m\n";
+				message += stringf("    |%22s|\n", "");
+				message += stringf("    0%22s%d\n", "", max_delay);
+				log("%s\n", message);
 				for (int k = top_length - 1; k >= 0; k--) {
-					log("  %10s  ", "");
+					message = stringf("  %10s  ", "");
 					for (auto &h : headings)
-						log("%c", (k < (int) h.size()) ? h[k] : ' ');
-					log("\n");
+						message += (k < (int) h.size()) ? h[k] : ' ';
+					log("%s\n", message);
 				}
 				log("\n");
 
 				for (auto bit : outputs) {
-					log("  %10s  ", bit_str(bit));
+					message = stringf("  %10s  ", bit_str(bit));
 					int *p = annotations.at(canonical_bit(bit));
 					for (auto i = 0; i < inputs.size(); i++)
-						log("\033[48;5;%dm ", 232 + ((std::max(p[i], 0) * 24) - 1) / max_delay);
-					log("\033[0m\n");
+						message += stringf("\033[48;5;%dm ", 232 + ((std::max(p[i], 0) * 24) - 1) / max_delay);
+					log("%s\033[0m\n", message);
 				}
 			}
 

passes/cmds/scc.cc

@@ -81,18 +81,18 @@ struct SccWorker
 			}
 			else
 			{
-				log("Found an SCC:");
+				std::string message = "Found an SCC:";
 				pool<RTLIL::Cell*> scc;
 				while (cellsOnStack.count(cell) > 0) {
 					RTLIL::Cell *c = cellStack.back();
 					cellStack.pop_back();
 					cellsOnStack.erase(c);
-					log(" %s", c);
+					message += stringf(" %s", c);
 					cell2scc[c] = sccList.size();
 					scc.insert(c);
 				}
 				sccList.push_back(scc);
-				log("\n");
+				log("%s\n", message);
 			}
 		}
 	}
@@ -199,13 +199,13 @@ struct SccWorker
 			sigToNextCells.find(cellToNextSig[cell], cellToNextCell[cell]);
 
 			if (!nofeedbackMode && cellToNextCell[cell].count(cell)) {
-				log("Found an SCC:");
+				std::string message = "Found an SCC:";
 				pool<RTLIL::Cell*> scc;
-				log(" %s", cell);
+				message += stringf(" %s", cell);
 				cell2scc[cell] = sccList.size();
 				scc.insert(cell);
 				sccList.push_back(scc);
-				log("\n");
+				log("%s\n", message);
 			}
 		}
 

passes/equiv/equiv_induct.cc

@@ -141,7 +141,7 @@ struct EquivInductWorker : public EquivWorker<>
 			SigBit bit_a = sigmap(cell->getPort(ID::A)).as_bit();
 			SigBit bit_b = sigmap(cell->getPort(ID::B)).as_bit();
 
-			log("  Trying to prove $equiv for %s:", log_signal(sigmap(cell->getPort(ID::Y))));
+			std::string message = stringf("  Trying to prove $equiv for %s:", log_signal(sigmap(cell->getPort(ID::Y))));
 
 			int ez_a = satgen.importSigBit(bit_a, cfg.max_seq+1);
 			int ez_b = satgen.importSigBit(bit_b, cfg.max_seq+1);
@@ -151,11 +151,11 @@ struct EquivInductWorker : public EquivWorker<>
 				cond = ez->AND(cond, ez->NOT(satgen.importUndefSigBit(bit_a, cfg.max_seq+1)));
 
 			if (!ez->solve(cond)) {
-				log(" success!\n");
+				log("%s success!\n", message);
 				cell->setPort(ID::B, cell->getPort(ID::A));
 				success_counter++;
 			} else {
-				log(" failed.\n");
+				log("%s failed.\n", message);
 			}
 		}
 	}

passes/equiv/equiv_make.cc

@@ -449,7 +449,7 @@ struct EquivMakePass : public Pass {
 		log("\n");
 		log("    -make_assert\n");
 		log("        Check equivalence with $assert cells instead of $equiv.\n");
-		log("        $eqx (===) is used to compare signals.");
+		log("        $eqx (===) is used to compare signals.\n");
 		log("\n");
 		log("Note: The circuit created by this command is not a miter (with something like\n");
 		log("a trigger output), but instead uses $equiv cells to encode the equivalence\n");

passes/equiv/equiv_simple.cc

@@ -308,7 +308,7 @@ struct EquivSimpleWorker : public EquivWorker<EquivSimpleConfig>
 			log("  Trying to prove $equiv cell %s:\n", cell);
 			log("    A = %s, B = %s, Y = %s\n", log_signal(bit_a), log_signal(bit_b), log_signal(cell->getPort(ID::Y)));
 		} else {
-			log("  Trying to prove $equiv for %s:", log_signal(cell->getPort(ID::Y)));
+			log("  Trying to prove $equiv for %s:\n", log_signal(cell->getPort(ID::Y)));
 		}
 
 		int step = cfg.max_seq;

passes/hierarchy/hierarchy.cc

@@ -886,6 +886,7 @@ struct HierarchyPass : public Pass {
 			if (args[argidx] == "-generate" && !flag_check && !flag_simcheck && !flag_smtcheck && !top_mod) {
 				generate_mode = true;
 				log("Entering generate mode.\n");
+				std::string message;
 				while (++argidx < args.size()) {
 					const char *p = args[argidx].c_str();
 					generate_port_decl_t decl;
@@ -910,10 +911,10 @@ struct HierarchyPass : public Pass {
 					if (*p == 0)
 						goto is_celltype;
 					decl.portname = p;
-					log("Port declaration: %s", decl.input ? decl.output ? "inout" : "input" : "output");
+					message = stringf("Port declaration: %s", decl.input ? decl.output ? "inout" : "input" : "output");
 					if (decl.index >= 1)
-						log(" [at position %d]", decl.index);
-					log(" %s\n", decl.portname);
+						message += stringf(" [at position %d]", decl.index);
+					log("%s %s\n", message, decl.portname);
 					generate_ports.push_back(decl);
 					continue;
 				is_celltype:

passes/memory/memory_bram.cc

@@ -460,10 +460,10 @@ bool replace_memory(Mem &mem, const rules_t &rules, FfInitVals *initvals, const
 				shuffle_map.push_back(-1);
 		}
 
-		log("      Results of bit order shuffling:");
+		std::string message = "      Results of bit order shuffling:";
 		for (int v : shuffle_map)
-			log(" %d", v);
-		log("\n");
+			message += stringf(" %d", v);
+		log("%s\n", message);
 
 		// update mem_*, wr_*, and rd_* variables
 	} else {
@@ -1018,10 +1018,10 @@ void handle_memory(Mem &mem, const rules_t &rules, FfInitVals *initvals)
 	match_properties["bits"]   = match_properties["words"] * match_properties["dbits"];
 	match_properties["ports"]  = match_properties["wports"] + match_properties["rports"];
 
-	log("  Properties:");
+	std::string message = "  Properties:";
 	for (auto &it : match_properties)
-		log(" %s=%d", it.first, it.second);
-	log("\n");
+		message += stringf(" %s=%d", it.first, it.second);
+	log("%s\n", message);
 
 	pool<pair<IdString, int>> failed_brams;
 	dict<pair<int, int>, tuple<int, int, int>> best_rule_cache;

passes/memory/memory_dff.cc

@@ -334,27 +334,27 @@ struct MemoryDffWorker
 	void handle_rd_port(Mem &mem, QuickConeSat &qcsat, int idx)
 	{
 		auto &port = mem.rd_ports[idx];
-		log("Checking read port `%s'[%d] in module `%s': ", mem.memid, idx, module->name);
+		log("Checking read port `%s'[%d] in module `%s':\n", mem.memid, idx, module->name);
 
 		std::vector<MuxData> muxdata;
 		SigSpec data = walk_muxes(port.data, muxdata);
 		FfData ff;
 		pool<std::pair<Cell *, int>> bits;
 		if (!merger.find_output_ff(data, ff, bits)) {
-			log("no output FF found.\n");
+			log("    no output FF found.\n");
 			return;
 		}
 		if (!ff.has_clk) {
-			log("output latches are not supported.\n");
+			log(    "output latches are not supported.\n");
 			return;
 		}
 		if (ff.has_aload) {
-			log("output FF has async load, not supported.\n");
+			log("    output FF has async load, not supported.\n");
 			return;
 		}
 		if (ff.has_sr) {
 			// Latches and FFs with SR are not supported.
-			log("output FF has both set and reset, not supported.\n");
+			log("    output FF has both set and reset, not supported.\n");
 			return;
 		}
 
@@ -446,7 +446,7 @@ struct MemoryDffWorker
 										continue;
 									if (!cache.can_collide_together(pi, k, bitidx))
 										continue;
-									log("FF found, but transparency logic priority doesn't match write priority.\n");
+									log("    FF found, but transparency logic priority doesn't match write priority.\n");
 									return;
 								}
 							}
@@ -454,7 +454,7 @@ struct MemoryDffWorker
 							trans_queue.push_back({pd, bitidx});
 							break;
 						} else {
-							log("FF found, but with a mux data input that doesn't seem to correspond to transparency logic.\n");
+							log("    FF found, but with a mux data input that doesn't seem to correspond to transparency logic.\n");
 							return;
 						}
 					}
@@ -467,7 +467,7 @@ struct MemoryDffWorker
 							continue;
 						if (cache.impossible_with_ren(sbit, md.is_b))
 							continue;
-						log("FF found, but with a mux select that doesn't seem to correspond to transparency logic.\n");
+						log("    FF found, but with a mux select that doesn't seem to correspond to transparency logic.\n");
 						return;
 					}
 				}
@@ -495,7 +495,7 @@ struct MemoryDffWorker
 					non_trans = true;
 			}
 			if (trans && non_trans) {
-				log("FF found, but soft transparency logic is inconsistent for port %d.\n", pi);
+				log("    FF found, but soft transparency logic is inconsistent for port %d.\n", pi);
 				return;
 			}
 			pd.final_transparency = trans;
@@ -503,7 +503,7 @@ struct MemoryDffWorker
 		}
 
 		// OK, it worked.
-		log("merging output FF to cell.\n");
+		log("    merging output FF to cell.\n");
 
 		merger.remove_output_ff(bits);
 		if (ff.has_ce && !ff.pol_ce)
@@ -554,24 +554,24 @@ struct MemoryDffWorker
 	void handle_rd_port_addr(Mem &mem, int idx)
 	{
 		auto &port = mem.rd_ports[idx];
-		log("Checking read port address `%s'[%d] in module `%s': ", mem.memid, idx, module->name);
+		log("Checking read port address `%s'[%d] in module `%s':\n", mem.memid, idx, module->name);
 
 		FfData ff;
 		pool<std::pair<Cell *, int>> bits;
 		if (!merger.find_input_ff(port.addr, ff, bits)) {
-			log("no address FF found.\n");
+			log("    no address FF found.\n");
 			return;
 		}
 		if (!ff.has_clk) {
-			log("address latches are not supported.\n");
+			log("    address latches are not supported.\n");
 			return;
 		}
 		if (ff.has_aload) {
-			log("address FF has async load, not supported.\n");
+			log("    address FF has async load, not supported.\n");
 			return;
 		}
 		if (ff.has_sr || ff.has_arst) {
-			log("address FF has async set and/or reset, not supported.\n");
+			log("    address FF has async set and/or reset, not supported.\n");
 			return;
 		}
 		// Trick part: this transform is invalid if the initial
@@ -579,13 +579,13 @@ struct MemoryDffWorker
 		// cannot simply reject FFs with any defined init bit,
 		// as this is often the result of merging a const bit.
 		if (ff.val_init.is_fully_def()) {
-			log("address FF has fully-defined init value, not supported.\n");
+			log("    address FF has fully-defined init value, not supported.\n");
 			return;
 		}
 		for (int i = 0; i < GetSize(mem.wr_ports); i++) {
 			auto &wport = mem.wr_ports[i];
 			if (!wport.clk_enable || wport.clk != ff.sig_clk || wport.clk_polarity != ff.pol_clk) {
-				log("address FF clock is not compatible with write clock.\n");
+				log("    address FF clock is not compatible with write clock.\n");
 				return;
 			}
 		}
@@ -601,7 +601,7 @@ struct MemoryDffWorker
 		for (int i = 0; i < GetSize(mem.wr_ports); i++)
 			port.transparency_mask[i] = true;
 		mem.emit();
-		log("merged address FF to cell.\n");
+		log("    merged address FF to cell.\n");
 	}
 
 	void run()

passes/opt/share.cc

@@ -1291,10 +1291,10 @@ struct ShareWorker
 				continue;
 			}
 
-			log("    Found %d candidates:", GetSize(candidates));
+			std::string message = stringf("    Found %d candidates:", GetSize(candidates));
 			for (auto c : candidates)
-				log(" %s", c);
-			log("\n");
+				message += stringf(" %s", c);
+			log("%s\n", message);
 
 			for (auto other_cell : candidates)
 			{
@@ -1429,10 +1429,10 @@ struct ShareWorker
 
 					if (res == SatEffortBudget::Result::Sat) {
 						log("      According to the SAT solver this pair of cells can not be shared.\n");
-						log("      Model from SAT solver: %s = %d'", log_signal(all_ctrl_signals), GetSize(sat_model_values));
+						std::string value;
 						for (int i = GetSize(sat_model_values)-1; i >= 0; i--)
-							log("%c", sat_model_values[i] ? '1' : '0');
-						log("\n");
+							value += sat_model_values[i] ? '1' : '0';
+						log("      Model from SAT solver: %s = %d'%s\n", log_signal(all_ctrl_signals), GetSize(sat_model_values), value);
 						continue;
 					}
 

passes/proc/proc_dff.cc

@@ -135,13 +135,14 @@ void gen_dff(RTLIL::Module *mod, RTLIL::SigSpec sig_in, RTLIL::Const val_rst, RT
 	if (!clk.empty())
 		cell->setPort(ID::CLK, clk);
 
+	std::string message;
 	if (!clk.empty())
-		log("  created %s cell `%s' with %s edge clock", cell->type, cell->name, clk_polarity ? "positive" : "negative");
+		message = stringf("  created %s cell `%s' with %s edge clock", cell->type, cell->name, clk_polarity ? "positive" : "negative");
 	else
-		log("  created %s cell `%s' with global clock", cell->type, cell->name);
+		message = stringf("  created %s cell `%s' with global clock", cell->type, cell->name);
 	if (arst)
-		log(" and %s level reset", arst_polarity ? "positive" : "negative");
-	log(".\n");
+		message += stringf(" and %s level reset", arst_polarity ? "positive" : "negative");
+	log("%s.\n", message);
 }
 
 void proc_dff(RTLIL::Module *mod, RTLIL::Process *proc, ConstEval &ce)

passes/sat/sat.cc

@@ -650,27 +650,27 @@ struct SatHelper
 						    "---------------------------------------------------------------------------------------------------"
 						    "---------------------------------------------------------------------------------------------------";
 				if (last_timestep == -2) {
-					log("%s", max_timestep > 0 ? "  Time " : "  ");
-					log("%-*s %11s %9s %*s\n", maxModelName+5, "Signal Name", "Dec", "Hex", maxModelWidth+3, "Bin");
+					log("%s%-*s %11s %9s %*s\n",  max_timestep > 0 ? "  Time " : "  ",
+						maxModelName+5, "Signal Name", "Dec", "Hex", maxModelWidth+3, "Bin");
 				}
-				log("%s", max_timestep > 0 ? "  ---- " : "  ");
-				log("%*.*s %11.11s %9.9s %*.*s\n", maxModelName+5, maxModelName+5,
+				log("%s%*.*s %11.11s %9.9s %*.*s\n", max_timestep > 0 ? "  ---- " : "  ", 
+						maxModelName+5, maxModelName+5,
 						hline, hline, hline, maxModelWidth+3, maxModelWidth+3, hline);
 				last_timestep = info.timestep;
 			}
 
+			std::string message = "  ";
 			if (max_timestep > 0) {
 				if (info.timestep > 0)
-					log("  %4d ", info.timestep);
+					message = stringf("  %4d ", info.timestep);
 				else
-					log("  init ");
-			} else
-				log("  ");
+					message = "  init ";
+			}
 
 			if (info.width <= 32 && !found_undef)
-				log("%-*s %11d %9x %*s\n", maxModelName+5, info.description, value.as_int(), value.as_int(), maxModelWidth+3, value.as_string());
+				log("%s%-*s %11d %9x %*s\n", message, maxModelName+5, info.description, value.as_int(), value.as_int(), maxModelWidth+3, value.as_string());
 			else
-				log("%-*s %11s %9s %*s\n", maxModelName+5, info.description, "--", "--", maxModelWidth+3, value.as_string());
+				log("%s%-*s %11s %9s %*s\n", message, maxModelName+5, info.description, "--", "--", maxModelWidth+3, value.as_string());
 		}
 
 		if (last_timestep == -2)

passes/sat/sim.cc

@@ -1620,10 +1620,10 @@ struct SimWorker : SimShared
 
 		bool initial = true;
 		int cycle = 0;
-		log("Co-simulation from %lu%s to %lu%s", (unsigned long)startCount, fst->getTimescaleString(), (unsigned long)stopCount, fst->getTimescaleString());
+		std::string message = stringf("Co-simulation from %lu%s to %lu%s", (unsigned long)startCount, fst->getTimescaleString(), (unsigned long)stopCount, fst->getTimescaleString());
 		if (cycles_set)
-			log(" for %d clock cycle(s)",numcycles);
-		log("\n");
+			message += stringf(" for %d clock cycle(s)",numcycles);
+		log("%s\n", message);
 		bool all_samples = fst_clock.empty();
 		unsigned int end_cycle = cycles_set ? numcycles*2 : INT_MAX;
 

passes/techmap/abc.cc

@@ -1117,14 +1117,14 @@ void AbcModuleState::prepare_module(RTLIL::Design *design, RTLIL::Module *module
 		if (clk_sig.size() == 0)
 			log("No%s clock domain found. Not extracting any FF cells.\n", clk_str.empty() ? "" : " matching");
 		else {
-			log("Found%s %s clock domain: %s", clk_str.empty() ? "" : " matching", clk_polarity ? "posedge" : "negedge", log_signal(clk_sig));
+			std::string message = stringf("Found%s %s clock domain: %s", clk_str.empty() ? "" : " matching", clk_polarity ? "posedge" : "negedge", log_signal(clk_sig));
 			if (en_sig.size() != 0)
-				log(", enabled by %s%s", en_polarity ? "" : "!", log_signal(en_sig));
+				message += stringf(", enabled by %s%s", en_polarity ? "" : "!", log_signal(en_sig));
 			if (arst_sig.size() != 0)
-				log(", asynchronously reset by %s%s", arst_polarity ? "" : "!", log_signal(arst_sig));
+				message += stringf(", asynchronously reset by %s%s", arst_polarity ? "" : "!", log_signal(arst_sig));
 			if (srst_sig.size() != 0)
-				log(", synchronously reset by %s%s", srst_polarity ? "" : "!", log_signal(srst_sig));
-			log("\n");
+				message += stringf(", synchronously reset by %s%s", srst_polarity ? "" : "!", log_signal(srst_sig));
+			log("%s\n", message);
 		}
 	}
 

passes/techmap/alumacc.cc

@@ -475,7 +475,7 @@ struct AlumaccWorker
 
 		for (auto cell : lge_cells)
 		{
-			log("  creating $alu model for %s (%s):", cell, cell->type.unescape());
+			std::string message = stringf("  creating $alu model for %s (%s):", cell, cell->type.unescape());
 
 			bool cmp_less = cell->type.in(ID($lt), ID($le));
 			bool cmp_equal = cell->type.in(ID($le), ID($ge));
@@ -513,10 +513,11 @@ struct AlumaccWorker
 				n->invert_b = true;
 				n->oversized = false;
 				sig_alu[RTLIL::SigSig(A, B)].insert(n);
-				log(" new $alu\n");
+				message += " new $alu";
 			} else {
-				log(" merged with %s.\n", n->cells.front());
+				message += stringf(" merged with %s.", n->cells.front());
 			}
+			log("%s\n", message);
 
 			n->cells.push_back(cell);
 			n->cmp.push_back(std::make_tuple(cmp_less, !cmp_less, cmp_equal, false, is_signed, Y));
@@ -558,6 +559,7 @@ struct AlumaccWorker
 	void replace_alu()
 	{
 		std::string src("");
+		std::string message;
 		for (auto &it1 : sig_alu)
 		for (auto n : it1.second)
 		{
@@ -565,10 +567,10 @@ struct AlumaccWorker
 			{
 				n->alu_cell = module->addPos(NEW_ID, n->a, n->y, n->is_signed);
 
-				log("  creating $pos cell for ");
+				message = "  creating $pos cell for ";
 				for (int i = 0; i < GetSize(n->cells); i++)
-					log("%s%s", i ? ", ": "", n->cells[i]);
-				log(": %s\n", n->alu_cell);
+					message += stringf("%s%s", i ? ", ": "", n->cells[i]);
+				log("%s: %s\n", message, n->alu_cell);
 
 				goto delete_node;
 			}
@@ -576,10 +578,10 @@ struct AlumaccWorker
 			n->alu_cell = module->addCell(NEW_ID, ID($alu));
 			alu_counter++;
 
-			log("  creating $alu cell for ");
+			message = "  creating $alu cell for ";
 			for (int i = 0; i < GetSize(n->cells); i++)
-				log("%s%s", i ? ", ": "", n->cells[i]);
-			log(": %s\n", n->alu_cell);
+				message += stringf("%s%s", i ? ", ": "", n->cells[i]);
+			log("%s: %s\n", message, n->alu_cell);
 
 			if (n->cells.size() > 0)
 				n->alu_cell->set_src_attribute(n->cells[0]->get_src_attribute());

passes/techmap/dfflibmap.cc

@@ -39,7 +39,7 @@ static void logmap(IdString dff)
 	if (cell_mappings.count(dff) == 0) {
 		log("    unmapped dff/dlatch cell: %s\n", dff);
 	} else {
-		log("    %s %s (", cell_mappings[dff].cell_name, dff.substr(1));
+		std::string message = stringf("    %s %s (", cell_mappings[dff].cell_name, dff.substr(1));
 		bool first = true;
 		for (auto &port : cell_mappings[dff].ports) {
 			char arg[3] = { port.second, 0, 0 };
@@ -47,10 +47,10 @@ static void logmap(IdString dff)
 				arg[1] = arg[0] - ('a' - 'A'), arg[0] = '~';
 			else
 				arg[1] = arg[0], arg[0] = ' ';
-			log("%s.%s(%s)", first ? "" : ", ", port.first, arg);
+			message += stringf("%s.%s(%s)", first ? "" : ", ", port.first, arg);
 			first = false;
 		}
-		log(");\n");
+		log("%s);\n", message);
 	}
 }
 

passes/techmap/extract.cc

@@ -667,10 +667,10 @@ struct ExtractPass : public Pass {
 					auto &result = results[i];
 					log("\nMatch #%d: (%s in %s)\n", i, result.needleGraphId, result.haystackGraphId);
 					for (const auto &it : result.mappings) {
-						log("  %s -> %s", it.first, it.second.haystackNodeId);
+						std::string message = stringf("  %s -> %s", it.first, it.second.haystackNodeId);
 						for (const auto & it2 : it.second.portMapping)
-							log(" %s:%s", it2.first, it2.second);
-						log("\n");
+							message += stringf(" %s:%s", it2.first, it2.second);
+						log("%s\n", message);
 					}
 					RTLIL::Cell *new_cell = replace(needle_map.at(result.needleGraphId), haystack_map.at(result.haystackGraphId), result);
 					design->select(haystack_map.at(result.haystackGraphId), new_cell);

passes/techmap/extract_fa.cc

@@ -328,10 +328,10 @@ struct ExtractFaWorker
 				if (it.first != xor3_func && it.first != xnor3_func)
 					continue;
 
-				log("      %08d ->", bindec(it.first));
+				std::string message = stringf("      %08d ->", bindec(it.first));
 				for (auto bit : it.second)
-					log(" %s", log_signal(bit));
-				log("\n");
+					message += stringf(" %s", log_signal(bit));
+				log("%s\n", message);
 			}
 
 			dict<int, tuple<SigBit, SigBit, Cell*>> facache;
@@ -354,18 +354,18 @@ struct ExtractFaWorker
 				if (!f3i.inv_a && !f3i.inv_b && !f3i.inv_c && !f3i.inv_y) {
 					log("    Majority without inversions:\n");
 				} else {
-					log("    Majority with inverted");
-					if (f3i.inv_a) log(" A");
-					if (f3i.inv_b) log(" B");
-					if (f3i.inv_c) log(" C");
-					if (f3i.inv_y) log(" Y");
-					log(":\n");
+					std::string message = "    Majority with inverted";
+					if (f3i.inv_a) message += " A";
+					if (f3i.inv_b) message += " B";
+					if (f3i.inv_c) message += " C";
+					if (f3i.inv_y) message += " Y";
+					log("%s:\n", message);
 				}
 
-				log("      %08d ->", bindec(func));
+				std::string message = stringf("      %08d ->", bindec(func));
 				for (auto bit : func3.at(key).at(func))
-					log(" %s", log_signal(bit));
-				log("\n");
+					message += stringf(" %s", log_signal(bit));
+				log("%s\n", message);
 
 				int fakey = 0;
 				if (f3i.inv_a) fakey |= 1;
@@ -444,10 +444,10 @@ struct ExtractFaWorker
 				if (it.first != xor2_func && it.first != xnor2_func)
 					continue;
 
-				log("    %04d ->", bindec(it.first));
+				std::string message = stringf("    %04d ->", bindec(it.first));
 				for (auto bit : it.second)
-					log(" %s", log_signal(bit));
-				log("\n");
+					message += stringf(" %s", log_signal(bit));
+				log("%s\n", message);
 			}
 
 			dict<int, tuple<SigBit, SigBit, Cell*>> facache;
@@ -463,17 +463,17 @@ struct ExtractFaWorker
 				if (!f2i.inv_a && !f2i.inv_b && !f2i.inv_y) {
 					log("    AND without inversions:\n");
 				} else {
-					log("    AND with inverted");
-					if (f2i.inv_a) log(" A");
-					if (f2i.inv_b) log(" B");
-					if (f2i.inv_y) log(" Y");
-					log(":\n");
+					std::string message = "    AND with inverted";
+					if (f2i.inv_a) message += " A";
+					if (f2i.inv_b) message += " B";
+					if (f2i.inv_y) message += " Y";
+					log("%s:\n", message);
 				}
 
-				log("      %04d ->", bindec(func));
+				std::string message = stringf("      %04d ->", bindec(func));
 				for (auto bit : func2.at(key).at(func))
-					log(" %s", log_signal(bit));
-				log("\n");
+					message += stringf(" %s", log_signal(bit));
+				log("%s\n", message);
 
 				int fakey = 0;
 				if (f2i.inv_a) fakey |= 1;

passes/techmap/lut2mux.cc

@@ -78,7 +78,7 @@ struct Lut2muxPass : public Pass {
 	void execute(std::vector<std::string> args, RTLIL::Design *design) override
 	{
 		log_header(design, "Executing LUT2MUX pass (convert $lut to $mux/$_MUX_).\n");
-			log("ARGS:"); for (auto &a: args) log(" [%s]", a.c_str()); log("\n");
+		std::string message = "ARGS:"; for (auto &a: args) message += stringf(" [%s]", a.c_str()); log("%s\n", message);
 
 		size_t argidx;
 		bool word_mode = false;

passes/techmap/techmap.cc

@@ -144,10 +144,10 @@ struct TechmapWorker
 	void techmap_module_worker(RTLIL::Design *design, RTLIL::Module *module, RTLIL::Cell *cell, RTLIL::Module *tpl)
 	{
 		if (tpl->processes.size() != 0) {
-			log("Technology map yielded processes:");
+			std::string message = "Technology map yielded processes:";
 			for (auto &it : tpl->processes)
-				log(" %s",it.first.unescape());
-			log("\n");
+				message += stringf(" %s",it.first.unescape());
+			log("%s\n", message);
 			if (autoproc_mode) {
 				Pass::call_on_module(tpl->design, tpl, "proc");
 				log_assert(GetSize(tpl->processes) == 0);

passes/tests/test_cell.cc

@@ -571,7 +571,9 @@ static void run_edges_test(RTLIL::Design *design, bool verbose)
 
 static void run_eval_test(RTLIL::Design *design, bool verbose, bool nosat, std::string uut_name, std::ofstream &vlog_file)
 {
-	log("Eval testing:%c", verbose ? '\n' : ' ');
+	std::string msg = "Eval testing:";
+	if (verbose)
+		log("%s\n", msg);
 
 	RTLIL::Module *gold_mod = design->module(ID(gold));
 	RTLIL::Module *gate_mod = design->module(ID(gate));
@@ -620,7 +622,6 @@ static void run_eval_test(RTLIL::Design *design, bool verbose, bool nosat, std::
 
 	for (int i = 0; i < 64; i++)
 	{
-		log("%s", verbose ? "\n" : ".");
 		gold_ce.clear();
 		gate_ce.clear();
 
@@ -737,10 +738,10 @@ static void run_eval_test(RTLIL::Design *design, bool verbose, bool nosat, std::
 				log_error("Evaluating sat model 1 (no undef modeling) failed!\n");
 
 			if (verbose) {
-				log("SAT 1: ");
+				std::string message = "SAT 1: ";
 				for (int i = GetSize(out_sig)-1; i >= 0; i--)
-					log("%c", sat1_model_value.at(i) ? '1' : '0');
-				log("\n");
+					message += sat1_model_value.at(i) ? '1' : '0';
+				log("%s\n", message);
 			}
 
 			for (int i = 0; i < GetSize(out_sig); i++) {
@@ -772,10 +773,10 @@ static void run_eval_test(RTLIL::Design *design, bool verbose, bool nosat, std::
 				log_error("Evaluating sat model 2 (undef modeling) failed!\n");
 
 			if (verbose) {
-				log("SAT 2: ");
+				std::string message = "SAT 2: ";
 				for (int i = GetSize(out_sig)-1; i >= 0; i--)
-					log("%c", sat2_model_value.at(GetSize(out_sig) + i) ? 'x' : sat2_model_value.at(i) ? '1' : '0');
-				log("\n");
+					message += sat2_model_value.at(GetSize(out_sig) + i) ? 'x' : sat2_model_value.at(i) ? '1' : '0';
+				log("%s\n", message);
 			}
 
 			for (int i = 0; i < GetSize(out_sig); i++) {
@@ -800,7 +801,7 @@ static void run_eval_test(RTLIL::Design *design, bool verbose, bool nosat, std::
 	}
 
 	if (!verbose)
-		log(" ok.\n");
+		log("%s ok.\n", msg);
 }
 
 struct TestCellPass : public Pass {

techlibs/ice40/ice40_dsp.cc

@@ -132,25 +132,25 @@ void create_ice40_dsp(ice40_dsp_pm &pm)
 		cell->setPort(ID(CE), State::S1);
 		cell->setParam(ID(NEG_TRIGGER), st.clock_pol ? State::S0 : State::S1);
 
-		log("  clock: %s (%s)", log_signal(st.clock), st.clock_pol ? "posedge" : "negedge");
+		log("  clock: %s (%s)\n", log_signal(st.clock), st.clock_pol ? "posedge" : "negedge");
 
 		if (st.ffA)
-			log(" ffA:%s", st.ffA);
+			log(" ffA:%s\n", st.ffA);
 
 		if (st.ffB)
-			log(" ffB:%s", st.ffB);
+			log(" ffB:%s\n", st.ffB);
 
 		if (st.ffCD)
-			log(" ffCD:%s", st.ffCD);
+			log(" ffCD:%s\n", st.ffCD);
 
 		if (st.ffFJKG)
-			log(" ffFJKG:%s", st.ffFJKG);
+			log(" ffFJKG:%s\n", st.ffFJKG);
 
 		if (st.ffH)
-			log(" ffH:%s", st.ffH);
+			log(" ffH:%s\n", st.ffH);
 
 		if (st.ffO)
-			log(" ffO:%s", st.ffO);
+			log(" ffO:%s\n", st.ffO);
 
 		log("\n");
 	}

techlibs/microchip/microchip_dsp.cc

@@ -171,13 +171,13 @@ void microchip_dsp_pack(microchip_dsp_pm &pm)
 		log("  clock: %s (%s)\n", log_signal(st.clock), "posedge");
 
 		if (st.ffA)
-			log(" \t ffA:%s\n", st.ffA);
+			log("  ffA:%s\n", st.ffA);
 		if (st.ffB)
-			log(" \t ffB:%s\n", st.ffB);
+			log("  ffB:%s\n", st.ffB);
 		if (st.ffD)
-			log(" \t ffD:%s\n", st.ffD);
+			log("  ffD:%s\n", st.ffD);
 		if (st.ffP)
-			log(" \t ffP:%s\n", st.ffP);
+			log("  ffP:%s\n", st.ffP);
 	}
 	log("\n");
 
@@ -261,10 +261,10 @@ void microchip_dsp_packC(microchip_dsp_CREG_pm &pm)
 			cell->setPort(ID::C, C);
 		}
 
-		log("  clock: %s (%s)", log_signal(st.clock), "posedge");
+		log("  clock: %s (%s)\n", log_signal(st.clock), "posedge");
 
 		if (st.ffC)
-			log(" ffC:%s", st.ffC);
+			log(" ffC:%s\n", st.ffC);
 		log("\n");
 	}
 

techlibs/xilinx/xilinx_dsp.cc

@@ -453,31 +453,31 @@ void xilinx_dsp_pack(xilinx_dsp_pm &pm)
 			cell->setParam(ID(PREG), State::S1);
 		}
 
-		log("  clock: %s (%s)", log_signal(st.clock), "posedge");
+		log("  clock: %s (%s)\n", log_signal(st.clock), "posedge");
 
 		if (st.ffA2) {
-			log(" ffA2:%s", st.ffA2);
+			log(" ffA2:%s\n", st.ffA2);
 			if (st.ffA1)
-				log(" ffA1:%s", st.ffA1);
+				log(" ffA1:%s\n", st.ffA1);
 		}
 
 		if (st.ffAD)
-			log(" ffAD:%s", st.ffAD);
+			log(" ffAD:%s\n", st.ffAD);
 
 		if (st.ffB2) {
-			log(" ffB2:%s", st.ffB2);
+			log(" ffB2:%s\n", st.ffB2);
 			if (st.ffB1)
-				log(" ffB1:%s", st.ffB1);
+				log(" ffB1:%s\n", st.ffB1);
 		}
 
 		if (st.ffD)
-			log(" ffD:%s", st.ffD);
+			log(" ffD:%s\n", st.ffD);
 
 		if (st.ffM)
-			log(" ffM:%s", st.ffM);
+			log(" ffM:%s\n", st.ffM);
 
 		if (st.ffP)
-			log(" ffP:%s", st.ffP);
+			log(" ffP:%s\n", st.ffP);
 	}
 	log("\n");
 
@@ -636,28 +636,29 @@ void xilinx_dsp48a_pack(xilinx_dsp48a_pm &pm)
 			cell->setParam(ID(PREG), State::S1);
 		}
 
-		log("  clock: %s (%s)", log_signal(st.clock), "posedge");
+		std::string message = stringf("  clock: %s (%s)", log_signal(st.clock), "posedge");
 
 		if (st.ffA0)
-			log(" ffA0:%s", st.ffA0);
+			message += stringf(" ffA0:%s", st.ffA0);
 		if (st.ffA1)
-			log(" ffA1:%s", st.ffA1);
+			message += stringf(" ffA1:%s", st.ffA1);
 
 		if (st.ffB0)
-			log(" ffB0:%s", st.ffB0);
+			message += stringf(" ffB0:%s", st.ffB0);
 		if (st.ffB1)
-			log(" ffB1:%s", st.ffB1);
+			message += stringf(" ffB1:%s", st.ffB1);
 
 		if (st.ffD)
-			log(" ffD:%s", st.ffD);
+			message += stringf(" ffD:%s", st.ffD);
 
 		if (st.ffM)
-			log(" ffM:%s", st.ffM);
+			message += stringf(" ffM:%s", st.ffM);
 
 		if (st.ffP)
-			log(" ffP:%s", st.ffP);
+			message += stringf(" ffP:%s", st.ffP);
+
+		log("%s\n", message);
 	}
-	log("\n");
 
 	SigSpec P = st.sigP;
 	if (GetSize(P) < 48)
@@ -721,11 +722,11 @@ void xilinx_dsp_packC(xilinx_dsp_CREG_pm &pm)
 			cell->setParam(ID(CREG), 1);
 		}
 
-		log("  clock: %s (%s)", log_signal(st.clock), "posedge");
+		std::string message = stringf("  clock: %s (%s)", log_signal(st.clock), "posedge");
 
 		if (st.ffC)
-			log(" ffC:%s", st.ffC);
-		log("\n");
+			message += stringf(" ffC:%s", st.ffC);
+		log("%s\n", message);
 	}
 
 	pm.blacklist(cell);