[PATCH v1 1/2] tools subcmd: Add check_if_command_finished

[PATCH v1 1/2] tools subcmd: Add check_if_command_finished

[Ian Rogers]

Add non-blocking function to check if a child_process has
completed. If the process has completed the exit code is stored in the
child_process so that finish_command returns it.

Signed-off-by: Ian Rogers <irogers@google.com>
---
 tools/lib/subcmd/run-command.c | 70 ++++++++++++++++++++++------------
 tools/lib/subcmd/run-command.h |  3 ++
 2 files changed, 49 insertions(+), 24 deletions(-)

diff --git a/tools/lib/subcmd/run-command.c b/tools/lib/subcmd/run-command.c
index d435eb42354b..4e3a557a2f37 100644
--- a/tools/lib/subcmd/run-command.c
+++ b/tools/lib/subcmd/run-command.c
@@ -165,43 +165,65 @@ int start_command(struct child_process *cmd)
 	return 0;
 }
 
-static int wait_or_whine(pid_t pid)
+static int wait_or_whine(struct child_process *cmd, bool block)
 {
-	char sbuf[STRERR_BUFSIZE];
+	bool finished = cmd->finished;
+	int result = cmd->finish_result;
 
-	for (;;) {
+	while (!finished) {
 		int status, code;
-		pid_t waiting = waitpid(pid, &status, 0);
+		pid_t waiting = waitpid(cmd->pid, &status, block ? 0 : WNOHANG);
+
+		if (!block && waiting == 0)
+			break;
+
+		if (waiting < 0 && errno == EINTR)
+			continue;
 
+		finished = true;
 		if (waiting < 0) {
-			if (errno == EINTR)
-				continue;
+			char sbuf[STRERR_BUFSIZE];
+
 			fprintf(stderr, " Error: waitpid failed (%s)",
 				str_error_r(errno, sbuf, sizeof(sbuf)));
-			return -ERR_RUN_COMMAND_WAITPID;
-		}
-		if (waiting != pid)
-			return -ERR_RUN_COMMAND_WAITPID_WRONG_PID;
-		if (WIFSIGNALED(status))
-			return -ERR_RUN_COMMAND_WAITPID_SIGNAL;
-
-		if (!WIFEXITED(status))
-			return -ERR_RUN_COMMAND_WAITPID_NOEXIT;
-		code = WEXITSTATUS(status);
-		switch (code) {
-		case 127:
-			return -ERR_RUN_COMMAND_EXEC;
-		case 0:
-			return 0;
-		default:
-			return -code;
+			result = -ERR_RUN_COMMAND_WAITPID;
+		} else if (waiting != cmd->pid) {
+			result = -ERR_RUN_COMMAND_WAITPID_WRONG_PID;
+		} else if (WIFSIGNALED(status)) {
+			result = -ERR_RUN_COMMAND_WAITPID_SIGNAL;
+		} else if (!WIFEXITED(status)) {
+			result = -ERR_RUN_COMMAND_WAITPID_NOEXIT;
+		} else {
+			code = WEXITSTATUS(status);
+			switch (code) {
+			case 127:
+				result = -ERR_RUN_COMMAND_EXEC;
+				break;
+			case 0:
+				result = 0;
+				break;
+			default:
+				result = -code;
+				break;
+			}
 		}
 	}
+	if (finished) {
+		cmd->finished = 1;
+		cmd->finish_result = result;
+	}
+	return result;
+}
+
+int check_if_command_finished(struct child_process *cmd)
+{
+	wait_or_whine(cmd, /*block=*/false);
+	return cmd->finished;
 }
 
 int finish_command(struct child_process *cmd)
 {
-	return wait_or_whine(cmd->pid);
+	return wait_or_whine(cmd, /*block=*/true);
 }
 
 int run_command(struct child_process *cmd)
diff --git a/tools/lib/subcmd/run-command.h b/tools/lib/subcmd/run-command.h
index d794138a797f..b2d39de6e690 100644
--- a/tools/lib/subcmd/run-command.h
+++ b/tools/lib/subcmd/run-command.h
@@ -41,17 +41,20 @@ struct child_process {
 	int err;
 	const char *dir;
 	const char *const *env;
+	int finish_result;
 	unsigned no_stdin:1;
 	unsigned no_stdout:1;
 	unsigned no_stderr:1;
 	unsigned exec_cmd:1; /* if this is to be external sub-command */
 	unsigned stdout_to_stderr:1;
+	unsigned finished:1;
 	void (*preexec_cb)(void);
 	 /* If set, call function in child rather than doing an exec. */
 	int (*no_exec_cmd)(struct child_process *process);
 };
 
 int start_command(struct child_process *);
+int check_if_command_finished(struct child_process *);
 int finish_command(struct child_process *);
 int run_command(struct child_process *);
 
-- 
2.44.0.478.gd926399ef9-goog

[PATCH v1 2/2] perf test: Display number of remaining tests

[Ian Rogers]

Before polling or sleeping to wait for a test to complete, print out
": Running (<num> remaining)" where the number of remaining tests is
determined by iterating over the remaining tests and seeing which
return true for check_if_command_finished. After the delay, erase the
line and either update it with the new number of remaining tests, or
print the test's result. This allows a user to know a test is running
and in parallel mode (default) how many of the tests are waiting to
complete. If color mode is disabled then avoid displaying the
"Running" message.

Signed-off-by: Ian Rogers <irogers@google.com>
---
 tools/perf/tests/builtin-test.c | 77 ++++++++++++++++++++++-----------
 tools/perf/util/color.h         |  1 +
 2 files changed, 53 insertions(+), 25 deletions(-)

diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c
index 73f53b02f733..15b8e8e32749 100644
--- a/tools/perf/tests/builtin-test.c
+++ b/tools/perf/tests/builtin-test.c
@@ -238,7 +238,10 @@ static int run_test_child(struct child_process *process)
 	return -err;
 }
 
-static int print_test_result(struct test_suite *t, int i, int subtest, int result, int width)
+#define TEST_RUNNING -3
+
+static int print_test_result(struct test_suite *t, int i, int subtest, int result, int width,
+			     int remaining)
 {
 	if (has_subtests(t)) {
 		int subw = width > 2 ? width - 2 : width;
@@ -248,6 +251,9 @@ static int print_test_result(struct test_suite *t, int i, int subtest, int resul
 		pr_info("%3d: %-*s:", i + 1, width, test_description(t, subtest));
 
 	switch (result) {
+	case TEST_RUNNING:
+		color_fprintf(stderr, PERF_COLOR_YELLOW, " Running (%d remaining)\n", remaining);
+		break;
 	case TEST_OK:
 		pr_info(" Ok\n");
 		break;
@@ -269,13 +275,15 @@ static int print_test_result(struct test_suite *t, int i, int subtest, int resul
 	return 0;
 }
 
-static int finish_test(struct child_test *child_test, int width)
+static int finish_test(struct child_test **child_tests, int running_test, int child_test_num,
+		       int width)
 {
+	struct child_test *child_test = child_tests[running_test];
 	struct test_suite *t = child_test->test;
 	int i = child_test->test_num;
 	int subi = child_test->subtest;
 	int err = child_test->process.err;
-	bool err_done = err <= 0;
+	bool err_done = false;
 	struct strbuf err_output = STRBUF_INIT;
 	int ret;
 
@@ -290,7 +298,7 @@ static int finish_test(struct child_test *child_test, int width)
 	 * Busy loop reading from the child's stdout/stderr that are set to be
 	 * non-blocking until EOF.
 	 */
-	if (!err_done)
+	if (err > 0)
 		fcntl(err, F_SETFL, O_NONBLOCK);
 	if (verbose > 1) {
 		if (has_subtests(t))
@@ -304,29 +312,48 @@ static int finish_test(struct child_test *child_test, int width)
 			  .events = POLLIN | POLLERR | POLLHUP | POLLNVAL,
 			},
 		};
-		char buf[512];
-		ssize_t len;
-
-		/* Poll to avoid excessive spinning, timeout set for 100ms. */
-		poll(pfds, ARRAY_SIZE(pfds), /*timeout=*/100);
-		if (!err_done && pfds[0].revents) {
-			errno = 0;
-			len = read(err, buf, sizeof(buf) - 1);
-
-			if (len <= 0) {
-				err_done = errno != EAGAIN;
-			} else {
-				buf[len] = '\0';
-				if (verbose > 1)
-					fprintf(stdout, "%s", buf);
-				else
+		if (perf_use_color_default) {
+			int tests_in_progress = running_test;
+
+			for (int y = running_test; y < child_test_num; y++) {
+				if (check_if_command_finished(&child_tests[y]->process))
+					tests_in_progress++;
+			}
+			print_test_result(t, i, subi, TEST_RUNNING, width,
+					  child_test_num - tests_in_progress);
+		}
+
+		err_done = true;
+		if (err <= 0) {
+			/* No child stderr to poll, sleep for 10ms for child to complete. */
+			usleep(10 * 1000);
+		} else {
+			/* Poll to avoid excessive spinning, timeout set for 100ms. */
+			poll(pfds, ARRAY_SIZE(pfds), /*timeout=*/100);
+			if (pfds[0].revents) {
+				char buf[512];
+				ssize_t len;
+
+				len = read(err, buf, sizeof(buf) - 1);
+
+				if (len > 0) {
+					err_done = false;
+					buf[len] = '\0';
 					strbuf_addstr(&err_output, buf);
+				}
 			}
 		}
+		if (err_done)
+			err_done = check_if_command_finished(&child_test->process);
+
+		if (perf_use_color_default) {
+			/* Erase "Running (.. remaining)" line printed before poll/sleep. */
+			fprintf(debug_file(), PERF_COLOR_DELETE_LINE);
+		}
 	}
 	/* Clean up child process. */
 	ret = finish_command(&child_test->process);
-	if (verbose == 1 && ret == TEST_FAIL) {
+	if (verbose > 1 || (verbose == 1 && ret == TEST_FAIL)) {
 		/* Add header for test that was skipped above. */
 		if (has_subtests(t))
 			pr_info("%3d.%1d: %s:\n", i + 1, subi + 1, test_description(t, subi));
@@ -335,7 +362,7 @@ static int finish_test(struct child_test *child_test, int width)
 		fprintf(stderr, "%s", err_output.buf);
 	}
 	strbuf_release(&err_output);
-	print_test_result(t, i, subi, ret, width);
+	print_test_result(t, i, subi, ret, width, /*remaining=*/0);
 	if (err > 0)
 		close(err);
 	return 0;
@@ -351,7 +378,7 @@ static int start_test(struct test_suite *test, int i, int subi, struct child_tes
 		pr_debug("--- start ---\n");
 		err = test_function(test, subi)(test, subi);
 		pr_debug("---- end ----\n");
-		print_test_result(test, i, subi, err, width);
+		print_test_result(test, i, subi, err, width, /*remaining=*/0);
 		return 0;
 	}
 
@@ -376,7 +403,7 @@ static int start_test(struct test_suite *test, int i, int subi, struct child_tes
 	err = start_command(&(*child)->process);
 	if (err || !sequential)
 		return  err;
-	return finish_test(*child, width);
+	return finish_test(child, /*running_test=*/0, /*child_test_num=*/1, width);
 }
 
 #define for_each_test(j, k, t)					\
@@ -461,7 +488,7 @@ static int __cmd_test(int argc, const char *argv[], struct intlist *skiplist)
 	}
 	for (i = 0; i < child_test_num; i++) {
 		if (!sequential) {
-			int ret  = finish_test(child_tests[i], width);
+			int ret  = finish_test(child_tests, i, child_test_num, width);
 
 			if (ret)
 				return ret;
diff --git a/tools/perf/util/color.h b/tools/perf/util/color.h
index 01f7bed21c9b..4b9f8d5d4439 100644
--- a/tools/perf/util/color.h
+++ b/tools/perf/util/color.h
@@ -22,6 +22,7 @@
 #define MIN_GREEN	0.5
 #define MIN_RED		5.0
 
+#define PERF_COLOR_DELETE_LINE	"\033[A\33[2K\r"
 /*
  * This variable stores the value of color.ui
  */
-- 
2.44.0.478.gd926399ef9-goog

Re: [PATCH v1 2/2] perf test: Display number of remaining tests

[Arnaldo Carvalho de Melo]

On Fri, Apr 05, 2024 at 12:09:31AM -0700, Ian Rogers wrote:
> Before polling or sleeping to wait for a test to complete, print out
> ": Running (<num> remaining)" where the number of remaining tests is
> determined by iterating over the remaining tests and seeing which
> return true for check_if_command_finished. After the delay, erase the
> line and either update it with the new number of remaining tests, or
> print the test's result. This allows a user to know a test is running
> and in parallel mode (default) how many of the tests are waiting to
> complete. If color mode is disabled then avoid displaying the
> "Running" message.

Tested and applied, great improvement!

- Arnaldo
 
> Signed-off-by: Ian Rogers <irogers@google.com>
> ---
>  tools/perf/tests/builtin-test.c | 77 ++++++++++++++++++++++-----------
>  tools/perf/util/color.h         |  1 +
>  2 files changed, 53 insertions(+), 25 deletions(-)
> 
> diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c
> index 73f53b02f733..15b8e8e32749 100644
> --- a/tools/perf/tests/builtin-test.c
> +++ b/tools/perf/tests/builtin-test.c
> @@ -238,7 +238,10 @@ static int run_test_child(struct child_process *process)
>  	return -err;
>  }
>  
> -static int print_test_result(struct test_suite *t, int i, int subtest, int result, int width)
> +#define TEST_RUNNING -3
> +
> +static int print_test_result(struct test_suite *t, int i, int subtest, int result, int width,
> +			     int remaining)
>  {
>  	if (has_subtests(t)) {
>  		int subw = width > 2 ? width - 2 : width;
> @@ -248,6 +251,9 @@ static int print_test_result(struct test_suite *t, int i, int subtest, int resul
>  		pr_info("%3d: %-*s:", i + 1, width, test_description(t, subtest));
>  
>  	switch (result) {
> +	case TEST_RUNNING:
> +		color_fprintf(stderr, PERF_COLOR_YELLOW, " Running (%d remaining)\n", remaining);
> +		break;
>  	case TEST_OK:
>  		pr_info(" Ok\n");
>  		break;
> @@ -269,13 +275,15 @@ static int print_test_result(struct test_suite *t, int i, int subtest, int resul
>  	return 0;
>  }
>  
> -static int finish_test(struct child_test *child_test, int width)
> +static int finish_test(struct child_test **child_tests, int running_test, int child_test_num,
> +		       int width)
>  {
> +	struct child_test *child_test = child_tests[running_test];
>  	struct test_suite *t = child_test->test;
>  	int i = child_test->test_num;
>  	int subi = child_test->subtest;
>  	int err = child_test->process.err;
> -	bool err_done = err <= 0;
> +	bool err_done = false;
>  	struct strbuf err_output = STRBUF_INIT;
>  	int ret;
>  
> @@ -290,7 +298,7 @@ static int finish_test(struct child_test *child_test, int width)
>  	 * Busy loop reading from the child's stdout/stderr that are set to be
>  	 * non-blocking until EOF.
>  	 */
> -	if (!err_done)
> +	if (err > 0)
>  		fcntl(err, F_SETFL, O_NONBLOCK);
>  	if (verbose > 1) {
>  		if (has_subtests(t))
> @@ -304,29 +312,48 @@ static int finish_test(struct child_test *child_test, int width)
>  			  .events = POLLIN | POLLERR | POLLHUP | POLLNVAL,
>  			},
>  		};
> -		char buf[512];
> -		ssize_t len;
> -
> -		/* Poll to avoid excessive spinning, timeout set for 100ms. */
> -		poll(pfds, ARRAY_SIZE(pfds), /*timeout=*/100);
> -		if (!err_done && pfds[0].revents) {
> -			errno = 0;
> -			len = read(err, buf, sizeof(buf) - 1);
> -
> -			if (len <= 0) {
> -				err_done = errno != EAGAIN;
> -			} else {
> -				buf[len] = '\0';
> -				if (verbose > 1)
> -					fprintf(stdout, "%s", buf);
> -				else
> +		if (perf_use_color_default) {
> +			int tests_in_progress = running_test;
> +
> +			for (int y = running_test; y < child_test_num; y++) {
> +				if (check_if_command_finished(&child_tests[y]->process))
> +					tests_in_progress++;
> +			}
> +			print_test_result(t, i, subi, TEST_RUNNING, width,
> +					  child_test_num - tests_in_progress);
> +		}
> +
> +		err_done = true;
> +		if (err <= 0) {
> +			/* No child stderr to poll, sleep for 10ms for child to complete. */
> +			usleep(10 * 1000);
> +		} else {
> +			/* Poll to avoid excessive spinning, timeout set for 100ms. */
> +			poll(pfds, ARRAY_SIZE(pfds), /*timeout=*/100);
> +			if (pfds[0].revents) {
> +				char buf[512];
> +				ssize_t len;
> +
> +				len = read(err, buf, sizeof(buf) - 1);
> +
> +				if (len > 0) {
> +					err_done = false;
> +					buf[len] = '\0';
>  					strbuf_addstr(&err_output, buf);
> +				}
>  			}
>  		}
> +		if (err_done)
> +			err_done = check_if_command_finished(&child_test->process);
> +
> +		if (perf_use_color_default) {
> +			/* Erase "Running (.. remaining)" line printed before poll/sleep. */
> +			fprintf(debug_file(), PERF_COLOR_DELETE_LINE);
> +		}
>  	}
>  	/* Clean up child process. */
>  	ret = finish_command(&child_test->process);
> -	if (verbose == 1 && ret == TEST_FAIL) {
> +	if (verbose > 1 || (verbose == 1 && ret == TEST_FAIL)) {
>  		/* Add header for test that was skipped above. */
>  		if (has_subtests(t))
>  			pr_info("%3d.%1d: %s:\n", i + 1, subi + 1, test_description(t, subi));
> @@ -335,7 +362,7 @@ static int finish_test(struct child_test *child_test, int width)
>  		fprintf(stderr, "%s", err_output.buf);
>  	}
>  	strbuf_release(&err_output);
> -	print_test_result(t, i, subi, ret, width);
> +	print_test_result(t, i, subi, ret, width, /*remaining=*/0);
>  	if (err > 0)
>  		close(err);
>  	return 0;
> @@ -351,7 +378,7 @@ static int start_test(struct test_suite *test, int i, int subi, struct child_tes
>  		pr_debug("--- start ---\n");
>  		err = test_function(test, subi)(test, subi);
>  		pr_debug("---- end ----\n");
> -		print_test_result(test, i, subi, err, width);
> +		print_test_result(test, i, subi, err, width, /*remaining=*/0);
>  		return 0;
>  	}
>  
> @@ -376,7 +403,7 @@ static int start_test(struct test_suite *test, int i, int subi, struct child_tes
>  	err = start_command(&(*child)->process);
>  	if (err || !sequential)
>  		return  err;
> -	return finish_test(*child, width);
> +	return finish_test(child, /*running_test=*/0, /*child_test_num=*/1, width);
>  }
>  
>  #define for_each_test(j, k, t)					\
> @@ -461,7 +488,7 @@ static int __cmd_test(int argc, const char *argv[], struct intlist *skiplist)
>  	}
>  	for (i = 0; i < child_test_num; i++) {
>  		if (!sequential) {
> -			int ret  = finish_test(child_tests[i], width);
> +			int ret  = finish_test(child_tests, i, child_test_num, width);
>  
>  			if (ret)
>  				return ret;
> diff --git a/tools/perf/util/color.h b/tools/perf/util/color.h
> index 01f7bed21c9b..4b9f8d5d4439 100644
> --- a/tools/perf/util/color.h
> +++ b/tools/perf/util/color.h
> @@ -22,6 +22,7 @@
>  #define MIN_GREEN	0.5
>  #define MIN_RED		5.0
>  
> +#define PERF_COLOR_DELETE_LINE	"\033[A\33[2K\r"
>  /*
>   * This variable stores the value of color.ui
>   */
> -- 
> 2.44.0.478.gd926399ef9-goog

Re: [PATCH v1 2/2] perf test: Display number of remaining tests

[Ian Rogers]

On Mon, Apr 8, 2024 at 7:12 AM Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
>
> On Fri, Apr 05, 2024 at 12:09:31AM -0700, Ian Rogers wrote:
> > Before polling or sleeping to wait for a test to complete, print out
> > ": Running (<num> remaining)" where the number of remaining tests is
> > determined by iterating over the remaining tests and seeing which
> > return true for check_if_command_finished. After the delay, erase the
> > line and either update it with the new number of remaining tests, or
> > print the test's result. This allows a user to know a test is running
> > and in parallel mode (default) how many of the tests are waiting to
> > complete. If color mode is disabled then avoid displaying the
> > "Running" message.
>
> Tested and applied, great improvement!

And I think it is broken. Specifically I think the nohang waitpid can
cause the later read of the stdout/err pipe to fail. We may need to
drain the files before checking. I suspect this as I've seen an
increase test fails where the verbose output shows nothing. The only
remedy for that in the current code would be to run the tests
sequentially, so we should probably back this out for now.

Thanks,
Ian

> - Arnaldo
>
> > Signed-off-by: Ian Rogers <irogers@google.com>
> > ---
> >  tools/perf/tests/builtin-test.c | 77 ++++++++++++++++++++++-----------
> >  tools/perf/util/color.h         |  1 +
> >  2 files changed, 53 insertions(+), 25 deletions(-)
> >
> > diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c
> > index 73f53b02f733..15b8e8e32749 100644
> > --- a/tools/perf/tests/builtin-test.c
> > +++ b/tools/perf/tests/builtin-test.c
> > @@ -238,7 +238,10 @@ static int run_test_child(struct child_process *process)
> >       return -err;
> >  }
> >
> > -static int print_test_result(struct test_suite *t, int i, int subtest, int result, int width)
> > +#define TEST_RUNNING -3
> > +
> > +static int print_test_result(struct test_suite *t, int i, int subtest, int result, int width,
> > +                          int remaining)
> >  {
> >       if (has_subtests(t)) {
> >               int subw = width > 2 ? width - 2 : width;
> > @@ -248,6 +251,9 @@ static int print_test_result(struct test_suite *t, int i, int subtest, int resul
> >               pr_info("%3d: %-*s:", i + 1, width, test_description(t, subtest));
> >
> >       switch (result) {
> > +     case TEST_RUNNING:
> > +             color_fprintf(stderr, PERF_COLOR_YELLOW, " Running (%d remaining)\n", remaining);
> > +             break;
> >       case TEST_OK:
> >               pr_info(" Ok\n");
> >               break;
> > @@ -269,13 +275,15 @@ static int print_test_result(struct test_suite *t, int i, int subtest, int resul
> >       return 0;
> >  }
> >
> > -static int finish_test(struct child_test *child_test, int width)
> > +static int finish_test(struct child_test **child_tests, int running_test, int child_test_num,
> > +                    int width)
> >  {
> > +     struct child_test *child_test = child_tests[running_test];
> >       struct test_suite *t = child_test->test;
> >       int i = child_test->test_num;
> >       int subi = child_test->subtest;
> >       int err = child_test->process.err;
> > -     bool err_done = err <= 0;
> > +     bool err_done = false;
> >       struct strbuf err_output = STRBUF_INIT;
> >       int ret;
> >
> > @@ -290,7 +298,7 @@ static int finish_test(struct child_test *child_test, int width)
> >        * Busy loop reading from the child's stdout/stderr that are set to be
> >        * non-blocking until EOF.
> >        */
> > -     if (!err_done)
> > +     if (err > 0)
> >               fcntl(err, F_SETFL, O_NONBLOCK);
> >       if (verbose > 1) {
> >               if (has_subtests(t))
> > @@ -304,29 +312,48 @@ static int finish_test(struct child_test *child_test, int width)
> >                         .events = POLLIN | POLLERR | POLLHUP | POLLNVAL,
> >                       },
> >               };
> > -             char buf[512];
> > -             ssize_t len;
> > -
> > -             /* Poll to avoid excessive spinning, timeout set for 100ms. */
> > -             poll(pfds, ARRAY_SIZE(pfds), /*timeout=*/100);
> > -             if (!err_done && pfds[0].revents) {
> > -                     errno = 0;
> > -                     len = read(err, buf, sizeof(buf) - 1);
> > -
> > -                     if (len <= 0) {
> > -                             err_done = errno != EAGAIN;
> > -                     } else {
> > -                             buf[len] = '\0';
> > -                             if (verbose > 1)
> > -                                     fprintf(stdout, "%s", buf);
> > -                             else
> > +             if (perf_use_color_default) {
> > +                     int tests_in_progress = running_test;
> > +
> > +                     for (int y = running_test; y < child_test_num; y++) {
> > +                             if (check_if_command_finished(&child_tests[y]->process))
> > +                                     tests_in_progress++;
> > +                     }
> > +                     print_test_result(t, i, subi, TEST_RUNNING, width,
> > +                                       child_test_num - tests_in_progress);
> > +             }
> > +
> > +             err_done = true;
> > +             if (err <= 0) {
> > +                     /* No child stderr to poll, sleep for 10ms for child to complete. */
> > +                     usleep(10 * 1000);
> > +             } else {
> > +                     /* Poll to avoid excessive spinning, timeout set for 100ms. */
> > +                     poll(pfds, ARRAY_SIZE(pfds), /*timeout=*/100);
> > +                     if (pfds[0].revents) {
> > +                             char buf[512];
> > +                             ssize_t len;
> > +
> > +                             len = read(err, buf, sizeof(buf) - 1);
> > +
> > +                             if (len > 0) {
> > +                                     err_done = false;
> > +                                     buf[len] = '\0';
> >                                       strbuf_addstr(&err_output, buf);
> > +                             }
> >                       }
> >               }
> > +             if (err_done)
> > +                     err_done = check_if_command_finished(&child_test->process);
> > +
> > +             if (perf_use_color_default) {
> > +                     /* Erase "Running (.. remaining)" line printed before poll/sleep. */
> > +                     fprintf(debug_file(), PERF_COLOR_DELETE_LINE);
> > +             }
> >       }
> >       /* Clean up child process. */
> >       ret = finish_command(&child_test->process);
> > -     if (verbose == 1 && ret == TEST_FAIL) {
> > +     if (verbose > 1 || (verbose == 1 && ret == TEST_FAIL)) {
> >               /* Add header for test that was skipped above. */
> >               if (has_subtests(t))
> >                       pr_info("%3d.%1d: %s:\n", i + 1, subi + 1, test_description(t, subi));
> > @@ -335,7 +362,7 @@ static int finish_test(struct child_test *child_test, int width)
> >               fprintf(stderr, "%s", err_output.buf);
> >       }
> >       strbuf_release(&err_output);
> > -     print_test_result(t, i, subi, ret, width);
> > +     print_test_result(t, i, subi, ret, width, /*remaining=*/0);
> >       if (err > 0)
> >               close(err);
> >       return 0;
> > @@ -351,7 +378,7 @@ static int start_test(struct test_suite *test, int i, int subi, struct child_tes
> >               pr_debug("--- start ---\n");
> >               err = test_function(test, subi)(test, subi);
> >               pr_debug("---- end ----\n");
> > -             print_test_result(test, i, subi, err, width);
> > +             print_test_result(test, i, subi, err, width, /*remaining=*/0);
> >               return 0;
> >       }
> >
> > @@ -376,7 +403,7 @@ static int start_test(struct test_suite *test, int i, int subi, struct child_tes
> >       err = start_command(&(*child)->process);
> >       if (err || !sequential)
> >               return  err;
> > -     return finish_test(*child, width);
> > +     return finish_test(child, /*running_test=*/0, /*child_test_num=*/1, width);
> >  }
> >
> >  #define for_each_test(j, k, t)                                       \
> > @@ -461,7 +488,7 @@ static int __cmd_test(int argc, const char *argv[], struct intlist *skiplist)
> >       }
> >       for (i = 0; i < child_test_num; i++) {
> >               if (!sequential) {
> > -                     int ret  = finish_test(child_tests[i], width);
> > +                     int ret  = finish_test(child_tests, i, child_test_num, width);
> >
> >                       if (ret)
> >                               return ret;
> > diff --git a/tools/perf/util/color.h b/tools/perf/util/color.h
> > index 01f7bed21c9b..4b9f8d5d4439 100644
> > --- a/tools/perf/util/color.h
> > +++ b/tools/perf/util/color.h
> > @@ -22,6 +22,7 @@
> >  #define MIN_GREEN    0.5
> >  #define MIN_RED              5.0
> >
> > +#define PERF_COLOR_DELETE_LINE       "\033[A\33[2K\r"
> >  /*
> >   * This variable stores the value of color.ui
> >   */
> > --
> > 2.44.0.478.gd926399ef9-goog

Re: [PATCH v1 2/2] perf test: Display number of remaining tests

[Arnaldo Carvalho de Melo]

On Thu, Apr 11, 2024 at 10:22:42PM -0700, Ian Rogers wrote:
> On Mon, Apr 8, 2024 at 7:12 AM Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> >
> > On Fri, Apr 05, 2024 at 12:09:31AM -0700, Ian Rogers wrote:
> > > Before polling or sleeping to wait for a test to complete, print out
> > > ": Running (<num> remaining)" where the number of remaining tests is
> > > determined by iterating over the remaining tests and seeing which
> > > return true for check_if_command_finished. After the delay, erase the
> > > line and either update it with the new number of remaining tests, or
> > > print the test's result. This allows a user to know a test is running
> > > and in parallel mode (default) how many of the tests are waiting to
> > > complete. If color mode is disabled then avoid displaying the
> > > "Running" message.
> >
> > Tested and applied, great improvement!
> 
> And I think it is broken. Specifically I think the nohang waitpid can
> cause the later read of the stdout/err pipe to fail. We may need to
> drain the files before checking. I suspect this as I've seen an
> increase test fails where the verbose output shows nothing. The only
> remedy for that in the current code would be to run the tests
> sequentially, so we should probably back this out for now.

Removing it then,

- Arnaldo