Implement -D rates.

4 files changed, 93 insertions, 16 deletions

diff --git a/RELEASES.md b/RELEASES.md
index cdfd778..83007c8 100644
--- a/RELEASES.md
+++ b/RELEASES.md
@@ -24,6 +24,7 @@
 - Treat `-`, `)`, and `,` as paths when required to by POSIX
   - `)` and `,` are only supported before the expression begins
 - Implement `-D opt`
+- Implement `-D rates`
 - Implement `-fprint`
 - Implement `-fprint0`
 
diff --git a/bfs.h b/bfs.h
index 1ebbf0d..fc2bcc8 100644
--- a/bfs.h
+++ b/bfs.h
@@ -54,11 +54,13 @@ typedef bool eval_fn(const struct expr *expr, struct eval_state *state);
  */
 enum debug_flags {
 	/** Print optimization details. */
-	DEBUG_OPT  = 1 << 0,
+	DEBUG_OPT   = 1 << 0,
+	/** Print rate information. */
+	DEBUG_RATES = 1 << 1,
 	/** Trace all stat() calls. */
-	DEBUG_STAT = 1 << 1,
+	DEBUG_STAT  = 1 << 2,
 	/** Print the parse tree. */
-	DEBUG_TREE = 1 << 2,
+	DEBUG_TREE  = 1 << 3,
 };
 
 /**
@@ -173,6 +175,13 @@ struct expr {
 	/** Whether this expression has no side effects. */
 	bool pure;
 
+	/** Number of times this predicate was executed. */
+	size_t evaluations;
+	/** Number of times this predicate succeeded. */
+	size_t successes;
+	/** Total time spent running this predicate. */
+	struct timespec elapsed;
+
 	/** The number of command line arguments for this expression. */
 	size_t argc;
 	/** The command line arguments comprising this expression. */
@@ -215,6 +224,11 @@ struct expr {
 struct cmdline *parse_cmdline(int argc, char *argv[]);
 
 /**
+ * Dump the parsed command line.
+ */
+void dump_cmdline(const struct cmdline *cmdline, bool verbose);
+
+/**
  * Evaluate the command line.
  */
 int eval_cmdline(const struct cmdline *cmdline);
diff --git a/eval.c b/eval.c
index f7292a2..48603fb 100644
--- a/eval.c
+++ b/eval.c
@@ -743,10 +743,49 @@ bool eval_xtype(const struct expr *expr, struct eval_state *state) {
 }
 
 /**
+ * Record the time that elapsed evaluating an expression.
+ */
+static void add_elapsed(struct expr *expr, const struct timespec *start, const struct timespec *end) {
+	expr->elapsed.tv_sec += end->tv_sec - start->tv_sec;
+	expr->elapsed.tv_nsec += end->tv_nsec - start->tv_nsec;
+	if (expr->elapsed.tv_nsec < 0) {
+		expr->elapsed.tv_nsec += 1000000000L;
+		--expr->elapsed.tv_sec;
+	} else if (expr->elapsed.tv_nsec >= 1000000000L) {
+		expr->elapsed.tv_nsec -= 1000000000L;
+		++expr->elapsed.tv_sec;
+	}
+}
+
+/**
  * Evaluate an expression.
  */
-static bool eval_expr(const struct expr *expr, struct eval_state *state) {
-	return expr->eval(expr, state);
+static bool eval_expr(struct expr *expr, struct eval_state *state) {
+	struct timespec start, end;
+	bool time = state->cmdline->debug & DEBUG_RATES;
+	if (time) {
+		if (clock_gettime(CLOCK_MONOTONIC, &start) != 0) {
+			perror("clock_gettime()");
+			time = false;
+		}
+	}
+
+	bool ret = expr->eval(expr, state);
+
+	if (time) {
+		if (clock_gettime(CLOCK_MONOTONIC, &end) == 0) {
+			add_elapsed(expr, &start, &end);
+		} else {
+			perror("clock_gettime()");
+		}
+	}
+
+	++expr->evaluations;
+	if (ret) {
+		++expr->successes;
+	}
+
+	return ret;
 }
 
 /**
@@ -943,5 +982,9 @@ int eval_cmdline(const struct cmdline *cmdline) {
 		}
 	}
 
+	if (cmdline->debug & DEBUG_RATES) {
+		dump_cmdline(cmdline, true);
+	}
+
 	return args.ret;
 }
diff --git a/parse.c b/parse.c
index a448289..1b963c3 100644
--- a/parse.c
+++ b/parse.c
@@ -84,6 +84,10 @@ static struct expr *new_expr(eval_fn *eval, bool pure, size_t argc, char **argv)
 		expr->lhs = NULL;
 		expr->rhs = NULL;
 		expr->pure = pure;
+		expr->evaluations = 0;
+		expr->successes = 0;
+		expr->elapsed.tv_sec = 0;
+		expr->elapsed.tv_nsec = 0;
 		expr->argc = argc;
 		expr->argv = argv;
 		expr->file = NULL;
@@ -124,7 +128,7 @@ static struct expr *new_binary_expr(eval_fn *eval, struct expr *lhs, struct expr
 /**
  * Dump the parsed expression tree, for debugging.
  */
-static void dump_expr(const struct expr *expr) {
+static void dump_expr(const struct expr *expr, bool verbose) {
 	fputs("(", stderr);
 
 	for (size_t i = 0; i < expr->argc; ++i) {
@@ -134,14 +138,23 @@ static void dump_expr(const struct expr *expr) {
 		fputs(expr->argv[i], stderr);
 	}
 
+	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;
+		}
+		fprintf(stderr, " [%zu/%zu=%g%%; %gns]", expr->successes, expr->evaluations, rate, time);
+	}
+
 	if (expr->lhs) {
 		fputs(" ", stderr);
-		dump_expr(expr->lhs);
+		dump_expr(expr->lhs, verbose);
 	}
 
 	if (expr->rhs) {
 		fputs(" ", stderr);
-		dump_expr(expr->rhs);
+		dump_expr(expr->rhs, verbose);
 	}
 
 	fputs(")", stderr);
@@ -245,7 +258,7 @@ static void debug_opt(const struct parser_state *state, const char *format, ...)
 				break;
 
 			case 'e':
-				dump_expr(va_arg(args, const struct expr *));
+				dump_expr(va_arg(args, const struct expr *), false);
 				break;
 			}
 		} else {
@@ -584,15 +597,18 @@ static struct expr *parse_debug(struct parser_state *state) {
 	if (strcmp(flag, "help") == 0) {
 		printf("Supported debug flags:\n\n");
 
-		printf("  help:  This message.\n");
-		printf("  opt:   Print optimization details.\n");
-		printf("  stat:  Trace all stat() calls.\n");
-		printf("  tree:  Print the parse tree.\n");
+		printf("  help:   This message.\n");
+		printf("  opt:    Print optimization details.\n");
+		printf("  rates:  Print predicate success rates.\n");
+		printf("  stat:   Trace all stat() calls.\n");
+		printf("  tree:   Print the parse tree.\n");
 
 		state->just_info = true;
 		return NULL;
 	} else if (strcmp(flag, "opt") == 0) {
 		cmdline->debug |= DEBUG_OPT;
+	} else if (strcmp(flag, "rates") == 0) {
+		cmdline->debug |= DEBUG_RATES;
 	} else if (strcmp(flag, "stat") == 0) {
 		cmdline->debug |= DEBUG_STAT;
 	} else if (strcmp(flag, "tree") == 0) {
@@ -1799,7 +1815,7 @@ static struct expr *optimize_whole_expr(const struct parser_state *state, struct
 /**
  * Dump the parsed form of the command line, for debugging.
  */
-static void dump_cmdline(const struct cmdline *cmdline) {
+void dump_cmdline(const struct cmdline *cmdline, bool verbose) {
 	if (cmdline->flags & BFTW_FOLLOW_NONROOT) {
 		fputs("-L ", stderr);
 	} else if (cmdline->flags & BFTW_FOLLOW_ROOT) {
@@ -1815,6 +1831,9 @@ static void dump_cmdline(const struct cmdline *cmdline) {
 	if (cmdline->debug & DEBUG_OPT) {
 		fputs("-D opt ", stderr);
 	}
+	if (cmdline->debug & DEBUG_RATES) {
+		fputs("-D rates ", stderr);
+	}
 	if (cmdline->debug & DEBUG_STAT) {
 		fputs("-D stat ", stderr);
 	}
@@ -1844,7 +1863,7 @@ static void dump_cmdline(const struct cmdline *cmdline) {
 		fputs("-nocolor ", stderr);
 	}
 
-	dump_expr(cmdline->expr);
+	dump_expr(cmdline->expr, verbose);
 
 	fputs("\n", stderr);
 }
@@ -1925,7 +1944,7 @@ struct cmdline *parse_cmdline(int argc, char *argv[]) {
 	}
 
 	if (cmdline->debug & DEBUG_TREE) {
-		dump_cmdline(cmdline);
+		dump_cmdline(cmdline, 0);
 	}
 
 done: