Print failures in parallel make check (#9188)

Summary:
Generating megabytes of successful test output has caused
issues / inconveniences for CI and internal sandcastle runs. This
changes their configuration to only print output from failed tests.
(Successful test output is still available in files under t/.)

This likewise changes default behavior of parallel `make check` as
a quick team poll showed interest in that.

Pull Request resolved: https://github.com/facebook/rocksdb/pull/9188

Test Plan:
Seed some test failures and observe
* `make -j24 check` (new behavior)
* `PRINT_PARALLEL_OUTPUTS=1 make -j24 check` (old CI behavior)
* `QUIET_PARALLEL_TESTS=1 make -j24 check` (old manual run behavior)

Reviewed By: siying

Differential Revision: D32567392

Pulled By: pdillinger

fbshipit-source-id: 8d8fb64aebd16bca103b11e3bd1f13c488a69611

.circleci/config.yml

@@ -48,7 +48,6 @@ commands:
             echo "export GTEST_THROW_ON_FAILURE=0" >> $BASH_ENV
             echo "export GTEST_OUTPUT=\"xml:/tmp/test-results/\"" >> $BASH_ENV
             echo "export SKIP_FORMAT_BUCK_CHECKS=1" >> $BASH_ENV
-            echo "export PRINT_PARALLEL_OUTPUTS=1" >> $BASH_ENV
             echo "export GTEST_COLOR=1" >> $BASH_ENV
             echo "export CTEST_OUTPUT_ON_FAILURE=1" >> $BASH_ENV
             echo "export CTEST_TEST_TIMEOUT=300" >> $BASH_ENV

Makefile

@@ -834,9 +834,9 @@ $(parallel_tests): $(PARALLEL_TEST)
   TEST_NAMES=` \
     (./$$TEST_BINARY --gtest_list_tests || echo "  $${TEST_BINARY}__list_tests_failure") \
     | awk '/^[^ ]/ { prefix = $$1 } /^[ ]/ { print prefix $$1 }'`; \
+	echo "  Generating parallel test scripts for $$TEST_BINARY"; \
 	for TEST_NAME in $$TEST_NAMES; do \
 		TEST_SCRIPT=t/run-$$TEST_BINARY-$${TEST_NAME//\//-}; \
-		echo "  GEN     " $$TEST_SCRIPT; \
     printf '%s\n' \
       '#!/bin/sh' \
       "d=\$(TMPD)$$TEST_SCRIPT" \
@@ -883,12 +883,18 @@ J ?= 100%
 
 # Use this regexp to select the subset of tests whose names match.
 tests-regexp = .
-EXCLUDE_TESTS_REGEX ?= "^$"
+EXCLUDE_TESTS_REGEX ?= "^$$"
 
 ifeq ($(PRINT_PARALLEL_OUTPUTS), 1)
 	parallel_redir =
-else
+else ifeq ($(QUIET_PARALLEL_TESTS), 1)
 	parallel_redir = >& t/$(test_log_prefix)log-{/}
+else
+# Default: print failure output only, as it happens
+# Note: gnu_parallel --eta is now always used, but has been modified to provide
+# only infrequent updates when not connected to a terminal. (CircleCI will
+# kill a job if no output for 10min.)
+	parallel_redir = >& t/$(test_log_prefix)log-{/} || bash -c "cat t/$(test_log_prefix)log-{/}; exit $$?"
 endif
 
 .PHONY: check_0
@@ -897,7 +903,6 @@ check_0:
 	printf '%s\n' ''						\
 	  'To monitor subtest <duration,pass/fail,name>,'		\
 	  '  run "make watch-log" in a separate window' '';		\
-	test -t 1 && eta=--eta || eta=; \
 	{ \
 		printf './%s\n' $(filter-out $(PARALLEL_TEST),$(TESTS)); \
 		find t -name 'run-*' -print; \
@@ -905,7 +910,7 @@ check_0:
 	  | $(prioritize_long_running_tests)				\
 	  | grep -E '$(tests-regexp)'					\
 	  | grep -E -v '$(EXCLUDE_TESTS_REGEX)'					\
-	  | build_tools/gnu_parallel -j$(J) --plain --joblog=LOG $$eta --gnu '{} $(parallel_redir)' ; \
+	  | build_tools/gnu_parallel -j$(J) --plain --joblog=LOG --eta --gnu '{} $(parallel_redir)' ; \
 	parallel_retcode=$$? ; \
 	awk '{ if ($$7 != 0 || $$8 != 0) { if ($$7 == "Exitval") { h = $$0; } else { if (!f) print h; print; f = 1 } } } END { if(f) exit 1; }' < LOG ; \
 	awk_retcode=$$?; \
@@ -920,7 +925,6 @@ valgrind_check_0:
 	printf '%s\n' ''						\
 	  'To monitor subtest <duration,pass/fail,name>,'		\
 	  '  run "make watch-log" in a separate window' '';		\
-	test -t 1 && eta=--eta || eta=;					\
 	{								\
 	  printf './%s\n' $(filter-out $(PARALLEL_TEST) %skiplist_test options_settable_test, $(TESTS));		\
 	  find t -name 'run-*' -print; \
@@ -928,7 +932,7 @@ valgrind_check_0:
 	  | $(prioritize_long_running_tests)				\
 	  | grep -E '$(tests-regexp)'					\
 	  | grep -E -v '$(valgrind-exclude-regexp)'					\
-	  | build_tools/gnu_parallel -j$(J) --plain --joblog=LOG $$eta --gnu \
+	  | build_tools/gnu_parallel -j$(J) --plain --joblog=LOG --eta --gnu \
 	  '(if [[ "{}" == "./"* ]] ; then $(DRIVER) {}; else {}; fi) \
 	  $(parallel_redir)' \
 

build_tools/gnu_parallel

@@ -1561,6 +1561,7 @@ sub save_stdin_stdout_stderr {
 	::die_bug("Can't dup STDERR: $!");
     open $Global::original_stdin, "<&", "STDIN" or
 	::die_bug("Can't dup STDIN: $!");
+    $Global::is_terminal = (-t $Global::original_stderr);
 }
 
 sub enough_file_handles {
@@ -1840,12 +1841,17 @@ sub start_another_job {
 }
 }
 
+$opt::min_progress_interval = 0;
+
 sub init_progress {
     # Uses:
     #   $opt::bar
     # Returns:
     #   list of computers for progress output
     $|=1;
+    if (not $Global::is_terminal) {
+      $opt::min_progress_interval = 30;
+    }
     if($opt::bar) {
 	return("","");
     }
@@ -1870,6 +1876,7 @@ sub drain_job_queue {
     }
     my $last_header="";
     my $sleep = 0.2;
+    my $last_progress_time = 0;
     do {
         while($Global::total_running > 0) {
             debug($Global::total_running, "==", scalar
@@ -1880,7 +1887,8 @@ sub drain_job_queue {
 		    close $job->fh(0,"w");
 		}
 	    }
-            if($opt::progress) {
+            if($opt::progress and (time() - $last_progress_time) >= $opt::min_progress_interval) {
+                $last_progress_time = time();
                 my %progress = progress();
                 if($last_header ne $progress{'header'}) {
                     print $Global::original_stderr "\n", $progress{'header'}, "\n";

build_tools/rocksdb-lego-determinator

@@ -91,7 +91,7 @@ fi
 
 # Should probably be called PARALLEL_TEST
 if [ -z $PARALLEL_J ]; then
-  PARALLEL_J="PRINT_PARALLEL_OUTPUTS=1 J=$(expr $(nproc) / ${RATIO})"
+  PARALLEL_J="J=$(expr $(nproc) / ${RATIO})"
 fi
 
 # Should probably be called PARALLEL_MAKE