diag: Unify debug printing

10 files changed, 262 insertions, 156 deletions

diff --git a/cmdline.h b/cmdline.h
index bb75798..29da3fa 100644
--- a/cmdline.h
+++ b/cmdline.h
@@ -1,6 +1,6 @@
 /****************************************************************************
  * bfs                                                                      *
- * Copyright (C) 2015-2018 Tavian Barnes <tavianator@tavianator.com>        *
+ * Copyright (C) 2015-2020 Tavian Barnes <tavianator@tavianator.com>        *
  *                                                                          *
  * Permission to use, copy, modify, and/or distribute this software for any *
  * purpose with or without fee is hereby granted.                           *
@@ -117,7 +117,7 @@ struct cmdline *parse_cmdline(int argc, char *argv[]);
 /**
  * Dump the parsed command line.
  */
-void dump_cmdline(const struct cmdline *cmdline, bool verbose);
+void dump_cmdline(const struct cmdline *cmdline, enum debug_flags flag);
 
 /**
  * Optimize the parsed command line.
diff --git a/color.c b/color.c
index c06840b..cfb3f47 100644
--- a/color.c
+++ b/color.c
@@ -17,6 +17,7 @@
 #include "color.h"
 #include "bftw.h"
 #include "dstring.h"
+#include "expr.h"
 #include "fsade.h"
 #include "stat.h"
 #include "trie.h"
@@ -863,6 +864,65 @@ done:
 	return ret;
 }
 
+/** Dump a parsed expression tree, for debugging. */
+static int print_expr(CFILE *cfile, const struct expr *expr, bool verbose) {
+	if (fputs("(", cfile->file) == EOF) {
+		return -1;
+	}
+
+	if (expr->lhs || expr->rhs) {
+		if (cfprintf(cfile, "${red}%s${rs}", expr->argv[0]) < 0) {
+			return -1;
+		}
+	} else {
+		if (cfprintf(cfile, "${blu}%s${rs}", expr->argv[0]) < 0) {
+			return -1;
+		}
+	}
+
+	for (size_t i = 1; i < expr->argc; ++i) {
+		if (cfprintf(cfile, " ${bld}%s${rs}", expr->argv[i]) < 0) {
+			return -1;
+		}
+	}
+
+	if (verbose) {
+		double rate = 0.0, time = 0.0;
+		if (expr->evaluations) {
+			rate = 100.0*expr->successes/expr->evaluations;
+			time = (1.0e9*expr->elapsed.tv_sec + expr->elapsed.tv_nsec)/expr->evaluations;
+		}
+		if (cfprintf(cfile, " [${ylw}%zu${rs}/${ylw}%zu${rs}=${ylw}%g%%${rs}; ${ylw}%gns${rs}]",
+		             expr->successes, expr->evaluations, rate, time)) {
+			return -1;
+		}
+	}
+
+	if (expr->lhs) {
+		if (fputs(" ", cfile->file) == EOF) {
+			return -1;
+		}
+		if (print_expr(cfile, expr->lhs, verbose) != 0) {
+			return -1;
+		}
+	}
+
+	if (expr->rhs) {
+		if (fputs(" ", cfile->file) == EOF) {
+			return -1;
+		}
+		if (print_expr(cfile, expr->rhs, verbose) != 0) {
+			return -1;
+		}
+	}
+
+	if (fputs(")", cfile->file) == EOF) {
+		return -1;
+	}
+
+	return 0;
+}
+
 int cfprintf(CFILE *cfile, const char *format, ...) {
 	va_list args;
 	va_start(args, format);
@@ -946,6 +1006,17 @@ int cvfprintf(CFILE *cfile, const char *format, va_list args) {
 					}
 					break;
 
+				case 'e':
+					if (print_expr(cfile, va_arg(args, const struct expr *), false) != 0) {
+						return -1;
+					}
+					break;
+				case 'E':
+					if (print_expr(cfile, va_arg(args, const struct expr *), true) != 0) {
+						return -1;
+					}
+					break;
+
 				default:
 					goto invalid;
 				}
diff --git a/color.h b/color.h
index 7df3785..e6ee49d 100644
--- a/color.h
+++ b/color.h
@@ -1,6 +1,6 @@
 /****************************************************************************
  * bfs                                                                      *
- * Copyright (C) 2015-2018 Tavian Barnes <tavianator@tavianator.com>        *
+ * Copyright (C) 2015-2020 Tavian Barnes <tavianator@tavianator.com>        *
  *                                                                          *
  * Permission to use, copy, modify, and/or distribute this software for any *
  * purpose with or without fee is hereby granted.                           *
@@ -108,6 +108,8 @@ int cfclose(CFILE *cfile);
  *         %m: strerror(errno)
  *         %pP: A colored file path, from a const struct BFTW * argument
  *         %pL: A colored link target, from a const struct BFTW * argument
+ *         %pe: Dump a const struct expr *, for debugging.
+ *         %pE: Dump a const struct expr * in verbose form, for debugging.
  *         %%: A literal '%'
  *         ${cc}: Change the color to 'cc'
  *         $$: A literal '$'
diff --git a/diag.c b/diag.c
index f43ed2e..fb1a295 100644
--- a/diag.c
+++ b/diag.c
@@ -18,6 +18,7 @@
 #include "cmdline.h"
 #include "color.h"
 #include "util.h"
+#include <assert.h>
 #include <errno.h>
 #include <stdarg.h>
 #include <stdlib.h>
@@ -30,11 +31,20 @@ void bfs_error(const struct cmdline *cmdline, const char *format, ...)  {
 	va_end(args);
 }
 
-void bfs_warning(const struct cmdline *cmdline, const char *format, ...)  {
+bool bfs_warning(const struct cmdline *cmdline, const char *format, ...)  {
 	va_list args;
 	va_start(args, format);
-	bfs_vwarning(cmdline, format, args);
+	bool ret = bfs_vwarning(cmdline, format, args);
 	va_end(args);
+	return ret;
+}
+
+bool bfs_debug(const struct cmdline *cmdline, enum debug_flags flag, const char *format, ...)  {
+	va_list args;
+	va_start(args, format);
+	bool ret = bfs_vdebug(cmdline, flag, format, args);
+	va_end(args);
+	return ret;
 }
 
 void bfs_verror(const struct cmdline *cmdline, const char *format, va_list args) {
@@ -46,14 +56,27 @@ void bfs_verror(const struct cmdline *cmdline, const char *format, va_list args)
 	cvfprintf(cmdline->cerr, format, args);
 }
 
-void bfs_vwarning(const struct cmdline *cmdline, const char *format, va_list args) {
-	if (cmdline->warn) {
-		int error = errno;
+bool bfs_vwarning(const struct cmdline *cmdline, const char *format, va_list args) {
+	int error = errno;
+
+	if (bfs_warning_prefix(cmdline)) {
+		errno = error;
+		cvfprintf(cmdline->cerr, format, args);
+		return true;
+	} else {
+		return false;
+	}
+}
 
-		bfs_warning_prefix(cmdline);
+bool bfs_vdebug(const struct cmdline *cmdline, enum debug_flags flag, const char *format, va_list args) {
+	int error = errno;
 
+	if (bfs_debug_prefix(cmdline, flag)) {
 		errno = error;
 		cvfprintf(cmdline->cerr, format, args);
+		return true;
+	} else {
+		return false;
 	}
 }
 
@@ -61,6 +84,50 @@ void bfs_error_prefix(const struct cmdline *cmdline) {
 	cfprintf(cmdline->cerr, "${bld}%s:${rs} ${er}error:${rs} ", xbasename(cmdline->argv[0]));
 }
 
-void bfs_warning_prefix(const struct cmdline *cmdline) {
-	cfprintf(cmdline->cerr, "${bld}%s:${rs} ${wr}warning:${rs} ", xbasename(cmdline->argv[0]));
+bool bfs_warning_prefix(const struct cmdline *cmdline) {
+	if (cmdline->warn) {
+		cfprintf(cmdline->cerr, "${bld}%s:${rs} ${wr}warning:${rs} ", xbasename(cmdline->argv[0]));
+		return true;
+	} else {
+		return false;
+	}
+}
+
+bool bfs_debug_prefix(const struct cmdline *cmdline, enum debug_flags flag) {
+	if (!(cmdline->debug & flag)) {
+		return false;
+	}
+
+	const char *str;
+
+	switch (flag) {
+	case DEBUG_COST:
+		str = "cost";
+		break;
+	case DEBUG_EXEC:
+		str = "exec";
+		break;
+	case DEBUG_OPT:
+		str = "opt";
+		break;
+	case DEBUG_RATES:
+		str = "rates";
+		break;
+	case DEBUG_SEARCH:
+		str = "search";
+		break;
+	case DEBUG_STAT:
+		str = "stat";
+		break;
+	case DEBUG_TREE:
+		str = "tree";
+		break;
+	default:
+		assert(false);
+		str = "???";
+		break;
+	}
+
+	cfprintf(cmdline->cerr, "${bld}%s:${rs} ${cyn}-D %s${rs}: ", xbasename(cmdline->argv[0]), str);
+	return true;
 }
diff --git a/diag.h b/diag.h
index 54f2366..2e5513e 100644
--- a/diag.h
+++ b/diag.h
@@ -24,6 +24,7 @@
 #include "cmdline.h"
 #include "util.h"
 #include <stdarg.h>
+#include <stdbool.h>
 
 /**
  * Shorthand for printing error messages.
@@ -33,9 +34,19 @@ void bfs_error(const struct cmdline *cmdline, const char *format, ...);
 
 /**
  * Shorthand for printing warning messages.
+ *
+ * @return Whether a warning was printed.
  */
 BFS_FORMATTER(2, 3)
-void bfs_warning(const struct cmdline *cmdline, const char *format, ...);
+bool bfs_warning(const struct cmdline *cmdline, const char *format, ...);
+
+/**
+ * Shorthand for printing debug messages.
+ *
+ * @return Whether a debug message was printed.
+ */
+BFS_FORMATTER(3, 4)
+bool bfs_debug(const struct cmdline *cmdline, enum debug_flags flag, const char *format, ...);
 
 /**
  * bfs_error() variant that takes a va_list.
@@ -45,7 +56,12 @@ void bfs_verror(const struct cmdline *cmdline, const char *format, va_list args)
 /**
  * bfs_warning() variant that takes a va_list.
  */
-void bfs_vwarning(const struct cmdline *cmdline, const char *format, va_list args);
+bool bfs_vwarning(const struct cmdline *cmdline, const char *format, va_list args);
+
+/**
+ * bfs_debug() variant that takes a va_list.
+ */
+bool bfs_vdebug(const struct cmdline *cmdline, enum debug_flags flag, const char *format, va_list args);
 
 /**
  * Print the error message prefix.
@@ -55,6 +71,11 @@ void bfs_error_prefix(const struct cmdline *cmdline);
 /**
  * Print the warning message prefix.
  */
-void bfs_warning_prefix(const struct cmdline *cmdline);
+bool bfs_warning_prefix(const struct cmdline *cmdline);
+
+/**
+ * Print the debug message prefix.
+ */
+bool bfs_debug_prefix(const struct cmdline *cmdline, enum debug_flags flag);
 
 #endif // BFS_DIAG_H
diff --git a/eval.c b/eval.c
index a4cb8f3..114bb53 100644
--- a/eval.c
+++ b/eval.c
@@ -1052,7 +1052,9 @@ static bool eval_file_unique(struct eval_state *state, struct trie *seen) {
 /**
  * Log a stat() call.
  */
-static void debug_stat(const struct BFTW *ftwbuf, const struct bftw_stat *cache, enum bfs_stat_flag flags) {
+static void debug_stat(const struct cmdline *cmdline, const struct BFTW *ftwbuf, const struct bftw_stat *cache, enum bfs_stat_flag flags) {
+	bfs_debug_prefix(cmdline, DEBUG_STAT);
+
 	fprintf(stderr, "bfs_stat(");
 	if (ftwbuf->at_fd == AT_FDCWD) {
 		fprintf(stderr, "AT_FDCWD");
@@ -1081,15 +1083,19 @@ static void debug_stat(const struct BFTW *ftwbuf, const struct bftw_stat *cache,
 /**
  * Log any stat() calls that happened.
  */
-static void debug_stats(const struct BFTW *ftwbuf) {
+static void debug_stats(const struct cmdline *cmdline, const struct BFTW *ftwbuf) {
+	if (!(cmdline->debug & DEBUG_STAT)) {
+		return;
+	}
+
 	const struct bfs_stat *statbuf = ftwbuf->stat_cache.buf;
 	if (statbuf || ftwbuf->stat_cache.error) {
-		debug_stat(ftwbuf, &ftwbuf->stat_cache, BFS_STAT_FOLLOW);
+		debug_stat(cmdline, ftwbuf, &ftwbuf->stat_cache, BFS_STAT_FOLLOW);
 	}
 
 	const struct bfs_stat *lstatbuf = ftwbuf->lstat_cache.buf;
 	if ((lstatbuf && lstatbuf != statbuf) || ftwbuf->lstat_cache.error) {
-		debug_stat(ftwbuf, &ftwbuf->lstat_cache, BFS_STAT_NOFOLLOW);
+		debug_stat(cmdline, ftwbuf, &ftwbuf->lstat_cache, BFS_STAT_NOFOLLOW);
 	}
 }
 
@@ -1213,12 +1219,9 @@ static enum bftw_action cmdline_callback(const struct BFTW *ftwbuf, void *ptr) {
 	}
 
 done:
-	if (cmdline->debug & DEBUG_STAT) {
-		debug_stats(ftwbuf);
-	}
+	debug_stats(cmdline, ftwbuf);
 
-	if (cmdline->debug & DEBUG_SEARCH) {
-		fprintf(stderr, "cmdline_callback({\n");
+	if (bfs_debug(cmdline, DEBUG_SEARCH, "cmdline_callback({\n")) {
 		fprintf(stderr, "\t.path = \"%s\",\n", ftwbuf->path);
 		fprintf(stderr, "\t.root = \"%s\",\n", ftwbuf->root);
 		fprintf(stderr, "\t.depth = %zu,\n", ftwbuf->depth);
@@ -1336,8 +1339,7 @@ int eval_cmdline(const struct cmdline *cmdline) {
 		.mtab = cmdline->mtab,
 	};
 
-	if (cmdline->debug & DEBUG_SEARCH) {
-		fprintf(stderr, "bftw({\n");
+	if (bfs_debug(cmdline, DEBUG_SEARCH, "bftw({\n")) {
 		fprintf(stderr, "\t.paths = {\n");
 		for (size_t i = 0; i < bftw_args.npaths; ++i) {
 			fprintf(stderr, "\t\t\"%s\",\n", bftw_args.paths[i]);
@@ -1368,9 +1370,7 @@ int eval_cmdline(const struct cmdline *cmdline) {
 		args.ret = EXIT_FAILURE;
 	}
 
-	if (cmdline->debug & DEBUG_RATES) {
-		dump_cmdline(cmdline, true);
-	}
+	dump_cmdline(cmdline, DEBUG_RATES);
 
 	if (cmdline->unique) {
 		trie_destroy(&seen);
diff --git a/exec.c b/exec.c
index 3c791d7..7c199a3 100644
--- a/exec.c
+++ b/exec.c
@@ -37,7 +37,9 @@
 /** Print some debugging info. */
 BFS_FORMATTER(2, 3)
 static void bfs_exec_debug(const struct bfs_exec *execbuf, const char *format, ...) {
-	if (!(execbuf->cmdline->debug & DEBUG_EXEC)) {
+	const struct cmdline *cmdline = execbuf->cmdline;
+
+	if (!bfs_debug(cmdline, DEBUG_EXEC, "${blu}")) {
 		return;
 	}
 
@@ -49,7 +51,7 @@ static void bfs_exec_debug(const struct bfs_exec *execbuf, const char *format, .
 	if (execbuf->flags & BFS_EXEC_CHDIR) {
 		fputs("dir", stderr);
 	}
-	fputs(": ", stderr);
+	cfprintf(cmdline->cerr, "${rs}: ");
 
 	va_list args;
 	va_start(args, format);
diff --git a/expr.h b/expr.h
index 0251d6b..4bb2e84 100644
--- a/expr.h
+++ b/expr.h
@@ -211,11 +211,6 @@ bool expr_never_returns(const struct expr *expr);
 bool expr_cmp(const struct expr *expr, long long n);
 
 /**
- * Dump a parsed expression.
- */
-void dump_expr(CFILE *cfile, const struct expr *expr, bool verbose);
-
-/**
  * Free an expression tree.
  */
 void free_expr(struct expr *expr);
diff --git a/opt.c b/opt.c
index 42307a2..8bc990e 100644
--- a/opt.c
+++ b/opt.c
@@ -41,6 +41,7 @@
 
 #include "cmdline.h"
 #include "color.h"
+#include "diag.h"
 #include "eval.h"
 #include "expr.h"
 #include "pwcache.h"
@@ -313,41 +314,17 @@ struct opt_state {
 };
 
 /** Log an optimization. */
-static void debug_opt(const struct opt_state *state, const char *format, ...) {
-	if (!(state->cmdline->debug & DEBUG_OPT)) {
-		return;
-	}
-
-	CFILE *cerr = state->cmdline->cerr;
-
-	va_list args;
-	va_start(args, format);
-
-	for (const char *i = format; *i != '\0'; ++i) {
-		if (*i == '%') {
-			switch (*++i) {
-			case 'd':
-				fprintf(cerr->file, "%d", va_arg(args, int));
-				break;
-
-			case 'e':
-				dump_expr(cerr, va_arg(args, const struct expr *), false);
-				break;
-
-			case 'g':
-				cfprintf(cerr, "${ylw}%g${rs}", va_arg(args, double));
-				break;
-
-			default:
-				assert(false);
-				break;
-			}
-		} else {
-			fputc(*i, stderr);
-		}
+BFS_FORMATTER(3, 4)
+static bool debug_opt(const struct opt_state *state, int level, const char *format, ...) {
+	if (bfs_debug(state->cmdline, DEBUG_OPT, "${cyn}-O%d${rs}: ", level)) {
+		va_list args;
+		va_start(args, format);
+		cvfprintf(state->cmdline->cerr, format, args);
+		va_end(args);
+		return true;
+	} else {
+		return false;
 	}
-
-	va_end(args);
 }
 
 /** Extract a child expression, freeing the outer expression. */
@@ -384,7 +361,7 @@ static struct expr *optimize_or_expr(const struct opt_state *state, struct expr
  * Apply De Morgan's laws.
  */
 static struct expr *de_morgan(const struct opt_state *state, struct expr *expr, char **argv) {
-	debug_opt(state, "-O1: De Morgan's laws: %e ", expr);
+	bool debug = debug_opt(state, 1, "De Morgan's laws: %pe ", expr);
 
 	struct expr *parent = negate_expr(expr, argv);
 	if (!parent) {
@@ -413,7 +390,9 @@ static struct expr *de_morgan(const struct opt_state *state, struct expr *expr,
 		return NULL;
 	}
 
-	debug_opt(state, "<==> %e\n", parent);
+	if (debug) {
+		cfprintf(state->cmdline->cerr, "<==> %pe\n", parent);
+	}
 
 	if (expr->lhs->eval == eval_not) {
 		expr->lhs = optimize_not_expr(state, expr->lhs);
@@ -461,18 +440,18 @@ static struct expr *optimize_not_expr(const struct opt_state *state, struct expr
 	int optlevel = state->cmdline->optlevel;
 	if (optlevel >= 1) {
 		if (rhs == &expr_true) {
-			debug_opt(state, "-O1: constant propagation: %e <==> %e\n", expr, &expr_false);
+			debug_opt(state, 1, "constant propagation: %pe <==> %pe\n", expr, &expr_false);
 			free_expr(expr);
 			return &expr_false;
 		} else if (rhs == &expr_false) {
-			debug_opt(state, "-O1: constant propagation: %e <==> %e\n", expr, &expr_true);
+			debug_opt(state, 1, "constant propagation: %pe <==> %pe\n", expr, &expr_true);
 			free_expr(expr);
 			return &expr_true;
 		} else if (rhs->eval == eval_not) {
-			debug_opt(state, "-O1: double negation: %e <==> %e\n", expr, rhs->rhs);
+			debug_opt(state, 1, "double negation: %pe <==> %pe\n", expr, rhs->rhs);
 			return extract_child_expr(expr, &rhs->rhs);
 		} else if (expr_never_returns(rhs)) {
-			debug_opt(state, "-O1: reachability: %e <==> %e\n", expr, rhs);
+			debug_opt(state, 1, "reachability: %pe <==> %pe\n", expr, rhs);
 			return extract_child_expr(expr, &expr->rhs);
 		} else if ((rhs->eval == eval_and || rhs->eval == eval_or)
 			   && (rhs->lhs->eval == eval_not || rhs->rhs->eval == eval_not)) {
@@ -514,27 +493,28 @@ static struct expr *optimize_and_expr(const struct opt_state *state, struct expr
 	struct expr *lhs = expr->lhs;
 	struct expr *rhs = expr->rhs;
 
-	int optlevel = state->cmdline->optlevel;
+	const struct cmdline *cmdline = state->cmdline;
+	int optlevel = cmdline->optlevel;
 	if (optlevel >= 1) {
 		if (lhs == &expr_true) {
-			debug_opt(state, "-O1: conjunction elimination: %e <==> %e\n", expr, rhs);
+			debug_opt(state, 1, "conjunction elimination: %pe <==> %pe\n", expr, rhs);
 			return extract_child_expr(expr, &expr->rhs);
 		} else if (rhs == &expr_true) {
-			debug_opt(state, "-O1: conjunction elimination: %e <==> %e\n", expr, lhs);
+			debug_opt(state, 1, "conjunction elimination: %pe <==> %pe\n", expr, lhs);
 			return extract_child_expr(expr, &expr->lhs);
 		} else if (lhs->always_false) {
-			debug_opt(state, "-O1: short-circuit: %e <==> %e\n", expr, lhs);
+			debug_opt(state, 1, "short-circuit: %pe <==> %pe\n", expr, lhs);
 			return extract_child_expr(expr, &expr->lhs);
 		} else if (lhs->always_true && rhs == &expr_false) {
-			debug_opt(state, "-O1: strength reduction: %e <==> ", expr);
+			bool debug = debug_opt(state, 1, "strength reduction: %pe <==> ", expr);
 			struct expr *ret = extract_child_expr(expr, &expr->lhs);
 			ret = negate_expr(ret, &fake_not_arg);
-			if (ret) {
-				debug_opt(state, "%e\n", ret);
+			if (debug && ret) {
+				cfprintf(cmdline->cerr, "%pe\n", ret);
 			}
 			return ret;
 		} else if (optlevel >= 2 && lhs->pure && rhs == &expr_false) {
-			debug_opt(state, "-O2: purity: %e <==> %e\n", expr, rhs);
+			debug_opt(state, 2, "purity: %pe <==> %pe\n", expr, rhs);
 			return extract_child_expr(expr, &expr->rhs);
 		} else if (lhs->eval == eval_not && rhs->eval == eval_not) {
 			return de_morgan(state, expr, expr->lhs->argv);
@@ -582,27 +562,28 @@ static struct expr *optimize_or_expr(const struct opt_state *state, struct expr
 	struct expr *lhs = expr->lhs;
 	struct expr *rhs = expr->rhs;
 
-	int optlevel = state->cmdline->optlevel;
+	const struct cmdline *cmdline = state->cmdline;
+	int optlevel = cmdline->optlevel;
 	if (optlevel >= 1) {
 		if (lhs->always_true) {
-			debug_opt(state, "-O1: short-circuit: %e <==> %e\n", expr, lhs);
+			debug_opt(state, 1, "short-circuit: %pe <==> %pe\n", expr, lhs);
 			return extract_child_expr(expr, &expr->lhs);
 		} else if (lhs == &expr_false) {
-			debug_opt(state, "-O1: disjunctive syllogism: %e <==> %e\n", expr, rhs);
+			debug_opt(state, 1, "disjunctive syllogism: %pe <==> %pe\n", expr, rhs);
 			return extract_child_expr(expr, &expr->rhs);
 		} else if (rhs == &expr_false) {
-			debug_opt(state, "-O1: disjunctive syllogism: %e <==> %e\n", expr, lhs);
+			debug_opt(state, 1, "disjunctive syllogism: %pe <==> %pe\n", expr, lhs);
 			return extract_child_expr(expr, &expr->lhs);
 		} else if (lhs->always_false && rhs == &expr_true) {
-			debug_opt(state, "-O1: strength reduction: %e <==> ", expr);
+			bool debug = debug_opt(state, 1, "strength reduction: %pe <==> ", expr);
 			struct expr *ret = extract_child_expr(expr, &expr->lhs);
 			ret = negate_expr(ret, &fake_not_arg);
-			if (ret) {
-				debug_opt(state, "%e\n", ret);
+			if (debug && ret) {
+				cfprintf(cmdline->cerr, "%pe\n", ret);
 			}
 			return ret;
 		} else if (optlevel >= 2 && lhs->pure && rhs == &expr_true) {
-			debug_opt(state, "-O2: purity: %e <==> %e\n", expr, rhs);
+			debug_opt(state, 2, "purity: %pe <==> %pe\n", expr, rhs);
 			return extract_child_expr(expr, &expr->rhs);
 		} else if (lhs->eval == eval_not && rhs->eval == eval_not) {
 			return de_morgan(state, expr, expr->lhs->argv);
@@ -650,12 +631,12 @@ static struct expr *ignore_result(const struct opt_state *state, struct expr *ex
 	if (optlevel >= 1) {
 		while (true) {
 			if (expr->eval == eval_not) {
-				debug_opt(state, "-O1: ignored result: %e --> %e\n", expr, expr->rhs);
+				debug_opt(state, 1, "ignored result: %pe --> %pe\n", expr, expr->rhs);
 				expr = extract_child_expr(expr, &expr->rhs);
 			} else if (optlevel >= 2
 			           && (expr->eval == eval_and || expr->eval == eval_or || expr->eval == eval_comma)
 			           && expr->rhs->pure) {
-				debug_opt(state, "-O2: ignored result: %e --> %e\n", expr, expr->lhs);
+				debug_opt(state, 2, "ignored result: %pe --> %pe\n", expr, expr->lhs);
 				expr = extract_child_expr(expr, &expr->lhs);
 			} else {
 				break;
@@ -663,7 +644,7 @@ static struct expr *ignore_result(const struct opt_state *state, struct expr *ex
 		}
 
 		if (optlevel >= 2 && expr->pure && expr != &expr_false) {
-			debug_opt(state, "-O2: ignored result: %e --> %e\n", expr, &expr_false);
+			debug_opt(state, 2, "ignored result: %pe --> %pe\n", expr, &expr_false);
 			free_expr(expr);
 			expr = &expr_false;
 		}
@@ -684,14 +665,14 @@ static struct expr *optimize_comma_expr(const struct opt_state *state, struct ex
 		lhs = expr->lhs = ignore_result(state, lhs);
 
 		if (expr_never_returns(lhs)) {
-			debug_opt(state, "-O1: reachability: %e <==> %e\n", expr, lhs);
+			debug_opt(state, 1, "reachability: %pe <==> %pe\n", expr, lhs);
 			return extract_child_expr(expr, &expr->lhs);
 		} else if ((lhs->always_true && rhs == &expr_true)
 			   || (lhs->always_false && rhs == &expr_false)) {
-			debug_opt(state, "-O1: redundancy elimination: %e <==> %e\n", expr, lhs);
+			debug_opt(state, 1, "redundancy elimination: %pe <==> %pe\n", expr, lhs);
 			return extract_child_expr(expr, &expr->lhs);
 		} else if (optlevel >= 2 && lhs->pure) {
-			debug_opt(state, "-O2: purity: %e <==> %e\n", expr, rhs);
+			debug_opt(state, 2, "purity: %pe <==> %pe\n", expr, rhs);
 			return extract_child_expr(expr, &expr->rhs);
 		}
 	}
@@ -900,7 +881,7 @@ static struct expr *optimize_expr_recursive(struct opt_state *state, struct expr
 
 	if (facts_are_impossible(&state->facts_when_true)) {
 		if (expr->pure) {
-			debug_opt(state, "-O2: data flow: %e --> %e\n", expr, &expr_false);
+			debug_opt(state, 2, "data flow: %pe --> %pe\n", expr, &expr_false);
 			free_expr(expr);
 			expr = &expr_false;
 		} else {
@@ -909,7 +890,7 @@ static struct expr *optimize_expr_recursive(struct opt_state *state, struct expr
 		}
 	} else if (facts_are_impossible(&state->facts_when_false)) {
 		if (expr->pure) {
-			debug_opt(state, "-O2: data flow: %e --> %e\n", expr, &expr_true);
+			debug_opt(state, 2, "data flow: %pe --> %pe\n", expr, &expr_true);
 			free_expr(expr);
 			expr = &expr_true;
 		} else {
@@ -925,11 +906,13 @@ done:
 /** Swap the children of a binary expression if it would reduce the cost. */
 static bool reorder_expr(const struct opt_state *state, struct expr *expr, double swapped_cost) {
 	if (swapped_cost < expr->cost) {
-		debug_opt(state, "-O3: cost: %e", expr);
+		bool debug = debug_opt(state, 3, "cost: %pe <==> ", expr);
 		struct expr *lhs = expr->lhs;
 		expr->lhs = expr->rhs;
 		expr->rhs = lhs;
-		debug_opt(state, " <==> %e (~%g --> ~%g)\n", expr, expr->cost, swapped_cost);
+		if (debug) {
+			cfprintf(state->cmdline->cerr, "%pe (~${ylw}%g${rs} --> ~${ylw}%g${rs})\n", expr, expr->cost, swapped_cost);
+		}
 		expr->cost = swapped_cost;
 		return true;
 	} else {
@@ -1009,7 +992,7 @@ int optimize_cmdline(struct cmdline *cmdline) {
 			mindepth = INT_MAX;
 		}
 		cmdline->mindepth = mindepth;
-		debug_opt(&state, "-O2: data flow: mindepth --> %d\n", cmdline->mindepth);
+		debug_opt(&state, 2, "data flow: mindepth --> %d\n", cmdline->mindepth);
 	}
 
 	if (optlevel >= 4 && maxdepth < cmdline->maxdepth) {
@@ -1017,7 +1000,7 @@ int optimize_cmdline(struct cmdline *cmdline) {
 			maxdepth = INT_MIN;
 		}
 		cmdline->maxdepth = maxdepth;
-		debug_opt(&state, "-O4: data flow: maxdepth --> %d\n", cmdline->maxdepth);
+		debug_opt(&state, 4, "data flow: maxdepth --> %d\n", cmdline->maxdepth);
 	}
 
 	return 0;
diff --git a/parse.c b/parse.c
index 8269d22..301e5df 100644
--- a/parse.c
+++ b/parse.c
@@ -207,44 +207,6 @@ static void expr_set_never_returns(struct expr *expr) {
 }
 
 /**
- * Dump the parsed expression tree, for debugging.
- */
-void dump_expr(CFILE *cfile, const struct expr *expr, bool verbose) {
-	fputs("(", cfile->file);
-
-	if (expr->lhs || expr->rhs) {
-		cfprintf(cfile, "${red}%s${rs}", expr->argv[0]);
-	} else {
-		cfprintf(cfile, "${blu}%s${rs}", expr->argv[0]);
-	}
-
-	for (size_t i = 1; i < expr->argc; ++i) {
-		cfprintf(cfile, " ${bld}%s${rs}", expr->argv[i]);
-	}
-
-	if (verbose) {
-		double rate = 0.0, time = 0.0;
-		if (expr->evaluations) {
-			rate = 100.0*expr->successes/expr->evaluations;
-			time = (1.0e9*expr->elapsed.tv_sec + expr->elapsed.tv_nsec)/expr->evaluations;
-		}
-		cfprintf(cfile, " [${ylw}%zu${rs}/${ylw}%zu${rs}=${ylw}%g%%${rs}; ${ylw}%gns${rs}]", expr->successes, expr->evaluations, rate, time);
-	}
-
-	if (expr->lhs) {
-		fputs(" ", cfile->file);
-		dump_expr(cfile, expr->lhs, verbose);
-	}
-
-	if (expr->rhs) {
-		fputs(" ", cfile->file);
-		dump_expr(cfile, expr->rhs, verbose);
-	}
-
-	fputs(")", cfile->file);
-}
-
-/**
  * An open file for the command line.
  */
 struct open_file {
@@ -392,11 +354,12 @@ static void parse_error(const struct parser_state *state, const char *format, ..
  * Print a warning message during parsing.
  */
 BFS_FORMATTER(2, 3)
-static void parse_warning(const struct parser_state *state, const char *format, ...) {
+static bool parse_warning(const struct parser_state *state, const char *format, ...) {
 	va_list args;
 	va_start(args, format);
-	bfs_vwarning(state->cmdline, format, args);
+	bool ret = bfs_vwarning(state->cmdline, format, args);
 	va_end(args);
+	return ret;
 }
 
 /**
@@ -917,8 +880,7 @@ static struct expr *parse_debug(struct parser_state *state, int arg1, int arg2)
 		for (int i = 0; ; ++i) {
 			const char *expected = debug_flags[i].name;
 			if (!expected) {
-				if (cmdline->warn) {
-					parse_warning(state, "Unrecognized debug flag ${bld}");
+				if (parse_warning(state, "Unrecognized debug flag ${bld}")) {
 					fwrite(flag, 1, len, stderr);
 					cfprintf(cmdline->cerr, "${rs}.\n\n");
 					unrecognized = true;
@@ -3351,7 +3313,11 @@ fail:
 /**
  * Dump the parsed form of the command line, for debugging.
  */
-void dump_cmdline(const struct cmdline *cmdline, bool verbose) {
+void dump_cmdline(const struct cmdline *cmdline, enum debug_flags flag) {
+	if (!bfs_debug_prefix(cmdline, flag)) {
+		return;
+	}
+
 	CFILE *cerr = cmdline->cerr;
 
 	cfprintf(cerr, "${ex}%s${rs} ", cmdline->argv[0]);
@@ -3444,7 +3410,11 @@ void dump_cmdline(const struct cmdline *cmdline, bool verbose) {
 		cfprintf(cerr, "${blu}-xdev${rs} ");
 	}
 
-	dump_expr(cerr, cmdline->expr, verbose);
+	if (flag == DEBUG_RATES) {
+		cfprintf(cerr, "%pE", cmdline->expr);
+	} else {
+		cfprintf(cerr, "%pe", cmdline->expr);
+	}
 
 	fputs("\n", stderr);
 }
@@ -3453,10 +3423,9 @@ void dump_cmdline(const struct cmdline *cmdline, bool verbose) {
  * Dump the estimated costs.
  */
 static void dump_costs(const struct cmdline *cmdline) {
-	CFILE *cerr = cmdline->cerr;
 	const struct expr *expr = cmdline->expr;
-	cfprintf(cerr, "       Cost: ~${ylw}%g${rs}\n", expr->cost);
-	cfprintf(cerr, "Probability: ~${ylw}%g%%${rs}\n", 100.0*expr->probability);
+	bfs_debug(cmdline, DEBUG_COST, "       Cost: ~${ylw}%g${rs}\n", expr->cost);
+	bfs_debug(cmdline, DEBUG_COST, "Probability: ~${ylw}%g%%${rs}\n", 100.0*expr->probability);
 }
 
 /**
@@ -3621,12 +3590,8 @@ struct cmdline *parse_cmdline(int argc, char *argv[]) {
 		cmdline->flags |= BFTW_DETECT_CYCLES;
 	}
 
-	if (cmdline->debug & DEBUG_TREE) {
-		dump_cmdline(cmdline, false);
-	}
-	if (cmdline->debug & DEBUG_COST) {
-		dump_costs(cmdline);
-	}
+	dump_cmdline(cmdline, DEBUG_TREE);
+	dump_costs(cmdline);
 
 done:
 	return cmdline;