Re: [PATCH v2 1/2] selftests/harness: Move test child waiting logic

[Kees Cook <keescook@chromium.org>]

On Mon, Mar 23, 2020 at 12:08:13PM -0600, shuah wrote:
> Hi Kees,
> 
> On 3/13/20 5:12 PM, Kees Cook wrote:
> > In order to better handle timeout failures, rearrange the child waiting
> > logic into a separate function. This is mostly a copy/paste with an
> > indentation change. To handle pid tracking, a new field is added for
> > the child pid. Also move the alarm() pairing into the function.
> > 
> > Signed-off-by: Kees Cook <keescook@chromium.org>
> 
> Sorry for the delay. I was on vacation all of last week
> and totally trying to stay away from checking email.

Indeed; that's what vacation is for! :)

> My commit scripts falied on checkpatch warnings.

All the macros in this file tend to anger checkpatch. ;)

> 
> A couple of comments below:
> 
> 
> > ---
> >   tools/testing/selftests/kselftest_harness.h | 93 +++++++++++----------
> >   1 file changed, 49 insertions(+), 44 deletions(-)
> >  > diff --git a/tools/testing/selftests/kselftest_harness.h
> b/tools/testing/selftests/kselftest_harness.h
> > index 5336b26506ab..c7b67e379219 100644
> > --- a/tools/testing/selftests/kselftest_harness.h
> > +++ b/tools/testing/selftests/kselftest_harness.h
> > @@ -635,6 +635,7 @@
> >   struct __test_metadata {
> >   	const char *name;
> >   	void (*fn)(struct __test_metadata *);
> > +	pid_t pid;	/* pid of test when being run */
> >   	int termsig;
> >   	int passed;
> >   	int trigger; /* extra handler after the evaluation */
> > @@ -695,64 +696,68 @@ static inline int __bail(int for_realz, bool no_print, __u8 step)
> >   	return 0;
> >   }
> > -void __run_test(struct __test_metadata *t)
> > +void __wait_for_test(struct __test_metadata *t)
> >   {
> > -	pid_t child_pid;
> >   	int status;
> > +	alarm(t->timeout);
> > +	waitpid(t->pid, &status, 0);
> > +	alarm(0);
> > +
> > +	if (WIFEXITED(status)) {
> > +		t->passed = t->termsig == -1 ? !WEXITSTATUS(status) : 0;
> > +		if (t->termsig != -1) {
> > +			fprintf(TH_LOG_STREAM,
> > +				"%s: Test exited normally "
> > +				"instead of by signal (code: %d)\n",
> > +				t->name,
> > +				WEXITSTATUS(status));
> 
> This one isn't an error and gets printed to stderr? Except for
> this one message, all other messages in this routine are indeed
> errors. It makes sense to print this out to stdout instead.

No, this is an error. A signal was _expected_ in this case, but the
program exited without a signal. i.e. the test case failed, and the
error is reported to stderr.

(This portion, btw, is just moved from below.)

> 
> > +		} else if (!t->passed) {
> > +			fprintf(TH_LOG_STREAM,
> > +				"%s: Test failed at step #%d\n",
> > +				t->name,
> > +				WEXITSTATUS(status));
> > +		}
> > +	} else if (WIFSIGNALED(status)) {
> > +		t->passed = 0;
> > +		if (WTERMSIG(status) == SIGABRT) {
> > +			fprintf(TH_LOG_STREAM,
> > +				"%s: Test terminated by assertion\n",
> > +				t->name);
> > +		} else if (WTERMSIG(status) == t->termsig) {
> > +			t->passed = 1;
> > +		} else {
> > +			fprintf(TH_LOG_STREAM,
> > +				"%s: Test terminated unexpectedly "
> > +				"by signal %d\n",
> > +				t->name,
> > +				WTERMSIG(status));
> > +		}
> > +	} else {
> > +		fprintf(TH_LOG_STREAM,
> > +			"%s: Test ended in some other way [%u]\n",
> > +			t->name,
> > +			status);
> > +	}
> > +}
> > +
> > +void __run_test(struct __test_metadata *t)
> > +{
> >   	t->passed = 1;
> >   	t->trigger = 0;
> >   	printf("[ RUN      ] %s\n", t->name);
> > -	alarm(t->timeout);
> > -	child_pid = fork();
> > -	if (child_pid < 0) {
> > +	t->pid = fork();
> > +	if (t->pid < 0) {
> >   		printf("ERROR SPAWNING TEST CHILD\n");
> >   		t->passed = 0;
> > -	} else if (child_pid == 0) {
> > +	} else if (t->pid == 0) {
> >   		t->fn(t);
> >   		/* return the step that failed or 0 */
> >   		_exit(t->passed ? 0 : t->step);
> >   	} else {
> > -		/* TODO(wad) add timeout support. */
> > -		waitpid(child_pid, &status, 0);
> > -		if (WIFEXITED(status)) {
> > -			t->passed = t->termsig == -1 ? !WEXITSTATUS(status) : 0;
> > -			if (t->termsig != -1) {
> > -				fprintf(TH_LOG_STREAM,
> > -					"%s: Test exited normally "
> > -					"instead of by signal (code: %d)\n",
> > -					t->name,
> > -					WEXITSTATUS(status));
> > -			} else if (!t->passed) {
> > -				fprintf(TH_LOG_STREAM,
> > -					"%s: Test failed at step #%d\n",
> > -					t->name,
> > -					WEXITSTATUS(status));
> > -			}
> > -		} else if (WIFSIGNALED(status)) {
> > -			t->passed = 0;
> > -			if (WTERMSIG(status) == SIGABRT) {
> > -				fprintf(TH_LOG_STREAM,
> > -					"%s: Test terminated by assertion\n",
> > -					t->name);
> > -			} else if (WTERMSIG(status) == t->termsig) {
> > -				t->passed = 1;
> > -			} else {
> > -				fprintf(TH_LOG_STREAM,
> > -					"%s: Test terminated unexpectedly "
> > -					"by signal %d\n",
> > -					t->name,
> > -					WTERMSIG(status));
> > -			}
> > -		} else {
> > -			fprintf(TH_LOG_STREAM,
> > -				"%s: Test ended in some other way [%u]\n",
> > -				t->name,
> > -				status);
> > -		}
> > +		__wait_for_test(t);
> >   	}
> >   	printf("[     %4s ] %s\n", (t->passed ? "OK" : "FAIL"), t->name);
> > -	alarm(0);
> >   }
> >   static int test_harness_run(int __attribute__((unused)) argc,
> > 
> 
> thanks,
> -- Shuah

Hopefully that clears it up. I don't see anything to change for a v2?
Did I miss anything?

Thanks!

-Kees

-- 
Kees Cook